2.5 日志记录
日志收集与分析是运维工作中十分重要的内容,要分析日志,最好先知道日志是如何生成的,这样才能知己知彼,分析日志才更有成效。本节将介绍如何通过Python的标准库logging模块定制自己多样化的记录日志需求。
2.5.1 日志模块简介
运维工作有很多情况需要查问题、解决bug,而查问题和解决bug的过程离不开查看日志,我们编写脚本或程序时总是需要有日志输出,Python的logging模块就是为记录日志使用的,而且是线程安全的,意味着使用它完全不用担心因日志模块的异常导致程序崩溃。
【示例2-21】首先看一下日志模块的第一个例子。简单将日志打印到屏幕:
输出为:
WARNING:root:warning message ERROR:root:error message CRITICAL:root:critical message
默认情况下,Python的logging模块将日志打印到标准输出中,而且只显示大于等于WARNING级别的日志,这说明默认的日志级别设置为WARNING(日志级别等级CRITICAL> ERROR > WARNING > INFO > DEBUG)。默认的日志格式:日志级别为Logger,名称为用户输出消息。
各日志级别代表的含义如下。
DEBUG:调试时的信息打印。
INFO:正常的日志信息记录。
WARNING:发生了警告信息,但程序仍能正常工作。
ERROR:发生了错误,部分功能已不正常。
CRITICAL:发生严重错误,程序可能已崩溃。
上面的例子是非常简单的,还不足以显示logging模块的强大,因为我们使用print函数也可以实现以上功能。下面来看第二个例子。
【示例2-22】将日志信息记录至文件(文件名:lx_log1.py)。
执行以上代码后发现,在当前目录多了一个文件lx_log1.log,文件内容与第一个例子的输出是一致的。多次执行lx_log1.py发现log文件的内容变多了,说明默认的写log文件的方式是追加。
2.5.2 logging模块的配置与使用
我们可以通过logging模块的配置改变log文件的写入方式、日志级别、时间戳等信息。例如下面的配置:
可见在logging.basicConfig()函数中可通过具体参数来更改logging模块的默认行为。
filename:用指定的文件名创建FiledHandler,这样日志会被存储在指定的文件中。
filemode:文件打开方式,在指定了filename时使用这个参数,默认值为a,还可指定为w。
format:指定handler使用的日志显示格式。
datefmt:指定日期时间格式。
level:设置rootlogger的日志级别。
stream:用指定的stream创建StreamHandler。可以指定输出到sys.stderr,sys.stdout或者文件,默认为sys.stderr。若同时列出了filename和stream两个参数,则stream参数会被忽略。
format参数中可能用到的格式化串如下。
%(name)s Logger的名字。
%(levelno)s数字形式的日志级别。
%(levelname)s文本形式的日志级别。
%(pathname)s调用日志输出函数的模块的完整路径名,可能没有。
%(filename)s调用日志输出函数的模块的文件名。
%(module)s调用日志输出函数的模块名。
%(funcName)s调用日志输出函数的函数名。
%(lineno)d调用日志输出函数的语句所在的代码行。
%(created)f当前时间,用UNIX标准表示时间的浮点数。
%(relativeCreated)d输出日志信息时,自Logger创建以来的毫秒数。
%(asctime)s字符串形式的当前时间。默认格式是“2013-07-08 16:49:45,896”。逗号后面的是毫秒。
%(thread)d线程ID,可能没有。
%(threadName)s线程名,可能没有。
%(process)d进程ID,可能没有。
%(message)s用户输出的消息。
【示例2-23】例如以下代码。
运行代码后我们会看到lx_log1.py文件的内容如下:
2018-06-07 21:09:51 lx_log1.py[line:9] DEBUG debug message 2018-06-07 21:09:51 lx_log1.py[line:10] INFO info message 2018-06-07 21:09:51 lx_log1.py[line:11] WARNING warning message 2018-06-07 21:09:51 lx_log1.py[line:12] ERROR error message 2018-06-07 21:09:51 lx_log1.py[line:13] CRITICAL critical message
这样的配置已基本满足我们写一些小程序或Python脚本的日志需求。然而这还不够体现logging模块的强大,毕竟以上功能通过自定义一个函数也可以方便实现。下面先介绍几个概念以及它们之间的关系图。
logger:记录器,应用程序代码能直接使用的接口。
handler:处理器,将(记录器产生的)日志记录发送至合适的目的地。
filter:过滤器,提供了更好的粒度控制,可以决定输出哪些日志记录。
formatter:格式化器,指明了最终输出中日志记录的布局。
日志事件信息在记录器(logger)、处理器(handler)、过滤器(filter)、格式化器(formatter)之间通过一个日志记录实例来传递。通过调用记录器实例的方法来记录日志,每一个记录器实例都有一个名字,名字相当于其命名空间,是一个树状结构。例如,一个记录器叫scan,记录器scan.tex、scan.html、scan.pdf的父节点。记录器的名称。可以任意取,但一个比较好的实践是通过下面的方式来命名一个记录器。
logger = logging.getLogger(__name__)
上面这条语句意味着记录器的名字会通过搜索包的层级来获致,根记录器叫root logger。记录器通过debug()、info()、warning()、error()和critical()方法记录相应级别的日志,根记录器也一样。
根记录器root logger输出的名称是'root'。当然,日志的输出位置可能是不同的,logging模块支持将日志信息输出到终端、文件、HTTP GET/POST请求、邮件、网络sockets、队列或操作系统级的日志等。日志的输出位置在处理器handler类中进行配置,如果内建的hangler类无法满足需求,则可以自定义hander类来实现自己特殊的需求。默认情况下,日志的输出位置为终端(标准错误输出),可以通过logging模块的basicConfig()方法指定一个具体的位置来输出日志,如终端或文件。
logger和hander的工作流程如图2.16所示。
图2.16 logging模块的工作流程
现在让我们从整体到局部来说明logger的日志记录过程。
第一步:获取logger的名称。
logger = logging.getLogger(‘logger name’) #这里的logger name是自己定义的
第二步:配置logger。
1)配置该logger的输出级别,如logger.setLevel(loging.INFO)。
2)添加该logger的输出位置,即logger的handler,logger.addHandler(ch)。这里ch是我们自定义的handler,如ch=logging.StreamHandler,即输出到终端。我们可以添加多个handler,一次性将日志输出到不同的位置。日志的输出格式是在handler中进行配置,如ch.setFormatter(formatter),formatter也我们自定义的,如formatter =logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')。不同的hander可以配置不同的格式化器,可以实现不同的输出位置,不同的输出格式,完全可能灵活配置。
第三步:在应用程序中记录日志。
logger.debug('debug message') logger.info('info message') logger.warn('warn message') logger.error('error message') logger.critical('critical message')
【示例2-24】将日志信息显示在终端的同时也在文件中记录(lx_log2.py)。
在以上程序中我们设置了logger的日志级别为INFO,handler ch的日志级别为DEBUG,handler fh的日志级别为WARNING,这样做是为了解释它们之前的优先级。
handler的日志级别以logger的日志级为基础,logger的日志级别为INFO,低于INFO级别的(如DEBUG)均不会在handler中出现。handler中的日志级别如果高于logger,则只显示更高级别的日志信息,如fh应该只显示WARNING及以上的日志信息;handler中的日志级别如果低于或等于logger的日志级别,则显示logger的日志级别及以上信息,如ch应该显示INFO及以上的日志信息。
下面运行程序进行验证:执行python lx_log2.py得到如下结果。
lx_log2 2018-06-12 22:18:10,378 - lx_log2 - INFO - info message 2018-06-12 22:18:10,379 - lx_log2 - WARNING - warn message 2018-06-12 22:18:10,379 - lx_log2 - ERROR - error message 2018-06-12 22:18:10,380 - lx_log2 - CRITICAL - critical message
查看lx_log2.log文件,内容如下:
2018-06-12 22:18:10,379 - lx_log2 - WARNING - warn message 2018-06-12 22:18:10,379 - lx_log2 - ERROR - error message 2018-06-12 22:18:10,380 - lx_log2 - CRITICAL - critical message
从运行结果来看,符合我们的预期。除了StreamHandler和FileHandler外,logging模块还提供了其他更为实用的Handler子类,它们都继承在Handler基类,如下所示。
BaseRotatingHandler:是循环日志处理器的基类,不能直接被实例化,可使用RotatingFileHandler和TimedRotatingFileHandler。
RotatingFileHandler:将日志文件记录至磁盘文件,可以设置每个日志文件的最大占用空间。
TimedRotatingFileHandler:将日志文件记录至磁盘文件,按固定的时间间隔来循环记录日志。
SocketHandler:可以将日志信息发送到TCP/IP套接字。
DatagramHandler:可以将日志信息发送到UDP套接字。
SMTPHandler:可以将日志文件发送至邮箱。
SysLogHandler:系统日志处理器,可以将日志文件发送至UNIX系统日志,也可以是一个远程机器。
NTEventLogHandler:Windows系统事件日志处理器,可以将日志文件发送到Windows系统事件日志。
MemoryHandler:MemoryHandler实例向内存中的缓冲区发送消息,只要满足特定的条件,缓冲区就会被刷新。
HTTPHandler:使用GET或POST方法向HTTP服务器发送消息。
WatchedFileHandler:WatchedFileHandler实例监视它们登录到的文件。如果文件发生更改,则使用文件名关闭并重新打开。这个处理器只适用于类unix系统,Windows不支持使用的底层机制。
QueueHandler:QueueHandler实例向队列发送消息,比如在队列或多处理模块中实现的消息。
NullHandler:NullHandler实例不使用错误消息。库开发人员使用日志记录,但希望避免在库用户未配置日志记录时显示“日志记录器XXX无法找到任何处理程序”消息。
【示例2-25】日志的配置信息也可以来源于配置文件(lx_log3.py)。代码如下:
下面是配置文件的信息logging.conf。
上面几种常用的方法已经基本满足我们的需求,如需要更为细致的了解,可参考logging模块的官方文档。