Python logging library logging summary – probably the best article summarizing the logging library so far

When deploying a project, it is impossible to output all the information directly to the console. We can record this information in a log file, which not only makes it convenient for us to view the status of the program during runtime, but also allows us to quickly locate the problem based on the logs generated during runtime when a project fails.

1. Log level

Python standard library logging is used for logging. By default, there are six log levels (the brackets are the corresponding values ​​of the levels): NOTSET (0), DEBUG (10), INFO (20), WARNING (30), ERROR (40), and CRITICAL (50). When we customize the log level, we should be careful not to use the same value as the default log level. When logging is executed, log information greater than or equal to the set log level will be output. If the log level is set to INFO, then logs of the INFO, WARNING, ERROR, and CRITICAL levels will be output.

2. Logging Process

The official logging module workflow diagram is as follows:

From the figure below we can see these Python types, Logger , LogRecord , Filter , Handler , Formatter .

Type description:

Logger : Logs, exposes functions to the application, and decides which logs are valid based on the logger and filter level.

LogRecord : Logger, which passes the log to the corresponding processor for processing.

Handler : Processor, sends log records (generated by the logger) to the appropriate destination.

Filter : Filters provide finer granularity control over which log records are output.

Formatter : Formatter, which specifies the layout of log records in the final output.

1. Determine whether the Logger object is available for the set level. If it is available, execute below, otherwise, the process ends.
2. Create a LogRecord object. If the Filter object registered in the Logger object returns False after filtering, no log is recorded and the process ends. Otherwise, the process continues.
3. The LogRecord object passes the Handler object to the current Logger object. (The subprocess in the figure) If the log level of the Handler object is greater than the set log level, it determines whether the Filter object registered in the Handler object returns True after filtering and allows the output of log information. Otherwise, it does not allow the output and the process ends.
4. If the level of the passed Handler is greater than the level set in the Logger, that is, the Handler is valid, the process will continue, otherwise, the process ends.
5. Determine whether this Logger object has a parent Logger object. If not (it means the current Logger object is the top-level Logger object, the root Logger), the process ends. Otherwise, set the Logger object to its parent Logger object, repeat steps 3 and 4 above, and output the log output in the parent class Logger object until it is the root Logger.

3. Log output format

The output format of the log can be set. The default format is as shown in the figure below.

4. Basic use

Logging is very simple to use. The basicConfig() method can meet basic usage needs. If no parameters are passed into the method, a Logger object will be created according to the default configuration. The default log level is set to WARNING . The default log output format is as shown above. The optional parameters of this function are shown in the following table.

The sample code is as follows:

import logging

logging.basicConfig()
logging.debug('This is a debug message')
logging.info('This is an info message')
logging.warning('This is a warning message')
logging.error('This is an error message')
logging.critical('This is a critical message')

The output is as follows:

WARNING:root:This is a warning message
ERROR:root:This is an error message
CRITICAL:root:This is a critical message

Pass in common parameters. The sample code is as follows (the variables in the log format placeholder are introduced later):

import logging

logging.basicConfig(filename="test.log", filemode="w", format="%(asctime)s %(name)s:%(levelname)s:%(message)s", datefmt="%d-%m-%Y %H:%M:%S", level=logging.DEBUG)
logging.debug('This is a debug message')
logging.info('This is an info message')
logging.warning('This is a warning message')
logging.error('This is an error message')
logging.critical('This is a critical message')

The generated log file test.log has the following content:

13-10-18 21:10:32 root:DEBUG:This is a debug message
13-10-18 21:10:32 root:INFO:This is an info message
13-10-18 21:10:32 root:WARNING:This is a warning message
13-10-18 21:10:32 root:ERROR:This is an error message
13-10-18 21:10:32 root:CRITICAL:This is a critical message

However, when an exception occurs, directly using the debug(), info(), warning(), error(), and critical() methods without parameters cannot record the exception information. You need to set the exc_info parameter to True, or use the exception() method. You can also use the log() method, but you also need to set the log level and exc_info parameter.

import logging

logging.basicConfig(filename="test.log", filemode="w", format="%(asctime)s %(name)s:%(levelname)s:%(message)s", datefmt="%d-%M-%Y %H:%M:%S", level=logging.DEBUG)
a = 5
b = 0
try:
    c = a / b
except Exception as e:
    logging.exception("Exception occurred")
    logging.error("Exception occurred", exc_info=True)
    logging.log(level=logging.DEBUG, msg="Exception occurred", exc_info=True)

5. Custom Logger

The above basic usage allows us to quickly get started with the logging module, but it generally cannot meet the actual use. We also need to customize the Logger.

A system has only one Logger object, and this object cannot be instantiated directly. Yes, the singleton pattern is used here, and the method to obtain the Logger object is getLogger .

Note: The singleton mode here does not mean that there is only one Logger object, but that there is only one root Logger object in the entire system. When the Logger object executes methods such as info() and error(), it actually calls the info() and error() methods corresponding to the root Logger object.

We can create multiple Logger objects, but the root Logger object is the one that actually outputs logs. Each Logger object can be set with a name. If set logger = logging.getLogger(__name__), __name__ is a special built-in variable in Python that represents the name of the current module (__main__ by default). The name of the Logger object is recommended to use a namespace hierarchy with dots as separators.

Logger objects can set multiple Handler objects and Filter objects, and Handler objects can set Formatter objects. Formatter objects are used to set specific output formats. Common variable formats are shown in the following table. For all parameters, see the official Python (3.7) documentation :

Both Logger objects and Handler objects can set levels, and the default Logger object level is 30, which is WARNING, and the default Handler object level is 0, which is NOTSET. The logging module is designed in this way for better flexibility. For example, sometimes we want to output DEBUG level logs in the console and WARNING level logs in the file. You can set only one Logger object with the lowest level and two Handler objects with different levels. The sample code is as follows:

import logging
import logging.handlers

logger = logging.getLogger("logger")

handler1 = logging.StreamHandler()
handler2 = logging.FileHandler(filename="test.log")

logger.setLevel(logging.DEBUG)
handler1.setLevel(logging.WARNING)
handler2.setLevel(logging.DEBUG)

formatter = logging.Formatter("%(asctime)s %(name)s %(levelname)s %(message)s")
handler1.setFormatter(formatter)
handler2.setFormatter(formatter)

logger.addHandler(handler1)
logger.addHandler(handler2)


# print(handler1.level)
# print(handler2.level)
# print(logger.level)

logger.debug('This is a customer debug message')
logger.info('This is an customer info message')
logger.warning('This is a customer warning message')
logger.error('This is an customer error message')
logger.critical('This is a customer critical message')

The console output is:

2018-10-13 23:24:57,832 logger WARNING This is a customer warning message
2018-10-13 23:24:57,832 logger ERROR This is an customer error message
2018-10-13 23:24:57,832 logger CRITICAL This is a customer critical message

The output in the file is:

2018-10-13 23:44:59,817 logger DEBUG This is a customer debug message
2018-10-13 23:44:59,817 logger INFO This is an customer info message
2018-10-13 23:44:59,817 logger WARNING This is a customer warning message
2018-10-13 23:44:59,817 logger ERROR This is an customer error message
2018-10-13 23:44:59,817 logger CRITICAL This is a customer critical message

After creating a custom Logger object, do not use the log output methods in logging. These methods use the default configured Logger object. Otherwise, the log information output will be repeated.

import logging
import logging.handlers

logger = logging.getLogger("logger")
handler = logging.StreamHandler()
handler.setLevel(logging.DEBUG)
formatter = logging.Formatter("%(asctime)s %(name)s %(levelname)s %(message)s")
handler.setFormatter(formatter)
logger.addHandler(handler)
logger.debug('This is a customer debug message')
logging.info('This is an customer info message')
logger.warning('This is a customer warning message')
logger.error('This is an customer error message')
logger.critical('This is a customer critical message')

The output is as follows (you can see that the log information is output twice):

2018-10-13 22:21:35,873 logger WARNING This is a customer warning message
WARNING:logger:This is a customer warning message
2018-10-13 22:21:35,873 logger ERROR This is an customer error message
ERROR:logger:This is an customer error message
2018-10-13 22:21:35,873 logger CRITICAL This is a customer critical message
CRITICAL:logger:This is a customer critical message

Note: When importing a Python file with log output, for example import test.py, the log in the imported file will be output when the log level is greater than the currently set log level.

6. Logger Configuration

Through the above example, we know the configuration required to create a Logger object. The above configuration object is hard-coded in the program. The configuration can also be obtained from dictionary-type objects and configuration files. Open the logging.config Python file and you can see the configuration parsing conversion function.

Get configuration information from the dictionary:

import logging.config

config = {
    'version': 1,
    'formatters': {
        'simple': {
            'format': '%(asctime)s - %(name)s - %(levelname)s - %(message)s',
        },

    },
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
            'level': 'DEBUG',
            'formatter': 'simple'
        },
        'file': {
            'class': 'logging.FileHandler',
            'filename': 'logging.log',
            'level': 'DEBUG',
            'formatter': 'simple'
        },

    },
    'loggers':{
        'StreamLogger': {
            'handlers': ['console'],
            'level': 'DEBUG',
        },
        'FileLogger': {

            'handlers': ['console', 'file'],
            'level': 'DEBUG',
        },

    }
}

logging.config.dictConfig(config)
StreamLogger = logging.getLogger("StreamLogger")
FileLogger = logging.getLogger("FileLogger")
#

Get configuration information from the configuration file:

Common configuration files include ini format, yaml format, JSON format, or can be obtained from the network, as long as there is a corresponding file parser to parse the configuration. The following only shows the configuration in ini format and yaml format.

test.ini file

[loggers]
keys=root,sampleLogger

[handlers]
keys=consoleHandler

[formatters]
keys=sampleFormatter

[logger_root]
level=DEBUG
handlers=consoleHandler

[logger_sampleLogger]
level=DEBUG
handlers=consoleHandler
qualname=sampleLogger
propagate=0

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

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

testinit.py file

import logging.config

logging.config.fileConfig(fname='test.ini', disable_existing_loggers=False)
logger = logging.getLogger("sampleLogger")
#

test.yaml file

version: 1
formatters:
  simple:
    format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
handlers:
  console:
    class: logging.StreamHandler
    level: DEBUG
    formatter: simple
  
loggers:
  simpleExample:
    level: DEBUG
    handlers: [console]
    propagate: no
root:
  level: DEBUG
  handlers: [console]

testyaml.py file

import logging.config
#
import yaml

with open('test.yaml', 'r') as f:
    config = yaml.safe_load(f.read())
    logging.config.dictConfig(config)

logger = logging.getLogger("sampleLogger")
# 

7. Problems in actual combat

1. Chinese characters are garbled

In the above example, the log output is all in English. It is not found that there will be garbled Chinese characters when the log is output to the file. How to solve this problem? The file encoding can be set when the FileHandler creates an object. If the file encoding is set to “utf-8” (utf-8 and utf8 are equivalent), the garbled Chinese characters problem can be solved. One method is to customize the Logger object, which requires writing a lot of configuration. Another method is to use the default configuration method basicConfig(), pass in the handlers processor list object, and set the file encoding in the handler. Many methods on the Internet are invalid. The key reference code is as follows:

# Logger 
handler = logging.FileHandler(filename="test.log", encoding="utf-8")

# Logger 
logging.basicConfig(handlers=[logging.FileHandler("test.log", encoding="utf-8")], level=logging.DEBUG)

2. Temporarily disable log output

Sometimes we don’t want to log output, but we want to log output later. If we use the print() method to print information, we need to comment out all the print() methods. After using logging, we have the “magic” of turning logs on and off with one click. One way is to pass the disabled log level to the logging.disabled() method when using the default configuration, and then log output below the set level can be prohibited. Another way is to set the disable attribute of the Logger object to True when customizing the Logger. The default value is False, which means it is not disabled.

logging.disable(logging.INFO)

logger.disabled = True

3. Log files are divided by time or size

If the logs are saved in a file, then over time or if there are many logs, a single log file will be very large, which is not conducive to backup or viewing. We may wonder if we can divide the log files by time or size? The answer is definitely yes, and it is also very simple. Logging takes this requirement into consideration. The logging.handlers file provides the TimedRotatingFileHandler and RotatingFileHandler classes, which can be divided by time and size respectively. Open this handles file, and you can see that there are other functional Handler classes, all of which inherit from the base class BaseRotatingHandler .

# TimedRotatingFileHandler 
def __init__(self, filename, when='h', interval=1, backupCount=0, encoding=None, delay=False, utc=False, atTime=None):
# RotatingFileHandler 
def __init__(self, filename, mode='a', maxBytes=0, backupCount=0, encoding=None, delay=False)

The sample code is as follows:

# 
file_handler = logging.handlers.RotatingFileHandler("test.log", mode="w", maxBytes=1000, backupCount=3, encoding="utf-8")

# 
handler2 = logging.handlers.TimedRotatingFileHandler("test.log", when="H", interval=1, backupCount=10)

Although the Python official website says that the logging library is thread-safe, there are still issues worth considering in a multi-process, multi-thread, or multi-process multi-thread environment, such as how to divide logs into different log files according to processes (or threads), that is, one process (or thread) corresponds to one file. Due to the limited length of this article, I will not explain it in detail here, but only to stimulate readers’ thinking. I will discuss these issues in another article.

Summary: The Python logging library is designed to be very flexible. If you have special needs, you can also improve on this basic logging library and create a new Handler class to solve problems in actual development.

If you think the article is good, welcome to follow my WeChat public account, there are many benefits waiting for you.