Python Flask + Gunicorn + Docker 的日志输出设置
普通 Flask 日志设置输出日志文件按天分割、调整格式引入蓝图 BluePrint
使用 Gunicorn 运行的 Flask 日志设置对日志文件进行分割
使用 Docker 部署 Gunicorn + Flask 应用并输出日志Dockerfilerequirements.txtconf/supervisor_flask.conf构建镜像、运行容器
我们一个项目使用了 Python Flask 框架来实现 Web 服务，之前的日志输出一直有问题。而从项目需求、运行维护出发，正确的日志输出对使用者来说都是非常重要的。
这里完整的整理了从 开发 Flask 时的日志设置，到生产环境使用 Gunicorn 运行 Flask 的日志设置 以及 使用 Docker 容器化部署的日志输出 的全部细节。
普通 Flask 日志设置
Flask 本身使用 Python 的 logging 模块来实现日志记录、输出，以一个最简单的 Flask 应用代码为例：
import logging
from flask import Flask, jsonify
app = Flask(__name__)
@app.route('/')
def default_route():
"""Default route"""
app.logger.debug('this is a DEBUG message')
app.logger.info('this is an INFO message')
app.logger.warning('this is a WARNING message')
app.logger.error('this is an ERROR message')
app.logger.critical('this is a CRITICAL message')
return jsonify('hello world')
if __name__ == '__main__':
app.run(host='0.0.0.0', port=8000, debug=True)
运行程序：
$ pip install flask
$ python app.py
* Serving Flask app "app" (lazy loading)
* Environment: production
WARNING: This is a development server. Do not use it in a production deployment.
Use a production WSGI server instead.
* Debug mode: on
* Running on http://0.0.0.0:8000/ (Press CTRL+C to quit)
* Restarting with stat
* Debugger is active!
* Debugger PIN: 265-991-043
访问 http://localhost:8000/ ，程序会在命令行窗口输出：
[2022-12-21 15:46:29,113] DEBUG in app: this is a DEBUG message
[2022-12-21 15:46:29,113] INFO in app: this is an INFO message
[2022-12-21 15:46:29,113] WARNING in app: this is a WARNING message
[2022-12-21 15:46:29,113] ERROR in app: this is an ERROR message
[2022-12-21 15:46:29,113] CRITICAL in app: this is a CRITICAL message
127.0.0.1 - - [21/Dec/2022 15:46:29] "GET / HTTP/1.1" 200 -
输出日志文件
我们可以使用 logging 模块的不同输出处理器（Handler）来实现标准输出、文件输出或邮件提醒。例如添加日志文件：
import logging
from flask import Flask, jsonify
app = Flask(__name__)
@app.route('/')
def default_route():
"""Default route"""
app.logger.debug('this is a DEBUG message')
app.logger.info('this is an INFO message')
app.logger.warning('this is a WARNING message')
app.logger.error('this is an ERROR message')
app.logger.critical('this is a CRITICAL message')
return jsonify('hello world')
if __name__ == '__main__':
# Define log level and log file
app.debug = True
handler = logging.FileHandler('flask.log')
app.logger.addHandler(handler)
app.run(host='0.0.0.0', port=8000, debug=True)
访问 http://localhost:8000 ，我们可以看到在当前目录下生成了 flask.log 日志文件：
$ ls
app.py flask.log
$ cat flask.log
this is a DEBUG message
this is an INFO message
this is a WARNING message
this is an ERROR message
this is a CRITICAL message
按天分割、调整格式
我们常见的日志文件一般按天分割，这样方便查找。另外日志里还需要记录一些必须的时间等值：
import logging
from flask import Flask, jsonify
from logging.handlers import TimedRotatingFileHandler
app = Flask(__name__)
@app.route('/')
def default_route():
"""Default route"""
app.logger.debug('this is a DEBUG message')
app.logger.info('this is an INFO message')
app.logger.warning('this is a WARNING message')
app.logger.error('this is an ERROR message')
app.logger.critical('this is a CRITICAL message')
return jsonify('hello world')
if __name__ == '__main__':
app.debug = True
formatter = logging.Formatter(
"[%(asctime)s][%(filename)s:%(lineno)d][%(levelname)s][%(thread)d] - %(message)s")
handler = TimedRotatingFileHandler(
"flask.log", when="D", interval=1, backupCount=30,
encoding="UTF-8", delay=False, utc=False)
handler.setFormatter(formatter)
app.logger.addHandler(handler)
app.run(host='0.0.0.0', port=8000, debug=True)
TimedRotatingFileHandler 的参数设置：
when=D： 按天进行切分，还可以按秒（S）、分钟（M）、小时（H）、星期时间（‘W0’-‘W6’，W0=周一，此时 interval 不起作用）、半夜时间（midnight） interval=1： 每1天切分，这个值根据上面的 when 来确定单位 backupCount=30：保留30天的日志 encoding=UTF-8: 使用 UTF-8 的编码 delay=False：如果为 True，文件打开会被推迟到第一次调用 emit() utc=False：使用当前系统时间而非 UTC 时间 Formatter 的格式可以参考 https://docs.python.org/2/library/logging.html#logrecord-attributes
再次访问 http://localhost:8000 ，日志文件输出变成了：
[2022-12-21 16:17:05,825][app.py:10][DEBUG][139836122048256] - this is a DEBUG message
[2022-12-21 16:17:05,826][app.py:11][INFO][139836122048256] - this is an INFO message
[2022-12-21 16:17:05,826][app.py:12][WARNING][139836122048256] - this is a WARNING message
[2022-12-21 16:17:05,827][app.py:13][ERROR][139836122048256] - this is an ERROR message
[2022-12-21 16:17:05,827][app.py:14][CRITICAL][139836122048256] - this is a CRITICAL message
引入蓝图 BluePrint
稍微复杂一点的 Flask 程序，可能会使用 BluePrint 来对不同功能模块进行拆分。而使用 BluePrint 后的 Flask 程序，其日志的调用方式有少许变化。
.
├── api
│ └── test.py
├── app.py
└── flask.log
我们在当前项目目录下新建一个 api 目录，然后在其下创建 test.py ，这里我们创建了一个名为 test 的 Blueprint 对象，并且添加了路由 /test 到其下的 show() 方法。这里要获得 Flask 的应用对象，就需要用它的 current_app 来实现对 app 的引用了。
from flask import Blueprint, jsonify, current_app
test = Blueprint('test', __name__)
@test.route('/test', methods=('GET', 'POST'))
def show():
current_app.logger.debug('Test DEBUG message')
current_app.logger.info('Test INFO message')
current_app.logger.warning('Test WARNING message')
current_app.logger.error('Test ERROR message')
current_app.logger.critical('Test CRITICAL message')
return jsonify('Show test')
然后对 app.py 进行修改，把上面的 test 蓝图注册到 app 对象里，并且添加路由前缀 /api 。
import logging
from flask import Flask, jsonify
from logging.handlers import TimedRotatingFileHandler
app = Flask(__name__)
from api.test import test
app.register_blueprint(test, url_prefix='/api')
@app.route('/')
def default_route():
"""Default route"""
app.logger.debug('this is a DEBUG message')
app.logger.info('this is an INFO message')
app.logger.warning('this is a WARNING message')
app.logger.error('this is an ERROR message')
app.logger.critical('this is a CRITICAL message')
return jsonify('hello world')
if __name__ == '__main__':
app.debug = True
formatter = logging.Formatter(
"[%(asctime)s][%(filename)s:%(lineno)d][%(levelname)s][%(thread)d] - %(message)s")
handler = TimedRotatingFileHandler(
"flask.log", when="D", interval=1, backupCount=30,
encoding="UTF-8", delay=False, utc=False)
handler.setFormatter(formatter)
app.logger.addHandler(handler)
app.run(host='0.0.0.0', port=8000, debug=True)
我们分别访问 http://localhost:8000 和 http://localhost:8000/api/test ，可以看到返回正确的结果，日志文件变成了：
[2022-12-21 17:30:34,627][app.py:14][DEBUG][140282256979712] - this is a DEBUG message
[2022-12-21 17:30:34,628][app.py:15][INFO][140282256979712] - this is an INFO message
[2022-12-21 17:30:34,628][app.py:16][WARNING][140282256979712] - this is a WARNING message
[2022-12-21 17:30:34,629][app.py:17][ERROR][140282256979712] - this is an ERROR message
[2022-12-21 17:30:34,629][app.py:18][CRITICAL][140282256979712] - this is a CRITICAL message
[2022-12-21 17:30:50,946][test.py:7][DEBUG][140282256979712] - Test DEBUG message
[2022-12-21 17:30:50,947][test.py:8][INFO][140282256979712] - Test INFO message
[2022-12-21 17:30:50,947][test.py:9][WARNING][140282256979712] - Test WARNING message
[2022-12-21 17:30:50,947][test.py:10][ERROR][140282256979712] - Test ERROR message
[2022-12-21 17:30:50,949][test.py:11][CRITICAL][140282256979712] - Test CRITICAL message
至此，Flask 的日志一切都运转良好。然后我们在生产服务器上部署的时候，现在常常会使用 Gunicorn 来运行，这时候的日志输出就有问题了，日志文件没有内容写入。
使用 Gunicorn 运行的 Flask 日志设置
Gunicorn 有自己的日志记录器，它通过本身的机制控制日志级别。我们只能通过配置 Gunicorn 的日志设定，来实现我们的需求。同时，需要对上面例子应用的日志处理器设置进行调整。
修改 app.py，注意我们添加的 if __name__ != '__main__' 这部分，就是在 Gunicorn 运行时，让 Flask 使用它的日志处理器。
import logging
from flask import Flask, jsonify
from logging.handlers import TimedRotatingFileHandler
app = Flask(__name__)
from api.test import test
app.register_blueprint(test, url_prefix='/api')
@app.route('/')
def default_route():
"""Default route"""
app.logger.debug('this is a DEBUG message')
app.logger.info('this is an INFO message')
app.logger.warning('this is a WARNING message')
app.logger.error('this is an ERROR message')
app.logger.critical('this is a CRITICAL message')
return jsonify('hello world')
# make app to use gunicorn logger handler
if __name__ != '__main__':
gunicorn_logger = logging.getLogger('gunicorn.error')
app.logger.handlers = gunicorn_logger.handlers
app.logger.setLevel(gunicorn_logger.level)
if __name__ == '__main__':
app.debug = True
formatter = logging.Formatter(
"[%(asctime)s][%(filename)s:%(lineno)d][%(levelname)s][%(thread)d] - %(message)s")
handler = TimedRotatingFileHandler(
"flask.log", when="D", interval=1, backupCount=30,
encoding="UTF-8", delay=False, utc=False)
handler.setFormatter(formatter)
app.logger.addHandler(handler)
app.run(host='0.0.0.0', port=8000, debug=True)
参考 Gunicorn 日志设置，我们在启动 Gunicorn 时可以使用下面的命令行：
# 创建日志目录
$ mkdir -p /var/log/gunicorn/
# 赋予日志目录当前用户权限
$ chown tattoo:tattoo /var/log/gunicorn/
# 运行 gunicorn
$ gunicorn -w 2 \
-b 0.0.0.0:5000 \
--log-level debug \
--log-file /var/log/gunicorn/gunicorn.log \
app:app
运行后，访问 http://localhost:5000 和 http://localhost:5000/api/test ，我们得到 gunicorn.log 日志：
[2022-12-21 17:59:05 +0800] [32174] [DEBUG] Current configuration:
config: ./gunicorn.conf.py
wsgi_app: None
bind: ['0.0.0.0:5000']
backlog: 2048
workers: 2
worker_class: sync
threads: 1
worker_connections: 1000
max_requests: 0
max_requests_jitter: 0
timeout: 30
graceful_timeout: 30
keepalive: 2
limit_request_line: 4094
limit_request_fields: 100
limit_request_field_size: 8190
reload: False
reload_engine: auto
reload_extra_files: []
spew: False
check_config: False
print_config: False
preload_app: False
sendfile: None
reuse_port: False
chdir: /home/tattoo/workspace/flask
daemon: False
raw_env: []
pidfile: None
worker_tmp_dir: None
user: 1000
group: 1000
umask: 0
initgroups: False
tmp_upload_dir: None
secure_scheme_headers: {'X-FORWARDED-PROTOCOL': 'ssl', 'X-FORWARDED-PROTO': 'https', 'X-FORWARDED-SSL': 'on'}
forwarded_allow_ips: ['127.0.0.1']
accesslog: None
disable_redirect_access_to_syslog: False
access_log_format: %(h)s %(l)s %(u)s %(t)s "%(r)s" %(s)s %(b)s "%(f)s" "%(a)s"
errorlog: /var/log/gunicorn/gunicorn.log
loglevel: debug
capture_output: False
logger_class: gunicorn.glogging.Logger
logconfig: None
logconfig_dict: {}
syslog_addr: udp://localhost:514
syslog: False
syslog_prefix: None
syslog_facility: user
enable_stdio_inheritance: False
statsd_host: None
dogstatsd_tags:
statsd_prefix:
proc_name: None
default_proc_name: app:app
pythonpath: None
paste: None
on_starting:
on_reload:
when_ready:
pre_fork:
post_fork:
post_worker_init:
worker_int:
worker_abort:
pre_exec:
pre_request:
post_request:
child_exit:
worker_exit:
nworkers_changed:
on_exit:
proxy_protocol: False
proxy_allow_ips: ['127.0.0.1']
keyfile: None
certfile: None
ssl_version: 2
cert_reqs: 0
ca_certs: None
suppress_ragged_eofs: True
do_handshake_on_connect: False
ciphers: None
raw_paste_global_conf: []
strip_header_spaces: False
[2022-12-21 17:59:05 +0800] [32174] [INFO] Starting gunicorn 20.1.0
[2022-12-21 17:59:05 +0800] [32174] [DEBUG] Arbiter booted
[2022-12-21 17:59:05 +0800] [32174] [INFO] Listening at: http://0.0.0.0:5000 (32174)
[2022-12-21 17:59:05 +0800] [32174] [INFO] Using worker: sync
[2022-12-21 17:59:05 +0800] [32176] [INFO] Booting worker with pid: 32176
[2022-12-21 17:59:05 +0800] [32177] [INFO] Booting worker with pid: 32177
[2022-12-21 17:59:05 +0800] [32174] [DEBUG] 2 workers
[2022-12-21 17:59:11 +0800] [32177] [DEBUG] GET /
[2022-12-21 17:59:11 +0800] [32177] [DEBUG] this is a DEBUG message
[2022-12-21 17:59:11 +0800] [32177] [INFO] this is an INFO message
[2022-12-21 17:59:11 +0800] [32177] [WARNING] this is a WARNING message
[2022-12-21 17:59:11 +0800] [32177] [ERROR] this is an ERROR message
[2022-12-21 17:59:11 +0800] [32177] [CRITICAL] this is a CRITICAL message
[2022-12-21 17:59:17 +0800] [32177] [DEBUG] GET /api/test
[2022-12-21 17:59:17 +0800] [32177] [DEBUG] Test DEBUG message
[2022-12-21 17:59:17 +0800] [32177] [INFO] Test INFO message
[2022-12-21 17:59:17 +0800] [32177] [WARNING] Test WARNING message
[2022-12-21 17:59:17 +0800] [32177] [ERROR] Test ERROR message
[2022-12-21 17:59:17 +0800] [32177] [CRITICAL] Test CRITICAL message
你也可以参考 https://docs.python.org/3/library/logging.config.html ，使用 Gunicorn 的 --log-config FILE 选项，用一个日志配置文件来做更精细的日志调整。
对日志文件进行分割
Gunicorn 自身不对日志进行分割，所以我们可以使用 logrotate 工具来实现日志分割的需求。
创建 /etc/logrotate.d/gunicorn 文件：
/var/log/gunicorn/gunicorn.log {
daily
dateext
dateformat -%Y-%m-%d
dateyesterday
rotate 90
missingok
notifempty
}
daily 每天执行，也可以是 weekly 或 monthly dateext 使用当期日期作为命名格式 dateformat 日志文件命名格式 rotate 分割次数，如果设置的是daily，就代表保留多少天的记录
如果要立即执行： logrotate -f gunicorn
使用 Docker 部署 Gunicorn + Flask 应用并输出日志
我们在服务器上配置 Python 环境，常常会碰到各种各样的麻烦，而使用现成的 Docker 镜像就很方便，它在各种环境下的行为都能保持一致。
添加 Dockerfile、requirements.txt 和 conf/supervisor_flask.conf 文件：
.
├── api
│ └── test.py
├── app.py
├── conf
│ └── supervisor_flask.conf
├── Dockerfile
└── requirements.txt
Dockerfile
我们使用 alpine 基础镜像以减小镜像体积。使用 supervisord 来后台启动 Gunicorn + Flask。日志输出到 /var/log/flask-app 目录。
FROM python:3-alpine
WORKDIR /home/app
USER root
RUN sed -i 's/dl-cdn.alpinelinux.org/mirrors.aliyun.com/g' /etc/apk/repositories \
# upgrade pip
&& pip config set global.index-url https://mirrors.aliyun.com/pypi/simple \
&& pip install --upgrade pip \
# install supervisor gunicorn
&& pip install supervisor gunicorn \
&& mkdir -p /etc/supervisor \
&& /usr/local/bin/echo_supervisord_conf > /etc/supervisor/supervisord.conf \
&& echo "[include]" >> /etc/supervisor/supervisord.conf \
&& echo "files = /etc/supervisor/*.conf" >> /etc/supervisor/supervisord.conf \
# get curl for healthchecks
&& apk add curl \
# add log folder
&& mkdir -p /var/log/flask-app
COPY conf/supervisor_flask.conf /etc/supervisor
# copy all the files to the container
COPY . .
# python setup
RUN pip install -r requirements.txt
# define the port number the container should expose
EXPOSE 5000
CMD ["supervisord","-n","-c","/etc/supervisor/supervisord.conf"]
requirements.txt
注意 markupsafe 2.1.0 移除了 soft_unicode，不指定较低版本的话会导致 Flask 报错。
markupsafe==2.0.1
Flask~=1.1.4
conf/supervisor_flask.conf
[supervisord]
nodaemon=true
[program:flask]
command=gunicorn -w 2 -b 0.0.0.0:5000 --log-level debug --log-file /var/log/flask-app/gunicorn.log app:app
directory=/home/app
autostart=true
autorestart=true
redirect_stderr=true
stdout_logfile=/dev/stdout
构建镜像、运行容器
使用下面的命令构建镜像 flasktest：
docker build -t flasktest .
运行，这里我们把日志输出目录映射到了宿主机的 /home/logs 目录：
docker run --name flask \
-it -d \
-p 5000:5000 \
-v /home/logs:/var/log/flask-app \
flasktest
运行起来后，docker logs -f flask 查看一下容器输出有没有问题，正常的应该是：
$ docker logs -f flasktest
2022-12-22 03:33:32,368 CRIT Supervisor is running as root. Privileges were not dropped because no user is specified in the config file. If you intend to run as root, you can set user=root in the config file to avoid this message.
2022-12-22 03:33:32,368 INFO Included extra file "/etc/supervisor/supervisor_flask.conf" during parsing
2022-12-22 03:33:32,368 INFO Included extra file "/etc/supervisor/supervisord.conf" during parsing
2022-12-22 03:33:32,371 INFO RPC interface 'supervisor' initialized
2022-12-22 03:33:32,371 CRIT Server 'unix_http_server' running without any HTTP authentication checking
2022-12-22 03:33:32,372 INFO supervisord started with pid 1
2022-12-22 03:33:33,374 INFO spawned: 'flask' with pid 6
2022-12-22 03:33:34,376 INFO success: flask entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
访问 http://localhost:5000 和 http://localhost:5000/api/test ，我们可以在 /home/logs 目录下找到 gunicorn.log 日志，跟前面的没有什么区别
Tangramor
Python Flask + Gunicorn + Docker 的日志输出设置
好文阅读
发表评论