Python 日志记录 : Why is __init__ called twice?

Question

我正在尝试将 python 日志记录与配置文件和自己的处理程序结合使用。这在某种程度上起作用。真正让我困惑的是 __init__ 被调用了两次而 __del__ 被调用了一次。当我删除整个配置文件内容并直接在代码中创建处理程序时，__init__ 被调用一次，而 __del__ 永远不会被调用。

我的问题:

1. 为什么 __init__ 被调用了两次？
2. 为什么 __del__ 的调用频率低于 __init__？

代码:

#!/bin/env python

import logging
import logging.handlers
import logging.config

class Test1TimedRotatingFileHandler(logging.handlers.TimedRotatingFileHandler):
    def __init__(self,filename):
        print "init called"
        logging.handlers.TimedRotatingFileHandler.__init__(self,filename, when='S', interval=86400, backupCount=8, encoding=None)

    def __del__(self):
        print "del called"
        if hasattr(logging.handlers.TimedRotatingFileHandler,"__del__"):
            logging.handlers.TimedRotatingFileHandler.__del__(self)

logging.config.fileConfig('/root/test1.conf')
logger = logging.getLogger("test1")

配置文件:

[formatters]
keys: simple

[handlers]
keys: file

[loggers]
keys: root

[formatter_simple]
format: "%(message)s"

[handler_file]
class: test1.Test1TimedRotatingFileHandler
args: ("/root/test1.log",)
level=INFO

[logger_root]
level: INFO
handlers: file
qualname: test1

输出看起来像这样:

init called
init called
del called

按照 Sentinal 的建议使用调试器获取堆栈跟踪揭示了这一点:

第一次调用:

> /root/test1.py(12)__init__()
-> print "init called"
(Pdb) where
  /root/test1.py(21)<module>()
-> logging.config.fileConfig('/root/test1.conf')
  /usr/local/python/2.6.4/lib/python2.6/logging/config.py(84)fileConfig()
-> handlers = _install_handlers(cp, formatters)
  /usr/local/python/2.6.4/lib/python2.6/logging/config.py(156)_install_handlers()
-> klass = _resolve(klass)
  /usr/local/python/2.6.4/lib/python2.6/logging/config.py(94)_resolve()
-> found = __import__(used)
  /root/test1.py(21)<module>()
-> logging.config.fileConfig('/root/test1.conf')
  /usr/local/python/2.6.4/lib/python2.6/logging/config.py(84)fileConfig()
-> handlers = _install_handlers(cp, formatters)
  /usr/local/python/2.6.4/lib/python2.6/logging/config.py(159)_install_handlers()
-> h = klass(*args)
> /root/test1.py(12)__init__()
-> print "init called"
(Pdb) c
init called

第二次通话:

> /root/test1.py(12)__init__()
-> print "init called"
(Pdb) w
  /root/test1.py(21)<module>()
-> logging.config.fileConfig('/root/test1.conf')
  /usr/local/python/2.6.4/lib/python2.6/logging/config.py(84)fileConfig()
-> handlers = _install_handlers(cp, formatters)
  /usr/local/python/2.6.4/lib/python2.6/logging/config.py(159)_install_handlers()
-> h = klass(*args)
> /root/test1.py(12)__init__()
-> print "init called"

Answer 1

1. Why is init called twice?

如果您遵循logging 模块的代码，您会看到当您加载日志记录配置文件时，它会实例化所有处理程序(第一次实例化)。

在您的代码中，您将处理程序声明为 test1.Test1TimedRotatingFileHandler，因此当它尝试导入您的处理程序时，它会解析 test1 模块中的代码...因此它会重新创建处理程序!

更正后的代码将使用 __name__ == '__main__' 进行保护:

#!/bin/env python

import logging
import logging.handlers
import logging.config

class Test1TimedRotatingFileHandler(logging.handlers.TimedRotatingFileHandler):
    def __init__(self,filename):
        print "init called"
        logging.handlers.TimedRotatingFileHandler.__init__(self,filename, when='S', interval=86400, backupCount=8, encoding=None)

    def __del__(self):
        print "del called"
        if hasattr(logging.handlers.TimedRotatingFileHandler,"__del__"):
            logging.handlers.TimedRotatingFileHandler.__del__(self)

if __name__ == "__main__":
    logging.config.fileConfig('./test1.conf')
    logger = logging.getLogger("test1")

2 . Why is del called less often than init?

一般来说，__del__操作符在python-wants时被调用，更确切地说，它在垃圾收集器决定对对象进行垃圾收集时被调用；这不一定是在您发布之后。