为什么Flask logger在前面使用UWSGI时没有登录docker？

Question

我有一个Flask应用程序Docker,docker logs当它UWSGI在前面运行时登录.现在我使用UWSGI下面的配置来运行我的应用程序Docker:

[uwsgi]

master = true

processes = 5
threads = 2

socket = 127.0.0.1:3031
chmod-socket = 664
stats=0.0.0.0:30310

chdir = /etc/fantas

uid = root
gid = root

wsgi-file=uwsgi_fantas.py
callable=app

vacuum = true

该uwsgi_fantas.py文件包含:

from fantas.fantas_app import FantasApp

app = FantasApp().setup()

该setup方法返回app:

from flask_restful import Api
from fantas import app

class FantasApp(object):
    def setup(self):
        api = Api(app)
        api.add_resource(Token, '/users')

        return app

最后,启动Flask框架的部分__init__.py位于项目的根目录中:

from flask import Flask
import logging

app = Flask(__name__)

s_handler = logging.StreamHandler()
s_handler.setLevel(logging.DEBUG)
app.logger.addHandler(s_handler)

由于UWSGI直接使用了app我在其中配置了logger 的对象__init__.py,但问题是Docker它在运行时没有记录任何内容,只是记录UWSGI请求.

app.logger配置过程中出了什么问题？

问题已经解决,但现在日志重复了!

---

编辑1: 我设置app.logger.setLevel(logging.DEBUG),似乎成功Flask登录Docker.奇怪的是它记录了3次!我删除了所有记录器配置和处理程序,并使用了:

app.logger.setLevel(logging.DEBUG)

但现在它记录了2次:

proj_fantas.1.huagnqqpzo1n@linuxkit-025000000001    | [2018-07-13 07:02:38,008] DEBUG in token: [Token] authenticating user...
proj_fantas.1.huagnqqpzo1n@linuxkit-025000000001    | DEBUG:flask.app:[Token] authenticating user...

为什么会这样？

---

EDIT 2:

输出app.logger.handlers是[<logging.StreamHandler object at 0x7f0f430ca8d0>].它只显示我之前初始化的StreamHandler,仅此而已.

---

编辑-3:

ps -ef命令输出内部Docker:

UID        PID  PPID  C STIME TTY          TIME CMD
root         1     0  0 15:26 ?        00:00:00 uwsgi uwsgi_coconuty.ini
root        10     1  0 15:26 ?        00:00:00 uwsgi uwsgi_coconuty.ini
root        12     1  0 15:26 ?        00:00:00 uwsgi uwsgi_coconuty.ini
root        13     1  0 15:26 ?        00:00:00 uwsgi uwsgi_coconuty.ini
root        15     1  0 15:26 ?        00:00:00 uwsgi uwsgi_coconuty.ini
root        16     1  0 15:26 ?        00:00:00 uwsgi uwsgi_coconuty.ini
root        20     0  0 15:27 pts/0    00:00:00 /bin/bash
root       112    20  0 15:28 pts/0    00:00:00 ps -ef

里面没有其他进程在运行Docker.

Answer 1

首先，例如，Flask日志从版本0.9初始化到当前稳定的1.0.2的方式发生了新变化。您可以在这里检查。我假设您的Docker映像使用最新版本。

如果是这样的话，即使没有任何自定义日志记录配置，它实际上也正在为您的输出流进行日志记录，但它的过滤率低于警告日志（DEBUG和INFO）。当您依靠Flask为您初始化日志并且未设置--debug标志（uwsgi情况）时，会发生这种情况。

配置日志记录时，可以查看多种策略。一种建议是在定义应用程序之前，在uwsgi主服务器上使用库本身提到的dictConfig初始化，然后将其派生。按照您的示例，在__init__.py：

from flask import Flask
from logging.config import dictConfig

dictConfig({
    'version': 1,
    'formatters': {'default': {
        'format': '[%(asctime)s] %(levelname)s in %(module)s: %(message)s',
    }},
    'handlers': {'wsgi': {
        'class': 'logging.StreamHandler',
        'formatter': 'default'
    }},
    'root': {
        'level': 'DEBUG',
        'handlers': ['wsgi']
    }
})

app = Flask(__name__)

您在EDIT-1中提到的问题看起来像是python 日志记录传播问题。有一个独立的情况下，更容易调试，在这里。

即使您只设置了一个流处理程序，如您的日志所示，它也可能附加了一个父级。如果您检查其父级，则可能会附加一个处理程序，该处理程序与您在EDIT-2中提到的处理程序不同 ：

print logger.handlers
[<logging.StreamHandler object at 0x7f15669c1550>]
print logger.parent.handlers
[<logging.StreamHandler object at 0x7f15669c1610>]

当启用日志记录传播并且在其他地方发生了一些日志记录初始化时，就会发生这种情况。您可以检查如何进行传播通过看callHandlers在Python的源代码：

    ...
    hdlr.handle(record)
    if not c.propagate:
        c = None    #break out
    else:
        c = c.parent
    ...

回到您的案例（Flask），通过查看日志中的痕迹，有一个名为的记录器flask.app，它是Flask本身创建的。有格式化版本和未格式化版本（logging.BASIC_FORMAT）。因此，它可能已在代码中的某个位置或导入的库之一中初始化了。

有多种方法可以解决此问题：

• 将传播设置为假（简单的解决方法，但解决方法）
• 搜索“无效”配置并将其删除
• 实例化应用程序之前，请先使用dictConfig初始化，如Flask日志教程所建议