python - 为什么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我在 __init__.py 中配置了记录器的对象，但问题是它没有将任何内容记录到 Docker当它运行时，它只记录 UWSGI请求。

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

问题已解决，但现在日志出现重复!

---

EDIT-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，仅此而已。

---

EDIT-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 的方式最近发生了变化。您可以查看 here .我假设您的 docker 镜像使用的是最新版本。

如果是这种情况，即使没有任何自定义日志配置，实际上它也在为您的输出流进行日志记录，但它会过滤掉低于 WARNING 日志(DEBUG 和 INFO)的日志。当您依赖 Flask 为您初始化日志并且您没有设置 --debug 标志(uwsgi 案例)时，就会发生这种情况。

在配置日志记录时可以查看多种策略。一种建议是使用 library itself 中提到的 dictConfig 初始化。 ，在 uwsgi 主机上，在定义应用程序之前，然后 fork 。按照您的示例，在 __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 logging propagation issue .有一个独立的案例，更容易调试，here .

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

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

当日志传播被启用并且在其他地方发生了一些日志初始化时会发生这种情况。您可以通过查看 python's source code 中的 callHandlers 来检查传播的工作原理。 :

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

回到你的案例(Flask)，通过查看日志中的跟踪，有一个名为 flask.app 的记录器，它是由 Flask itself 创建的记录器.分别有格式化版本和未格式化版本( logging.BASIC_FORMAT )。因此，它可能正在您的代码中的某处或您导入的某个库中被初始化。

有多种方法可以解决这个问题:

• 将传播设置为 false(简单的解决方案，但解决方法)
• 搜索“无效”配置并将其删除
• 按照 Flask 日志记录教程的建议，在实例化应用之前使用 dictConfig 初始化