Python 3.X | 标准库之一:logging模块

环境

  • Python 3.6.8
  • Ubuntu 16.04 LTS

前言
学习一个知识(点),需要知道3个方面:

  1. what:是什么?有哪些方面?作用是什么?
  2. how:怎么用?规则、语法是什么?
  3. where/when:用在哪?什么时候用?即什么场景下使用它。

log,其中一个含义译作:n.(旅程、某段时间或事件的)日记,日志;v.正式记录,记载
logging,动名词。


本文导读:

  • 1 日志基础知识:概念、作用、级别、形式、内容、实现
  • 2 Python标准库之logging模块详解:级别、使用方式、记录日志
  • 3 logging模块之日志流处理流程:四大组件、相关类和方法、流程
  • 4 配置日志的 3种方式:Python代码显式、创建日志配置文件、创建包含配置信息的dict
  • 5 向日志输出中添加上下文信息的3种方式:extra参数、LoggerAdapter、Filter

1、log(日志) 基础知识概览

1.1、what:日志是什么?

日志(logging)是一种可追踪(track)某些软件运行时所发生事件的方法。软件开发人员 可在他们的代码中调用日志记录相关的方法来表明发生了某些事件。通过一个描述性的消息来描述这个事件,该消息能够可选地包含可变数据。而 事件有重要性的概念,重要性被称为 严重性级别(Level)

1.2、日志的作用?

  • 通过对log的分析,可以方便用户了解系统或软件、应用的运行情况;
  • 若应用的log足够丰富,可分析出以往用户的操作行为、类型喜好、地域分析、或其他更多信息,据此来改进业务、提高商业利益;
  • 若一个应用的log分了多个级别,则可轻松地分析得到应用的健康状况,及时发现问题并快速定位、解决问题,补救损失。

通过记录和分析日志可以了解一个系统 或软件程序运行情况是否正常,也可以在应用程序出现故障时快速定位问题。例如:开发者可通过在控制台上输出的各种日志进行程序调试;运维人员在接收到报警或各种问题反馈后,进行问题排查时通常都会先看各种日志,大部分问题都可在日志中找到答案。日志的作用可总结为3点:

  1. 程序调试
  2. 了解软件程序运行情况,是否正常
  3. 软件程序运行故障分析与问题定位

1.3、日志的级别(Level)

先思考两个问题:

  • 开发人员在开发一个应用程序时需要什么日志信息?在程序正式上线后需要什么日志信息?
  • 运维人员在部署开发环境时需要什么日志信息?在部署生产环境时需要什么日志信息?

软件开发阶段 或部署开发环境时,为了尽可能地详细查看应用程序的运行状态以保证上线后的稳定性,若是把应用程序所有的运行日志全部记录下来进行分析,那么将是非常耗费机器性能的。而在应用程序正式发布 或在生产环境部署应用程序时,通常只需要记录应用程序的异常信息、错误信息等,这样既可以减小服务器I/O压力,也可以避免在排查故障时被淹没在日志的海洋里。那么,如何在不改动应用程序代码的情况下实现在不同的环境下记录不同详细程序的日志?日志级别的作用就来了,通过配置文件指定我们需要的日志级别就OK。

不同应用程序所定义的级别可能有所差别。分的详细点的会包含以下几个等级:

  • DEBUG
  • INFO
  • NOTICE
  • WARNING
  • ERROR
  • CRITICAL
  • ALERT
  • EMERGENCY

1.4、日志是什么形式(日志格式)?有什么内容(字段信息)?

一条日志信息对应的是 一个事件的发生,而一个事件通常需要包括以下内容:

  1. 发生时间
  2. 发生位置
  3. 严重程度,即 日志级别
  4. 内容

上述都是一条日志记录中可能包含的字段信息。还可能包括一些其他信息,如进程ID、进程名称、线程ID、线程名称等。

日志格式是用来定义一条日志记录中包含哪些字段的,而且日志格式通常是可以自定义的。

PS:输出一条日志时,日志内容、日志级别是需要开发人员明确指定的。对于其他字段信息,只需要是否显示在日志中即可。

1.5、如何实现日志功能?

几乎所有开发语言都会内置日志相关的功能,或者会有比较优秀的第三方库来提供日志操作功能,它们功能强大、使用简单。在Python 语言中,自身提供了一个用于记录日志的标准库模块---- logging

以下将围绕Python标准库模块 logging展开。

2、logging 模块

logging模块【定义的函数 和类】为应用程序和库的开发 实现了一个灵活的【事件日志系统】。logging模块 是Python的一个标准库模块,由标准库模块提供【日志记录API】的重要好处是所有Python模块都可以使用这个日志记录功能。所以,开发者的应用日志可以将开发者自己的日志信息 与来自第三方模块的信息整合起来。

2.1、logging模块的日志级别

级别名称简介(及何时使用)
1(级别最低)DEBUGdebug,调试。记录详细信息(这是最详细的日志信息。通常只在【诊断问题】时有意义)
2(重要)INFOinformation的简写。通常只记录关键节点信息,用于确认事件按预期工作。
3(警告)WARNINGwarning,警告。当某些不期望的事件发生时记录的信息。表明发生了意外情况,或者预示在不久的将来将发生一些问题(如磁盘空间不足)。但软件现在仍按预期正常工作。
4(错误)ERRORerror,错误。记录 【由于更严重的问题而导致软件无法执行某些功能时】的信息。
5(严重)CRITICALcritical,严重/危急。记录【当发生严重错误,表示程序本身可能无法继续运行】时的信息。
表中日志级别从上到下依次升高,即 DEBUG < INFO < WARNING < ERROR < CRITICAL。而日志的信息量是依次减少的。
  • 开发应用程序 或部署开发环境时,可使用DEBUG 或INFO级别的日志获取尽可能详细的日志信息来进行开发或部署调试;
  • 应用上线 或部署生产环境时,应该使用WARNING或CRITICAL级别的日志来降低机器的I/O压力和提高获取错误日志信息的效率;
  • 日志级别的指定通常是在应用程序的配置文件中进行指定的。

PS:当为某个应用程序指定一个日志级别后,应用程序会记录所有日志级别大于或等于指定日志级别的日志信息,而不是仅仅记录指定级别的日志信息,只要级别大于或等于该指定日志级别的日志记录才会被输出,小于该级别的日志记录将会被丢弃。

2.2、logging模块的使用方式

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

  • 方式1:使用logging提供的模块级别的函数
  • 方式2:使用Logging日志系统的四大组件

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

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

函数说明
logging.debug(msg, *args, **kwrags)创建一条严重级别为DEBUG的日志记录
logging.info(msg, *args, **kwrags)创建一条严重级别为INFO的日志记录
logging.warning(msg, *args, **kwrags)创建一条严重级别为WARNING的日志记录
logging.error(msg, *args, **kwrags)创建一条严重级别为ERROR的日志记录
logging.critical(msg, *args, **kwrags)创建一条严重级别为CRITICAL的日志记录
logging.log(level, *args, **kwrags)创建一条严重级别为level的日志记录
logging.basicConfig(**kwrags)对root logger进行一次性配置

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

logging模块的四大组件

组件说明
loggers提供应用程序代码直接使用的接口
handlers用于将日志记录发送到指定的目的位置
filters提供更细粒度的日志过滤功能,用于决定哪些日志记录将会被输出(其它的日志将会被忽略)
formatters用于控制日志信息的最终输出格式

PS:logging模块提供的模块级别的上述函数 实质上也是通过上述几个组件的相关类来记录日志的,只是在创建这些类的实例时设置了一些默认值。

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

回顾两个重要知识点:

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

最简单的日志输出
分别输入一条不同日志级别的日志记录:

chenchen@chenchen-ubuntu:/usr/ccdocs/test$ vim logtest.py

代码如下:

from logging import debug, info, warning, error, critical

debug("This is a debug log.")
info("This is a info log.")
warning("This a warning log.")
error("This a error log.")
critical("This a critical log.")

运行py文件,输出结果:

chenchen@chenchen-ubuntu:/usr/ccdocs/test$ python logtest.py
WARNING:root:This a warning log.
ERROR:root:This a error log.
CRITICAL:root:This a critical log.

上述源码等价于:

import logging

logging.log(logging.DEBUG, "This is a debug log.")
logging.log(logging.INFO, "This is a info log.")
logging.log(logging.WARNING, "This a warning log.")
logging.log(logging.ERROR, "This a error log.")
logging.log(logging.CRITICAL, "This a critical log.")

从上述打印结果可看出:

  • 前两条日志级别(DEBUG和INFO)的日志没有被打印出来。这是因为logging模块提供的日志记录函数所使用的日志器设置的日志级别是WRANING,因此只有大于或等于WARNING级别的日志才会被输出。
  • 打印的每行日志记录的各个字段含义分别是:日志级别:日志器名称:日志内容。之所以这样输出,是因为logging模块提供的日志记录函数所使用的日志器设置的日志格式默认是BASIC_FORMAT,其值为"%(levelname)s:%(name)s:%(message)s"
  • 如何将日志记录输出到文件中,而不是打印到控制台?答案是:更改logging模块提供的日志记录函数所使用的日志器设置的处理器所指定的日志输出位置,默认是sys.stderr(即打印到控制台)。
  • 查看这些日志记录函数的实现代码,可发现:当开发者未提供任何配置信息时,这些函数都回去调用logging.basicConfig(**kwargs)方法,且不会向该方法传递任何参数。如果想修改默认设置,那么就在调用上述这些日志记录函数之前,手动调用basicConfig()方法,并将欲设置的内容以参数形式传递进去。

详解logging.basciConfig()函数:
这个方法(函数)是用于为logging日志系统做一些基本配置,方法定义是logging.basicConfig(**kwargs),可接收的关键字参数如下:

参数名称说明
filename指定日志输出目标文件的文件名,指定该设置项后日志信息就不会被输出到控制台了
filemode指定日志文件的打开模式,默认为'a'。该选项须指定了filename时才有效
format指定日志格式字符串,即 指定日志输出时所包含的字段信息以及它们的顺序。logging模块定义的格式字段会在下面列出
datefmt指定日期/时间格式。该选项需在format中包含时间字段%(asctime)s时才有效
stylePython3.2中新添加的配置项。用于指定format格式字符串的风格,可取值为'%''{''$',默认为'%'
level指定日志器的日志级别
stream指定日志输出目标stream,如sys.stdoutsys.stderr、以及网络stream。streamfilename不能同时提供,否则会引发ValueError异常。
handlersPython3.3中新添加的配置项。该选项如果被指定,它应该是一个创建了多个Handler的可迭代对象,这些handler将会被添加到root logger。另外,filenamestreamhandlers三个配置项只能有一个存在,不能同时出现2个或3个,否则会引发ValueError异常。

参考官方链接logging.basicConfig(**kwargs)

附:详解logging模块定义的format格式字符串字段:

字段/属性名称使用格式说明
asctime%(asctime)s日志事件发生的时间,即人类可读时间,如 2019-01-16 11:32:56,689
created%(created)f日志事件发生的时间,即 时间戳,就是当时调用time.time()函数返回的值
relativeCreated%(relativeCreated)d日志事件发生的时间相对于logging模块加载时间的相对毫秒数
msecs%(msecs)d日志事件发生的时间的毫秒部分
levelname%(levelname)s该日志记录的文字形式的日志级别(DEBUG、INFO、WARNING、ERROR、CRITICAL)
levelno%(levelno)s该日志记录的数字形式的日志级别(10,20,30,40,50)
name%(name)s所使用的日志器名称,默认是'root',因为默认使用rootLogger
message%(message)s日志记录的文本内容,通过msg % args 计算得到的
pathname%(pathname)s调用日志记录函数的源码文件的全路径
filename%(filename)spathname的文件名部分,包含文件后缀
module%(module)sfilename的名称部分,不包含后缀
lineno%(lineno)d调用日志记录函数的源代码所在的行号
funcName%(funcName)s调用日志记录函数的函数名
process%(process)d进程ID
processName%(processName)s进程名称,Python3.1新增的
thread%(thread)d线程ID
threadName%(threadName)s线程名称

经过上述讲解,下方实践一下:通过“自定义”配置输出日志
实例1:配置日志器的日志级别

import logging

logging.basicConfig(level=logging.DEBUG)

logging.debug("This is a debug log.")
logging.info("This is a info log.")
logging.warning("This a warning log.")
logging.error("This a error log.")
logging.critical("This a critical log.")

打印:

(Tcloud) chenchen@chenchen-ubuntu:/usr/ccdocs/test$ python logtest.py
DEBUG:root:This is a debug log.
INFO:root:This is a info log.
WARNING:root:This a warning log.
ERROR:root:This a error log.
CRITICAL:root:This a critical log.

所有等级的日志信息都被打印出来了。

实例2:配置日志输出目标文件和日志格式

(Tcloud) chenchen@chenchen-ubuntu:/usr/ccdocs/test$ vim logtest.py
import logging

LOG_FORMAT = "%(asctime)s - %(levelname)s - %(message)s"
logging.basicConfig(filename='mytest.log', level=logging.DEBUG, format=LOG_FORMAT)

logging.debug("This is a debug log.")
logging.info("This is a info log.")
logging.warning("This a warning log.")
logging.error("This a error log.")
logging.critical("This a critical log.")

运行该py文件:

(Tcloud) chenchen@chenchen-ubuntu:/usr/ccdocs/test$ python logtest.py

控制台中不会打印日志内容了,而是在该py文件所在相同目录下生成了名为mytest.py的日志文件,其内容是:

2019-01-17 17:55:50,060 - DEBUG - This is a debug log.
2019-01-17 17:55:50,061 - INFO - This is a info log.
2019-01-17 17:55:50,061 - WARNING - This a warning log.
2019-01-17 17:55:50,061 - ERROR - This a error log.
2019-01-17 17:55:50,061 - CRITICAL - This a critical log.

实例3:设置日期和时间格式

import logging

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

logging.basicConfig(filename='mytest.log', level=logging.DEBUG, format=LOG_FORMAT, datefmt=DATE_FORMAT)

logging.debug("This is a debug log.")
logging.info("This is a info log.")
logging.warning("This a warning log.")
logging.error("This a error log.")
logging.critical("This a critical log.")

运行该py文件,日志内容会保存在mytest.log文件中:

01/17/2019 18:09:48 PM - DEBUG - This is a debug log.
01/17/2019 18:09:48 PM - INFO - This is a info log.
01/17/2019 18:09:48 PM - WARNING - This a warning log.
01/17/2019 18:09:48 PM - ERROR - This a error log.
01/17/2019 18:09:48 PM - CRITICAL - This a critical log.

几点注意

  • logging.basicConfig()函数是一个一次性的简单配置工具,即只有在第一次调用该函数时会起作用,后续再次调用该函数时完全不会产生任何操作的,多次调用的设置并不是累加操作
  • 日志器(Logger)是有层级关系的,上面调用的logging模块级别的函数所使用的日志器是RootLogger类的实例,其名称为'root',它是处于日志器层级关系最顶层的日志器,且该实例是以单例模式存在的。
  • 如果要记录的日志中包含变量数据,可使用一个格式字符串作为这个事件的描述信息(logging.debug、logging.info等函数的第一个参数),然后将变量数据作为第二个参数*args的值进行传递,如logging.warning('%s is %d years old.', 'Lily', 18),打印内容为WARNING:root:Lily is 18 years old.
  • logging.debug()logging.info()等方法的定义中,除了msgargs参数外,还有一个**kwargs参数。它们支持3个关键字参数:exc_infostack_infoextra,下方将对这几个关键字参数做解释。

关于exc_infostack_infoextra关键字参数的说明:

  • exc_info:其值为布尔值,如果该参数的值设置为True,则会将异常信息添加到日志消息中。如果没有异常信息,则添加None到日志信息中。
  • stack_info:其值也为布尔值,默认值为False。如果该参数的值设置为True,栈信息将会被添加到日志信息中。
  • extra:这是一个字典(dict)参数,它可以用来自定义消息格式所包含的字段,但它的key不能与logging模块定义的字段冲突。

实例:在日志消息中添加exc_info信息,并添加两个自定义的字段ipuser

import logging

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

logging.basicConfig(level=logging.DEBUG, format=LOG_FORMAT, datefmt=DATE_FORMAT)

logging.debug("Some one delete the log file.", exc_info=True, extra={'user':'Lily', 'ip':'10.2.0.140'})

运行,打印结果:

(Tcloud) chenchen@chenchen-ubuntu:/usr/ccdocs/test$ python logtest.py
2019-01-18 14:32:41 PM - DEBUG - Lily[10.2.0.140] - Some one delete the log file.
None

3、logging 模块 日志流处理流程

3.1、logging日志模块-基础知识:四大组件

组件名称对应类名功能描述
日志器Logger提供了应用程序可一直使用的接口
处理器Handler将logger创建的日志记录发送到合适的目的地输出
过滤器Filter提供了更细粒度的控制工具来决定输出哪条日志记录,丢弃哪条日志记录
格式器Formatter决定日志记录的最终输出格式
logging模块 就是通过这些组件来完成日志处理的,上述所使用的logging模块级别的函数也是通过这些组件对应的类来实现的。

这些组件之间的关系描述

  • 日志器(logger)需要通过处理器(handler)将日志信息输出到目标位置,如:文件、sys.stdout、网络等;
  • 不同的处理器(handler)可以将日志输出到不同的位置;
  • 日志器(logger)可以设置多个处理器(handler)将同一条日志记录输出到不同的位置;
  • 每个处理器(handler)都可以设置自己的过滤器(filter)实现日志过滤,从而只保留感兴趣的日志;
  • 每个处理器(handler)都可以设置自己的格式器(formatter)实现同一条日志以不同的格式输出到不同的地方。

总结:日志器(logger)是入口,真正“干活”的是处理器(handler),处理器(handler)还可以通过过滤器(filter)和格式器(fomatter)对要输出的日志内容做过滤和格式化等处理操作。

3.2、logging日志模块-相关类、及其常用方法介绍:

接下来将讲述与logging四大组件相关的类:LoggerHandlerFilterFormatter

Logger类

Logger对象有3个任务要做:

  1. 向应用程序代码暴露几个方法,使应用程序可以在运行时记录日志消息;
  2. 基于日志严重等级(默认的过滤设置)或filter对象来决定要对哪些日志进行后续处理;
  3. 将日志消息传送给所有感兴趣的日志handlers。

Logger对象最常用的方法分为两类:配置方法、消息发送方法。最常用的配置方法如下:

方法描述
Logger.setLevel()设置日志器将会处理的日志消息的最低严重级别
Logger.addHandler()Logger.removeHandler()为该logger对象添加或移除一个handler对象
Logger.addFilter()Logger.removeFilter()为该logger对象添加或移除一个filter对象

其中,Logger.setLevel()方法的说明:
内建等级中,级别最低的是DEBUG,级别最高的是CRITICAL。例:setLevel(logging.INFO),此时函数函数为INFO,那么该logger将只会处理INFO、WARNING、ERROR、CRITICAL级别的日志,而DEBUG级别的消息将会被忽略或丢弃。

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

方法描述
Logger.debug()Logger.info()Logger.warning()Logger.error()Logger.critical()创建一个与它们的方法名对应等级的日志记录
Logger.exception()创建一个类似于Logger.error()的日志消息
Logger.log()需要获取一个明确的日志level参数来创建一个日志记录
其中,有两点说明:
  • Logger.exception()Logger.error()的区别:前者将会输出堆栈追踪信息,另外通常只是在一个exception handler中调用该方法。
  • Logger.log()Logger.debug()Logger.info()等方法相比,虽然需要多传一个level参数,显得不是那么方便,但是当需要记录自定义level的日志时还是需要该方法来完成的。

那么,如何得到一个Logger对象?有两种方式:

  • 方式1:通过Logger类的实例化方法创建一个Logger类的实例;
  • 方式2:logging.getLogger()方法
    。(这是最常用的)

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

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

  • logger的名称是一个以 . 分割的层级结构,每个.后面的logger都是 .前面的logger的children。例:有一个名称为foo的logger,其他名称分别为foo.barfoo.bar.bazfoo.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在完成对日志消息的处理后,默认会将日志消息传递给与它们的祖先logger相关的handlers。因此,我们不必为一个应用程序中所使用的所有loggers定义和配置handlers,只需要为一个顶层的logger配置handlers,然后按照需要创建child loggers就可足够了。我们也可以通过将一个logger的propagate属性设置为False来关闭这种传递机制。

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

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

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

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

方法描述
Handler.setLevel()设置handler将会处理的日志消息的最低严重级别
Handler.setFormatter()为handler设置一个格式器对象
Handler.addFilter()Handler.removeFilter()为handler添加和删除一个过滤器对象
注意:应用程序代码 不应该直接实例化和使用Handler实例。因为Handler是一个基类,它只定义了所有handlers都应该有的接口,同时提供了一些子类可以直接使用或覆盖的默认行为。下方是一些常用的Handler:
Handler 名称描述
logging.StreamHandler将日志消息发送到输出到Stream,如std.out或任何file-like对象
logging.FileHandler将日志消息发送到磁盘文件,默认情况下文件大小无限增长
logging.handlers.RotatingFileHandler将日志消息发送到磁盘文件,并支持日志文件按大小切割
logging.handlers.TimedRotatingFileHandler将日志消息发送到磁盘文件,并支持日志文件按时间切割
logging.handlers.HTTPHandler将日志消息以GET或POST的方式发送给一个HTTP服务器
logging.handlers.SMTPHandler将日志消息发送给一个指定的email地址
logging.NullHandler该Handler实例会忽略error messages,通常被想使用logging的library开发者使用来避免“No handlers could be found for logger XXX”信息的出现

Formatter类

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

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

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

可见,该构造方法接收3个可选参数:

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

Filter类

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

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

例如,一个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 表示可以通过过滤。

PS:

  • 如果有需要,也可以在filter(record)方法内部改变该record,比如添加、删除或修改一些属性;
  • 还可以通过filter做一些统计工作,比如计算被一个特殊的logger或handler所处理的record数量

3.3、logging日志流 处理流程

在这里插入图片描述
流程解析:

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

可见,一条日志信息要想被最终输出需要依次经过以下4次过滤:

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

PS:上方第9个步骤,如果propagate值为1,那么日志消息会直接传递交给上一级logger的handlers进行处理,此时上一级logger的日志等级并不会对该日志消息进行等级过滤。

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

到此为止,对logging模块的重要组件 及整个日志流处理流程已有一个较全面的了解了。下方实例:

1)日志记录的需求

  • ①将所有级别的所有日志都写入磁盘文件中;
  • ②all.log文件中记录所有的日志信息,日志格式为:日期和时间-日志级别-日志信息;
  • ③error.log文件中单独记录error及以上级别的日志信息,日志格式为:日期和时间-日志级别-文件名[:行号]-日志信息;
  • ④all.log在每天凌晨进行日志切割。

2)分析

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

3)代码实现
logtest.py

import logging
import logging.handlers
import datetime

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

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

运行py文件

chenchen@chenchen-ubuntu:/usr/ccdocs/test$ python3 logtest.py

与该py文件同目录下将新增all.log和error.log文件,内容分别为:
all.log

chenchen@chenchen-ubuntu:/usr/ccdocs/test$ cat all.log
2019-02-20 21:56:26,052 - DEBUG - debug message
2019-02-20 21:56:26,053 - INFO - info message
2019-02-20 21:56:26,053 - WARNING - warning message
2019-02-20 21:56:26,053 - ERROR - error message
2019-02-20 21:56:26,053 - CRITICAL - critical message

error.log

chenchen@chenchen-ubuntu:/usr/ccdocs/test$ cat error.log
2019-02-20 21:56:26,053 - ERROR - logtest.py[:21] - error message
2019-02-20 21:56:26,053 - CRITICAL - logtest.py[:22] - critical message

4、配置 log(日志) 的几种方式

作为开发者,可通过下方3种方式来配置logging:

  • ① 使用Python代码显式地创建loggershandlersformatters,并分别调用它们的配置函数;
  • ② 创建一个日志配置文件,然后使用fileConfig()函数来读取该文件的内容;
  • ③ 创建一个包含配置信息的dict,然后把它传递dictConfig()函数。

PS:logging.basicConfig()也属于第①种方式,它只是对loggershandlersformatters的配置函数进行了封装。第②种配置方式优于第①种在于,它将配置信息和代码进行了分离,这一方面降低了日志的维护成本,同时让非开发人员也可以容易地修改日志配置。

4.1、使用Python代码实现日志配置
实例:代码

chenchen@chenchen-ubuntu:/usr/ccdocs/test$ vim logtest02.py
import sys
import logging

# 创建一个日志器logger,并设置其日志级别为DEBUG
logger = logging.getLogger('simple_logger')
logger.setLevel(logging.DEBUG)

# 创建一个流处理器handler,并设置其日志级别为DEBUG
handler = logging.StreamHandler(sys.stdout)
handler.setLevel(logging.DEBUG)

# 创建一个格式器formatter,并将其添加到处理器handler
formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s")
handler.setFormatter(formatter)

# 为日志器logger添加上面创建的处理器handler
logger.addHandler(handler)

# 日志输出
logger.debug("debug message")
logger.info("info message")
logger.warn("warn message")
logger.error("error message")
logger.critical("critical message")

运行,结果:

chenchen@chenchen-ubuntu:/usr/ccdocs/test$ python3 logtest02.py
2019-02-22 11:55:43,936 - simple_logger - DEBUG - debug message
2019-02-22 11:55:43,937 - simple_logger - INFO - info message
2019-02-22 11:55:43,937 - simple_logger - WARNING - warn message
2019-02-22 11:55:43,937 - simple_logger - ERROR - error message
2019-02-22 11:55:43,937 - simple_logger - CRITICAL - critical message

4.2、使用配置文件和fileConfig()函数实现日志配置

通过【配置文件】的方式来实现与上面同样的功能:
logtest03.py

import logging
import logging.config

# 读取日志配置文件的内容
logging.config.fileConfig('logging.conf')

# 创建一个日志器logger
logger = logging.getLogger('simpleExample')

# 日志输出
logger.debug('debug message')
logger.info('info message')
logger.warn('warn message')
logger.error('error message')
logger.critical('critical message')

配置文件loging.conf内容如下:

[loggers]
keys=root,simpleExample

[handlers]
keys=fileHandler,consoleHandler

[formatters]
keys=simpleFormatter

[logger_root]
level=DEBUG
handlers=fileHandler

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

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

[handler_fileHandler]
class=FileHandler
args=('logging.log', 'a')
level=ERROR
formatter=simpleFormatter

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

运行,结果:

chenchen@chenchen-ubuntu:/usr/ccdocs/test$ python3 logtest03.py
2019-02-22 18:06:22,936 - simpleExample - DEBUG - debug message
2019-02-22 18:06:22,936 - simpleExample - INFO - info message
2019-02-22 18:06:22,936 - simpleExample - WARNING - warn message
2019-02-22 18:06:22,936 - simpleExample - ERROR - error message
2019-02-22 18:06:22,936 - simpleExample - CRITICAL - critical message

几点说明:
①、fileConfig()函数说明:
该函数实际上是 对configparser模块的封装。
函数定义:
该函数定义在logging.config模块下:

logging.config.fileConfig(fname, defaults=None, disable_existing_loggers=True)

其中参数详解:

  • fname:表示配置文件的文件名或文件对象
  • defaults:指定传给ConfigParser的默认值
  • disable_existing_loggers:布尔型值,默认值为True(为了向后兼容)表示禁用已经存在的logger,除非它们或它们的parent明确地出现在日志配置中;如果 值为False,则对已存在的loggers保持启动状态。

②、配置文件格式说明:
fileConfig()函数是对configparser模块的封装,即:fileConfig()函数是基于configparser模块来理解日志配置文件的。换句话说,fileConfig()函数所能理解的配置文件基础格式是与configparser模块一致的,只是在此基础上对文件包含的sectionoption做了一下规定和限制。比如:

  • 1)配置文件中一定要包含loggershandlersformatters这些section,它们通过keys这个option来指定该配置文件中已经定义好的loggershandlersfomatters,多个值之间用逗号分割;另外,loggers这个section中的keys一定要包含root这个值;
  • 2)loggershandlersformatters中所指定的日志器、处理器、格式器都需要在下面以单独的section进行定义。section的命名规则为[logger_loggerName][formatter_formatterName][handler_handlerName]
  • 3)定义logger的section必须指定levelhandlers这两个option。其中,level的可取值有DEBUGINFOWARNINGERRORCRITICALNOTSET(NOTSET表示所有级别的日志消息都要记录,包括用户定义级别);handlers的值是以逗号分隔的handlers名字列表,这里出现的handlers必须出现在[handlers]这个section中,并且相应的handler必须在配置文件中有对应的section定义;
  • 4)对于非root logger来说,除了levelhandlers这两个option之外,还需要一些额外的option,其中qualname是必须提供的option,它表示在logger层级中的名字,在应用代码中通过这个名字得到logger;propagate是可选项,其默认值为1,表示消息将会传递给高层次logger的handler,通常我们需要指定其值为0,这个可以看下方例子;另外,对于非root logger的level,如果设置为NOTSET,系统将会查找高层次的logger来决定此logger的有效level
  • 5)定义handler的section中必须指定classargs这两个option,levelformatter为可选option。其中,class表示用于创建handler的类名,args表示传递给class所指定的handler类初始化方法参数,它必须是一个元组(tuple)的形式,即便只有一个参数值也需要是一个元组的形式;level与logger中的level一样,而formatter指定的是该处理器所使用的格式器,这里指定的格式器名称必须出现在formatters这个section中,且在配置文件中必须要有这个formatter的section定义;如果不指定formatter则该handler将会以消息本身作为日志消息进行记录,而不添加额外的时间、日志器名称等信息;
  • 6)定义formatter的section中的option都是可选的,其中包括format用于指定格式字符串,默认为消息字符串本身;datefmt用于指定asctime的时间格式,默认为'%Y-%m-%d %H:%M:%S'class用于指定格式器类名,默认为logging.Formatter

PS:配置文件中的class指定类名时,该类名可以是相对于logging模块的相对值,如:FileHandlerhandlers.TimedRotatingFIleHandler;也可以是一个绝对路径值,通过普通的import机制来解析,如自定义的handler类mypackage.mymodule.MyHandler,但是mypackage需要在Python可用的导入路径中(即 sys.path)。

③、propagate属性说明

propagate:译作“传播、传递”

实例1:
logging.conf中simpleExample这个handler定义中的propagate属性值改为1,或者删除这个option(默认值就是1):

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

再次执行logtest03.py的代码,除了在控制台有输出信息,在logging.log文件中也有内容输出:

chenchen@chenchen-ubuntu:/usr/ccdocs/test$ python3 logtest03.py
2019-02-23 16:39:31,050 - simpleExample - DEBUG - debug message
2019-02-23 16:39:31,050 - simpleExample - INFO - info message
2019-02-23 16:39:31,050 - simpleExample - WARNING - warn message
2019-02-23 16:39:31,050 - simpleExample - ERROR - error message
2019-02-23 16:39:31,050 - simpleExample - CRITICAL - critical message
chenchen@chenchen-ubuntu:/usr/ccdocs/test$ cat logging.log
2019-02-23 16:39:31,050 - simpleExample - ERROR - error message
2019-02-23 16:39:31,050 - simpleExample - CRITICAL - critical message

这说明simpleExample这个logger在处理完日志记录后,将日志记录传递给了上级的root logger再次做处理,所以才会有两个地方都有日志记录的输出。通常,我们都需要显式地指定propagate值为0,防止日志记录向上层logger传递。

实例2:
试着用一个没有在配置文件中定义的logger名称来获取logger:修改logtest03.py代码

import logging
import logging.config

# 读取日志配置文件内容
logging.config.fileConfig('logging.conf')

# 用一个【没有在配置文件中】定义的logger名称来创建一个日志器logger
logger = logging.getLogger('simpleExample1')

# 日志输出
logger.debug('debug message')
logger.info('info message')
logger.warn('warn message')
logger.error('error message')
logger.critical('critical message')

运行可发现:在控制台没有任何输出,而logging.log文件中又多了两行输出:

chenchen@chenchen-ubuntu:/usr/ccdocs/test$ python3 logtest03.py
chenchen@chenchen-ubuntu:/usr/ccdocs/test$ cat logging.log
2019-02-23 16:39:31,050 - simpleExample - ERROR - error message
2019-02-23 16:39:31,050 - simpleExample - CRITICAL - critical message
2019-02-23 16:48:45,969 - simpleExample1 - ERROR - error message
2019-02-23 16:48:45,969 - simpleExample1 - CRITICAL - critical message

这是因为:当一个日志器没有被设置任何处理器时,系统会去查找该日志器的上层日志器上所设置的日志处理器来处理日志记录。simpleExample1在配置文件中没有被定义,因此logging.getLogger(simpleExample1)这行代码是获取了一个logger实例,并没有给它设置任何处理器,但是它的上级日志器(root logger)在配置文件中有定义且设置了一个FileHandler处理器,simpleExample1处理器最终通过这个FileHandler处理器将日志记录输出到logging.log文件中。

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

Python 3.2中引入的一种新的配置日志记录的方法,即 用字典来保存logging配置信息。这个方法 相对于上述所讲的基于配置文件来保存logging配置信息的方式来说,功能更加强大,也更加灵活,因为我们可将很多的数据转换成字典。比如,可使用JSON格式的配置文件、YAML格式的配置文件,然后将它们填充到一个配置字典中;或者,也可以用Python代码构建这个配置字典,或者通过socket接收pickled序列化后的配置信息。总之,可以使用我们的应用程序可以操作的任何方法来构建这个配置字典。

实例:使用YAML格式的配置文件来完成与上述同样的日志配置
首先,需要安装PyYAML模块:

pip install PyYAML

(我已经将其安装在了虚拟环境中,所以有如下步骤。并且这里使用的是Python 2.x)

更多关于YAML信息可参考博文:Python使用第三方库之【yaml】

chenchen@chenchen-ubuntu:/usr/ccdocs/test$ cd /usr/Tcloud
chenchen@chenchen-ubuntu:/usr/Tcloud$ pipenv shell
(Tcloud) chenchen@chenchen-ubuntu:/usr/Tcloud$ cd /usr/ccdocs/test

logtest04.py代码

import logging
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')

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
loggers:
  simpleExample:
    level: DEBUG
    handlers: [console]
    propagate: yes
root:
  level: DEBUG
  handlers: [console_err]

运行,输出结果:

(Tcloud) chenchen@chenchen-ubuntu:/usr/ccdocs/test$ python logtest04.py
2019-02-23 20:45:33,097 - simpleExample - DEBUG - debug message
2019-02-23 20:45:33,097 - simpleExample - INFO - info message
2019-02-23 20:45:33,097 - simpleExample - WARNING - warn message
2019-02-23 20:45:33,097 - simpleExample - ERROR - error message
2019-02-23 20:45:33,097 - simpleExample - ERROR - error message
2019-02-23 20:45:33,097 - simpleExample - CRITICAL - critical message
2019-02-23 20:45:33,097 - simpleExample - CRITICAL - critical message

几点说明:
dictConfig()函数的说明:
该函数实际是对configparser模块的封装。
函数定义:
该函数定义在logging.config模块下:

logging.config.dictConfig(config)

该函数可以从一个字典对象中获取日志配置信息,config参数就是这个字典对象。

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

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

key 名称描述
version必选项。其值是一个整数值,表示配置格式的版本,当前唯一可用的值是1
formatters可选项。其值是一个字典对象,该字典对象每个元素的key为要定义的格式器名称,value为格式器的配置信息组成的dict,如format和datefmt
filters可选项。其值是一个字典对象,该字典对象每个元素的key为要定义的过滤器名称,value为过滤器的配置信息组成的dict,如value
handlers可选项。其值是一个字典,该字典对象每个元素的key为要定义的处理器名称,value为处理器的配置信息组成的dict,如class、level、formatters、filters,其中class为必选项,其他为可选项;其他配置信息将会传递给class所指定的处理器类的构造函数,如下面的handlers定义示例中的stream、filename、maxBytes和backupCount等
loggers可选项。其值是一个字典对象,该字典对象每个元素的key为要定义的日志器名称,value为日志器的配置信息组成的dict,如level、handlers、filters和propagate。
root可选项。是root logger的配置信息,其值也是一个字典对象。除非在定义其它logger时,明确指定propagate值为no,否则root logger定义的handlers都会被作用到其他logger上
incremental可选项。默认值为False,该选项的意义在于:如果这里定义的对象已经存在,那么这里对这些对象的定义是否应用到已存在的对象上。值为False表示,已存在的对象将会被重新定义。
disable_existing_loggers可选项。默认值为True,该选项用于指定是否禁用已存在的日志器loggers,如果incremental的值为True,则该选项将会被忽略

handlers定义示例:

handlers:
  console:
    class : logging.StreamHandler
    formatter: brief
    level   : INFO
    filters: [allow_foo]
    stream  : ext://sys.stdout
  file:
    class : logging.handlers.RotatingFileHandler
    formatter: precise
    filename: logconfig.log
    maxBytes: 1024
    backupCount: 3

③ 外部对象的访问:

需要说明的是,上面所使用的对象并不限于logging模块所提供的对象,我们可以实现自己的formatterhandlers类。另外这些类的参数也许需要包含sys.stderr这样的外部对象。如果配置字典对象是使用Python代码构造的,可以直接使用sys.stdoutsys.stderr;但是当通过文本文件(如JSON、YAML格式的配置文件)提供配置时就会出现问题,因为在文本文件中,没有标准的方法来区分sys.stderr和字符串'sys.stderr'。为了区分它们,配置系统会在字符串值中查找特定的前缀,例如'ext://sys.stderr'中的'ext://'会被移除,然后import sys.stderr

5、向日志输出 中添加上下文信息

除了传递日志记录函数的参数(如 msg)外,有时还想在日志输出中包含一些额外的上下文信息。比如,在一个网络应用中,或许希望在日志中记录客户端的特定信息,如:远程客户端的IP地址和用户名。在此介绍如下3种实现方式:

  • ① 通过向日志记录函数传递一个extra参数引入上下文信息;
  • ② 使用LoggerAdapter引入上下文信息;
  • ③ 使用Filter引入上下文信息。

方式1:通过向日志记录函数传递一个extra参数引入上下文信息

这个方法前面提到过,例:

(Tcloud) chenchen@chenchen-ubuntu:/usr/ccdocs/test$ vim logtest05.py
(Tcloud) chenchen@chenchen-ubuntu:/usr/ccdocs/test$ cat logtest05.py
import logging
import sys

fmt = logging.Formatter("%(asctime)s - %(name)s - %(ip)s - %(username)s - %(message)s")
h_console = logging.StreamHandler(sys.stdout)
h_console.setFormatter(fmt)
logger = logging.getLogger("myPro")
logger.setLevel(logging.DEBUG)
logger.addHandler(h_console)

extra_dict = {"ip":"10.2.0.142", "username":"chen"}
logger.debug("User Login!", extra=extra_dict)

extra_dict = {"ip":"192.168.0.13", "username":"lv"}
logger.info("User Access!", extra=extra_dict)

运行:

(Tcloud) chenchen@chenchen-ubuntu:/usr/ccdocs/test$ python3 logtest05.py
2019-02-24 17:48:51,782 - myPro - 10.2.0.142 - chen - User Login!
2019-02-24 17:48:51,782 - myPro - 192.168.0.13 - lv - User Access!

但是 用这种方式传递信息并不是很方便,因为每次调用日志记录方法都要传递一个extra关键词参数。即便没有需要插入的上下文信息也是如此,因为该logger设置的formatter格式中指定的字典必须要存在。所以,推荐使用下方的方式2 和3来实现上下文信息的引入。

PS:可以尝试创建许多不同的Logger实例来解决上面存在的问题,但是显然不是好的解决方案,因为这些Logger实例并不会进行垃圾回收。尽管这在实践中不是个问题,但当Logger数量变得不可控时,将会非常难以管理。

方式2:使用LoggerAdapters 引入上下文信息

使用 LoggerAdapters类 来传递上下文信息到日志事件的信息中 是一个非常简单的方式,可以将其看作第一种实现方式的优化版,即 它为extra提供了一个默认值。这个类 设计的类似于Logger,因此可以像使用 Logger类 的实例那样来调用debug()info()warning()error()exception()critical()log()方法。
当创建一个LoggerAdapter实例时,我们需要传递一个Logger实例 和一个包含上下文信息的类字典对象给该类的实例构建方法。当调用LoggerAdapter实例的一个日志记录方法时,该方法会在对日志消息和字典对象进行处理后,调用构建该实例时传递给该实例的logger对象的同名的日志记录方法。下方是LoggerAdapter类中几个方法的定义:源码

class LoggerAdapter(object):
    """
    An adapter for loggers which makes it easier to specify contextual
    information in logging output.
    """

    def __init__(self, logger, extra):
        """
        Initialize the adapter with a logger and a dict-like object which
        provides contextual information. This constructor signature allows
        easy stacking of LoggerAdapters, if so desired.

        You can effectively pass keyword arguments as shown in the
        following example:

        adapter = LoggerAdapter(someLogger, dict(p1=v1, p2="v2"))
        """
        self.logger = logger
        self.extra = extra
    
    def process(self, msg, kwargs):
        """
        Process the logging message and keyword arguments passed in to
        a logging call to insert contextual information. You can either
        manipulate the message itself, the keyword args or both. Return
        the message and kwargs modified (or not) to suit your needs.

        Normally, you'll only need to override this one method in a
        LoggerAdapter subclass for your specific needs.
        """
        kwargs["extra"] = self.extra
        return msg, kwargs
        
    def debug(self, msg, *args, **kwargs):
        """
        Delegate a debug call to the underlying logger, after adding
        contextual information from this adapter instance.
        """
        msg, kwargs = self.process(msg, kwargs)
        self.logger.debug(msg, *args, **kwargs)

通过分析上述源码可得出结论:

  • 上下文信息是在LoggerAdapter类的process()方法中被添加到日志记录的输出消息中,如果要实现自定义需要 只需要实现LoggerAdapter的子类并重写process()方法即可;
  • process()方法的默认实现中,没有修改msg的值,只是为关键词参数插入了一个名为extra的key,这个extra的值为传递给LoggerAdapter类构造方法的参数值;
  • LoggerAdapter类构造方法所接收的extra参数,实际上就是为了满足logger的formatter格式要求所提供的默认上下文信息。

例:

(Tcloud) chenchen@chenchen-ubuntu:/usr/ccdocs/test$ vim logtest06.py
(Tcloud) chenchen@chenchen-ubuntu:/usr/ccdocs/test$ cat logtest06.py
import logging
import sys


# 初始化一个要传递给LoggerAdapter构造方法的logger实例
fmt = logging.Formatter("%(asctime)s - %(name)s - %(ip)s - %(username)s - %(message)s")
h_console = logging.StreamHandler(sys.stdout)
h_console.setFormatter(fmt)
init_logger = logging.getLogger("myPro")
init_logger.setLevel(logging.DEBUG)
init_logger.addHandler(h_console)

# 初始化一个要传递给LoggerAdapter构造方法的上下文字典对象
extra_dict = {"ip": "IP", "username": "USERNAME"}

# 获取一个LoggerAdapter类的实例
logger = logging.LoggerAdapter(init_logger, extra_dict)

# 应用中的日志记录方法调用
logger.info("User Login!")
logger.info("User Login!", extra={"ip": "10.2.0.142", "username": "Chen"})
logger.extra = {"ip": "10.2.0.142", "username": "Chen"}
logger.info("User Login!")
logger.info("User Login!")

运行,结果:

(Tcloud) chenchen@chenchen-ubuntu:/usr/ccdocs/test$ python3 logtest06.py
# 使用extra默认值:{"ip": "IP", "username": "USERNAME"}
2019-02-24 20:47:14,644 - myPro - IP - USERNAME - User Login!

# info(msg, extra)方法中传递的extra方法没有覆盖默认值
2019-02-24 20:47:14,644 - myPro - IP - USERNAME - User Login!

# extra默认值被修改了
2019-02-24 20:47:14,644 - myPro - 10.2.0.142 - Chen - User Login!
2019-02-24 20:47:14,644 - myPro - 10.2.0.142 - Chen - User Login!

根据上述输出的结果,会发现一个问题:传递给LoggerAdapter类构造方法的extra参数不能被LoggerAdapter实例的日志记录函数(如上方调用的info())中的extra参数覆盖,只能通过修改LoggerAdapter实例extra属性来修改默认值(如上面使用的logger.extra=xxx),但是这将意味着默认值被修改了。

解决此问题的思路应该是:实现一个LoggerAdapter的子类,重写process()方法。其中对于kwargs参数的操作应该是先判断其本身是否包含extra关键字,如果包含则不使用默认值进行替换;如果kwargs参数中不包含extra关键字则取默认值。具体实现如下:

import logging
import sys

class MyLoggerAdapter(logging.LoggerAdapter):

    def process(self, msg, kwargs):
        if 'extra' not in kwargs:
            kwargs["extra"] = self.extra
        return msg, kwargs

if __name__ == '__main__':
    # 初始化一个要传递给LoggerAdapter构造方法的logger实例
    fmt = logging.Formatter("%(asctime)s - %(name)s - %(ip)s - %(username)s - %(message)s")
    h_console = logging.StreamHandler(sys.stdout)
    h_console.setFormatter(fmt)
    init_logger = logging.getLogger("myPro")
    init_logger.setLevel(logging.DEBUG)
    init_logger.addHandler(h_console)
    
    # 初始化一个要传递给LoggerAdapter构造方法的上下文字典对象
    extra_dict = {"ip": "IP", "username": "USERNAME"}
    
    # 获取一个自定义LoggerAdapter类的实例
    logger = MyLoggerAdapter(init_logger, extra_dict)
    
    # 应用中的日志记录方法调用
    logger.info("User Login!")
    logger.info("User Login!", extra={"ip": "10.2.0.142", "username": "Chen"})
    logger.info("User Login!")
    logger.info("User Login!")

运行,结果:

# 使用extra默认值:{"ip": "IP", "username": "USERNAME"}
2019-02-24 20:54:38,441 - myPro - IP - USERNAME - User Login!

# info(msg, extra)方法中传递的extra方法已覆盖默认值
2019-02-24 20:54:38,441 - myPro - 10.2.0.142 - Chen - User Login!

# extra默认值保持不变
2019-02-24 20:54:38,441 - myPro - IP - USERNAME - User Login!
2019-02-24 20:54:38,441 - myPro - IP - USERNAME - User Login!

其实,如果想不受formatter的限制,在日志输出中实现自由的字段插入,可以通过在自定义LoggerAdapter的子类process()方法中将字典参数中的关键字信息拼接到日志事件的消息中。很明显,这些上下文中的字段信息在日志输出中的位置是有限制的。而使用'extra'的优势在于,这个类字典对象的值将被合并到这个LogRecord实例__dict__中,这样就允许我们通过Formatter实例自定义日志输出的格式字符串。这虽然使得上下文信息中的字段信息在日志输出中的位置变得与内置字段一样灵活,但是前提是传递给构造器方法的这个类字典对象中的key必须是确定且明了的。

方式3:使用 Filters 引入上下文信息

使用自定义的Filter.Filter实例的方式,在filter(record)方法中修改传递过来的LogRecord实例,将要加入的上下文信息作为新的属性赋值给该实例,这样就可以通过指定formatter的字符串格式来输出这些上下文信息了。

模仿上面的实现,在传递个filter(record)方法的LogRecord实例中添加两个与当前网络请求相关的信息:ipusername

(Tcloud) chenchen@chenchen-ubuntu:/usr/ccdocs/test$ vim logtest07.py
(Tcloud) chenchen@chenchen-ubuntu:/usr/ccdocs/test$ cat logtest07.py
import logging
from random import choice


class ContextFilter(logging.Filter):

        ip = 'IP'
        username = 'USER'

        def filter(self, record):
            record.ip = self.ip
            record.username = self.username
            return True

if __name__ == '__main__':
    levels = (logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR, logging.CRITICAL)
    users = ['Chen', 'LiHua', 'MenZhuo']
    ips = ['10.2.0.142', '192.168.0.91', '10.1.0.90']

    logging.basicConfig(level=logging.DEBUG,
                        format='%(asctime)-15s %(name)-5s %(levelname)-8s %(ip)-15s %(username)-8s %(message)s')
    logger = logging.getLogger('myLogger')
    filter = ContextFilter()
    logger.addFilter(filter)
    logger.debug('A debug message')
    logger.info('An info message with %s', 'some parameters')

    for x in range(5):
        lvl = choice(levels)
        lvlname = logging.getLevelName(lvl)
        filter.ip = choice(ips)
        filter.username = choice(users)
        logger.log(lvl, 'A message at %s level with %d %s' , lvlname, 2, 'parameters')

运行,结果:

(Tcloud) chenchen@chenchen-ubuntu:/usr/ccdocs/test$ python3 logtest07.py
2019-02-24 21:00:42,847 myLogger DEBUG    IP              USER     A debug message
2019-02-24 21:00:42,847 myLogger INFO     IP              USER     An info message with some parameters
2019-02-24 21:00:42,847 myLogger WARNING  192.168.0.91    MenZhuo  A message at WARNING level with 2 parameters
2019-02-24 21:00:42,847 myLogger CRITICAL 10.2.0.142      Chen     A message at CRITICAL level with 2 parameters
2019-02-24 21:00:42,847 myLogger CRITICAL 10.1.0.90       LiHua    A message at CRITICAL level with 2 parameters
2019-02-24 21:00:42,847 myLogger WARNING  10.1.0.90       MenZhuo  A message at WARNING level with 2 parameters
2019-02-24 21:00:42,847 myLogger CRITICAL 10.2.0.142      MenZhuo  A message at CRITICAL level with 2 parameters

PS:
实际的网络应用程序中,可能还要考虑多线程并发时的线程安全问题,此时可以把连接信息或者自定义过滤器的实例通过threading.local保存到到一个threadlocal中。

参考文档:
1、logging官方教程
2、logging模块官方文档
3、关于Python logging的更多高级用法,参考 Logging CookBook

  • 2
    点赞
  • 3
    收藏
    觉得还不错? 一键收藏
  • 1
    评论
评论 1
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值