logging的使用分析

昨天，Lord Leatherface问我为什么使用了suds后，输出日志变成了两条。于是我仔细地研究了logging的日志处理机制，并且再次考虑了uliweb的日志处理，最终对uliweb的日志进行了重构，并且弄清楚了为什么会有两条日志的现象，因此以本文作一个记录。

对于logging我想大家用得应该不少，那么我先提几个问题：

1. logging直接输出日志，如logging.info()与log = logging.getLogger('name') log.info()有什么不同？

2. “No handlers could be found for logger”是怎么回事？

3. root logger有什么用，如何获得？

4. 形如"a.b.c"的logger名有什么用？

5. 如果一个logger执行多次addHandler，那么每个handler都会被执行吗？

6. logger的传播(propagate)是怎么回事？如何阻止它？

有时候带着问题学习可能会更快。那么下面根据我的理解一点点进行解释。

logging中log是可以分级的，它的级别与你使用getLogger()中的名字有关系。比如，你可以使用"uliweb"或"uliweb.app"，它们的区别就是"uliweb.app"中有一个'.'。那么logging会自动生成"uliweb"和"uliweb.app"的logger，并且"uliweb"将是"uliweb.app"的logger的父对象。这一点可以这样验证：

>>> import logging

>>> log = logging.getLogger('uliweb.app')

>>> log.manager.loggerDict.items()

[('uliweb.app', <logging.Logger instance at 0x017CE238>), ('uliweb', <logging.PlaceHolder instance at 0x017CE2D8>)]

这里有一个挺有意思的，就是'uliweb'这个logger它的对象是PlaceHolder，相当于是一个“虚"日志对象。logging可以允许通过getLogger()来自动生成对应的logger对象。对于分级的日志名字，它会一级级地创建，如果父对象还不存在，则会自动创建一个占位对象。如果，后面用户又通过getLogger()来创建一个父对象，则logging会自动对父子关系进行重新修订，保证对象关系的正确性。

再看一看父子关系：

>>> log.parent

<logging.RootLogger instance at 0x017E3AD0>

>>> log1 = logging.getLogger('uliweb')

>>> log.parent

<logging.Logger instance at 0x01820DA0>

>>> log.parent.name

'uliweb'

挺有意思。当我们直接通过getLogger('uliweb.app')获得日志对象时，它的parent并不是占位对象'uliweb'，而是RootLogger。这个RootLogger是在导入logging时自动由模块创建的，它的创建代码是：

root = RootLogger(WARNING)

Logger.root = root

Logger.manager = Manager(Logger.root)

root对象有什么用呢？它就是缺省的日志对象。使用logging的最简单的方法是：

import logging

logging.info()

可以直接输出。这里有什么秘密？看一看代码一切就都清楚了。

def info(msg, *args, **kwargs):

    """

    Log a message with severity 'INFO' on the root logger.

    """

    if len(root.handlers) == 0:

        basicConfig()

    root.info(*((msg,)+args), **kwargs)