logging.handlers.TimedRotatingFileHandler 的错误？

Question

以下代码使用 logging.handlers.TimedRotatingFileHandler 产生了一些意外行为：

logger1 = logging.getLogger("One")
logger2 = logging.getLogger("Two")

handler1 = TimedRotatingFileHandler(
    "service.log",
    when="M",
    backupCount=2,
    utc=True
)
handler2 = TimedRotatingFileHandler(
    "service.log",
    when="M",
    backupCount=2,
    utc=True
)

formatter = logging.Formatter("%(asctime)s - %(name)s - %(message)s")

handler1.setFormatter(formatter)
handler2.setFormatter(formatter)

logger1.addHandler(handler1)
logger2.addHandler(handler2)

while True:
    sleep(0.5)
    logger1.error("ONE")
    logger2.error("TWO")

我将其运行放置了几分钟，在第一个运行结束时一切正常。我知道有一些不一致的行为，文件不会在人们期望的那一刻翻转，但我同意这个：

-rw-rw-r-- 1 dave dave 3.8K Sep 24 16:11 service.log
-rw-rw-r-- 1 dave dave 3.8K Sep 24 16:11 service.log.2019-09-24_09-09
-rw-rw-r-- 1 dave dave 4.3K Sep 24 16:10 service.log.2019-09-24_09-08

但是，如果我在同一目录 中再次启动脚本之前等待几分钟而不删除现有的 service.log* 文件，现在 logger1 开始按预期写入 service.log.2019-09-24_09-11 和 logger2 写入 service.log。注意service.log.2019-09-24_09-11.

旁边的16:17的最后修改时间

-rw-rw-r-- 1 dave dave  540 Sep 24 16:17 service.log
-rw-rw-r-- 1 dave dave  540 Sep 24 16:17 service.log.2019-09-24_09-11
-rw-rw-r-- 1 dave dave 3.8K Sep 24 16:11 service.log.2019-09-24_09-09

这对我来说似乎是一个错误，因为 logger1 从几分钟前开始通过对 logger.error 的不同调用继续写入文件 - 它不仅仅是脚本重新启动时的第一个条目。

dave:~$ cat service.log.2019-09-24_09-11

2019-09-24 16:16:55,390 - One - ONE
2019-09-24 16:16:55,892 - One - ONE
2019-09-24 16:16:56,393 - One - ONE
2019-09-24 16:16:56,894 - One - ONE
2019-09-24 16:16:57,395 - One - ONE
2019-09-24 16:16:57,896 - One - ONE
2019-09-24 16:16:58,397 - One - ONE
2019-09-24 16:16:58,898 - One - ONE
...

我正在使用 Python 3.7.4.

编辑：只要几分钟内没有写入日志，就可以在不停止和启动脚本的情况下重现警报行为。

如果我们替换

，则在 sleep(180) 时间内观察日志文件的状态（每个文件的大小已清除为 36 字节！）

while True:
    sleep(0.5)
    logger1.error("ONE")
    logger2.error("TWO")

...与...

for _ in range(60):
    sleep(1)
    logger1.error("ONE")
    logger2.error("TWO")

sleep(180)  # blocking, no logs written but log files are in eroded state

for _ in range(60):
    sleep(1)
    logger1.error("ONE")
    logger2.error("TWO")

Answer 1

基本上，错误的根源是存在多个 TimedRotatingFileHandlers 实例。我猜翻车不能很好地处理这种不寻常的情况。似乎在几乎所有情况下都可以避免这种情况，因为我们可以在两个处理程序上设置相同的格式化程序对象，并将相同的处理程序实例添加到多个记录器对象。

logging.handlers.TimedRotatingFileHandler 的错误？

Bug with with logging.handlers.TimedRotatingFileHandler?

python

logging

filehandler

python-3.x

python-logging