在交互式会话中使用Python日志

Question

我正在尝试在我的Python 2.7应用程序中实现日志记录，发现这非常有用。不过，我注意到在交互式运行Python时，每条日志消息会打印多次。消息打印的次数和我之前运行脚本的次数是一样的，所以看起来日志记录器在脚本结束时没有被正确清理（我猜的）。请看下面的例子：

import sys
import logging

def main(argv=None):

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

    console_handler = logging.StreamHandler()
    console_handler.setFormatter(logging.Formatter("%(message)s"))
    log.addHandler(console_handler)

    log.info('Starting something...')
    log.info('Doing something...')
    log.info('Finished something.')

    logging.shutdown()

if __name__=='__main__':
    sys.exit(main(sys.argv[1:]))

输入

>>> import file.py
>>> file.main()

会得到以下结果：

Starting something...
Doing something...
Finished something.

然后第二次输入 file.main() 会得到：

Starting something...
Starting something...
Doing something...
Doing something...
Finished something.
Finished something.

再重复第三次会让每条消息都打印三次，依此类推。有没有人知道这是为什么？这是日志模块的预期行为吗？如果是的话，我该怎么改变这个？上面的脚本如果作为脚本运行（python file.py），只会打印每条消息一次，这也是正常的。

Answer 1

每次重新加载配置时，你可以删除所有的处理器，具体来说就是在调用 file.main() 之前：

file.logging.getLogger('test').handlers = []

---

注意（主观观点）：

正如 @stderr 所说，建议在模块级别定义你的日志记录器。不过，我觉得在应用程序的入口点设置它们也是个好习惯。所以在这里，我建议你只在 if __name__=='__main__' 之后添加处理器，或者在你的 (I)Python 控制台中。这样一来，导入这个模块时就不会创建各种处理器，只有在真正执行你模块中的某些函数时，才会创建这些处理器。

Answer 2

试试这个解决方法：

if len(logging.root.handlers) == 0:
     log.add_handler(console_handler)

日志模块使用一个全局的静态日志记录器对象，这个对象在你使用解释器时会一直存在。所以每次你调用 add_handler 时，其实是在添加一个全新的流处理器，但并没有把旧的处理器去掉。日志记录模块会遍历它的所有处理器，把输出发送给每一个处理器，因此每次你运行的时候，控制台上都会出现一份新的相同内容。

Answer 3

是的，你正在创建并重复使用一个日志记录器的实例。每个添加到这个日志记录器上的处理器也在记录信息。

你可能希望在模块级别或者在一个单独的函数中设置日志记录，这样你只需要运行一次。

可以像这样做：

import atexit
import sys
import logging

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

console_handler = logging.StreamHandler()
console_handler.setFormatter(logging.Formatter("%(message)s"))
log.addHandler(console_handler)

def shutdown_logging():
    logging.shutdown()    

atexit.register(shutdown_logging)

def main(argv=None):
    log.info('Starting something...')
    log.info('Doing something...')
    log.info('Finished something.')


if __name__=='__main__':
    sys.exit(main(sys.argv[1:]))