谈谈 Python logging 模块中的 RotatingH
RotatingHandler 简介
Python 的 logging 模块提供了两个支持日志回滚的 FileHandler 类,分别是 RotatingFileHandler 和 TimedRotatingFileHandler.
RotatingFileHandler 的回滚时刻是当日志文件的大小达到一定值。当日志文件的大小达到指定值的时候,RotatingFileHandler 会将日志文件重命名存档,然后打开一个新的日志文件。
TimedRotatingFileHandler 是当某个时刻到来时执行回滚。同 RotatingFileHandler 一样,当回滚时机来临时,TimedRotatingFileHandler 会将日志文件重命名存档,然后打开一个新的日志文件。
RotatingHandler 存在的问题
在单进程环境下,使用上面两个 RotatingHandler 不会有问题。但是当有多个进程向同一个日志文件写入日志的时候,这两个 RotatingHandler 就会带来问题。
举个例子,假如某个 Web 应用通过 uWSGI 提供服务,uWSGI 一般以多进程 master/worker 的方式启动。然后该 Web 应用需要记录运行日志,并且希望日志能够每天午夜时刻自动切分回滚。如果使用 TimedRotatingFileHandler,那么由于 uWSGI 的多个 worker 可能同时也可能相差很小一段时间对日志文件进行回滚操作,这会导致先前回滚的存档日志被后来的 worker 的回滚操作覆盖,导致日志丢失。详细解释可以看看最后面附上的参考资料。
解决方案
针对这个午夜自动切分回滚日志存在的问题,有什么解决办法呢?我们采取的方案的思路不一样,重点来说有两点:
- 日志文件以日期结尾,当天的日志写入以当天日期结尾的文件
- 每到午夜,原子性地创建新的日志文件,新的日志文件以新日期结尾
如何原子性地创建文件呢?以 os.O_CREAT | os.O_EXCL 模式打开文件就可以了。如果日志文件已经存在,打开文件就失败。
可能有人会问,多个进程同时往一个日志文件里面写日志,不会导致日志混乱吗?只要每行日志大小不超过一定值,就不会错乱(这个还没有深入研究)。
最后附上自己写的 MidnightRotatingFileHandler.
from logging import FileHandler
import os
import errno
import datetime
class MidnightRotatingFileHandler(FileHandler):
def __init__(self, filename):
self._filename = filename
self._rotate_at = self._next_rotate_datetime()
super(MidnightRotatingFileHandler, self).__init__(filename, mode='a')
@staticmethod
def _next_rotate_datetime():
# rotate at midnight
now = datetime.datetime.now()
return now.replace(hour=0, minute=0, second=0) + datetime.timedelta(days=1)
def _open(self):
now = datetime.datetime.now()
log_today = "%s.%s" % (self._filename, now.strftime('%Y-%m-%d'))
try:
# create the log file atomically
fd = os.open(log_today, os.O_CREAT | os.O_EXCL)
# if coming here, the log file was created successfully
os.close(fd)
except OSError as e:
if e.errno != errno.EEXIST:
# should not happen
raise
self.baseFilename = log_today
return super(MidnightRotatingFileHandler, self)._open()
def emit(self, record):
now = datetime.datetime.now()
if now > self._rotate_at:
# time to rotate
self._rotate_at = self._next_rotate_datetime()
self.close()
super(MidnightRotatingFileHandler, self).emit(record)