python WatchedFileHandler 在旋转后仍然写入旧文件

Posted 2023-02-26

【中文标题】python WatchedFileHandler 在旋转后仍然写入旧文件

【英文标题】：python WatchedFileHandler still writing to old file after rotation

【发布时间】：2016-05-19 19:56:59

【问题描述】：

我一直使用WatchedFileHandler 作为我的 python 日志文件处理程序，这样我就可以使用logrotate（在 ubuntu 14.04 上）轮换我的日志，你知道这就是文档所说的。我的logrotate 配置文件看起来像

/path_to_logs/*.log 
        daily
        rotate 365
        size 10M
        compress
        delaycompress
        missingok
        notifempty
        su root root

一切似乎都运行良好。我正在使用 logstash 将我的日志发送到我的 elasticsearch 集群，一切都很好。我为我的调试日志添加了第二个日志文件，该日志文件被轮换但不被 logstash 监视。我注意到，当该文件被旋转时，python 只是继续写入 /path_to_debug_logs/*.log.1 并且永远不会开始写入新文件。如果我手动跟踪/path_to_debug_logs/*.log.1，它会立即切换并开始写入/path_to_debug_logs/*.log。

这对我来说真的很奇怪。

我相信正在发生的事情是，logstash 总是拖尾我的非调试日志，这在调用logrotate 之后触发了切换到新文件的一些方式。如果logrotate 在没有切换的情况下被调用两次，log.1 文件将被移动并压缩为 log.2.gz，python 无法再登录到该文件并且日志会丢失。

很明显，对此有很多骇人听闻的解决方案（例如不时跟踪我所有日志的 cronjob），但我觉得我一定是做错了什么。

出于多种原因，我使用 WatchedFileHandler 和 logrotate 而不是 RotatingFileHandler，但主要是因为它会在轮换后很好地为我压缩日志。

更新：

我尝试了在日志轮换配置脚本末尾添加手动尾部的可怕技巧。

sharedscripts
postrotate
    /usr/bin/tail -n 1 path_to_logs/*.log.1
endscript

果然这在大多数情况下都有效，但有时无缘无故随机失败，所以不是解决方案。我还尝试了一些不那么老套的解决方案，我修改了WatchFileHandler 检查文件是否已更改的方式，但没有运气。

我很确定我的问题的根源在于日志存储在网络驱动器上，这在某种程度上混淆了文件系统。

我正在使用 RotatingFileHandler 将我的轮换转移到 python，但如果有人知道处理此问题的正确方法，我很想知道。

【参考方案1】：

使用copytruncate logrotate 选项。来自docs

复制截断

在创建副本后将原始日志文件截断到位，而不是移动旧日志文件并选择性地创建新日志文件，当某些程序无法被告知关闭其日志文件并因此可能继续写入时可以使用它（附加）到以前的日志文件永远。请注意，复制文件和截断文件之间的时间片非常短，因此可能会丢失一些日志记录数据。使用此选项时，create 选项将不起作用，因为旧日志文件保留在原处。

【讨论】：

我之前尝试过copytruncate，结果很糟糕。虽然它确实会导致新文件的创建，但它会导致一个非常奇怪的 python 错误，其中旧的日志文件是完整的空白空间，在 logstash 中显示为“\u0000\u0000\u0000...”，然后新的日志消息是附加到最后。这也有一个有趣的属性，即您的新日志文件以与旧日志文件完全相同的大小开始，只是什么都没有。

奇怪，我使用过许多 python 实用程序的 copytruncate，如 python 脚本、supervisord、django 等，但从未遇到过这样的问题。当文件被截断时，它的大小对我来说设置为 0。

你在运行什么操作系统，可能是 ubuntu 特有的问题？

我已经在 Ubuntu 服务器 12.04 和 14.04 上使用过它。

很奇怪。目前我的日志存储在网络驱动器上并安装在 samba 上，所以也许这就是区别。我在 AWS 上使用 EBS 卷上的日志进行复制截断时也遇到了问题。

【参考方案2】：

WatchedFileHandler 在写入之前在日志文件中检测到设备和/或 inode 更改时执行翻转。可能logstash 没有观看的文件在其设备/inode 中没有看到变化？这可以解释为什么处理程序不断写信给它。