python之日志配置

日志：日志是记录软件运行状态的一种方法，对于软件的调试等工作有极大作用。
通常我们想将软件的运行状态呈现出来，比如输出到屏幕上，或者写到文件中，或者发到网路上等等，这时就需要有我们自己的日志记录。在python中的logging日志库设计的非常好，它可以帮助我们完成相应的日志记录设计。

一、简单的日志配置记录

对于部分人来说logging提供的模块级函数logging.basiconFig()已经足以让人进行日志记录实践。它的简单用法如下：

# myapp.py
import logging
import mylib

def main():
    logging.basicConfig(filename='myapp.log', level=logging.INFO)
    logging.info('Started')
    mylib.do_something()
    logging.info('Finished')

if __name__ == '__main__':
    main()
# mylib.py
import logging

def do_something():
    logging.info('Doing something')

运行myapp.py，可以在myapp.log中看到：
INFO:root:Started
INFO:root:Doing something
INFO:root:Finished
看到了吗？简单的几步就可以输出有用的日志信息，最重要的是它可以跨模块。修改其它的logging.basicConfig()的API还可以调整记录等级，输出信息格式等，足以满足部分人的日志需求。

二、logging库基础知识

logging库采取了模块化的设计，提供了许多组件：记录器、处理器、过滤器和格式化器。

  • Logger 暴露了应用程序代码能直接使用的接口。
  • Handler将（记录器产生的）日志记录发送至合适的目的地。
  • Filter提供了更好的粒度控制，它可以决定输出哪些日志记录。
  • Formatter 指明了最终输出中日志记录的信息格式。

日志功能都由调用Logger类实例的方法执行(以后都称为loggers)。每个实例都有名字，它们在概念上组织成一个层级式的命名空间，使用点（.）作为分隔符。例如，名为‘scan’的Logger是名为‘scan.text’、‘scan.html’和‘scan.pdf’的Logger的父节点。

程序员可以以三种方式来配置日志：

  • 调用Logger、Handler、Filter、Formatter的方法来配置日志
  • 创建一个日志配置文件，然后使用logging.config库中的logging.config.fileConfig函数来配置
  • 创建一个配置信息字典，然后传递给logging.config库中的logging.config.dictConfig函数来配置

本文介绍第一种配置方式
请大家记住，配置日志就是配置Logger的功能，因为Logger是提供给应用程序的接口，不管是Handler还是Filter或者是Formatter都是配置来给Logger使用的。

Logger的配置：
先使用logging.getLogger()生成一个logger对象，然后使用Logger.setLevel()方法指定logger将会处理的最低的安全等级日志信息。
再使用Logger.addHandler()方法加入一个handler(Logger.removeHandler()是移除handler，对于加入handler的数量没有限制)。
再使用Logger.addFilter() 方法加入一个Filter(Logger.removeFilter()是移除Filter)。

Handler的配置：
handler一般不会直接实例化来使用，而是继承它然后再实例化出一个handler来使用。因为handler的功能就是将日志信息发送到各个地方，如屏幕，文件，网路等，所以不同的handler类有不同的作用（Logging.handlers库中有各种不同handler）。
例如：

#设置一个高于DEBUG级别就输出到屏幕的handler
ch = logging.StreamHandler()
ch.setLevel(logging.DEBUG)
#设置一个高于DEBUG级别就输出到文件的handler
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
ch2 = logging.FileHandler()
ch2.setLevel(logging.DEBUG) #设置输出等级要求
ch2.setFormatter(formatter) #设置信息格式

Formatter的配置
Formatter对象决定日志消息最终的顺序，结构和内容。
例如：

formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')

formatter实例化后就可以传递给handler，利用ch2.setFormatter(formatter)方法。

Filter
Filter为日志配置提供了更细粒度的设置，但是不是必要的所以本文没有提及。

三、实际案例

import logging
import auxiliary_module

# 创建一个名为'spam_application'的logger
logger = logging.getLogger('spam_application')
logger.setLevel(logging.DEBUG)
# 创建一个将DEBUG以上信息输出到文件'spam.log'的handler
fh = logging.FileHandler('spam.log')
fh.setLevel(logging.DEBUG)
# 创建可以将ERROR信息输出到屏幕的hander
ch = logging.StreamHandler()
ch.setLevel(logging.ERROR)
# 创建一个formatter并传递给handler
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
fh.setFormatter(formatter)
ch.setFormatter(formatter)
# 将handler传递给logger
logger.addHandler(fh)
logger.addHandler(ch)

logger.info('creating an instance of auxiliary_module.Auxiliary')
a = auxiliary_module.Auxiliary()
logger.info('created an instance of auxiliary_module.Auxiliary')
logger.info('calling auxiliary_module.Auxiliary.do_something')
a.do_something()
logger.info('finished auxiliary_module.Auxiliary.do_something')
logger.info('calling auxiliary_module.some_function()')
auxiliary_module.some_function()
logger.info('done with auxiliary_module.some_function()')
import logging

# 创建一个logger
module_logger = logging.getLogger('spam_application.auxiliary')

class Auxiliary:
    def __init__(self):
        self.logger = logging.getLogger('spam_application.auxiliary.Auxiliary')
        self.logger.info('creating an instance of Auxiliary')

    def do_something(self):
        self.logger.info('doing something')
        a = 1 + 1
        self.logger.info('done doing something')

def some_function():
    module_logger.info('received a call to "some_function"')

最终输出：

2005-03-23 23:47:11,663 - spam_application - INFO -
   creating an instance of auxiliary_module.Auxiliary
2005-03-23 23:47:11,665 - spam_application.auxiliary.Auxiliary - INFO -
   creating an instance of Auxiliary
2005-03-23 23:47:11,665 - spam_application - INFO -
   created an instance of auxiliary_module.Auxiliary
2005-03-23 23:47:11,668 - spam_application - INFO -
   calling auxiliary_module.Auxiliary.do_something
2005-03-23 23:47:11,668 - spam_application.auxiliary.Auxiliary - INFO -
   doing something
2005-03-23 23:47:11,669 - spam_application.auxiliary.Auxiliary - INFO -
   done doing something
2005-03-23 23:47:11,670 - spam_application - INFO -
   finished auxiliary_module.Auxiliary.do_something
2005-03-23 23:47:11,671 - spam_application - INFO -
   calling auxiliary_module.some_function()
2005-03-23 23:47:11,672 - spam_application.auxiliary - INFO -
   received a call to 'some_function'
2005-03-23 23:47:11,673 - spam_application - INFO -
   done with auxiliary_module.some_function()