为什么在前面使用UWSGI时Flask logger无法登录docker? [英] Why Flask logger does not log in docker when using UWSGI in front?
问题描述
我在Docker内部有一个Flask应用程序，该应用程序在运行时没有前面的UWSGI时已登录到docker logs.现在，我将UWSGI与下面的配置结合使用，以在Docker中运行我的应用程序:
I have a Flask application inside of Docker that was logging into docker logs when it was running without UWSGI in front. Now I have used UWSGI with the config below to run my application inside of 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内部:
Finally the part that initiates the Flask framework is inside of __init__.py in the root directory of project:
from flask import Flask
import logging
app = Flask(__name__)
s_handler = logging.StreamHandler()
s_handler.setLevel(logging.DEBUG)
app.logger.addHandler(s_handler)
由于UWSGI直接与__init__.py内配置的logger一起使用的app对象，但是问题在于，运行时它不会将任何内容记录到Docker中，而只是记录UWSGI请求.
As UWSGI works directly with the app object I have configured logger inside of __init__.py, but the problem is that it does not log anything into Docker when it is run, it just logs UWSGI requests.
app.logger配置过程中出了什么问题?
What is wrong in the process of app.logger configuration?
问题已解决，但现在日志已重复！
EDIT-1:
我设置了app.logger.setLevel(logging.DEBUG)，看来Flask成功登录到Docker.奇怪的是它记录了3次！我删除了所有记录器配置和处理程序，并仅使用了它:
EDIT-1:
I set app.logger.setLevel(logging.DEBUG) and it seems that Flask logs into Docker successfully. The weird part is that it logs 3 times! I removed all logger configs and handlers and just used:
app.logger.setLevel(logging.DEBUG)
但是现在它记录了2次:
But now it logs 2 times:
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，仅此而已.
The output of app.logger.handlers is [<logging.StreamHandler object at 0x7f0f430ca8d0>]. It just shows the StreamHandler that I initialized earlier, nothing more.
EDIT-3:
Docker内部的ps -ef命令的输出:
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内部没有其他进程在运行.
There is no other process running inside of Docker.
推荐答案
首先，例如，Flask日志从版本0.9初始化到当前稳定的1.0.2的方式发生了新变化.您可以在此处进行检查.我假设您的Docker映像使用最新版本.
First of all, there are recent changes in the way Flask logs are initialized from version 0.9 to the current stable 1.0.2, for example. You can check this here. I am assuming your docker image uses the most recent version.
如果是这种情况，即使没有任何自定义日志配置，实际上它正在为您的输出流进行日志记录，但它的过滤率低于警告日志(DEBUG和INFO).当您依靠Flask为您初始化日志并且未设置--debug标志(uwsgi情况)时，会发生这种情况.
If that is the case, even without any custom logging config, actually it is logging for your output stream, but it is filtering out lower than WARNING logs (DEBUG and INFO). This happens when you rely on Flask initializing the log for you and you do not set a --debug flag (uwsgi case).
配置日志记录时可以查看多种策略.一种建议是使用uwsgi主机上的库本身提到的dictConfig初始化. ，然后定义应用，然后进行分叉.按照您的示例，在__init__.py:
There are multiple strategies that can be looked at when you configure logging. One suggestion is to use the dictConfig initialization mentioned by the library itself, at the uwsgi master, before defining the app, which then forks. Following your example, at __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 此处.
The problem you mention in EDIT-1 looks like a python logging propagation issue. There is a standalone case, easier to debug, here.
即使您只设置了一个流处理程序，如您的日志所示，它也可能附加了一个父级.如果您检查其父级，则可能会与您在 EDIT-2 中提到的处理程序相距不同的处理程序 :
Even though you have only set one Stream Handler, as your log shows, it probably has a parent attached. If you check for its parent it will probably have a handler attached different from the one you mentioned in EDIT-2 :
print logger.handlers
[<logging.StreamHandler object at 0x7f15669c1550>]
print logger.parent.handlers
[<logging.StreamHandler object at 0x7f15669c1610>]
当启用日志记录传播并且在其他地方发生了一些日志记录初始化时，会发生这种情况.您可以通过查看 python的源代码中的callHandlers来检查传播的工作方式.代码:
This happens when the logging propagation is enabled and there happened some logging initialization elsewhere. You can check how propagation works by looking at callHandlers in python's source code:
...
hdlr.handle(record)
if not c.propagate:
c = None #break out
else:
c = c.parent
...
回到您的案例(烧瓶)，通过查看日志中的痕迹，可以找到一个名为flask.app的记录器，它是由记录. BASIC_FORMAT ).因此，它可能已在代码中的某个位置或导入的库之一中初始化了.
Back to your case (Flask), by looking at the traces in your logs, there is a logger named flask.app, which is the one created by Flask itself. There is the formatted version, and the unformatted one (logging.BASIC_FORMAT), respectively. So it is probably being initialized somewhere in your code or in one of the libraries you import.
有多种方法可以解决此问题:
There are multiple ways you can solve this:
- 将传播设置为false(简单的解决方法，但解决方法)
- 搜索无效"配置并将其删除
- 按照Flask日志记录教程的建议，在实例化应用程序之前使用dictConfig初始化
这篇关于为什么在前面使用UWSGI时Flask logger无法登录docker?的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！
