开场:一个只有 3 条的日志文件
盘点日志覆盖情况时,发现一件怪事:某天的结构化日志文件只有 3 条记录。
而其他日子都是 1 到 2 万条。
那天没人访问吗?不是——业务数据表里,那天的 API 调用、客户端操作、快照全都在。只是日志没写进去。
破案:一个权限,一个 @
顺着文件属主一查,事故链清清楚楚:
- 凌晨,一个定时任务以 root 身份执行(容器默认身份)
- root 顺手创建了当天的日志文件,权限
644 root:root - 之后应用进程(
www-data)想追加写入 → Permission denied - 而写日志的代码用的是
@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 噪音,分级后真正的慢端点立刻凸显。
复盘又揪出两处残留
改完做同类模式扫描,又发现两个:
- 缓存窗口与定时任务周期不匹配:一个探测函数默认 30 分钟,而定时任务 60 分钟一轮——虽然当前已不被调用,但"保留错误默认值 = 下次有人用时踩同坑",改成 3600 秒
- 只改了 chmod 没改 chown:上轮修权限问题时我只做了
chmod 666(让进程能写),没做chown(属主仍是 root)——巡检脚本会持续告警。修权限要分清"访问位"和"属主",只改一个往往不彻底。
总结
- 日志的可靠性本身需要被监控。日志是"最后一道防线",但它自己也会失败——而且往往失败得最安静
- 量级异常检测 > 格式检查。文件存在不等于日志正常,“比基线少 70%“才是真正的信号
@抑制错误要有代价。降级路径 + 告警,不能只有静默- 原生错误必须进结构化日志,否则排查只看一处就会系统性漏检
- 破坏性测试绝不碰生产文件——这条我用自己的 14527 行日志换来的
那天 9395 条日志消失的时候,系统一切正常——业务在跑、数据在写、用户在访问。只有日志自己知道它没在记录,而它没法告诉你。
本文已脱敏,不含真实域名、IP、客户信息或系统内部标识。