Similar to the idea that code comments help developers read code, log messages help everyone understand the progress and problems of a running program. In Python, loggingmodule from the Standard Library provides the functionality and flexibility to produce professional log messages.

Compared to print, which can display console output directly, logging has the advantage of easily differentiating message severities, appearances, origins, and destinations. What’s more, instead of deleting print statements for debugging when shipping the code, logging.debug can remain intact in the source code and remain dormant until they are needed again by modifying the severity level of the logger and handler.

Basic logging

The below snippet provides a concise and helpful usage example when logging from a single main file. The console sys.stderr is used to output log messages if filename is not specified in basicConfig().

import logging

logging.basicConfig(level=logging.DEBUG, 
                    format='%(asctime)s %(levelname)s: %(message)s',  # default: %(levelname)s:%(name)s:%(message)s
                    datefmt='%m-%d %H:%M',  # default: '%Y-%m-%d %H:%M:%S,uuu'
                    filename='myapp.log', filemode='w')

logging.debug('report detailed information for diagnostic purposes')
logging.info('report expected normal progress for confirmation purposes')
logging.warning('report particular runtime events that should be noted')
logging.error('report errors that the program has not been able to funtion')
logging.critical('report critical errors')
logging.log(logging.DEBUG, 'report custom log levels')

Levels

Messages are catogorized on their severity levels, which are internally integer constants in the logging module. There are 6 pre-defined logging levels for use.

Level Value
logging.NOTSET 0
logging.DEBUG 10
logging.INFO 20
logging.WARNING (=logging.WARN) 30
logging.ERROR 40
logging.CRITICAL (= logging.FATAL) 50

Level of messages should not be less severe than level of logger and handlers in order for the messages to show up. When using syntax like logging.debug(), messages are logged on the root logger; since the default level of the root logger is logging.WARNING, debug and info messages will be ignored.

Formats

Formats specify how messages are rendered as text, i.e. which attributes are included and how they are cancatenated together. By default, percent style is used when specifying the formatting string.

Format (percent style) Description
%(name)s name of the logger
%(asctime)s human-readable time when the message was created
%(levelname)s Text logging level for the message
%(pathname)s full pathname of the source file where the logging call was issued
%(message)s the result of record.getMessage()
%(filename)s filename portion of pathname
%(module)s name portion of filename
%(funcName)s function name where the logging call was issued
%(lineno)d line number in the source file where the logging call was issued

Advanced logging

When logging from multiple modules, flexibility is limited when using only the root logger and one set of configuration defined by logging.basicConfig(). This is where logging.getLogger() come into stage - multiple loggers with different configurations can be created and used depending on the module.

Under the hood, messages are passed among loggers, handlers, filters, and formatters in LogRecord instances.

Structure of `logging` Classes (inspired by [Ref.5](#Reference))

There are three ways to create a set of configuration:

  1. Creating logging objects and calling their configuration methods explicitly using Python code

  2. Creating a config file and reading it using logging.config.fileConfig()

  3. Creating a dictionary and passing it to logging.config.dictConfig(); the dictionary schema is as follows; for the case where there is a configuring dict (loggers, handlers, filters, formatters specifically), the special key '()' means a custom user-defined instantiation is used, and its value should be a callable or a string that will be used with normal import mechanisms.

    • version - the only valid value at present is 1
    • disable_existing_loggers - recommended setting is False
    • incremental - default to False
    • root - configuration for the root logger; it’s equivalent to setting logger with id '' in loggers
    • loggers - key is id, value is a dict describing how to configure the corresponding instance; keys in its configuring dict:
    • optional: level, propagate, filters, handlers
    • handlers - same as above; keys in its configuring dict:
    • mandatory: class
    • optional: level, formatter, filters, others as keyword arguments to the handler’s constructor
    • filters
    • formatters - same as above; keys in its configuring dict:
    • optional: format (fmt), datefmt

Loggers

Logger name can be anything that indicate in which area of the program the message originated, however, it is conventional to use __name__, i.e. module-level loggers. '' is the name of the root logger.

Similar to hierarchical module names, logger names are also hierarchically separated by periods. For example, logger with name foo.bar is a descendant of foo.

  • If level of a logger is not explicitly set, the level of its parent is used.
  • Messages of a logger are also passed to its ancestor loggers’ handlers by default (propagate=True). To avoid the same record emitting mulitple times, it is conventional to attach handlers only to the root logger, so it will see all events logged by all descendant loggers.

Configuration methods of logger objects include:

  • logger.setLevel()
  • logger.addHandler() and logger.removeHandler()
  • logger.addFilter() and logger.removeFilter()

On the other hand, a configuration dictionary example for loggers is shown below:

'loggers': {
  '': {
    'leve': 'INFO',
    'handlers': ['handler_1']
  }
  'module_1': {
    'level': 'INFO',
    'handlers': ['handler_1', 'handler_2'],
    'propagate': False
  },
  'module_1.module_2': {
    'level': 'ERROR',
    'handlers': ['handler_2'],
    'propagate': False
  }
}

Handler

Destinations of log messages are served by handlers. There are a variety of built-in handler classes for use, such as:

  • logging.StreamHandler: send log messages to streams, i.e. any object which supports write() and flush() methods. If argument stream is not specified, sys.stderr is used as default.
  • logging.FileHandler: send log messages to a disk file. Arguments example: mode='w', encoding='utf-8'.
  • logging.handlers.RotatingFileHandler: rollover to a new file when current file reaches maxBytes in length. Arguments example: mode='a', maxBytes=1024*1024*10, backupCount=1.
  • logging.handlers.SMTPHandler: send log messages to an email address via SMTP.

Configuration methods of handler objects include:

  • handler.setLevel()
  • handler.setFormatter()
  • handler.addFilter() and handler.removeFilter()

On the other hand, a configuration dictionary example for handlers is shown below:

'handlers': {
  'console': {
    'level': 'DEBUG',
    'class': 'logging.StreamHandler',
    'formatter': 'simple'
  },
  'logfile': {
    'level': 'INFO',
    'class': 'logging.handlers.RotatingFileHandler',
    'formatter': 'verbose',
    'filename': 'example.log',
    'maxBytes': 1024 * 1024 * 10,
    'backupCount': 1
  }
}

Filters

Formatter

Formatter instances are used to convert a LogRecord to text. The base logging.Formatter class has three optional arguments in the constructor - a message format string fmt, a date format string datefmt, and a style indicator style, which is one of '%' (default), '{', '$'.

'formatters': {
  'verbose': {
    '()': CustomeFormatterClass,
    'format': '%(levelname)s %(asctime)s %(module)s %(process)d %(thread)d %(message)s',
    'datefmt': '%Y-%m-%dT%H:%M:%S%z'
  },
  'simple': {
    'format': '{levelname} {message}',
    'style': '{'
  }
}

Hack into implementation

class LogRecord():
  def __init__(self, name, level, pathname, lineno, 
               msg, args, exc_info, func=None, sinfo=None, **kwargs):
    ...
    
  def __repr__(self):
    return '<LogRecord: %s, %s, %s, %s, "%s">'%(self.name, self.levelno,
            self.pathname, self.lineno, self.msg)
  
  def getMessage(self):
    msg = str(self.msg)
    if self.args:
      msg = msg % self.args
    return 

class Handler(Filterer):
  def __init__(self, level=NONSET):
    Filterer.__init__(self)
    self._name = None
    self.level = _checkLevel(level)
    self.formatter = None
    ...
    
  def handle(self, record):
    ...
    
  def emit(self, record):
    ...

References

  1. logging - Logging facility for Python, https://docs.python.org/3/library/logging.html
  2. Logging HOWTO, Vinay Sajip, https://docs.python.org/3/howto/logging.html
  3. Logging Cookbook, Vinay Sajip, https://docs.python.org/3/howto/logging-cookbook.html
  4. Django Documentation - Logging, https://docs.djangoproject.com/en/3.2/topics/logging/
  5. A guided tour of Python logging, Curtis Maloney, https://www.youtube.com/watch?v=DxZ5WEo4hvU