python编程之logging模块的使用

       编程中，很多时候我们需要保存一个程序的中间输出，要了解一个程序的运行情况，记录程序运行中在一些关键节点处的信息，以便我们后续进行分析和问题的排查。对于简单的应用和相对不那么复杂的程序，我们当然可以通过最常用的print来实现这些需求，无论是输出到控制台还是重定向到磁盘文件。但是一旦程序的功能性和复杂性提升了，我们一直使用print会显得杂乱，而且print的意义有时候也不明显，print一般只适合对于局部问题的排查，对于较多的信息记录，print就显得有些无力，因为我们要让记录信息显得规范而且意义明确，用print会比较繁琐，而且也不高效。对此，python有一个标准库logging，就是专门用以满足这种需求的，其可以让结果输出更加的规范，意义更加明确，而且也可以对不同的信息进行管理，相当于是一个日志管理工具。本文将基于官方文档，总结一下loggin的用法，分为基础用法和高级用法两部分。

基础用法

       直接导入logging后，利用logging的函数来打印或者保存信息，基本的函数有：debug(),info(),warning(),error(),critical()，其等级依次递增。所谓等级level的概念是用以表示一条消息的严重等级，比如debug是最低等级，info次之，表示其对应的消息对于程序来说不那么严重，只是为了记录程序的运行情况，或者用以问题排查，而后面的warning则一般表示警告，表示程序出现了需要注意的结果，可能会对后续运行造成影响，以此类推。当然，这些函数名只是为了区分不同的使用场景，以让用户更好的识别信息，如果硬是要对debug对应的场景用critical函数输出或保存消息，也是可以的，消息也可以输出和保存，只是意义变得混淆而已，不影响使用。

       logging中一共有5个level，对应不同的使用场景，具体的可以看下图。

      如下所示，当运行如下语句时，会在控制台输出如下内容。

import logging

logging.info('info test')
logging.warning('warning test')
logging.critical('critical test')

# output:
# WARNING:root:warning test
# CRITICAL:root:critical test

       输出的内容中，默认是以(level name):(logger name):(message)的格式，其中关于logger name，后面的高级用法部分会讲到。从输出的结果可以看到，logging.info语句的内容并没有输出，只输出了warning和critical的内容，原因是logging默认只输出level等于以及高于warging的信息，所以level为info的便不会输出；当然，我们可以通过设置level改变这个行为，如下所示，同时logging输出的地方默认是控制台，当然也可以通过如下方式，即利用logging的basicConfig函数进行设置，将输出的内容保存在一个文件中。

import logging

logging.basicConfig(filename='test.log',level=logging.DEBUG)
logging.info('info test')
logging.warning('warning test')
logging.critical('critical test')

# file content:
# INFO:root:info test
# WARNING:root:warning test
# CRITICAL:root:critical test

       如上所述，我们可以通过basigConfig这个函数进行多种设置，除了上述设置，还可以设置信息的格式，时间戳以及其格式，文件模式等，参数如下所示。

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

# file content
# 12/12/2010 11:46:36 AM is when this event was logged.

       上述就是关于logging的基础用法，至此我们已经可以对一个程序在logging的模块层面进行日志记录，并以特定的格式保存。下面我们再介绍一些高级一点的用法，以更多更好的满足我们的工作需求。

高级用法

       高级用法将不再仅仅利用模块层面的函数，而是以几个基本的对象为基础：logger对象、handler对象以及formatter对象，有时候还会用大filter对象。在本文中，将主要简单介绍一下logger、handler和formatter对象。

       logger对象通过logging.getLogger(name)构造，其是直接和脚本进行交流，并发送源log信息的对象，其依然是通过debug()、info()这些函数来生成log信息；handler对象的作用是将logger产生的log信息进行一个分发，一个logger可以添加多个handler对象，从而将log信息分发到不同的地方；比如，可以将所有log信息通过FileHandler保存在一个本地文件中，同时将WARNING以上的信息通过StreamHandler输出到控制台。log信息的内容和格式是很重要的，因此我们可以通过formatter对象给log信息设置格式。下面的代码展示了这些对象的简单使用方式。

import logging

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

fh = logging.FileHandler('test1.log',mode='a',encoding='utf8')
fh.setLevel(logging.DEBUG)

ch = logging.StreamHandler()
ch.setLevel(logging.ERROR)

formatter = logging.Formatter('%(asctime)s - %(name)-8s - %(levelname)-8s - %(message)s',datefmt='%Y-%m-%d %H:%M:%S')
fh.setFormatter(formatter)
ch.setFormatter(formatter)

logger.addHandler(fh)
logger.addHandler(ch)

格式设置说明

      日志信息的格式设置是很重要的，首先对于message格式的设置是完全和字符串的格式化表达一样的，对格式化表达式内容的填充可以通过info,debug等这些函数的位置参数传入，比如info(msg_fmt,s1,s2,extra=d)，其中msg_fmt是字符串格式化表达式，而s1,s2表示对其的内容的填充，最后还有一个extra参数，其是一个字典对象，其填充的不是msg_fmt，而是通过formatter对象设置前置格式时需要填充的内容。

       对于fromatter对象，我们设置格式时，可以看到其中有一些类似asctime,name,levelname这样的字符串，这些字符串实际上是logRecord的属性，logRecord对象是一条日志信息的封装，每次调用info这些接口时会自动生成对应的logRecord对象；参考上述示例代码中对于格式的设置，类似'%(cs)-8s'%{'cs':'haha'} -->'haha    '  or  '%(cs)8s'%{'cs':'haha'}-->'    haha'，上述的示例中其中用的括号中的字符串实际上都是logRecord的属性，我们还可以设置其他的属性，比如行数，以方便我们定位日志在脚本中所在的位置，定义的方式实际上就是字符串格式化表达式，其中括号表示后续填充内容的字典的key。对于logRecord对象的属性，可看下图，我们可以在实际应用中自己利用这些属性设置格式，以下属性基本可以满足我们大部分的需求，当然如果我们有自定义的字段，可以在调用Info这些接口时通过extra参数进行传入。

       最后还需要说明的一点是，logging是线程安全的，即我们可以通过多个线程写入同一个日志文件，其会自动加锁，但是并不是进程安全的，要实现进程安全，可以参考官方文档，当然，更多的高级功能，也可以参看官方的logging cookbook。