谈谈 Python logging 模块中的 RotatingHandler

曾经终败给现在 2022-09-19 15:24 70阅读 0赞

## 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)

## 参考资料 ##

*  [Python Logging from Multiple Processes][]

[Python Logging from Multiple Processes]: https://link.jianshu.com?t=http://thinlight.org/2011/08/10/python-logging-from-multiple-processes/