Flask+uWSGI logging rotate：重要补充

2020-01-27 [2690] technology uwsgi flask python server logging

文章目录

我在 Flask+uWSGI 的 Logging 支持 一文中详细讲解过关于 Flask+uWSGI 中的 logging 支持情况。但还不够，这篇文章里面做一些重要补充。

1. copytruncate 的不足之处

在 Flask+uWSGI 的 Logging 支持 一文的最后，我对于 logging rotate 有这样一段描述：

uWSGI 还可以使用 touch-logrotate 和 touch-logreopen 来实现 logging rotate，但为了让系统更加简单的独立，我建议使用 logrotate 来实现 logging rotate，并已经在 uWSGI+rsyslog 实现 rotating logging 一文中介绍过具体做法。

需要注意的是，我在 uWSGI+rsyslog 实现 rotating logging 一文的 单独使用 logrotate 小节中提到的使用 copytruncate 选项替换 create 选项，是因为没有通知 uWSGI 重新打开 log 文件。要做到这一点非常简单，除了使用刚才提到的 touch-logreopen 之外，还可以使用 Master FIFO 中的 l 命令。

如果不使用 rsyslog 这类系统工具，而只用 logrotate 来实现 logging rotate，我们有两种选择，使用 copytruncate 或者使用 create 来 rotate 日志文件。

在使用 copytruncate 的时候，如果日志文件很小（例如小于 100MB），那么这样做问题不大。如果日志文件很大呢？例如 MJP 的日志文件是几十个 GB 的大小。这就出现了两个问题：

  1. 即使是使用高速 SSD 硬盘，复制 GB 级别的日志文件也成了一个非常耗时的工作。
  2. 每天制造几十个 GB 日志的服务是非常繁忙的服务，在 copy 的过程中，一定会丢失一部分日志无法写入。

那么使用 create 是否可行呢？

摘录一段 uWSGI+rsyslog 实现 rotating logging 中的原文：

这是因为在 linux 系统下，一个进程打开文件时使用的是文件系统的 inode 编号而非文件名。移动或者重命名一个文件，并不会修改它的 inode 编号。因此需要在进行 rotate 之后，通知 uwsgi 重新打开 log 文件。

或者，可以将 create 创建方式修改为 copytruncate 创建方式，后者的特点是复制一份现有的 log 为新文件，然后清空旧文件。这样就不需要通知 uwsgi 重新打开 log 文件了。

所以，我们只需要解决 重新打开 log 文件 的问题，就可以解决 copytruncata 带来的不足。

2. uwsgi 重新打开 log 文件

成功触发 logreopen 时，uWSGI 日志会给出下面的消息：

1[1580052181] logsize: 13574, triggering log-reopen...
2[1580052181] /srv/app/mjpadm/logs/uwsgi.log reopened.

关于重新打开 log 文件，uWSGI 中有两种方法可以实现：

2.1 方法一

首先加入 touch-logreopen 配置：

1[uwsgi]
2# 必须配置 log-master 才支持 logreopen
3log-master = true
4touch-logreopen = /srv/app/mjpadm/mjp-touch-logreopen.touch

改名旧 log 文件，创建新 log 文件之后，touch 一下 touch-logreopen 选项指定的文件，即可通知 uWSGI 重新打开新的 log 文件。

这个文件就是一个普通的 0 字节文件，但这个文件需要预先创建，否则 uWSGI 启动的时会报 warning。

重新打开文件，可以直接执行命令:

1touch /srv/app/mjpadm/mjp-touch-logreopen.touch

2.2 方法二

启用 The Master FIFO，配置如下：

1[uwsgi]
2# 必须配置 log-master 才支持 logreopen
3log-master = true
4master-fifo = /srv/app/mjpadm/uwsgi.fifo

改名旧 log 文件，创建新 log 文件之后，执行下面的命令向 fifo 文件写入 l 指令，即可通知 uWSGI 重新打开新的 log 文件。

1echo l > /srv/app/mjpadm/uwsgi.fifo

3. 哪个 logger 选项支持 logreopen

你以为像上面那样配置好就结束了？错！

uWSGI Logging 文档中提到，有好几个选项可以实现 logging，但这些选项的作用，文档中却没有仔细介绍。这是 uWSGI 文档的特点。但我也不能过多吐槽，毕竟它还是有文档的对不对？总比直接翻源码要好一点对不对？

你要记住的是： 并不是所有的 logger 选项都支持 logreopen！！！

根据实验，我把 uWSGI 的所有 logger 的支持列在下面。uWSGI 的 logger 选项分为 基本 logger 和 插件化 logger 两种。

3.1 基本 logger

  • logto/logto2 指定一个文件，将日志内容写入文件。支持 logreopen
  • daemonize 指定一个文件，将日志内容写入文件。也可以不指定文件，仅提供参数，此时需要配合其他 logger 指定日志写入到哪里。 不支持 logreopen

3.2 插件化 logger

  • logger 可以支持多种日志写入目标，当使用 file:/path/to/foo.log 语法的时候支持写入文件。不支持 logreopen
  • req-logger 仅处理请求日志，用于将请求日志单独分离。可以支持多种日志写入目标，当使用 file:/path/to/bar.log 语法的时候支持写入文件。 不支持 logreopen

插件化 logger 是支持多种写入目标的，通过配置 file:/socket:/syslog:/redislog:zeromq: 等等前缀来执行，具体可以查看 uWSGI Logging 文档，这里仅仅讨论 file: 的情况。

3.3 实战 uWSGI 配置

根据我的测试，只有这样的配置才能支持 logreopen：

1[uwsgi]
2# 不要给 daemonize 指定文件，简单设置为 true 即可
3daemonize = true
4# 必须配置 log-master 才支持 logreopen
5log-master = true
6logto = /srv/app/mjpadm/logs/uwsgi.log
7# master-fifo 和 touch-logreopen 任选其一
8master-fifo = /srv/app/mjpadm/uwsgi.fifo
9; touch-logreopen = /srv/app/mjpadm/mjp-touch-logreopen.touch

4. logrotate 相关配置

我们讨论不使用 logrotate 中的 copytruncate 配置，看看对应 logreopen 的相关 logrotate 配置：

 1/srv/app/mjpadm/logs/uwsgi.log {
 2    su app app
 3    create 0644 app app
 4    daily
 5    rotate 10
 6    missingok
 7    notifempty
 8    sharedscripts
 9    # 执行完毕 rotate 之后，通知 uWSGI 重新打开日志，以下两种方法任选其一
10    postrotate
11        # 方法一
12        touch /srv/app/mjpadm/mjp-touch-logreopen.touch
13        # 方法二
14        echo l > /srv/app/mjpadm/uwsgi.fifo
15    endscript
16}

5. Flask 中的日志处理

uWSGI 相关的部分讨论完了，接着来看看 Flask 中的日志处理。

我建议使用 Python 自带的 logging 模块来处理 Flask 的日志，这样会更加灵活也更容易控制。我在 MJP 项目中封装了两个方法 get_logger/get_logging_handler 供使用：

 1# -*- coding: utf-8 -*-
 2__version__ = '1.3.1'
 3
 4import logging 
 5from logging.handlers import WatchedFileHandler
 6from pathlib import Path
 7
 8import zmq
 9from pythonjsonlogger import jsonlogger
10
11
12TEXT_LOG_FORMAT = """
13[%(asctime)s] %(levelname)s in %(module)s.%(funcName)s [%(pathname)s:%(lineno)d]:
14%(message)s"""
15JSON_LOG_FORMAT = r'%(levelname)s %(module)s %(funcName)s %(pathname)s %(lineno) %(threadName) %(processName)'
16
17def _create_file_handler(target, filename):
18    """ 创建一个基于文件的 logging handler
19    :param target: 一个 Path 对象，或者一个 path 字符串
20    """
21    logsdir = None
22    if isinstance(target, Path):
23        logsdir = target.joinpath('logs')
24    else:
25        logsdir = Path(target).joinpath('logs')
26    # 创建或者设置 logs 文件夹的权限，让其他 user 也可以写入（例如nginx）
27    # 注意，要设置 777 权限，需要使用 0o40777 或者先设置 os.umask(0)
28    # 0o40777 是根据 os.stat() 获取到的 st_mode 得到的
29    if logsdir.exists():
30        logsdir.chmod(0o40777)
31    else:
32        logsdir.mkdir(mode=0o40777)
33    logfile = logsdir.joinpath(filename + '.log')
34    if not logfile.exists():
35        logfile.touch()
36    # 使用 WatchedFileHandler 在文件改变的时候自动打开新的流，配合 logrotate 使用
37    return WatchedFileHandler(logfile, encoding='utf8')
38
39
40def _create_zmq_handler(target):
41    """ 创建一个基于 zeromq 的 logging handler
42    :param target: 一个字符串，形如： tcp://127.0.0.1:8334
43    """
44    ctx = zmq.Context()
45    pub = ctx.socket(zmq.PUB)
46    pub.connect(target)
47    return zmq.log.handlers.PUBHandler(pub)
48
49
50def get_logging_handler(type_, fmt, level, target=None, name=None) :
51    """ 获取一个 logger handler
52
53    :param type_: stream/file/zmq
54    :param fmt: text/json
55    :param level: logging 的 level 级别
56    :param target: 项目主目录的的 path 字符串或者 Path 对象，也可以是 tcp://127.0.0.1:8334 这样的地址
57    :param name: logger 的名称，不要带扩展名
58    """
59    handler = None
60    if type_ == 'zmq':
61        if target is None:
62            raise TypeError('target is necessary if type is zmq!')
63        handler = _create_zmq_handler(target)
64    elif type_ == 'file':
65        if target is None or name is None:
66            raise TypeError('target and name is necessary if type is file!')
67        handler = _create_file_handler(target, name)
68    else:
69        handler = logging.StreamHandler()
70    if fmt == 'text':
71        formatter = logging.Formatter(TEXT_LOG_FORMAT)
72    else:
73        formatter = jsonlogger.JsonFormatter(JSON_LOG_FORMAT, timestamp=True)
74    handler.setLevel(level)
75    handler.setFormatter(formatter)
76    return handler
77
78
79def get_logger(name, target, type_='file', fmt='text', level=logging.INFO):
80    """ 基于 target 创建一个 logger
81
82    :param name: logger 的名称，不要带扩展名
83    :param target: 项目主目录的的 path 字符串或者 Path 对象，也可以是 tcp://127.0.0.1:8334 这样的地址
84    :param type_: stream/file/zmq
85    :param fmt: text/json
86    :param level: logging 的 level 级别
87    """
88    hdr = get_logging_handler(type_, fmt, level, target, name)
89
90    log = logging.getLogger(name)
91    log.addHandler(hdr)
92    log.setLevel(level)
93    return log

注意，上面的方法依赖两个外部模块 pyzmq 和 python-json-logger，请先使用 pip 安装。这两个外部模块提供 ZeroMQ 发送日志，并同时支持 JSON 格式的日志格式。

get_logger 和 get_logging_handler 可以单独使用。注释很详细，不再赘述。

5.1 WatchedFileHandler 支持自动 reopen

Python 标准库模块 logging.handlers.WatchedFileHandler 支持在文件改变的时候自动打开新的流，和 logrotate 是绝配了。有了这个我们甚至不需要在创建了新的 log 之后通知 uWSGI 重新打开 log 文件。

5.2 _set_logger 升级版

我在 Flask+uWSGI 的 Logging 支持 中展示了 _set_logger 方法，现在有了上面的 get_logging_handler 封装，可以让 _set_logger 升个级。

 1def _set_logger(mjpapp):
 2    """ 设置 Flask app 和 sqlalchemy 的logger
 3    """
 4    # 获取 flask 和 sqlalchemy 的 logger
 5    flasklogger = mjpapp.logger
 6    sqlalchemylogger = logging.getLogger('sqlalchemy')
 7    # 删除 Flask 的默认 Handler
 8    del flasklogger.handlers[:]
 9    handler = None
10    # 默认为 DEBUG 级别
11    level = logging.DEBUG
12    # 在 DEBUG 状态下，使用 stream handler
13    if mjpapp.config.get('DEBUG'):
14        handler = get_logging_handler('stream', 'text', level)
15    else:
16        # 切换为 INFO 级别，使用 json 格式的日志
17        level = logging.INFO
18        handler = get_logging_handler('file', 'json', level, target=config.getdir(), name='app')
19    flasklogger.setLevel(level)
20    sqlalchemylogger.setLevel(logging.WARNING)
21    for log in (flasklogger, sqlalchemylogger):
22        log.addHandler(handler)

6. 终极方案

你以为像上面那样处理好就结束了？错！！

还有一个 小问题 没有解决。

上面提到 req-logger 是不支持 logreopen 的，而且 uWSGI 的请求日志，也没办法让 Python 的 WatchedFileHandler 代劳。前面也讨论过，使用 copytruncate 处理几十个 GB 的请求日志，会丢失一部分数据。

uWSGI 的主要作者 unbit 也讨论过，req-logger 这个插件化的 logger 不支持 logreopen。

request logging only uses pluggable loggers, so "basic file-logging" procedure cannot work. Each plugin has its features, and, as an example, "reopening" is not meaningful for the vast majority of them. You could improve the logfile plugin to support reopening, or you can use the logpipe plugin to use (again as an example) a tool like this: http://httpd.apache.org/docs/2.2/programs/rotatelogs.html

这里不讨论 log-maxsize 这样的配置来实现基于文件大小的 rotate 的情况。毕竟大多数情况下我们需要的是 daily rotate。

而且，当你的 uWSGI 实例达到数十个的时候，使用 touch-logreopen 或者 Master FIFO 是个很麻烦的事情。因为 logrotate 的配置文件中，尽管对于路径支持通配符，但在 postrotate script 中不支持魔术变量，这会导致我们无法去 touch 数十个不同的文件。

MJP 就有近百个实例部署在多台服务器上，要处理它们的 logreopen 就是一件挺棘手的问题。

因此，我们需要一个终极解决方案来解决这个问题。这需要新开一篇文章来说明。请看下篇：

pyzog：uWSGI logging rotate 的终极方案

7. 相关阅读

全文完