Skip to content

Logger Config

Rohit Kaushik edited this page Apr 9, 2018 · 9 revisions

Best practices for logger module as used in IRCLogParser project.

Logging vs Print?

The only time that print is a better option than logging is when the goal is to display a help statement for a command line application. Other reasons why logging is better than print:

  • The log record, which is created with every logging event, contains readily available diagnostic information such as the file name, full path, function, and line number of the logging event.
  • Events logged in included modules are automatically accessible via the root logger to your application’s logging stream, unless you filter them out.
  • Logging can be selectively silenced by using the method logging.Logger.setLevel() or disabled by setting the attribute logging.Logger.disabled to True.

This StackOverflow answer provides good points in favor of logging.

Configuring Logging

  • If logging doesn't to be configured heavily and user wishes to use basic configuration then python logging library provides a basicConfig function to configure logging in the code itself.
import logging

# create logger
logger = logging.getLogger('simple_example')
logger.setLevel(logging.DEBUG)

# create console handler and set level to debug
ch = logging.StreamHandler()
ch.setLevel(logging.DEBUG)

# create formatter
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')

# add formatter to ch
ch.setFormatter(formatter)

# add ch to logger
logger.addHandler(ch)
  • Providing config file (ini, yaml, json) The logging config module provides a fileConfig function which can take a .ini, .yaml, or json specification and parse the config from the file.
import logging
import logging.config

logging.config.fileConfig('logging.conf')

# create logger
logger = logging.getLogger('simpleExample')

# 'application' code
logger.debug('debug message')
logger.info('info message')
logger.warn('warn message')
logger.error('error message')
logger.critical('critical message')

An example config file is:

[loggers]
keys=root,simpleExample

[handlers]
keys=consoleHandler

[formatters]
keys=simpleFormatter

[logger_root]
level=DEBUG
handlers=consoleHandler

[logger_simpleExample]
level=DEBUG
handlers=consoleHandler
qualname=simpleExample
propagate=0

[handler_consoleHandler]
class=StreamHandler
level=DEBUG
formatter=simpleFormatter
args=(sys.stdout,)

[formatter_simpleFormatter]
format=%(asctime)s - %(name)s - %(levelname)s - %(message)s
datefmt=

Configuration in Library

Libraries should log messages and it is the user's responsibility to handle these messages (i.e redirect the logs to desired output stream). This provides the user's the flexibility to redirect log message's to different handlers and also control the severity of message logged.

Keeping this in mind, the library should only add a NULL handler to logger to avoid handler not found error.

import logging
logging.getLogger('foo').addHandler(logging.NullHandler())

Logger naming and Configuration in __init__.py

The convention is to name the logger object based on the module. Since logger is now names same as the module, we will know the origin of logged event based on logger name.

logging.getLogger(__name__).addHandler(logging.NullHandler())

We use the __name__ variable to name the logger while configuring the logging in libraries since when the module is imported by user, the logger will be set to module name. i.e The value of __name__ variable is set to module name when the .py file is imported else it is "__main__".

  • Libraries logging configuration can be placed in __init__.py.
  • Whenever a module is imported, the code present inside __init__.py is executed first and hence any import done in __init__.py is available when the module is imported.
  • So our directory structure is with the logging config present in __init__.py and hence when user import any module from lib the logger is also present.
IRCLogparser/lib/
IRCLogparser/lib/__init__.py
IRCLogparser/lib/* (other modules)

Guide to Developers for configuring logging

  1. A default config ini file has been provided. To be able to see or redirect log messages library users need to either add handlers explicity or use or modify default config.
  2. To be able to use the config file, developers need to include the following code after importing the module.
lib_directory = os.path.join(os.path.dirname(os.path.realpath(__file__)), "lib")
fileConfig(os.path.join(lib_directory, 'logging_config.ini'))

Modifying Default Config.ini

  • The default config file is located in lib/logging_config.ini. Developers can copy and modify the default config file as per their usage requirement.
  • The first important thing to remember is that logger objects are named same as the modules they are used. So to be able to recieve the log messages for a particular module say module A, the config.ini file should have configuration for logger named A.
[logger_root]
level=DEBUG
handlers=stream_handler

[logger_log_download]
level=DEBUG
handlers=stream_handler
qualname=log_download
  • In the above code snippet, two loggers are defined log_download and root. The log_download logger will be used for the log_download.py module. Similarly other logger objects should be configured.

  • The default configuration is to redirect the log messages to a file. This is best suited for our library which also uses stdout to display results.

  • To be able to redirect log messages, the logger in config.ini should have a handler associated with it and the handler should be configured with an output stream. The handler object handles the messages and redirects it to the output stream.

[logger_log_download]
level=DEBUG
handlers=stream_handler
qualname=log_download

[handler_stream_handler]
class=StreamHandler
level=DEBUG
formatter=formatter
args=(sys.stderr,)

[formatter_formatter]
format=%(asctime)s  %(levelname)s -- %(processName)s %(filename)s:%(lineno)s -- %(message)s
  • The above code snippet demonstrate how to add a handler and stream to a logger. Every stream handler should also have a formatter which formats the log message to include details like processName, fileName which cause the message and line no.

  • The link describes different handler available in logging module.

Specifying multiple loggers and handlers

  • Logging library allows users to declare multiple logger object and handlers. Our library assumes a module level logger object. Hence the configuration file has loggers named for every module. If a logger is not defined then the root logger will be used as default.
  • The logging module has a parent-child hierarchy for logger objects with root as the parent and another logger as root children.
  • Also, we can define multiple handlers to be used by different loggers. This allows us to handle logs differently for the different module. i.e
[loggers]
keys=root, lib.log_download, lib.util

[handlers]
keys=stream_handler, file_handler

[formatters]
keys=formatter

[logger_root]
level=DEBUG
handlers=stream_handler

[logger_lib.log_download]
level=DEBUG
handlers=file_handler
qualname=lib.log_download


[logger_lib.util]
level=DEBUG
handlers=stream_handler
qualname=lib.util

The above code snippet demonstrate defining multiple loggers and handlers.

Severity level

  • Every Severity Level has a value associated with it. If we set severity level as INFO, then all the messages with severity above this level will be printed.
CRITICAL 50
ERROR 	 40
WARNING  30
INFO 	 20
DEBUG 	 10
NOTSET 	 0
  • In libraries, the configuration is done by users of library and hence severity level is also decided by the user.
What Severity Level to use?
  • Generally while executing the code the logging level should be set to WARNING so that user is able to receive any possible failure. The warning can help in identifying the cause of an ERROR.
  • While debugging i.e when you encounter an error with the code and don't know the cause of the error, the severity level to be used is DEBUG.
  • INFO provides information about the task being performed in the functions and can be useful in scenarios when performing analysis for longer durations which can run for a long time and INFO logs may provide the current progress or what is being currently executed.
  • ERROR - These logs messages when the current execution cannot proceed any further.
  • CRITICAL - The critical messages are those that occur if there is data corruption or loss. The following link has the further resources for using different log levels.

Handlers

  • The Handler class handlers the log messages and direct to correct output stream.
  • Generally we prefer logs to be redirected to files since the stdout can be polluted with lot of different informations.
  • The python docs explains different handlers present their functionality.
  • The Logging module defines several output stream as well which can be used.
  • Again, libraries allow users to define handlers and output streams as per their usage and hence we only add a null handler to loggers to avoid the NO HANDLER FOUND Exception.

Examples

  • Let us consider a library module that uses logging. For our example, we consider the log_download module. logger_downloader.py

  • The lib/__init__.py file is as follows:-

# Set default logging handler to avoid "No handler found" warnings.
import logging
try # Python 2.7+
    from logging import NullHandler
except ImportError:
    class NullHandler(logging.Handler):
        def emit(self, record):
            pass

logging.getLogger(__name__).addHandler(NullHandler())
  • The user should now configure logging when using the log_downloader module to receive log messages

Sample Usage:

import os
import datetime
import logging
from logging.config import fileConfig
import lib.log_download as downloader

fileConfig(os.path.join(os.path.dirname(os.path.realpath(__file__)), 'logging_config.ini'))

s_dt = datetime.datetime(2016, 1, 1)
e_dt = datetime.datetime(2017, 1, 1)

downloader.fetch_logs(s_dt, e_dt, downloader.ubuntu_url, save_dir=os.path.join(os.getcwd(),"logs/ubuntu"))

Further Resources