logging.handler.TimedRotatingFileHandler 从不旋转日志答案

【问题标题】：logging.handler.TimedRotatingFileHandler never rotates the loglogging.handler.TimedRotatingFileHandler 从不旋转日志
【发布时间】：2015-08-14 15:45:44
【问题描述】：

有一个脚本可以在 linux 服务器（CentOS 6）上同步时间并在日志中写入偏移量。我想在 10 天后将当前日志（ntp.log）复制到旧日志（ntp.log-date），但这不起作用。该脚本继续写入一个文件而不是旋转。它由 cron 每 5 分钟运行一次。我使用python 2.6版。我专门设置了以秒为单位的间隔来检查。我究竟做错了什么？

#!/usr/bin/env python
import ntplib
import logging
from logging.handlers import TimedRotatingFileHandler
from time import ctime
import os
import socket

hostname = socket.gethostname()
logHandler = TimedRotatingFileHandler('/root/ntp/log/ntp.log', when='S', interval=300)
logFormatter = logging.Formatter('%(asctime)s %(message)s', datefmt='%d/%m/%Y %H:%M:%S')
logHandler.setFormatter(logFormatter)
logger = logging.getLogger('MyLogger')
logger.addHandler(logHandler)
logger.setLevel(logging.INFO)


c = ntplib.NTPClient()
response = c.request('1.rhel.pool.ntp.org')
logger.info('| %s time offset is | %s' % (hostname, response.offset))
datestr = ctime(response.tx_time)
os.system('date -s "%s"' % datestr)

【问题讨论】：

我强烈建议使用ntpd 和logrotate 而不是重新发明轮子。 ntpd 的逻辑比周期性的一次性“同步”要合理得多。
关于logrotate必须看，我不能用ntpd，我需要同步'日志
ntpd 比“同步”更智能，它使用“内核时间规则”API，旨在真正让你一劳永逸地忘记同步的事情 i> (eecis.udel.edu/~mills/ntp/html/discipline.html#house : "如果保持连续运行，家庭或办公室环境中快速 LAN 上的 NTP 客户端名义上可以在一毫秒内保持同步。") 别担心，只要它对系统时钟。
我需要自定义日志记录，因为它在 Web 应用程序中使用
顺便说一句，如果您仍然不相信，这是您算法中的缺陷：response.tx_time (Transmit timestamp) 是接收到的数据包离开服务器的时间。从它离开到date 调用stime() 之间的时间框架下落不明。

标签： python logging log-rotation

【解决方案1】：

撇开您的算法完全不正确的事实，我将回答有关日志记录问题的问题。

这里是相关的logging.handlers.TimedRotatingFileHandler逻辑：

def __init__(<...>):
    <...>
    if self.when == 'S':
        self.interval = 1 # one second
    <...>
    self.interval = self.interval * interval # multiply by units requested
    <...>
    if os.path.exists(filename):
        t = os.stat(filename)[ST_MTIME]
    else:
        t = int(time.time())
    self.rolloverAt = self.computeRollover(t)

def computeRollover(self, currentTime):
    result = currentTime + self.interval
    <special logic that doesn't apply in your case>
    return result

因此，'S' 模式下的翻转时间是根据脚本初始化时文件的 mtime 计算得出的。 mtime 每次写入文件时都会被修改。

因此，只有当您在脚本启动后interval 秒后登录时才会完成翻转。从来没有这种情况，因为它的运行时间要少得多。

可能的修复：

让脚本运行那么久，例如正如你所建议的那样有一个无限循环。如果它要无限期运行，它可能应该成为一个守护进程
改变侧翻力矩计算算法
- 库存逻辑无法做到这一点（TimedRotatingFileHandler.computeRollover() 中的“特殊逻辑”仅适用于'MIDNIGHT' 和'Wn' 情况），因此您需要替换处理程序的computeRollover()
- 基本上，您需要将翻转时间设置为当前文件的mtime之后的下一个“参考时刻”。

【讨论】：

请告诉我我需要对算法进行哪些更改才能按我需要的方式工作？
也许我不能通过 cron 运行它并进行无限循环。或者我只是必须增加间隔？
无限循环将起作用。我现在看看其他处理程序参数是否也会。

【解决方案2】：

这可能会对您有所帮助（如果日志是在第 10 天的倍数中创建的并且日志最后一次修改是前一天的，则滚动日志）

 #!/usr/bin/env python
import ntplib
import logging
from logging.handlers import TimedRotatingFileHandler
from time import ctime
import os
import socket

hostname = socket.gethostname()
logHandler = TimedRotatingFileHandler('/root/ntp/log/ntp.log', when='D', interval=10)
logFormatter = logging.Formatter('%(asctime)s %(message)s', datefmt='%d/%m/%Y %H:%M:%S')
logHandler.setFormatter(logFormatter)
#Get File creation Time
log_ctime = datetime.fromtimestamp(os.path.getctime("/root/ntp/log/ntp.log")).date()
log_mtime = datetime.fromtimestamp(os.path.getmtime("/root/ntp/log/ntp.log")).date()
delta_c = datetime.now().date() - log_ctime 
delta_m = datetime.now().date() - log_mtime 
if delta_c.days %10 == 0 and delta_m.days>=1:
   logHandler.doRollover()
logger = logging.getLogger('MyLogger')
logger.addHandler(logHandler)
logger.setLevel(logging.INFO)


c = ntplib.NTPClient()
response = c.request('1.rhel.pool.ntp.org')
logger.info('| %s time offset is | %s' % (hostname, response.offset))
datestr = ctime(response.tx_time)
os.system('date -s "%s"' % datestr)

【讨论】：