Logging in Python - Pseudocode

logging_pseudocode.py

"""Pseudocode for how logging works.

The logic taken directly from the standard library's implementation
in `logging/__init__.py`.

Only important aspects of the implementation were picked out for
clarity. To get all details check the docs [1] and the source
code [2].

Interesting observations:
- Level checking and filtering takes place both in loggers and handlers.
- By default logging propagates and all handlers of all parent loggers
  are called. That's why it's often enough to only configure the root
  logger.
- The logger's level checking and filtering only takes place once in the
  called (leaf) logger, but not in the parent loggers.
- In contrast, level checking and filtering always takes place in all
  handlers.
- So, the called logger decides alone if the log message comes in and
  becomes a log record. But every single handler decides individually
  if the log record comes out and is emitted.

Not shown in the pseudocode, but also interesting
- Logger instances live in a global state, `logging.getLogger(name)`
  with the same `name` will not create a new instance but return the
  existing one, even if called in a different module.
- The full logger hierarchy is always created and updated. The non-
  existing loggers are represented by placeholer loggers. For example,
  after calling `logging.getLogger("a.b.c")` the global state is
  `[Logger("a.b.c"), PlaceHolder("a.b"), PlaceHolder("a"), RootLogger("")]`.
- If later `logging.getLogger("a")` is called, then `PlaceHolder("a")`
  will be replaced by `Logger("a")` and returned. 

[1] https://docs.python.org/3/library/logging.html
[2] https://github.com/python/cpython/blob/3.9/Lib/logging/__init__.py
"""

class Filterer:
    """Filterer for log records.
    
    Note that both loggers and handlers inherit from filterer. That's
    because log records are filtered in
    
    - the leaf logger that was called (but not in the parent loggers)
    - all handlers that are called (also those of the parent loggers)
    
    See below and pay attention to where filtering takes place.
    """
    def __init__(self):
        self.filters = [...]
        
    def filter(self, record):
        for f in self.filters:
            if not f(record):
                return False
        return True


class Logger(Filterer):

    def __init__(self):
        self.level = ...
        self.handlers = [...]
        self.disabled = False

    @property
    def effective_level(self):
        logger = self
        while logger:
            if logger.level:
                return logger.level
            logger = logger.parent
        return 0  # = NOTSET
    
    def debug(self, msg):
        self.log("DEBUG", msg)
        # And similar for other levels.
    
    def log(self, level, msg):
        if self.disabled or level < self.effective_level:
            return
        
        record = make_record(msg, level)
        if not self.filter(record):
            return
        
        for logger in [self] + self.parent_stack:
            for handler in logger.handlers:
                if record.level >= handler.level:
                    handler.handle(record)
            if not logger.propagate:
                # stop after the first logger that doesn't propagate
                return  
 

class Handler(Filterer):
    
    def __init__(self):
        self.level = ...
        self.formatter = ...
    
    def handle(self, record):
        if not self.filter(record):
            return
        
        # Simplest handling. In reality handlers do whatever they want with the record.
        msg = self.formatter(record)
        print(msg)