十月二十几号那事。给本地一家母婴连锁做的会员储值小程序,八千五,工期二十天,早验收了,尾款还压着两千没结。
那天晚上十一点多,甲方老板直接微信语音过来,说后台今天账不对,卖了四单储值,系统里出来八条记录,会员余额翻倍了。我当时正躺着刷手机,脑子嗡一下。余额翻倍是什么概念,人家充五百我给人记一千,这钱谁出,我出?
爬起来开电脑,远程连上去看日志。一条红字横在那:
Error: ER_DUP_ENTRY: Duplicate entry 'CK20261023-0042' for key 'order_no'
说白了就是同一个单号往库里插了两遍,被我那个唯一索引给拦下来了。可笑的是它拦是拦了,前面余额那条 update 已经跑完提交了,索引炸在后面。事务边界我没包好,这事现在想起来还脸红。
先怀疑是微信支付回调重试。这个太常见了,回调没及时返回 success,微信隔一会儿再推一遍。我翻了回调日志,四笔单子每笔回调都只进来一次,正常。那就不是回调的事。我当时还跟甲方回了句"找到了,小问题",其实一点头绪没有,先稳住他。跑题了说回来。
本地起环境跑,怎么跑怎么正常。手工造单一笔一笔塞,余额对得上。折腾到快一点,我开始怀疑是并发,虽然这破系统一天也就几十单,并发个鬼。但还是加了分布式锁的代码。加完发现没用,因为我压根没复现出来。
真正的转折是我去翻自己写的那个定时任务。当时为了处理"用户付款了但订单没生成"的补单场景,写了个每天夜里十一点半跑的脚本,扫当天没闭环的单子重新处理一遍。
问题就在这。服务器是 UTC 时区,我代码里取"当天"用的是 new Date() 直接当天算,晚上八点一过,UTC 就跨天了。也就是说晚上八点以后的单子,脚本扫的时候认为是"昨天"的、没闭环,全给捞出来重跑一遍。那天四笔单子正好都是晚上八点后充的。
等于说同一批单子被处理了两次,重复处理了一遍。
改起来其实就三行代码,取当天改成按北京时间切。真正花时间的是前面那两个多小时,我在并发和回调重试那条错路上越走越远。改完跑了一遍回归,把当天那四笔重复的余额手工扣回去,两笔已经消费掉了,还得跟甲方解释让人家会员补钱。甲方那边倒是配合,毕竟是他自己的客户。
三点半关电脑。躺下的时候天还黑着,脑子里全是那个 ER_DUP_ENTRY,闭眼就在转。
第二天九点照样起来,另一个单子要改样式。这单八千的活,多熬了半宿,钱没多一分。甲方后来就回了句"哦,修好了就行",尾款那两千我催了两次,还在拖。
这账不难算:为了一个自己写出来的低级 bug 熬四个小时,第二天还得照常干活。说白了,接单这行最贵的不是技术,是你半夜被叫起来的那口气。
那个定时任务我后来改成用服务器时间直接加八小时偏移,简单粗暴。现在每次写涉及时间的代码,我都先看一眼服务器时区。