具有多个模块的 Python 日志记录

Question

我有很多模块，其中大量使用 Python 日志记录。当我像 Python 文档中那样将它们导入主模块并尝试运行它时，我没有从日志记录中获得任何输出。有谁知道发生了什么事吗？

Logging是在下面导入的public模块导入的模块中调用的(这段代码太大，这里就不放了)。下面的代码是整个程序运行和日志记录初始化的地方:

import logging
from bottle import run, debug
import public

logging.basicConfig(level=logging.DEBUG)

if __name__ == '__main__':
   logging.info('Started')
   debug(mode=True)
   run(host='localhost', port = 8080, reloader=True)
   logging.info('Finished')

Answer 1

您的问题可能是由 import public 语句调用 logging.debug(...) 或类似语句引起的。然后发生的是这样的:

1. 您导入公共(public)。作为副作用，这会调用例如logging.debug 或类似的，它会自动调用 basicConfig，它会向根记录器添加一个 StreamHandler，但不会更改级别。
2. 然后您调用 basicConfig，但由于根记录器已经有一个处理程序，它什么都不做(如文档所述)。
3. 由于默认的日志记录级别是 WARNING，您的 info 和 debug 调用不会产生任何输出。

您真的应该避免对导入产生副作用:例如，您对 basicConfig 的调用应该在 if __name__ == '__main__' 子句中。使用此 public.py:

import logging

def main():
    logging.debug('Hello from public')

和这个main.py:

import logging
from bottle import run, debug
import public

def main():
    logging.basicConfig(level=logging.DEBUG)
    logging.info('Started')
    debug(mode=True)
    public.main()
    run(host='localhost', port = 8080, reloader=True)
    logging.info('Finished')

if __name__ == '__main__':
    main()

你得到以下输出:

$ python main.py
INFO:root:Started
DEBUG:root:Hello from public
INFO:root:Started
DEBUG:root:Hello from public
Bottle server starting up (using WSGIRefServer())...
Listening on http://localhost:8080/
Hit Ctrl-C to quit.

^CINFO:root:Finished
$ Shutdown...
INFO:root:Finished

从这里您会看到 Bottle 实际上在一个单独的进程中重新运行脚本，这会导致消息加倍。您可以使用显示进程 ID 的格式字符串来说明这一点:如果您使用

logging.basicConfig(level=logging.DEBUG,
                    format='%(process)s %(levelname)s %(message)s')

然后你得到类似的输出

$ python main.py
13839 INFO Started
13839 DEBUG Hello from public
13840 INFO Started
13840 DEBUG Hello from public
Bottle server starting up (using WSGIRefServer())...
Listening on http://localhost:8080/
Hit Ctrl-C to quit.

^C13839 INFO Finished
$ Shutdown...
13840 INFO Finished

请注意，如果您像这样向 public.py 添加一个产生副作用的语句:

logging.debug('Side-effect from public')

在模块级别，你根本没有日志输出:

$ python main.py
Bottle server starting up (using WSGIRefServer())...
Listening on http://localhost:8080/
Hit Ctrl-C to quit.

^C$ Shutdown...

这似乎证实了上述分析。