indelog 1.0.0

An extension of the standard logging package with indentation, severity coloring, default formatting and saving, trace level.

Indented Logger

An extension of the standard logging package, supplying:

• block indentation,
• severity coloring,
• default formatting and saving,
• dedicated level for control flow tracing.

Contents

1. Installation
2. Usage
   • Setup
   • Indentation
   • Verbosity levels
   • Namespace
   • Message prefix
   • Automated logging
   • Tracing recommendation

1. Installation

1.1 From PyPI index

The most straightforward way:

$ pip install indelog

1.2 From GitHub sources

If you plan to play with the code and make improvements, use editable mode with dev dependencies:

$ git clone https://github.com/petergee302/indelog.git .
$ pip install -e .[dev]

Run static code analysis and automated tests before each push:

$ pyright
$ pytest -vs

2. Usage

2.1 Setup

The recommended way to initialize and configure this logger is to use the with ilog.Setup(...) clause which guarantees the entry/exit points to be executed:

import ilog
...
with ilog.Setup() as logger:
    ...

There are several options to this object that control e.g. the global level or output file:

• global_level (str or int from ilog.LEVELS): Verbosity level to set for the logger. Can be either the name or the numerical value corresponding to the level. The default value of logging.NOTSET does not change current threshold.
• output_path (str or Path): Where to save the log file: This can be either complete file path, or a directory. In the latter case module_fname is required.
• module_fname: If given, its base name will be combined with given directory path and extension to build module-related log file. For instance train.py will become <output_path>/train.log
• namespace (str): If given, overrides the namespace
• colorize (bool): Enable/disable colored console output (notice, if enabled the escape sequences also appear in the file)
• line_format (str): Message prefix to override the default format.

Example:

Create <module>-<timestamp>.log file besides the executing <module>.py file. All messages within the two trace calls will be indented at least once.

import ilog
...
if __name__ == '__main__':
    with ilog.Setup(ilog.TRACE, __file__) as logger:
        logger.trace(f'> main')
        ...
        logger.trace(f'< main')

2.2 Indentation

The major shortcoming of the default logging module is the lack of block indentation mechanism. This is particularly painful when trying to analyze the control flow of a long, real-time, multi-turn, possibly multi-threaded or asynchronous code, like user interaction, or REST interface of a service. Debugging is basically excluded in these cases, and simple status printing does very poor job, if any.

Log indentation serves the same purpose as indentation of the code that generated it: To structure the flow into nested blocks that are much easier to understand. The difference is that while the code reflects the 'spatial' structure of an algorithm, the logs are its 'temporal' signature.

In Python one can use decorators to capture the entry and exit points of a function or method, nevertheless it is not recommended to use it as default means of logging due to (i) noticeable overhead, and (ii) lack of control over the selection and format of arguments and returned values.

In this module we use manual marking of the entry and exit points of a block. This has some pros and cons of course, but the need to control what and how to log is definitely more important than a desire to just dump everything automatically on a single press of a button.

There are two indentation markers:

• > = begin indented block starting next line
• < = end of a block and unindent

Example:

def fun() -> int:
    logger.debug('> fun()')
    result = gun(2)//3
    logger.debug('< fun(): %d', result)
    return result

def gun(arg :int) -> int:
    logger.debug('> gun(arg=%d)', arg)
    result = 5*hun(arg + 1)
    logger.debug('< gun(): %d', result)
    return result

def hun(arg :int) -> int:
    result = 13 + arg
    logger.debug('hun(arg=%d): %d', arg, result)
    return result

The above code would give output like this:

🔎 DEBUG   2025-11-26 14:13:23.731 78F45860B080 > fun()
🔎 DEBUG   2025-11-26 14:13:23.732 78F45860B080   > gun(arg=2)
🔎 DEBUG   2025-11-26 14:13:23.732 78F45860B080     hun(arg=3): 16
🔎 DEBUG   2025-11-26 14:13:23.732 78F45860B080   < gun(): 80
🔎 DEBUG   2025-11-26 14:13:23.732 78F45860B080 < fun(): 26

Notice that (i) the indentation is used only in nested functions; there's no point in nesting inside hun() because it neither calls any other function that logs, nor performs any time-consuming work. (ii) we use consistent convention to format the arguments and returned values. more on that in the last section.

2.3 Verbosity levels

Verbosity level is a severity threshold above which messages are passed to the handlers. There is one global level set by either:

• ILOG_VERBOSITY_LEVEL = ... environment variable, or
• Setup(global_level = ...) argument during initialization

And there are local levels which can be set when fetching local loggers:

• getLogger(local_level = ...)

The effective level within module is the maximum of the two, for instance:

    local  global  effective
    -----  ------  ---------
    DEBUG   INFO     INFO
    ERROR   INFO     ERROR

💀 FATAL:

This level indicates a critical error that causes the application to abort or terminate. It is used for unrecoverable errors that require immediate attention, such as a system crash or an application shutdown.

💥 ERROR:

This level signifies a significant problem that prevents a specific operation from being completed. While the application may continue running, this level alerts teams to critical issues that need immediate investigation and resolution.

⚠️ WARNING:

This level is used for unexpected events that do not prevent the application from functioning but may indicate potential problems. It is often used to signal conditions that are close to causing errors, such as approaching resource limits.

💬 INFO:

This level is used for general operational messages that provide information about the normal flow of the application. It is suitable for tracking typical operations, such as successful logins or service startups.

🐾 TRACE:

This level is used for tracing the execution flow of the application, and is not part of the standard Python logger. It is typically employed during development or debugging sessions to monitor the sequence of function calls and execution paths. Trace logs should provide object types and unique identifiers of their instances to allow object-level resolution of information.

🔎 DEBUG:

This level provides the most detailed information useful for diagnosing problems. It is typically used during development or troubleshooting to trace application state, variable values, and business logic decisions. Since this type of logs may output frequently and in large volumes necessary to understand particular problem, it may have significant impact on the performance. Python does not have preprocessor like C/C++ which could automatically eliminate preparation of data for such calls, the only available remedies are to condition the logger.debug() call, or simply not to push such debug logs to the repository.

2.4 Namespace

The IndentedLogger derives from, but does not modify the default root logger. Hence, all its instances must have non-empty namespace i.e. a name prefix distinguishing from loggers created by other packages in use. There are two ways the namespace may be specified by:

• ILOG_NAMESPACE = ... environment variable, or by
• Setup(namespace = ...) argument during initialization

2.5 Message prefix

By default all output messages are prefixed with additional information containing the event severity, its ISO date-time up to millisecond, and the thread ID of origin. Examples are given below:

💥 ERROR   2019-02-27 02:13:24.632 753DCED0A180 TrainingHistory.teardown(): UNEXPECTED_CALL
⚠️ WARNING 2020-12-01 12:58:34.763 7F46F17AA700 Job d50395084c9f4cfdb0c73190b740465d already removed
🐾 TRACE   2023-06-08 21:04:45.158 7036CCD1D080 DensityMatrix[7035BB4622D0](size=2)
🔎 DEBUG   2025-10-21 11:26:05.830 78F45860B080 n_samples=5674

The second part of the prefix can be modified (e.g. the thread ID removed, if not needed) by either:

• ILOG_LINE_FORMAT environment variable, or by
• Setup(line_format = ...) argument during initialization

2.6 Automated logging

As projects get shorter and shorter time-frames, hardly anyone has enough patience to go through the entire code weaving in such a lines. For those who seek error-resistance and uniformity despite lesser control and bigger overhead, there are set of decorators that make the logging automated. There are two kind of each:

call	Log arguments and result after exit of a function/method
block	Log arguments before the entry of a function/method, and result after its exit

They operate on function, method, and whole class level (the latter may be particularly useful if you just need to trace your code execution, but have no time for applying the logs):

function-level	@fatal_function_call(), @error_function_call(), @warning_function_call(), @info_function_call(), @trace_function_call(), @debug_function_call(), @fatal_function_block(), @error_function_block(), @warning_function_block(), @info_function_block(), @trace_function_block(), @debug_function_block(),
method-level	@fatal_method_call(), @error_method_call(), @warning_method_call(), @info_method_call(), @trace_method_call(), @debug_method_call(), @fatal_method_block(), @error_method_block(), @warning_method_block(), @info_method_block(), @trace_method_block(), @debug_method_block(),
class-level	@fatal_calls(), @error_calls(), @warning_calls(), @info_calls(), @trace_calls(), @debug_calls(), @fatal_blocks(), @error_blocks(), @warning_blocks(), @info_blocks(), @trace_blocks(), @debug_blocks(),

The drawbacks of using automated logs is that

• there's no control over which arguments and return values are serialized, what sometimes may backfire resulting in a cluttered and less readable console output, instead of a clear trace.
• they do not capture any internal working of a function/method, nor signal any state or stage changes; they are primarily intended for tracing.

Example:

Instead of

def fun() -> int:
    logger.debug('> fun()')
    result = ...
    logger.debug('< fun(): %d', result)
    return result

One can equivalently write

@debug_function_block(logger)
def fun() -> int:
    result = ...
    return result

Instead of painstakingly applying logs to all methods of a class

class A:
    def __init(self, ...):
        logger.trace(...)
        ...

you can simply use class-level decorator

@trace_calls(logger)
class A:
    def __init(self, ...):
        ...

2.7 Tracing recommendation

Standard Python logger is not designed with execution tracing in mind, thus there's no TRACE level, nor there's a convention on what and when to log. Herein we outline such proposal based on past experiences from over a couple of decades.

1. First of all, log the creation of objects (in C/C++ we'd also log destruction thereof).

2. Unless the object is a singleton, log its unique ID for the sake of distinguishing them in the trace, for example:

   def __init__(self, arg1 :int, arg2 :bool):
       logger.trace(f'ClassName[{id(self):012X}]({arg1=}, {arg2=})')
   

3. Unless the class is final replace the explicit ClassName above with {type(self).__name__} in order to make dynamic substitution:

   def __init__(self, arg1 :int, arg2 :bool):
       logger.trace(f'{type(self).__name__}[{id(self):012X}]({arg1=}, {arg2=})')
   

4. If the function or method is time-consuming, may crash, or causes other log messages to appear, use indentation with at least two messages marking both entry and exit points:

   def method(self, arg3 :str) -> float:
       logger.trace(f'> {type(self).__name__}[{id(self):012X}].method({arg3=})')
       ...
       logger.trace(f'< {type(self).__name__}[{id(self):012X}].method(): {result=}')
       return result
   

   Do not use indentation in functions or methods that are quick to complete and do not invoke other logging code.

5. The above logs are pretty standard, but long enough to make room for mistakes. In order to reduce their chances, bring the number of return statements to bare minimum, ideally to just one. That means instead of the usual code like:

   if condition-one:
       logger.trace(f'< some_function(): {x}')
       return x
   ...
   if condition-two:
       logger.trace(f'< some_function(): {y}')
       return y
   ...
   logger.trace(f'< some_function(): {z}')
   return z
   

   write

   if condition-one:
       result = x
   else:
       ...
       if condition-two:
           result = y
       else:
           ...
           result = z
   logger.trace(f'< some_function(): {result}')
   return result
   

   or use function/method/class decorators to automate logging.

6. In order to reduce chances for mistakes and inconsistency, prefer automated logging over manual. It is also the easier way to start with.

   Use manual logging if the automated one is insufficient, e.g.: it formats and prints large values which are not particularly important, or prints too much or too little, inundates the stream or does not capture some important elements.

---

Copyright © 2018-2025 Peter Gee
MIT License