Python 进阶之 Logging 模块

日志可以用于记录软件运行时触发的一系列事件,帮助开发者实时地跟踪和了解程序代码运行的状态。
由日志记录的事件消息通常会从属于特定的重要性等级(称为 levelseverity),该等级由低到高一般包括 DEBUGINFOWARNINGERRORCRITICAL 等。

一、Level

以下为一段简单的 Logging 代码:

1
2
3
4
5
6
7
8
9
import logging

logging.warning('Watch out!') # will print a message to the console
logging.error('Error happend') # will print a message to the console
logging.info('I told you so') # will not print anything
logging.debug('debug information') # will not print anything

# => WARNING:root:Watch out!
# => ERROR:root:Error happend

logging 模块默认的安全等级为 WARNING,只有属于或者高于此等级的日志消息才会被跟踪并进一步处理(比如输出到终端)。
因此上面代码中 warningerror 记录的信息会输出到终端窗口中,而 infodebug 由于所属的安全等级较低,其信息不会输出到终端界面。

logging 模块可以通过 basicConfig 方法中的 level 参数自定义安全等级。示例代码如下:

1
2
3
4
5
6
7
8
9
10
11
import logging

logging.basicConfig(level=logging.INFO)
logging.warning('Watch out!') # will print a message to the console
logging.error('Error happend') # will print a message to the console
logging.info('I told you so') # will not print anything
logging.debug('debug information') # will not print anything

# => WARNING:root:Watch out!
# => ERROR:root:Error happend
# => INFO:root:I told you so

二、记录日志到文件中

参考以下代码:

1
2
3
4
5
import logging
logging.basicConfig(filename='example.log',level=logging.DEBUG)
logging.debug('This message should go to the log file')
logging.info('So should this')
logging.warning('And this, too')

上面的代码运行后会在当前目录下生成 example.log 日志文件,其内容如下:

1
2
3
DEBUG:root:This message should go to the log file
INFO:root:So should this
WARNING:root:And this, too

三、更改信息格式

记录变量
类似于 print 语句,logging 也支持将变量的值嵌入到输出的信息中:

1
2
3
4
import logging

logging.warning(' %s before you %s', 'Look', 'Leap!')
# => WARNING:root: Look before you Leap!

更改输出信息的格式
可以通过 basicConfig 方法中的 format 参数定义日志消息的格式,比如具体需要输出哪些内容以及这些信息如何展现给用户等:

1
2
3
4
5
6
7
8
9
10
import logging

logging.basicConfig(format='%(levelname)s:%(message)s', level=logging.DEBUG)
logging.debug('This message should appear on the console')
logging.info('So should this')
logging.warning('And this, too')

# => DEBUG:This message should appear on the console
# => INFO:So should this
# => WARNING:And this, too

PS:默认的输出格式为 severity:logger name:message

显示时间信息

1
2
3
4
5
6
import logging

logging.basicConfig(format='%(asctime)s %(message)s', datefmt='%m/%d/%Y %I%M%S %p')
logging.warning('is when this event was logged.')

# => 09/06/2019 091722 AM is when this event was logged.

其中 datefmt 参数支持的格式定义与 time.strftime() 相同。

四、配置 Logging

logging 库可以通过模块化的方式向外部提供以下几种组件:

  • Loggers:提供可被应用直接调用的接口
  • Handlers:将 loggers 创建的日志记录发送到指定位置
  • Filters:提供过滤功能,决定哪些日志记录可以被输出显示
  • Formatters:决定日志最终显示时的布局格式

对日志的各类操作实际上是通过调用 Logger 实例中包含的方法来实现的。可以使用如下语句创建一个 Logger 类的实例对象并对其命名:
logger = logging.getLogger(__name__)
同时这种命名方式可以很方便地显示出产生日志信息的模块具体是哪一个。

以下是几种常见的 logging 配置:

(1)手动配置

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
import logging
import logging.config

# 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)

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

# => 2019-09-06 09:54:53,574 - simple_example - DEBUG - debug message
# => 2019-09-06 09:54:53,576 - simple_example - INFO - info message
# => 2019-09-06 09:54:53,577 - simple_example - WARNING - warn message
# => 2019-09-06 09:54:53,578 - simple_example - ERROR - error message
# => 2019-09-06 09:54:53,580 - simple_example - CRITICAL - critical message

(2)配置多个 handler

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
import logging

logger = logging.getLogger('simple_example')
logger.setLevel(logging.DEBUG)
# create file handler which logs even debug messages
fh = logging.FileHandler('E:\\spam.log')
fh.setLevel(logging.DEBUG)
# create console handler with a higher log level
ch = logging.StreamHandler()
ch.setLevel(logging.ERROR)
# create formatter and add it to the handlers
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
ch.setFormatter(formatter)
fh.setFormatter(formatter)
# add the handlers to logger
logger.addHandler(ch)
logger.addHandler(fh)

# 'application' code
logger.debug('debug message')
logger.info('info message')
logger.warning('warn message')
logger.error('error message')
logger.critical('critical message')
# => 2019-09-23 09:20:01,361 - simple_example - ERROR - error message
# => 2019-09-23 09:20:01,377 - simple_example - CRITICAL - critical message

上述代码除了配置 StreamHandler 用于在终端输出日志消息外,还配置了 FileHandler 用于创建 E:\spam.log 日志文件。且日志文件中包含了相对更丰富的信息(因为 Level 级别设置的更低):

1
2
3
4
5
2019-09-23 09:26:58,050 - simple_example - DEBUG - debug message
2019-09-23 09:26:58,051 - simple_example - INFO - info message
2019-09-23 09:26:58,052 - simple_example - WARNING - warn message
2019-09-23 09:26:58,052 - simple_example - ERROR - error message
2019-09-23 09:26:58,055 - simple_example - CRITICAL - critical message

(3)dictConfig 配置 Logging:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
import logging
from logging.config import dictConfig

logging_config = dict(
version=1,
formatters={
'f': {'format':
'%(asctime)s %(name)-12s %(levelname)-8s %(message)s'}
},
handlers={
'h': {'class': 'logging.StreamHandler',
'formatter': 'f',
'level': logging.DEBUG}
},
root={
'handlers': ['h'],
'level': logging.DEBUG,
},
)

dictConfig(logging_config)
logger = logging.getLogger('simple_example')

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

# => 2019-09-09 10:15:47,932 simple_example DEBUG debug message
# => 2019-09-09 10:15:47,934 simple_example INFO info message
# => 2019-09-09 10:15:47,935 simple_example WARNING warn message
# => 2019-09-09 10:15:47,936 simple_example ERROR error message
# => 2019-09-09 10:15:47,938 simple_example CRITICAL critical message

(4)YAML 格式的配置文件

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
# logging.py
import logging
import logging.config
import yaml

with open('E:\\Program\\python\\logging.yml', 'r') as f:
config = yaml.safe_load(f.read())
logging.config.dictConfig(config)
logger = logging.getLogger(__file__)

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

# => 2019-09-09 11:18:07,167 - e:\Program\python\logging.py - DEBUG - debug message
# => 2019-09-09 11:18:07,169 - e:\Program\python\logging.py - INFO - info message
# => 2019-09-09 11:18:07,170 - e:\Program\python\logging.py - WARNING - warn message
# => 2019-09-09 11:18:07,171 - e:\Program\python\logging.py - ERROR - error message
# => 2019-09-09 11:18:07,172 - e:\Program\python\logging.py - CRITICAL - critical message

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
# logging.yml
version: 1
formatters:
simple:
format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
handlers:
console:
class: logging.StreamHandler
level: DEBUG
formatter: simple
stream: ext://sys.stdout
loggers:
sampleLogger:
level: DEBUG
handlers: [console]
propagate: no
root:
level: DEBUG
handlers: [console]

参考资料

Python 3.7.4 documentation