上礼拜三开始,一个破报错卡了我三天。要我说,写了这么多年代码,栽在这种事上,说出来都嫌丢人。不说又不痛快。
事情是这样的。我们那个对账跑批,每天凌晨两点十五自动跑,跑了四年,稳的跟老狗一样。礼拜三早上九点多,运营小刘在群里 @ 我,说结算明细的导出没出来,报表是空的。我上去翻日志,一眼就看到那个报错:SQLSTATE[HY000] [2002] Connection timed out。数据库连不上。
第一反应,数据库那边的事。找老陈,老陈是 DBA,五十多了,脾气比我还大。他查了一圈说好好的,连接数正常,慢查询一条没有。我说你再看看,他说我看个屁。
那就往下查。是不是跑批那台机器网络抽风?ping 通,telnet 通,我单独手跑一遍脚本,能过。邪门就邪门在,单独跑都没事,一到凌晨两点十五那个点就挂。
我开始怀疑并发。那个点不只跑批,还有一堆定时任务挤在一起,是不是连接池被打爆了。我给它加了重试,加了退避,第二天照挂。
中间还有个小插曲,我一度怀疑是前阵子 PHP 版本升了,PDO 行为有变化,还专门去翻了 changelog——算了,这段说了你们也没赶上,反正没用。
转机在第三天下午。我一直咬着网络不放,老陈不知道哪根筋搭上了,跑去看那台机器的磁盘。df -h 一敲,/dev/vdb1 百分之百。
我第一反应是日志轮转挂了,日志堆满了。结果 du -sh /var/log 一排下来,是我自己目录底下,一个 debug.log,四十三个 G。
真相是:上礼拜一我排查另一个问题,在循环里加了一行 file_put_contents,把每一行数据 print_r 进去。当时想的是回头就删。然后就没删。那个跑批一天处理几十万行,三天,四十三个 G,磁盘写满,MySQL 连临时表都建不出来,报出来的是个连接超时。
一个数据库连接超时的错,根子在我自己 print_r 出来的一个文件上。
事后我还把当时的排查过程截图,问了那个什么 Claud,我一直少打一个 e,改不过来。它列了十条建议,第八条是"检查服务器磁盘空间"。我当时直接划过去了。工具是好工具,就是得你问对方向,方向不对,问谁都白搭。这种事主要还是靠自己回头看。
删掉,重跑,两分钟过。整三天,就为了一行自己忘了删的调试语句。
PHP 一点毛病没有,跑了四年,谁再说 PHP 扛不住跑批,让他来看看我们的对账系统——前提是磁盘别满。
对了,我们那个日志平台叫 Graylog,同事都打成 Greylog,我跟着打了好几年,将错就错。