问题
在 gunicorn 的配置文件中,有 accesslog
和 errorlog
两项,分别用来记录接口的访问历史和服务启动以及错误消息。
假设有部分配置文件如下:
代码语言:javascript复制loglevel = 'info'
accesslog = "log/gunicorn_access.log"
errorlog = "log/gunicorn_error.log"
正常来说服务启动并有相应请求后,应该在 log
目录下应该有非空的 gunicorn_access.log
和 gunicorn_error.log
。但是有时我们会发现这两个文件确实存在,只不过 gunicorn_access.log
是空的,而 gunicorn_error.log
正常。
WHY?
当然这里原因众多,我这里只是提出一种可能的原因和解决方案:Python 的 logging
模块导致的。
分析
我们通常会在 app.py
及其他程序中使用 logging
来记录必要信息,在配置 logging
模块时,有可能会使用 logging.config.fileConfig
或者 logging.config.dictConfig
,这通常会从一个配置文件中来读取配置。但是其中有个坑,官方也提到了。根据 Python logging
官方文档:
Warning The
fileConfig()
function takes a default parameter,disable_existing_loggers
, which defaults toTrue
for reasons of backward compatibility. This may or may not be what you want, since it will cause any non-root loggers existing before thefileConfig()
call to be disabled unless they (or an ancestor) are explicitly named in the configuration. Please refer to the reference documentation for more information, and specifyFalse
for this parameter if you wish. The dictionary passed todictConfig()
can also specify a Boolean value with keydisable_existing_loggers
, which if not specified explicitly in the dictionary also defaults to being interpreted asTrue
. This leads to the logger-disabling behaviour described above, which may not be what you want - in which case, provide the key explicitly with a value ofFalse
.
简单来说,就是无论使用 fileConfig()
还是 dictConfig()
,都会有个默认值为 True
的参数:disable_existing_loggers
,这会导致在调用 fileConfig()
或者 dictConfig()
之前的非 root 的 logger 失效。
OK,那么这和 gunicorn 有什么关系呢?
gunicorn 实际上也是使用的 logging
模块。在真正的启动 flask 服务之前,gunicorn 会先启动,并输出类似如下的信息到 gunicorn_error.log
:
[2014-09-10 10:22:28 0000] [30869] [INFO] Listening at: http://127.0.0.1:8000 (30869)
[2014-09-10 10:22:28 0000] [30869] [INFO] Using worker: sync
[2014-09-10 10:22:28 0000] [30874] [INFO] Booting worker with pid: 30874
[2014-09-10 10:22:28 0000] [30875] [INFO] Booting worker with pid: 30875
[2014-09-10 10:22:28 0000] [30876] [INFO] Booting worker with pid: 30876
[2014-09-10 10:22:28 0000] [30877] [INFO] Booting worker with pid: 30877
此时真正的 flask 服务还未启动,也就是 app.py
中的 fileConfig()
或者 dictConfig()
还未执行,此时的非 root logger 还未被禁用,所以 gunicorn_error.log
是正常的。但是随着 flask 服务真正启动之后,gunicorn 的 logger 就被禁用了,后续新请求也就没能够记录,从而导致 gunicorn_access.log
是空的。
解决
那么解决方法也很简单,在 logging
配置文件中将 disable_existing_loggers
设为 False
(或者 false
)即可。
Reference
- Logging HOWTO — Python 3.8.1rc1 documentation
- logging - Can’t get access log to work for gunicorn - Stack Overflow