关于 Gunicorn + Flask 在多进程中，日志轮转的一个 BUG

V2EX = way to explore

V2EX 是一个关于分享和探索的地方

现在注册

已注册用户请登录

请不要在回答技术问题时复制粘贴 AI 生成的内容

这是一个创建于 274 天前的主题，其中的信息可能已经有所发展或是发生改变。

语言、框架、环境

Python3.11

Gunicorn + Flask + logging

Debian 12

问题

我在开发一个小型的 Python Web 应用，选用的是 Gunicorn + Flask 的方案，日志采用了官方自带的 logging 库。

业务及其简单，但接口请求量比较大，日志记录比较多，我看到官方提供了一个logging.handlers.TimedRotatingFileHandler的日志轮转处理器，就直接用了。

但是过了一段时间，我发现了日志丢失的问题：

假设 Gunicorn 启动了 3 个 worker 进程，进程号分别是 1001 、1002 和 1003 ，一开始启动 Gunicorn 时，3 个进程的日志都能正确的写入到 app.log 中，但是一旦发生了日志轮转，最终只有一个进程（比如 1001 ）能够写入到新的 app.log 中，另外的 1002 和 1003 的日志就再也没有写入成功了。

我的猜测

我猜应该是和多进程日志处理和日志轮转相关的问题，轮转的时候，只有一个进程在切换 app.log ，其他进程找不到文件了，日志就丢失了？（我的猜测很粗糙，我不太理解原理）

当然，官方文档也提到了这点：

https://docs.python.org/zh-cn/3/howto/logging-cookbook.html#logging-to-a-single-file-from-multiple-processes

文档的建议是，使用 SocketHandler 或者 QueueHandler ，总之是单独使用一个进程处理日志。

提问

生产环境下，有什么好的解决方案？
刚刚上面的轮转日志丢失，更加具体的，本质的原理是什么？

代码

日志配置文件 logging.yaml 如下：

version: 1 formatters: brief: format: '%(asctime)s - %(levelname)s - %(name)s - %(message)s' detail: format: '%(asctime)s - %(levelname)s - %(process)d - %(processName)s - %(name)s - %(filename)s - %(funcName)s - %(message)s' handlers: console_handler: class: logging.StreamHandler level: DEBUG formatter: brief stream: ext://sys.stdout info_handler: class: logging.handlers.TimedRotatingFileHandler level: INFO formatter: detail filename: logs/app.log when: midnight backupCount: 2 encoding: utf-8 error_handler: class: logging.handlers.TimedRotatingFileHandler level: ERROR formatter: detail filename: logs/error.log when: midnight backupCount: 2 encoding: utf-8 loggers: study-flask: level: DEBUG handlers: [console_handler, info_handler, error_handler] propagate: False root: level: DEBUG handlers: [console_handler]

app.py 中关于日志配置的代码：

def log_config(log_config_file): dict_cOnfig= yaml.load( open(log_config_file, encoding='utf-8'), Loader=yaml.FullLoader ) Path.mkdir(Path.cwd().joinpath("logs"), parents=True, exist_ok=True) logging.config.dictConfig(dict_config) def create_app(config_mode): app = Flask(__name__) log_config('./logging.yaml') # ... 省略其他代码

第 1 条附言 274 天前

找到类似的提问：

1. https://stackoverflow.com/questions/9975609/python-timedrotatingfilehandler-logs-are-missing

2. https://stackoverflow.com/questions/18840785/timedrotatingfilehandler-doesnt-work-fine-in-django-with-multi-instance/18843553#18843553

gunicorn

flask

日志轮转

17 条回复 2025-01-10 16:00:50 +08:00

dajj

274 天前

多进程模式下肯定这样是不行的。考虑用其它东西，比如 redis 订阅之类的，交给另一个服务去处理日志

daxin945

274 天前

我 Python 开发的时候一直用 Loguru ，推荐你试试

Koril

274 天前

我自己又重新测试了下，假设 1001 对 app.log 进行轮转：

1. app.log 该名称变成 app.log.bak ，但实际上我发现 app.log.bak 的 inode 值没变

2. 1001 进程创建一个新的文件叫 app.log ，然后自己一个人把日志写入到这个新的文件里（新的 inode 值）

3. 1002 进程和 1003 进程被 1001 骗了，还在往 app.log.bak 写日志

大概，似乎，是这样子。。。

gcdsss

274 天前

我踩过坑，解决方法，写一个多线程兼容的 handler 去处理

`
class MultiCompatibleTimedRotatingFileHandler(TimedRotatingFileHandler):
def doRollover(self):
if self.stream:
self.stream.close()
self.stream = None
# get the time that this sequence started at and make it a TimeTuple
currentTime = int(time.time())
dstNow = time.localtime(currentTime)[-1]
t = self.rolloverAt - self.interval
if self.utc:
timeTuple = time.gmtime(t)
else:
timeTuple = time.localtime(t)
dstThen = timeTuple[-1]
if dstNow != dstThen:
if dstNow:
addend = 3600
else:
addend = -3600
timeTuple = time.localtime(t + addend)
dfn = self.baseFilename + "." + time.strftime(self.suffix, timeTuple)
# 兼容多进程并发 LOG_ROTATE
if not os.path.exists(dfn):
f = open(self.baseFilename, "a")
fcntl.lockf(f.fileno(), fcntl.LOCK_EX)
if not os.path.exists(dfn):
os.rename(self.baseFilename, dfn) # 释放锁释放老 log 句柄
f.close()
if self.backupCount > 0:
for s in self.getFilesToDelete():
os.remove(s)
if not self.delay:
self.stream = self._open()
newRolloverAt = self.computeRollover(currentTime)
while newRolloverAt <= currentTime:
newRolloverAt = newRolloverAt + self.interval
# If DST changes and midnight or weekly rollover, adjust for this.
if (self.when == "MIDNIGHT" or self.when.startswith("W")) and not self.utc:
dstAtRollover = time.localtime(newRolloverAt)[-1]
if dstNow != dstAtRollover:
if (
not dstNow
): # DST kicks in before next rollover, so we need to deduct an hour
addend = -3600
else: # DST bows out before next rollover, so we need to add an hour
addend = 3600
newRolloverAt += addend
self.rolloverAt = newRolloverAt
`

julyclyde

274 天前

用 stream 写就行了。日志存盘那是另外的事

adoal

274 天前

如果不是日志量大到惊悚，建议打到 syslog 去，用 logrotate 管理切分。比应用程序或者框架自己管理日志切分省心。

julyclyde

274 天前

@adoal syslog 倒不必……大量的应用程序日志会影响调查系统级别的问题

yumenlong

274 天前

import logging
from logging import getLogger, DEBUG
from concurrent_log_handler import ConcurrentRotatingFileHandler

formatter_log = logging.Formatter('%(asctime)s%(filename)s[%(lineno)d]%(funcName)s %(levelname)s %(message)s')

logger = getLogger()
logfile = os.path.abspath("log/resource.log")
rotateHandler = ConcurrentRotatingFileHandler(logfile, "a", 3000 * 1024, 50)
rotateHandler.setFormatter(formatter_log)
logger.addHandler(rotateHandler)
logger.setLevel(DEBUG)
我的也是 gunicorn 多进程,使用 ConcurrentRotatingFileHandler 正常记录多进程日志.

yumenlong

274 天前

使用 ConcurrentRotatingFileHandler 可以解决多进程日志记录的问题。ConcurrentRotatingFileHandler 是 ConcurrentLogHandler 库的一部分，专门设计用于在进程环境中安全地进行日志记录和日志轮转。

yingxiangyu

274 天前

python 自带的日志库想解决这个问题很麻烦，最简单的就是不在 python 内做轮转，直接打到 std ，用类似 supervisor 之类的捕获 std 输出做轮转

yingxiangyu

274 天前

现在大部分不都是用 docker 部署，直接打到 std ，用 docker 自带的日志管理实现轮转

zhangchunjiiw

274 天前

import os
import time

from logging.handlers import TimedRotatingFileHandler

class SafeRotatingFileHandler(TimedRotatingFileHandler):
def __init__(self, filename, when='h', interval=1, backupCount=0, encoding=None, delay=False, utc=False):
TimedRotatingFileHandler.__init__(self, filename, when, interval, backupCount, encoding, delay, utc)

"""
多进程, 文件处理.
Override doRollover
lines commanded by "##" is changed by cc
https://www.jianshu.com/p/d615bf01e37b
"""

def doRollover(self):
"""
do a rollover; in this case, a date/time stamp is appended to the filename
when the rollover happens. However, you want the file to be named for the
start of the interval, not the current time. If there is a backup count,
then we have to get a list of matching filenames, sort them and remove
the one with the oldest suffix.

Override, 1. if dfn not exist then do rename
2. _open with "a" model
"""
if self.stream:
self.stream.close()
self.stream = None
# get the time that this sequence started at and make it a TimeTuple
currentTime = int(time.time())
dstNow = time.localtime(currentTime)[-1]
t = self.rolloverAt - self.interval
if self.utc:
timeTuple = time.gmtime(t)
else:
timeTuple = time.localtime(t)
dstThen = timeTuple[-1]
if dstNow != dstThen:
if dstNow:
addend = 3600
else:
addend = -3600
timeTuple = time.localtime(t + addend)

# 多进程, 文件处理.
dfn = self.baseFilename + "." + time.strftime(self.suffix, timeTuple)
# if os.path.exists(dfn):
# os.remove(dfn)

# Issue 18940: A file may not have been created if delay is True.
# if os.path.exists(self.baseFilename):
if not os.path.exists(dfn) and os.path.exists(self.baseFilename):
os.rename(self.baseFilename, dfn)

if self.backupCount > 0:
for s in self.getFilesToDelete():
os.remove(s)
if not self.delay:
self.mode = "a"
self.stream = self._open()
newRolloverAt = self.computeRollover(currentTime)
while newRolloverAt <= currentTime:
newRolloverAt = newRolloverAt + self.interval
# If DST changes and midnight or weekly rollover, adjust for this.
if (self.when == 'MIDNIGHT' or self.when.startswith('W')) and not self.utc:
dstAtRollover = time.localtime(newRolloverAt)[-1]
if dstNow != dstAtRollover:
if not dstNow: # DST kicks in before next rollover, so we need to deduct an hour
addend = -3600
else: # DST bows out before next rollover, so we need to add an hour
addend = 3600
newRolloverAt += addend
self.rolloverAt = newRolloverAt

init:
class Logger(object):
def __init__(self):
handlers.SafeRotatingFileHandler = SafeRotatingFileHandler

yaml:
info:
class: logging.handlers.SafeRotatingFileHandler
level: INFO
formatter: console
filename: ./log/info.log
when: MIDNIGHT
interval : 1
backupCount: 7
encoding: utf8

表现就是在切分日志的时候, 会发生日志丢失

https://www.jianshu.com/p/d615bf01e37b
重写 TimedRotatingFileHandler, 之前遇到过相似问题, 希望可以帮到你

这是 21 年左右的方式了, 现在也许会有更好的 :)

zhangchunjiiw

274 天前

```py
import datetime
```

fcfangcc

273 天前

我们直接在日志文件后面加了进程号 app_name_{pid}.log

Koril

273 天前

@zhangchunjiiw 你在简书写的这篇博客对我很有帮助，感谢

Koril

273 天前

@yumenlong https://pypi.org/project/concurrent-log-handler/ 这个库对么，我试试

Bisn

273 天前

@Koril 是这个库，我最近在 django 中用这个库解决了类似的问题