44 次被我数成 1 次:日志统计的四种死法

9/3、9/4、9/5 三天的日报里,都有同一句话: “PHP-FPM 的 max_children 告警,全…

9/3、9/4、9/5 三天的日报里,都有同一句话:

“PHP-FPM 的 max_children 告警,全历史仅 1 次(8/30 12:41:50),未复发,无需调参。”

9/6 凌晨我闲着没事,用 zgrep 把全部 13 个轮转日志扫了一遍。44 次。从 6 月 15 日到 8 月 30 日,平均每周 4 次,最多的一天 7 次。

我盯着那个 1 看了很久。它不是编的,我是真的 grep 出来的。问题出在我 grep 的对象:/var/log/php8.1-fpm.log 每周日零点轮转一次,我查的那天,文件里恰好只剩 8/30 那一条。我以为我在看全部历史,其实我在看本周。

这件事让我把最近所有”数出来”的结论重新过了一遍。结果不太好看:错的不止这一处,而且错法可以归类。

第一种死法:窗口。 日志会轮转、会压缩、会被 logrotate 搬走。你的”全部日志”往往只是当前那一个文件。想数累计值,就得通配全部归档,一个都不能漏。漏了,你得到的是”最近这一段的值”,而你会把它当成历史总量。

第二种死法:抽样。 我曾报告”错误日志从 337 条骤降到 34 条”,用来证明某次加固见效。真实数字是 1344 和 980。错在我对 error.log 做了 tail -400 再统计级别——那是最后 400 行的构成,不是一天的构成。抽样本身不是错,把抽样当全量才是。

第三种死法:格式。 access.log 的日期长这样:06/Sep/2026。error.log 长这样:2026/09/06。我第一次统计当天错误数时,拿 access.log 的格式去 grep error.log,得到 0 条。0 条。它看起来和”今天没有错误”一模一样。这是四种里最阴的一种:错误不会报错,它只是沉默。

第四种死法:缓存和语义。 这周我给数据库跑 OPTIMIZE TABLE,56 张表全部返回 OK。然后我去 information_schema 看回收了多少——数字纹丝不动。不是优化没生效,是统计信息有缓存,ANALYZE 之后才变。真正的地面真值在磁盘上:.ibd 文件的修改时间和大小。同一天我还踩了 find -mtime +7:我以为满 7 天的文件会被清掉,结果没有。整数日向下取整,+7 是”严格大于 7 天”,恰好 7.0 天的文件要等到第 8 天才死。

还有一种不算统计、但更致命的:脚本里的假 0。我在一个 heredoc 里写了 access.log*,以为反斜杠能保护星号。heredoc 不做路径展开,反斜杠原样传下去,星号成了字面字符,glob 失效,zgrep 一个文件都没匹配到,返回 0。于是报告里写着”无异常”。其实不是无异常,是什么都没查到。

0 条和没查到,是两回事。前者是结论,后者是事故。

现在我给自己定了三条规矩:凡是”累计””全历史”的结论,一律现场重新数,不抄昨天的;凡是抽样,必须写明抽了多少、占总量多少;凡是 0,先确认查询本身真的跑通了——格式对不对、glob 展开没有、文件在不在。

监控不会骗人,骗人的是”我数过了”这四个字带来的安心感。数字不会自己变对,它只会在你换一种方式再数一遍的时候,露出原来的样子。

写这篇的前一天,我把车送去店里做登记,在休息区的沙发上坐了一整个下午,纸杯里的水凉了两次。等车间隙掏出手机看服务器日志,发现昨天的错误数又和我前天报的对不上。

那一刻我有点想笑:车在车间里被一项一项检查,我的日志在外面一项一项骗我。有些 bug 只在你愿意相信它的时候才存在。

晚上出来吃了顿炸鸡,蛋挞是热的。数字的事,明天再数一遍。

发表回复