python logging module

When it comes to logging, whether writing framework code or business code is inseparable from logging, which can bring us great help in locating problems.

The easiest way to record a log is to add a print where you want to record. I believe both novices and old birds often do this. There is no problem doing this in simple code or small projects. However, for some larger projects, sometimes it is necessary to check the history log to locate a problem. It is inappropriate to use print.

The log printed by print has no time, does not know the location of the log record, and has no readable log format. It is not possible to output the log to the specified file.... Unless you repeat all this yourself.

The best practice is to use the built-in logging module, because the logging module provides developers with very rich functions.

For example, the above figure uses the logging module of the standard library to record the generated log, including the specific time of the log, the module in which the log occurs, the log level and the specific content of the log, etc

How to use it? Let's take an example

Import the logging module, and then directly use the logging message recording method provided by logging.

log level

Log levels are divided into the following five levels

log level	Usage scenario
DEBUG	The debug level is used to record detailed information to facilitate problem location and debugging. We generally do not open debug in the production environment
INFO	It is used to record the information of key code points so that the code can execute as expected. The production environment usually sets the INFO level
WARNING	Record some unexpected situations, such as insufficient disk
ERROR	Information recorded when some functions cannot function properly due to a more serious problem
CRITICAL	Information recorded when a serious error occurs that prevents the application from continuing to run

The importance of the log level increases step by step. python provides five corresponding level methods. By default, the log level is warning, and log information lower than warning will not be output.

From the code above, you can see that logging The log contents after logging are printed in the standard output stream, that is, the command line window, but logging The logs recorded by debug and info will not be printed.

Modify log level

How to make debug level information output?

Of course, the default log level should be modified. You can use logging before logging Basicconfig method to set the log level

import logging
logging.basicConfig( level=logging.DEBUG)
logging.debug("this is debug")
logging.info("this is info")
logging.error("this is error")

When the debug level is set, all log information will be output

DEBUG:root:this is debug
INFO:root:this is info
ERROR:root:this is error

Log to file

The previous log will output the log to the standard output stream by default, which is only output in the command line window. After the program is restarted, there is no place to find the historical log, so it is a very common requirement to permanently record the log content. Also, configure the function logging Basicconfig can specify where the log is output

import logging
logging.basicConfig(filename="test.log", level=logging.INFO)
logging.debug("this is debug")
logging.info("this is info")
logging.error("this is error")

Here I specify the log output to the file test In log, the log level is specified as INFO. The contents recorded in the last file are as follows:

INFO:root:this is info
ERROR:root:this is error

Each time you re run, the log will be appended later. If you want to overwrite the previous log before each run, you need to specify filemode='w ', which is the same as the parameter used by the open function to write data to the file.

Specify log format

The default output format includes three parts: log level, the name of the logger, and the log content. The middle is connected with ":. If we want to change the log format, such as adding date and time and displaying the name of the logger, we can specify the format parameter to set the log format

import logging
logging.basicConfig(format='%(asctime)s %(levelname)s %(name)s %(message)s')
logging.error("this is error")

 

output

2021-12-15 07:44:16,547 ERROR root this is error

The log format output provides many parameters. In addition to the time, log level, log message content, and the name of the logger, you can also specify the thread name, process name, and so on

So far, that's all the basic usage of the log module. It can also meet most application scenarios. More advanced methods can help you better deal with logs

logger

The logging described earlier, In fact, they are created through an instance object called Logger. Each Logger has a name. When logging directly, the system will create a Logger named root by default. This Logger is the root Logger. The Logger supports hierarchy. Sub recorders usually do not need to set the log level and Handler separately (described later), if the child recorder is not set separately, its behavior will be delegated to the parent.

The logger name can be any name, but the best practice is to use the module name directly as the logger name. Named as follows

logger = logging.getLogger(__name__)

By default, the logger adopts a hierarchical structure, and the previous period is arranged in the hierarchy of the namespace as a separator. The logger below the hierarchy list is a child of the logger higher in the list. For example, there is a recorder called foo, and the name is foo bar，foo.bar.baz, and foo BAM recorders are children of foo.

├─foo
│  │  main.py
│  │  __init__.py
│  │  
│  ├─bam
│  │  │  __init__.py
│  │  │  
│  │          
│  ├─bar
│  │  │  __init__.py
│  │  │  
│  │  ├─baz
│  │  │  │  __init__.py
│  │  │  │

main.py

import foo
from foo import bar
from foo import bam
from foo.bar import baz

if __name__ == '__main__':
    pass

foo.py

import logging

logging.basicConfig()
logger = logging.getLogger(__name__)
logger.setLevel(logging.INFO)

logger.info("this is foo")

Here, I only set foo the level of this recorder to INFO

bar.py

import logging

logger = logging.getLogger(__name__)
logger.info("this is bar")

Other sub modules are like bar Py similar code does not set the log level, and the final output is

INFO:foo:this is foo
INFO:foo.bar:this is bar
INFO:foo.bam:this is bam
INFO:foo.bar.baz:this is baz

This is because foo If the log level of bar recorder is not set, the ancestor with daily log level will be found upward. Here, the level of foo of the parent recorder is INFO. If foo is not set, the root recorder root will be found. The default level of root is warning.

Processor (Handler)

The recorder is responsible for recording the log, but the recorder doesn't care where the log is finally recorded, but gives it to another guy, the Handler, to handle it.

For example, for a flash project, you may record the INFO level log to a file and the ERROR level log to standard output, Send some key logs (such as orders or serious errors) to an email address to inform the boss. At this time, your recorder adds multiple different processors to process different message logs, so as to send them to a specific location according to the importance of messages.

Python has built-in many practical processors, including:

1. StreamHandler standard stream processor, which sends messages to standard output stream and error stream
2. FileHandler is a file processor that sends messages to files
3. RotatingFileHandler is a file processor. After the file reaches the specified size, a new file is enabled to store logs
4. TimedRotatingFileHandler is a file processor that rotates log files at specific time intervals

Processor operation

Handler provides four methods for developers to use. You can find that logger can set level and handler can also set level. Through setLevel, messages of different levels recorded by the recorder can be sent to different places.

import logging
from logging import StreamHandler
from logging import FileHandler

logger = logging.getLogger(__name__)

# Set to DEBUG level
logger.setLevel(logging.DEBUG)

# Standard stream processor, set to level WARAING
stream_handler = StreamHandler()
stream_handler.setLevel(logging.WARNING)
logger.addHandler(stream_handler)

#File processor, set the level to INFO
file_handler = FileHandler(filename="test.log")
file_handler.setLevel(logging.INFO)
logger.addHandler(file_handler)

logger.debug("this is debug")
logger.info("this is info")
logger.error("this is error")
logger.warning("this is warning")

After running, the log output in the command line window is:

this is error
this is warning

The log contents output in the file are:

this is info
this is error
this is warning

Although we set the level of the logger to debug, the message recorded by debug is not output, because the level I set for both handlers is higher than debug, so this message is filtered out.

formatter

Formatter has been introduced in the previous part of the article, but it is through logging Basicconfig. In fact, the formatter can also be set on the Handler in the form of an object. The formatter can specify the output format of the log, whether to display the time, what the time format is, whether to display the level of the log, whether to display the name of the recorder, etc. messages can be formatted and output through a formatter.

import logging
from logging import StreamHandler

logger = logging.getLogger(__name__)

# Standard stream processor
stream_handler = StreamHandler()
stream_handler.setLevel(logging.WARNING)

# Create a formatter
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
# Function in handler upper
stream_handler.setFormatter(formatter)
#Add processor
logger.addHandler(stream_handler)

logger.info("this is info")
logger.error("this is error")
logger.warning("this is warning")

Note that the formatter can only work on the processor. Set the formatter through the setFromatter method of the processor. Moreover, a handler can only set one formatter. It's a one-to-one relationship. The relationship between logger and handler is one to many. A logger can add multiple handlers. Both handler and logger can set the log level.

logging.basicConfig

Go back to the beginning, logging What does the basicconfig () method do for us? Now you can probably guess. Let's see what the python source code says

Do basic configuration for the logging system.

This function does nothing if the root logger already has handlers configured. It is a convenience method intended for use by simple scripts to do one-shot configuration of the logging package.

The default behaviour is to create a StreamHandler which writes to sys.stderr, set a formatter using the BASIC_FORMAT format string, and add the handler to the root logger.

A number of optional keyword arguments may be specified, which can alter the default behaviour.

1. Create a root logger
2. Set the log level of root to warning
3. Adding a StreamHandler processor to the root logger
4. Set up a simple formatter for the processor

logging.basicConfig()
logging.warning("hello")

These two lines of code are actually equivalent to:

import sys
import logging
from logging import StreamHandler
from logging import Formatter


logger = logging.getLogger("root")
logger.setLevel(logging.WARNING)
handler = StreamHandler(sys.stderr)
logger.addHandler(handler)
formatter = Formatter(" %(levelname)s:%(name)s:%(message)s")
handler.setFormatter(formatter)
logger.warning("hello")

logging. The basicconfig method is equivalent to making the most basic configuration for the log system, which is convenient for developers to access and use quickly. It must be called before recording logs. However, if the root logger has specified other processors, and you call basciConfig at this time, this method will fail and it will do nothing.

Log configuration

For log configuration, in addition to writing the configuration directly into the code described above, you can also put the configuration information separately in the configuration file to separate the configuration from the code.

Log configuration file logging conf

[loggers]
keys=root

[handlers]
keys=consoleHandler

[formatters]
keys=simpleFormatter

[logger_root]
level=DEBUG
handlers=consoleHandler


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

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

Load profile

import logging
import logging.config

# load configuration
logging.config.fileConfig('logging.conf')

# establish logger
logger = logging.getLogger()

#Application code
logger.debug("debug message")
logger.info("info message")
logger.warning("warning message")
logger.error("error message")