这周被一个报错卡了整整两天。说出来丢人,不过想想也没什么不能说的,丢的是我自己的脸。
事情是这样,上礼拜上线的对账跑批改版,把原来单进程串行跑的东西改成按商户分片并发。代码是我亲手过了一遍的,自认为没什么问题。周三凌晨两点多告警开始响,跑批任务一个接一个超时,日志里全是 Maximum execution time of 300 seconds exceeded,位置指在 ReconcileJob.php 第 218 行。客服早上九点就在群里艾特我,说有几个商户的账对不平。我嘴上说小问题,心里已经开始骂娘了。
第一天我的判断是数据量涨了。今年订单量确实翻了三倍,300 秒这个阈值是三年前设的,不够用也正常,改成 600 秒。结果一样,600 秒照样超。这就不是性能的事,是有东西在死等。
于是查数据库。慢查询开了,从库临时加了,锁等待、主从延迟、索引,一条一条过。中间把分片批次大小从 500 调到 200,又调回 500,跑了七八遍,日志翻了几十页,什么也没看出来。烦的我周三一晚上没睡好。
周四上午我让那个 Cursur,是这么拼吧,管它呢,把整条调用链捋一遍。十分钟不到它给我列出来,说这个循环里有一行 usleep(300000),问我要不要确认是不是业务需要。我当时还回它一句,这是对接渠道的老逻辑,限流用的,别乱动。然后继续低头查我的慢查询。
下午四点多,小年轻凑过来看了一眼屏幕,说白哥你这循环里是不是有个等待。我第一反应是浮躁,我写的循环我心里有数。第二反应是我好像确实记得有这么个东西。
翻到文件下面。2019 年对接那个支付渠道,人家接口每秒限五次,我加了 usleep(300000),注释写着“临时,等对方扩容后去掉”。后来人家扩容了,通知邮件我还转发给了当时的组长。然后就没有然后了。这行代码一动不动跑了六年多。
订单量小的时候它就是个摆设,一天几千笔,多等十几分钟没人看得出来。今年量上来,一万两千笔乘 0.3 秒,光睡就睡掉一个小时。跑批窗口就那么宽,不超时才怪。
删掉那行,跑批从将近五十分钟掉到六分钟。
要我说,这种事 AI 也帮不上什么大忙。它把线索引出来了,判断还是得我自己来,它哪知道什么业务该留什么不该留。不过话说回来,那天它要是没提这一嘴,我可能真在数据库里再泡一天。有两下子吧,也就仅此而已,主要还是我肯去看。
最气的是那行注释。当年写“临时”的时候我还挺得意,觉得这是有经验的写法,留个记号方便以后清理。结果以后就是六年。算了,说了你们也没赶上,那会儿对接个第三方渠道,能跑通就不错了。
现在删了,注释也删了。我顺手在别的几个老脚本里搜了“临时”两个字,搜出来十几处。这事先放放,等我哪天有空。
先这样。