Python日志处理(logging模块介绍)_python logging日志处理模块

一、logging模块介绍

logging模块是Python的一个标准库模块，由标准库模块提供日志记录API的关键好处是所有Python模块都可以使用这个日志记录功能。

1.1 logging模块日志级别

logging模块默认定义了以下几个日志等级，它允许开发人员自定义其他日志级别，但是这是不被推荐的，尤其是在开发供别人使用的库时，因为这会导致日志级别的混乱。

1.2 logging模块使用方式介绍

logging模块提供了两种记录日志的方式：

• 第一种方式是使用logging提供的模块级别的函数。
• 第二种方式是使用Logging日志系统的四大组件

其实，logging所提供的模块级别的日志记录函数也是对logging日志系统相关类的封装而已。

logging模块定义的模块级别的常用函数

其中logging.basicConfig(**kwargs)函数用于指定“要记录的日志级别”、“日志格式”、“日志输出位置”、“日志文件的打开模式”等信息，其他几个都是用于记录各个级别日志的函数。

logging模块的四大组件

说明： logging提供的模块级别的函数，实际上也是通过这几个组件的相关实现类来记录日志的，只是在创建这些类的实例的时候设置了一些默认值。

二、使用logging提供的模块级函数记录日志

回顾前面提到的几个重要信息：

• 可以通过logging模块级别的方法完成简单的日志记录
• 只有级别大于或者等于日志记录器指定级别的日志才会被输出，小于该级别的日志将会被丢弃。

2.1 简单的日志输出

import logging

# 设置默认日志级别， >=logging.INFO 则输出
logging.basicConfig(level=logging.INFO)

logging.debug("This is a debug log.")
logging.info("This is a info log.")
logging.warning("This is a warning log.")
logging.error("This is a error log.")
logging.critical("This is a critical log.")
1
2
3
4
5
6
7
8
9
10

也可以这样写：

import logging

logging.basicConfig(level=logging.INFO)

logging.log(logging.DEBUG, "This is a debug log.")
logging.log(logging.INFO, "This is a info log.")
logging.log(logging.WARNING, "This is a warning log.")
logging.log(logging.ERROR, "This is a error log.")
logging.log(logging.CRITICAL, "This is a critical log.")
1
2
3
4
5
6
7
8
9

输出结果：

INFO:root:This is a info log.
WARNING:root:This is a warning log.
ERROR:root:This is a error log.
CRITICAL:root:This is a critical log.
1
2
3
4

2.2 问题来了

1. 打印出的日志的各字段是什么意思？为什么会这样输出？

日志级别：日志器名称：日志内容
1

之所以会这样输出，是因为logging模块提供的日志记录函数，所使用的日志器，其默认值为logging.BASIC_FORMAT:

BASIC_FORMAT = "%(levelname)s:%(name)s:%(message)s"
1
'
运行
运行

2. 打印出的日志默认输出到什么位置？

logging模块提供的日志记录函数的默认输出位置为sys.stderr

3. 我是怎样知道这些的？

查看这些日志记录函数的实现代码，可以发现：当我们没有提供任何配置信息的时候，这些函数都会去调用logging.basicConfig(**kwargs)方法，且不会向该方法传递任何参数。继续查看basicConfig()方法的代码就可以找到上面这些问题的答案了。

4. 怎么修改这些默认值呢？

其实很简单，在我们调用日志记录函数之前，手动调用一下basicConfig方法，把我们想设置的内容以参数的形式传进去就可以了。

2.3 logging.basicConfig函数说明

该方法用于logging系统做一些基本配置，其方法定义如下：

logging.basicConfig(**kwargs)
1

2.4 logging定义的格式字符字段

2.5 日志常用配置演示

简单配置一下日志级别：

logging.basicConfig(level=logging.DEBUG)

logging.log(logging.DEBUG, "This is a debug log.")
logging.log(logging.INFO, "This is a info log.")
logging.log(logging.WARNING, "This is a warning log.")
logging.log(logging.ERROR, "This is a error log.")
logging.log(logging.CRITICAL, "This is a critical log.")
1
2
3
4
5
6
7

输出结果：

DEBUG:root:This is a debug log.
INFO:root:This is a info log.
WARNING:root:This is a warning log.
ERROR:root:This is a error log.
CRITICAL:root:This is a critical log.
1
2
3
4
5

所有等级日志信息全部输出了，说明配置生效了。

在配置日志器日志级别的基础上，继续配置下日志输出目标文件和日志格式

import logging

LOG_FORMAT = "%(asctime)s-%(levelname)s-%(message)s"

logging.basicConfig(level=logging.DEBUG, format=LOG_FORMAT, filename="my.log")

logging.log(logging.DEBUG, "This is a debug log.")
logging.log(logging.INFO, "This is a info log.")
logging.log(logging.WARNING, "This is a warning log.")
logging.log(logging.ERROR, "This is a error log.")
logging.log(logging.CRITICAL, "This is a critical log.")
1
2
3
4
5
6
7
8
9
10
11
'
运行
运行

此时会发现控制台之中已经没有日志输出了，但是在python代码的相同目录下会生成一个名为"my.log"的日志文件，该文件的内容为：

2024-01-03 10:44:11,954-DEBUG-This is a debug log.
2024-01-03 10:44:11,954-INFO-This is a info log.
2024-01-03 10:44:11,955-WARNING-This is a warning log.
2024-01-03 10:44:11,955-ERROR-This is a error log.
2024-01-03 10:44:11,955-CRITICAL-This is a critical log.
1
2
3
4
5

在此基础上我们再来设置一下日期/时间格式：

import logging

LOG_FORMAT = "%(asctime)s-%(levelname)s-%(message)s"
DATE_FORMAT = "%m/%d/%Y %H:%M:%S %p"


logging.basicConfig(level=logging.DEBUG, format=LOG_FORMAT, filename="my.log", datefmt=DATE_FORMAT)

logging.log(logging.DEBUG, "This is a debug log.")
logging.log(logging.INFO, "This is a info log.")
logging.log(logging.WARNING, "This is a warning log.")
logging.log(logging.ERROR, "This is a error log.")
logging.log(logging.CRITICAL, "This is a critical log.")
1
2
3
4
5
6
7
8
9
10
11
12
13
'
运行
运行

01/03/2024 10:51:43 AM-DEBUG-This is a debug log.
01/03/2024 10:51:43 AM-INFO-This is a info log.
01/03/2024 10:51:43 AM-WARNING-This is a warning log.
01/03/2024 10:51:43 AM-ERROR-This is a error log.
01/03/2024 10:51:43 AM-CRITICAL-This is a critical log.
1
2
3
4
5

2.6 其它说明

几个要说明的内容：

• logging.basicConfig()函数是一个一次性的简单配置工具使，也就是说只有在第一次调用该函数时会起作用，后续再次调用该函数时完全不会产生任何操作的，多次调用的设置并不是累加操作。

• 日志器（Logger）是有层级关系的，上面调用的logging模块级别的函数所使用的日志器是RootLogger类的实例，其名称为root，它是处于日志器层级关系最顶层的日志器，且该实例是以单例模式存在的。

• 如果要记录的日志中包含变量，可以使用第一个参数作为字符串格式，然后将变量数据作为第二个参数*args的值进行传递，如:logging.warning('%s is %d years old.', 'Tom', 10)，输出内容为WARNING:root:Tom is 10 years old.。

• logging.debug(), logging.info()等方法的定义中，除了msg和args参数外，还有一个**kwargs参数。它们支持3个关键字参数: exc_info, stack_info, extra，下面对这几个关键字参数作个说明。

关于exc_info, stack_info, extra关键词参数的说明：

• exc_info(exception_info)： 其值为布尔值，如果该参数的值设置为True，则会将异常异常信息添加到日志消息中。如果没有异常信息则添加None到日志信息中。

• stack_info： 其值也为布尔值，默认值为False。如果该参数的值设置为True，栈信息将会被添加到日志信息中。

• extra： 这是一个字典（dict）参数，它可以用来自定义消息格式中所包含的字段，但是它的key不能与logging模块定义的字段冲突。

一个例子：

FORMAT = '%(asctime)s %(clientip)-15s %(user)-8s %(message)s'
logging.basicConfig(format=FORMAT)
d = {'clientip': '192.168.0.1', 'user': 'jack'}
logger = logging.getLogger('tcpserver')
logger.warning('Protocol problem: %s', 'connection reset', extra=d)
1
2
3
4
5

输出

2024-01-03 13:56:40,112 192.168.0.1     jack     Protocol problem: connection reset
1

exc_info=True的案例：

LOG_FORMAT = "%(asctime)s-%(levelname)s-%(message)s"
DATE_FORMAT = "%m/%d/%Y %H:%M:%S %p"
logging.basicConfig(level=logging.DEBUG, format=LOG_FORMAT, datefmt=DATE_FORMAT)
try:
    1/0
except Exception as e:
    logging.log(logging.WARNING, "This is a warning log.", exc_info=True, stack_info=False)
1
2
3
4
5
6
7

会在异常块，里面输出异常信息，如果不再异常块里面，则输出NoneType

01/03/2024 14:01:39 PM-WARNING-This is a warning log.
Traceback (most recent call last):
  File "demo.py", line 11, in <module>
    1/0
ZeroDivisionError: division by zero
1
2
3
4
5

stack_info=True的案例：

logging.log(logging.WARNING, "This is a warning log.", exc_info=False, stack_info=True)
1

stack_info=True无论如何都会输出调用栈信息。

01/03/2024 14:12:00 PM-WARNING-This is a warning log.
Stack (most recent call last):
  File "demo.py", line 9, in <module>
    logging.log(logging.WARNING, "This is a warning log.", exc_info=False, stack_info=True)
1
2
3
4

三、logging模块日志处理流程

3.1 logging日志模块四大组件

在介绍logging模块的日志流处理流程之前，我们先来介绍下logging模块的四大组件：

这些组件之间的关系描述：

• 日志器（logger）需要通过处理器（handler）将日志信息输出到目标位置，如：文件、sys.stdout、网络等；

• 不同的处理器（handler）可以将日志输出到不同的位置；

• 日志器（logger）可以设置多个处理器（handler）将同一条日志记录输出到不同的位置；
  每个处理器（handler）都可以设置自己的过滤器（filter）实现日志过滤，从而只保留感兴趣的日志；

• 每个处理器（handler）都可以设置自己的格式器（formatter）实现同一条日志以不同的格式输出到不同的地方。

• 简单点说就是：日志器（logger）是入口，真正干活儿的是处理器（handler），处理器（handler）还可以通过过滤器（filter）和格式器（formatter）对要输出的日志内容做过滤和格式化等处理操作。

3.2 日志组件的常用方法介绍

下面介绍下与logging四大组件相关的类：Logger, Handler, Filter, Formatter。

3.2.1 Logger类

Logger对象有3个任务要做：

1. 向应用程序代码暴露几个方法，使应用程序可以在运行时记录日志消息；
2. 基于日志严重等级（默认的过滤设施）或filter对象来决定要对哪些日志进行后续处理；
3. 将日志消息传送给所有感兴趣的日志handlers。
   Logger对象最常用的方法分为两类：配置类的方法和消息发送类的方法。

最常用的配置方法如下：

logger对象配置完成后，可以使用下面的方法来创建日志记录：

那么，怎样得到一个Logger对象呢？一种方式是通过Logger类的实例化方法创建一个Logger类的实例，但是我们通常都是用第二种方式–logging.getLogger()方法。

logging.getLogger()方法有一个可选参数name，该参数表示将要返回的日志器的名称标识，如果不提供该参数，则其值为’root’。若以相同的name参数值多次调用getLogger()方法，将会返回指向同一个logger对象的引用。

通过logging.Logger.manager.loggerDict.keys()可以获取到所有logger的名称

关于logger的层级结构与有效等级的说明：

• logger的名称是一个以.分割的层级结构，每个.后面的logger都是.前面的logger的children，例如，有一个名称为foo的logger，其它名称分别为foo.bar,foo.bar.baz和foo.bam都是foo的后代。

• logger有一个"有效等级（effective level）"的概念。如果一个logger上没有被明确设置一个level，那么该logger就是使用它parent的level;如果它的parent也没有明确设置level则继续向上查找parent的parent的有效level，依次类推，直到找到个一个明确设置了level的祖先为止。需要说明的是，root logger总是会有一个明确的level设置（默认为 WARNING）。当决定是否去处理一个已发生的事件时，logger的有效等级将会被用来决定是否将该事件传递给该logger的handlers进行处理。

• child loggers在完成对日志消息的处理后，默认会将日志消息传递给与它们的祖先loggers相关的handlers。因此，我们不必为一个应用程序中所使用的所有loggers定义和配置handlers，只需要为一个顶层的logger配置handlers，然后按照需要创建child loggers就可足够了。我们也可以通过将一个logger的propagate属性设置为False来关闭这种传递机制。

3.2.2 Handler

Handler对象的作用是（基于日志消息的level）将消息分发到handler指定的位置（文件、网络、邮件等）。Logger对象可以通过addHandler()方法为自己添加0个或者更多个handler对象。比如，一个应用程序可能想要实现以下几个日志需求：

• 把所有日志都发送到一个日志文件中；
• 把所有严重级别大于等于error的日志发送到stdout（标准输出）；
• 把所有严重级别为critical的日志发送到一个email邮件地址。

这种场景就需要3个不同的handlers，每个handler复杂发送一个特定严重级别的日志到一个特定的位置。

一个handler中只有非常少数的方法是需要应用开发人员去关心的。对于使用内建handler对象的应用开发人员来说，似乎唯一相关的handler方法就是下面这几个配置方法：

需要说明的是，应用程序代码不应该直接实例化和使用Handler实例，因为Handler是一个基类。下面是一些常用的Handler：

3.2.3 Formater

Formater对象用于配置日志信息的最终顺序、结构和内容。与logging.Handler基类不同的是，应用代码可以直接实例化Formatter类。另外，如果你的应用程序需要一些特殊的处理行为，也可以实现一个Formatter的子类来完成。

Formatter类的构造方法定义如下：

logging.Formatter.__init__(fmt=None, datefmt=None, style='%')
1

可见，该构造方法接收3个可选参数：

• fmt：指定消息格式化字符串，如果不指定该参数则默认使用message的原始值
• datefmt：指定日期格式字符串，如果不指定该参数则默认使用"%Y-%m-%d %H:%M:%S"
• style：Python 3.2新增的参数，可取值为 '%', '{'和 '$'，如果不指定该参数则默认使用’%’

3.2.4 Filter

Filter可以被Handler和Logger用来做比level更细粒度的、更复杂的过滤功能。Filter是一个过滤器基类，它只允许某个logger层级下的日志事件通过过滤。该类定义如下：

class logging.Filter(name='')
    filter(record)
1
2

比如，一个filter实例化时传递的name参数值为A.B，那么该filter实例将只允许名称为类似如下规则的loggers产生的日志记录通过过滤：A.B，A.B,C，A.B.C.D，A.B.D，而名称为A.BB, B.A.B的loggers产生的日志则会被过滤掉。如果name的值为空字符串，则允许所有的日志事件通过过滤。

filter方法用于具体控制传递的record记录是否能通过过滤，如果该方法返回值为0表示不能通过过滤，返回值为非0表示可以通过过滤。

3.3 日志处理流程

下面这个图描述了日志的处理流程：

我们来描述一下这个图的处理流程：

1. （在用户代码中进行）日志记录函数调用，如：logger.info(...)，logger.debug(...)等；
2. 判断要记录的日志级别是否满足日志器设置的级别要求（要记录的日志级别要大于或等于日志器设置的级别才算满足要求），如果不满足则该日志记录会被丢弃并终止后续的操作，如果满足则继续下一步操作；
3. 根据日志记录函数调用时掺入的参数，创建一个日志记录（LogRecord类）对象；
4. 判断日志记录器上设置的过滤器是否拒绝这条日志记录，如果日志记录器上的某个过滤器拒绝，则该日志记录会被丢弃并终止后续的操作，如果日志记录器上设置的过滤器不拒绝这条日志记录或者日志记录器上没有设置过滤器则继续下一步操作–将日志记录分别交给该日志器上添加的各个处理器；
5. 判断要记录的日志级别是否满足处理器设置的级别要求（要记录的日志级别要大于或等于该处理器设置的日志级别才算满足要求），如果不满足记录将会被该处理器丢弃并终止后续的操作，如果满足则继续下一步操作；
6. 判断该处理器上设置的过滤器是否拒绝这条日志记录，如果该处理器上的某个过滤器拒绝，则该日志记录会被当前处理器丢弃并终止后续的操作，如果当前处理器上设置的过滤器不拒绝这条日志记录或当前处理器上没有设置过滤器测继续下一步操作；
7. 如果能到这一步，说明这条日志记录经过了层层关卡允许被输出了，此时当前处理器会根据自身被设置的格式器（如果没有设置则使用默认格式）将这条日志记录进行格式化，最后将格式化后的结果输出到指定位置（文件、网络、类文件的Stream等）
8. 如果日志器被设置了多个处理器的话，上面的第5-8步会执行多次；
9. 这里才是完整流程的最后一步：判断该日志器输出的日志消息是否需要传递给上一级logger（之前提到过，日志器是有层级关系的）的处理器，如果propagate属性值为1则表示日志消息将会被输出到处理器指定的位置，同时还会被传递给parent日志器的handlers进行处理直到当前日志器的propagate属性为0停止，如果propagate值为0则表示不向parent日志器的handlers传递该消息，到此结束。

可见，一条日志信息要想被最终输出需要依次经过以下几次过滤：

• 日志器等级过滤；
• 日志器的过滤器过滤；
• 日志器的处理器等级过滤；
• 日志器的处理器的过滤器过滤；

需要说明的是： 关于上面第9个步骤，如果propagate值为1，那么日志消息会直接传递交给上一级logger的handlers进行处理，此时上一级logger的日志等级并不会对该日志消息进行等级过滤。

四、使用logging四大组件记录日志

4.1 需求

现在有以下几个日志记录的需求：

1. 要求将所有级别的所有日志都写入磁盘文件中
2. all.log文件中记录所有的日志信息，日志格式为：日期和时间 - 日志级别 - 日志信息
3. error.log文件中单独记录error及以上级别的日志信息，日志格式为：日期和时间 - 日志级别 - 文件名[:行号] - 日志信息
4. 要求all.log在每天凌晨进行日志切割

4.2 分析

1. 要记录所有级别的日志，因此日志器的有效level需要设置为最低级别–DEBUG
2. 日志需要发送到两个不同的目的地，因此需要设置两个handler；另外两个目的地都是磁盘文件，因此这两个handler都是与filehandler相关；
3. all.log要求按照时间进行日志切割，因此他需要用logging.handlers.TimedRotatingFileHandler; 而error.log没有要求日志切割，因此可以使用FileHandler;
4. 两个日志文件的格式不同，因此需要对这两个handler分别设置格式器；

import logging
import logging.handlers
import datetime

logger = logging.getLogger('mylogger')
logger.setLevel(logging.DEBUG)

# backup_interval = when * interval
# backupCount: backup logfile number
rf_handler = logging.handlers.TimedRotatingFileHandler('all.log', when='midnight', interval=1, backupCount=7, atTime=datetime.time(0, 0, 0, 0))
rf_handler.setFormatter(logging.Formatter("%(asctime)s - %(levelname)s - %(message)s"))

f_handler = logging.FileHandler('error.log')
f_handler.setLevel(logging.ERROR)

f_handler.setFormatter(logging.Formatter("%(asctime)s - %(levelname)s - %(filename)s[:%(lineno)d] - %(message)s"))
logger.addHandler(rf_handler)
logger.addHandler(f_handler)

logger.debug('debug message')
logger.info('info message')
logger.warning('warning message')
logger.error('error message')
logger.critical('critical message')
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
'
运行
运行

all.log文件输出：

2024-01-05 17:05:03,633 - DEBUG - debug message
2024-01-05 17:05:03,633 - INFO - info message
2024-01-05 17:05:03,633 - WARNING - warning message
2024-01-05 17:05:03,633 - ERROR - error message
2024-01-05 17:05:03,633 - CRITICAL - critical message
1
2
3
4
5

error.log文件输出：

2024-01-05 17:05:03,633 - ERROR - demo.py[:23] - error message
2024-01-05 17:05:03,633 - CRITICAL - demo.py[:24] - critical message
1
2

五、配置logging的集中方式

5.1 使用字典信息和dictConfig()函数实现日志配置

python代码：

import logging.config
import yaml

with open('logging.yml', 'r') as f_conf:
    dict_conf = yaml.load(f_conf)

logging.config.dictConfig(dict_conf)

logger = logging.getLogger('simpleExample')
logger.debug('debug message')
logger.info('info message')
logger.warn('warn message')
logger.error('error message')
logger.critical('critical message')
1
2
3
4
5
6
7
8
9
10
11
12
13
14

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
  console_err:
    class: logging.StreamHandler
    level: ERROR
    formatter: simple
    stream: ext://sys.stderr
  file:
    class: logging.FileHandler
    level: DEBUG
    formatter: simple
    filename: all.log
loggers:
  simpleExample:
    level: DEBUG
    handlers: [console, file]
    propagate: yes
root:
  level: DEBUG
  handlers: [console_err]
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

输出结果：

2024-01-05 17:34:33,087 - simpleExample - DEBUG - debug message
2024-01-05 17:34:33,087 - simpleExample - INFO - info message
2024-01-05 17:34:33,087 - simpleExample - WARNING - warn message
2024-01-05 17:34:33,087 - simpleExample - ERROR - error message
2024-01-05 17:34:33,087 - simpleExample - CRITICAL - critical message
1
2
3
4
5

1. 关于dictConfig()函数的说明：

函数定义：

该函数定义在loging.config模块下：

def dictConfig(config):
    """Configure logging using a dictionary."""
    dictConfigClass(config).configure()
1
2
3
'
运行
运行

该函数可以从一个字典对象中获取日志配置信息，config参数就是这个字典对象。关于这个字典对象的内容规则会在下面进行描述。

2. 配置字典说明

无论是上面提到的配置文件，还是这里的配置字典，它们都要描述出日志配置所需要创建的各种对象以及这些对象之间的关联关系。比如，可以先创建一个名额为simple的格式器formatter；然后创建一个名为console的处理器handler，并指定该handler输出日志所使用的格式器为simple；然后再创建一个日志器logger，并指定它所使用的处理器为console。

传递给dictConfig()函数的字典对象只能包含下面这些keys，其中version是必须指定的key，其它key都是可选项：

handlers的定义示例：

handlers:
  console:
    class : logging.StreamHandler
    formatter: brief
    level   : INFO
    filters: [allow_foo]
    stream  : ext://sys.stdout
  file:
    class : logging.handlers.RotatingFileHandler
    formatter: precise
    # 这里使用的是logging.handlers.RotatingFileHandler构造函数中的参数
    filename: logconfig.log
    maxBytes: 1024
    backupCount: 3
1
2
3
4
5
6
7
8
9
10
11
12
13
14

3. 关于外部对象的访问

需要说明的是，上面所使用的对象并不限于loggging模块所提供的对象，我们可以实现自己的formatter或handler类。另外，这些类的参数也许需要包含sys.stderr这样的外部对象。

如果配置字典对象是使用Python代码构造的，可以直接使用sys.stdout、sys.stderr；但是当通过文本文件（如JSON、YAML格式的配置文件）提供配置时就会出现问题，因为在文本文件中，没有标准的方法来区分sys.stderr和字符串sys.stderr。为了区分它们，配置系统会在字符串值中查找特定的前缀，例如ext://sys.stderr中ext://会被移除，然后import sys.stderr。