Python日志按时间自动切分——基于logging

1、TimedRotatingFileHandler

1. 简介

TimedRotatingFileHandler是logging内置的可设置固定时间间隔的日志记录类，直接调用进行实例化和配置就可以实现日志的按时间自动切分

关键参数

	描述
filename	输出日志的文件名/路径
when	日志切分的间隔时间单位;可选参数如下： “S”：Second 秒 “M”：Minutes 分钟 “H”：Hour 小时 “D”：Days 天 “W”：Week day（0 = Monday） “midnight”：Roll over at midnight
interval	间隔时间单位的个数，指等待多少个 when 的时间后进行分割
backupCount	保留日志的文件个数

2. 实现

import logging
import time
from logging.handlers import TimedRotatingFileHandler

new_formatter = '[%(levelname)s]%(asctime)s:%(msecs)s.%(process)d,%(thread)d#>[%(funcName)s]:%(lineno)s  %(message)s'
"""
%(asctime)s 字符串形式的当前时间。默认格式是“2021-09-08 16:49:45,896”。逗号后面的是毫秒
%(created)f 时间戳, 等同于time.time()
%(relativeCreated)d 日志发生的时间相对于logging模块加载时间的相对毫秒数
%(msecs)d 日志时间发生的毫秒部分
%(levelname)s 日志级别str格式
%(levelno)s 日志级别数字形式(10, 20, 30, 40, 50)
%(name)s 日志器名称, 默认root
%(message)s 日志内容
%(pathname)s 日志全路径
%(filename)s 文件名含后缀
%(module)s 文件名不含后缀
%(lineno)d 调用日志记录函数源代码的行号
%(funcName)s 调用日志记录函数的函数名
%(process)d 进程id
%(processName)s 进程名称
%(thread)d 线程ID
%(threadName)s 线程名称
"""
fmt = logging.Formatter(new_formatter)


log_handel = TimedRotatingFileHandler('my.log', when='M')
log_handel.setFormatter(fmt)

log_info = logging.getLogger('info')
log_info.setLevel(logging.INFO)
log_info.addHandler(log_handel)


if __name__ == '__main__':
    while 1:
        log_info.error('test error')
        time.sleep(1)
        log_info.info('test info')

通过TimedRotatingFileHandler可以实现日志的按时间自动切分，但是它切分后的文件日志文件的后缀是日期结尾，如下：

TimedRotatingFileHandler对日志的切分是在满足设定的时间间隔后，执行doRollover方法，将my.log重命名为带有当前时间后缀(my.log.****)的文件，并新建一个my.log，继续记录后续日志。

这种方式切分出来的日志文件不是很符合我的日常习惯，所以强迫症患者的我重写了doRollover方法。

2、自定义类

1. 实现

主要是重写TimedRotatingFileHandler的doRollover方法的文件翻转块代码

做了以下两点改动：

• 重定义了新文件名，将日期放在了中间而不是最后
• 直接将将baseFilename 指向新文件

完整代码：

#!/usr/bin/env python
# -*- encoding: utf-8 -*-
import datetime
import logging
import time
from logging.handlers import TimedRotatingFileHandler

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

    def doRollover(self):
        """
        """
        if self.stream:
            self.stream.close()
            self.stream = None
        currentTime = int(time.time())
        dstNow = time.localtime(currentTime)[-1]
        dfn = f"my.{datetime.datetime.now().strftime('%Y%m%d_%H:%M')}.log"
        self.baseFilename = dfn
        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:
            dstAtRollover = time.localtime(newRolloverAt)[-1]
            if dstNow != dstAtRollover:
                if not dstNow:
                    addend = -3600
                else:
                    addend = 3600
                newRolloverAt += addend
        self.rolloverAt = newRolloverAt


new_formatter = '[%(levelname)s]%(asctime)s:%(msecs)s.%(process)d,%(thread)d#>[%(funcName)s]:%(lineno)s  %(message)s'
fmt = logging.Formatter(new_formatter)

log_handel = TimeLoggerRolloverHandler(f"my.{datetime.datetime.now().strftime('%Y%m%d_%H:%M')}.log", when='M')
log_handel.setFormatter(fmt)

log_info = logging.getLogger('info')
log_info.setLevel(logging.INFO)
log_info.addHandler(log_handel)

if __name__ == '__main__':
    while 1:
        log_info.error('test error')
        time.sleep(1)
        log_info.info('test info')

效果：

2. 再优化

所有类型的日志信息全在一个文件，增加了排查问题的工作量，将每一种类型的日志信息都对应输出到指定的文件中，这样大大的方便了问题排查。

实现思路：

• 为每一种日志类型都定义一个handel
• 添加一个filter，实现这输出对应类型日志到对应文件

完整代码：

#!/usr/bin/env python
# -*- encoding: utf-8 -*-
import datetime
import logging
import time
from logging.handlers import TimedRotatingFileHandler

class LogFilter:
    @staticmethod
    def info_filter(record):
        if record.levelname == 'INFO':
            return True
        return False

    @staticmethod
    def error_filter(record):
        if record.levelname == 'ERROR':
            return True
        return False


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

    def doRollover(self):
        """
        """
        if self.stream:
            self.stream.close()
            self.stream = None
        currentTime = int(time.time())
        dstNow = time.localtime(currentTime)[-1]
        log_type = 'info' if self.level == 20 else 'error'
        dfn = f"my.{datetime.datetime.now().strftime('%Y%m%d')}.{log_type}.log"
        self.baseFilename = dfn
        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:
            dstAtRollover = time.localtime(newRolloverAt)[-1]
            if dstNow != dstAtRollover:
                if not dstNow:
                    addend = -3600
                else:
                    addend = 3600
                newRolloverAt += addend
        self.rolloverAt = newRolloverAt


new_formatter = '[%(levelname)s]%(asctime)s:%(msecs)s.%(process)d,%(thread)d#>[%(funcName)s]:%(lineno)s  %(message)s'
fmt = logging.Formatter(new_formatter)
log_error_file = 'my.{}.error.log'.format(datetime.datetime.now().strftime('%Y%m%d'))
log_info_file = 'my.{}.info.log'.format(datetime.datetime.now().strftime('%Y%m%d'))

error_handler = TimeLoggerRolloverHandler(log_error_file, when='midnight')
error_handler.addFilter(LogFilter.error_filter)
error_handler.setFormatter(fmt)
error_handler.setLevel(logging.ERROR)

info_handel = TimeLoggerRolloverHandler(log_info_file, when='midnight')
info_handel.setFormatter(fmt)
info_handel.addFilter(LogFilter.info_filter)
info_handel.setLevel(logging.INFO)


log_info = logging.getLogger('info')
log_info.setLevel(logging.INFO)

log_info.addHandler(info_handel)
log_info.addHandler(error_handler)

if __name__ == '__main__':
    while 1:
        log_info.error('test error')
        time.sleep(1)
        log_info.info('test info')

3、总结

通过TimedRotatingFileHandler类实现日志切分，最好的时间间隔是天，使用when='midnight'在每天凌晨切分，因为其他的秒、分、小时、天、周都是根据程序启动的时间计算的，比如按分钟划分，程序在17:25:33启动，那切分时间点是17:26:33，而不是17:26:00