Python 多进程日志输出到同一个文件并实现日志回滚

Python 多进程想要实现将日志输出到同一个文件中，使用同一个日志句柄，且日志需要按照日期，大小回滚。

出现问题

使用 Python 自带的有回滚功能的日志库 TimedRotatingFileHandler 日志并没有正常打印：在日志回滚时多个进程抢占句柄，最终只有一个进程能够正常打印日志；在多进程中回滚时会互相将日志文件删除，并且多进程同时启动时有小概率将多进程卡死。

注：使用该库的日志滚动只会发生在有新日志输出时，会出现像这样的情况：

假设日志按天回滚，第一天日志正常输出，第二天和第三天没有日志输出，第四天有日志输出，那么在第四天只会回滚第一天的日志，而不会生成第二天和第三天的日志文件。

TimedRotatingFileHandler 回滚 doRollover() 源码（省略初始化和其他函数部分）：

class TimedRotatingFileHandler(BaseRotatingHandler):
    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.
        """
        # 关闭向日志中打印的被回滚掉的流，将其流置为空
        if self.stream:
            self.stream.close()
            self.stream = None
        
        # 获得队列的起始时间，将值赋给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.rotation_filename(self.baseFilename + "." +
                                     time.strftime(self.suffix, timeTuple))
                                     
        # TODO 在该处多进程会互相删除各自的日志文件
        if os.path.exists(dfn):
            os.remove(dfn)
        self.rotate(self.baseFilename, dfn)
        
        # 回滚计数器大于0
        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 (self.when == 'MIDNIGHT' or self.when.startswith('W')) and not self.utc:
           # ~~~ 省略 ~~~~

问题原因

问题出在上述代码的 36 ~ 38 行 ，此处并没有加锁，并不是进程安全的。

在日志需要回滚时，多进程的每个进程都调用了 doRollover() 方法，导致多进程抢占日志句柄，最终在日志回滚后只有一个进程能够正常将日志打印到日志文件中。

问题解决

对日志文件的文件描述符加独占锁（fcntl.LOCK_EX），防止多个进程同时同时获取到日志文件描述符。

具体修改代码如下： 该类中的 doRollover() 方法中文件覆盖的部分（上述代码 36 ~ 38 行）重写

class MultiCompatibleTimedRotatingFileHandler(TimedRotatingFileHandler):
    def __init__(self, log_path, interval, when, backupCount, encoding):
        super().__init__(filename=log_path, interval=interval, when=when, backupCount=backupCount, encoding=encoding)

    def doRollover(self):
        # ~~~ 省略，与上面代码保持一致 ~~~
        
        # if os.path.exists(dfn):
        #     os.remove(dfn)
        # self.rotate(self.baseFilename, dfn)
        
        # 多进程检测到旧句柄存在则不覆盖，继续向文件续写，避免多进程日志互相覆盖
        if not os.path.exists(dfn) and os.path.exists(self.baseFilename):
            f = open(self.baseFilename, 'a')
            fcntl.lockf(f.fileno(), fcntl.LOCK_EX)
            if not os.path.exists(dfn) and os.path.exists(self.baseFilename):
                os.rename(self.baseFilename, dfn)
            f.close()  # 释放锁 释放老 log 句柄
            
        # ~~~ 省略，与上面代码保持一致 ~~~

作者：ZHOOU
链接：https://juejin.cn/post/7369559976552398858