9395 条日志,没有一声报警

一个日志文件,整天只写了 3 条。不是没人访问,是日志系统自己静默失败了——而且它失败的方式,正是我们最该监控的那种。

开场:一个只有 3 条的日志文件

盘点日志覆盖情况时,发现一件怪事:某天的结构化日志文件只有 3 条记录

而其他日子都是 1 到 2 万条。

那天没人访问吗?不是——业务数据表里,那天的 API 调用、客户端操作、快照全都在。只是日志没写进去。

破案:一个权限,一个 @

顺着文件属主一查,事故链清清楚楚:

  1. 凌晨,一个定时任务以 root 身份执行(容器默认身份)
  2. root 顺手创建了当天的日志文件,权限 644 root:root
  3. 之后应用进程(www-data)想追加写入 → Permission denied
  4. 而写日志的代码用的是 @file_put_contents——那个 @ 把错误静静吞掉了

于是:全天 9395 个请求的日志,一条都没落盘,没有任何报警。

这个失败方式的讽刺之处在于:@ 是为了"日志写不进去也不该影响业务"——这个取舍本身没错。但结果是,日志系统悄悄死了,而唯一能告诉我们它死了的,也是日志

第二个盲区:原生错误从不进日志

继续盘点,发现了更隐蔽的一层。

在结构化日志里搜三类近期修过的代码异常(一个计数器回归、一个页面变量缺失、一个方法可见性导致的 500)——命中 0 条

但在容器的原生日志里,同样的错误有 4149 + 257 条。

也就是说:PHP 的原生错误(Warning/Fatal)从来不进结构化日志。 如果排查时只看结构化日志(最自然的选择),就会完全漏掉代码级缺陷——而那正是我们当天修的三类 bug。

这意味着:同类缺陷下次还会漏检。

我自己的失误

治理过程中,我犯了个更不该犯的错。

为了复现"文件属主是 root"这个场景,验证脚本里写了 file_put_contents($file, '')——直接清空了当天的生产日志文件

14527 行,归零。

影响评估:业务数据完好(数据库表都在)、结构化日志是纯诊断文件无代码消费者、容器原生日志还留有 access 记录可追溯。但当天大半天(00:00-19:45)的请求级诊断日志,被我抹掉了

教训很直白:

破坏性测试必须在临时文件上做。 造权限场景应该 touch 一个 __test_*.log,而不是碰当天的真实日志。

治理:让日志的失败可见

三处修复 + 三项治理:

① 写入失败降级 + 告警 主文件不可写 → 自动降级到 .fallback.log(目录属主正确,必定可创建)+ 同时 error_log 告警。模拟 root:root 场景实测:主文件空,fallback 正确落盘并告警。

② 原生错误接入结构化日志 注册三个钩子:set_error_handler(Warning/Notice → WARN)、set_exception_handler(未捕获异常 → ERROR + 前 8 层栈)、register_shutdown_function(致命错误 → ERROR)。六个 HTTP 入口全部注册。

③ 日志健康巡检 + 定时任务 五项检查:文件属主/权限、降级日志存在性、当日日志量 vs 近 7 天均值(偏差 >70% 告警)、WARN/ERROR 统计、保留体积。

第三项是核心——因为这次事故的特征正是"文件存在,但内容几乎为空"。只有对比基线,才能发现这种静默丢失。

巡检脚本首跑就检出了异常(41KB vs 期望 2887KB)——正是我自己清空日志造成的影响。机制验证有效,虽然验证方式有点丢人。

④ 容器日志轮转 改 compose 文件给应用容器加 max-size: 50m / max-file: 3,而不是改全局 daemon 配置——不用 sudo、不影响其他容器、随时可回滚。

⑤ 慢请求阈值分级 AI 推理端点固有耗时 5-80 秒,用 30 秒阈值;其余端点保持 1 秒。97 条慢请求里 87 条是 AI 噪音,分级后真正的慢端点立刻凸显。

复盘又揪出两处残留

改完做同类模式扫描,又发现两个:

  1. 缓存窗口与定时任务周期不匹配:一个探测函数默认 30 分钟,而定时任务 60 分钟一轮——虽然当前已不被调用,但"保留错误默认值 = 下次有人用时踩同坑",改成 3600 秒
  2. 只改了 chmod 没改 chown:上轮修权限问题时我只做了 chmod 666(让进程能写),没做 chown(属主仍是 root)——巡检脚本会持续告警。修权限要分清"访问位"和"属主",只改一个往往不彻底。

总结

  1. 日志的可靠性本身需要被监控。日志是"最后一道防线",但它自己也会失败——而且往往失败得最安静
  2. 量级异常检测 > 格式检查。文件存在不等于日志正常,“比基线少 70%“才是真正的信号
  3. @ 抑制错误要有代价。降级路径 + 告警,不能只有静默
  4. 原生错误必须进结构化日志,否则排查只看一处就会系统性漏检
  5. 破坏性测试绝不碰生产文件——这条我用自己的 14527 行日志换来的

那天 9395 条日志消失的时候,系统一切正常——业务在跑、数据在写、用户在访问。只有日志自己知道它没在记录,而它没法告诉你。


本文已脱敏,不含真实域名、IP、客户信息或系统内部标识。

使用 Hugo 构建
主题 StackJimmy 设计