生产环境一个评测服务。一个用户连着点了三次评测:第一次跑到一半提示「服务重启了」,第二次用例全跑完、汇总时提示「任务被取消」,第三次直接被拒,提示「已取消的流程不允许评测」,从此点不动。容器当天确实重启了 3 次,第一反应就是机器出了问题。我只有日志查询权限,没有集群权限,看不到 Pod 事件。我的判断是:存活探针超时只能证明进程答不上话,不能证明进程死了,这两件事得用不同的证据去分,混起来就会把根因推给基础设施。
循环被占住的时候,连接还在队列里排着
服务是单进程单事件循环。打分那段代码的函数签名是 async,往下三层调到模型 SDK 的同步方法:
# 打分工具里,没有 await,也没有丢进线程bundle = estimate_report(...) # 一次 20 到 45 秒# 它最终走到client.chat.completions.create(...) # 同步客户端,超时上限 300 秒一个评测连着给 3、4 个用例打分,事件循环被连续占住 60 到 190 秒。
这期间进程没有任何异常。它在调模型,日志一直在写。被堵住的是循环:新连接由内核完成握手、排在等待 accept 的队列里,循环腾不出手去取。存活探针 30 秒打一次、10 秒超时,10 秒内没人应答就记一次失败,连续 6 次才算死。从阻塞开始到第 6 次失败落定大约 160 秒,加上首次探测的落点和关停宽限期,实际落在 160 到 190 秒之间。
60 秒那一档的阻塞越不过这条线,什么都不会发生。同样的代码路径每天都在走,只有用例多、模型慢的那几次才会炸,所以它看起来像偶发。9 月 1 日这个版本上线后一共重启 8 次,全在跑评测期间。
从应用自己的日志看,健康检查是有回应的。打分结束那一瞬间,积压的 9 个健康检查在几毫秒内全部返回 200。而 kubelet 早在 10 秒的超时上就放弃了那些连接,它拿到的是超时。同一批请求的两端,日志给出相反的结论——只照着应用日志查,这条线索会把人带反。
同步客户端和异步客户端的方法名一样,调用那一行长得完全一致,差别只在 client 是哪个类。审 diff 的时候看不出来。
「日志里没有 OOM」证明不了不是 OOM
我最早给技术负责人的理由是「日志里没有 OOM 记录,所以不是内存问题」。这条当场被否掉了,否得对:内存超限是内核直接发 SIGKILL,进程来不及写任何东西。查不到 OOM 日志和内存没爆是两件事,前者的信息量是零。否定性证据分几档强度,我在grep 不到只能证明你搜过的文件里没有里排过,「查不到」是最弱的那一档。
换成四条。
一、时间吻合。按「30 秒一次、连续 6 次失败、加关停宽限期」推出三次重启各自该发生的时刻,和实际时间戳对,误差不到 1 秒。这排除了随机重启,但还不能区分是谁杀的。
二、对照组。这个服务有 3 个副本,配置、镜像、节点池完全一样。当天只有跑评测那一台重启 3 次,另外两台 0 次。节点、镜像、资源配额这些共享因素被排掉了。
三、退出方式。三次重启里有两次,日志里有完整的优雅关停流程,每一步都在。内存超限走 SIGKILL,不会有关停。
四、行为特征。前面那 9 个积压的健康检查在几毫秒内一起返回。被杀掉的进程没有积压可以冲,丢包或者连接被重置也不会让请求存着等几十秒再被处理。只有进程活着、循环被占住、连接在内核队列里排着,才攒得出这么一批。
前三条各排掉一类解释,合起来也只说了「不是别的」。「是什么」要另一种证据来指认——一个只在这种机制下才会出现的现象,也就是第四条。
关停时写了一个新状态,入口没有跟着加
第二层问题和事件循环没关系。第二次重启走的是优雅关停,关停逻辑把这个评测的状态写成了 cancelled。而发起评测的入口只接受三种状态:
self._ensure_state(session, {"awaiting_evaluation", "failed", "completed"})cancelled 不在里面。用户第三次点击被拒,而且没有任何接口能把状态改回去,得找能操作生产存储的人去改一个 JSON 文件。关停路径新增了一个状态,状态机的入口没人同步,异常路径上就留了一个走不出去的格子。
用户先后看到的那三条提示指向三个不同方向,没有一条提到阻塞。出错的地方和报出来的地方隔了几层,这个形状我在静默失败比报错难查,所以宁可显式拒绝里写过。
一行能修,但我让他们先别改
卡顿那处的修法是把同步调用丢出循环:
bundle = await asyncio.to_thread(estimate_report, ...)状态机那处加上 cancelled,用户至少能自己重试。
这两处我都没验证过,所以报告发出去之后我又补了一句,让对方先别动代码。没想清楚的有两件:修掉这处卡顿之后流程会继续往后走,后面的阶段可能有同样写法的同步调用,我没查完;改成丢线程池之后,原本串行打分的几个用例会并发调模型,这个并发度可能撞上网关限流。方案没验证就发出去,是我的问题。
还有一件事到现在也没坐实。「是存活探针杀的」是按日志时间推算的,误差不到 1 秒,但它仍然是推算。直接证据是 Pod 事件里那条 Liveness probe failed,需要集群权限才看得到,我没有。报告里这一节单独列着,标的是待确认。
探针本身没判错。那个进程当时确实无法响应任何请求,kubelet 的活就是把这种进程重启掉。至于该拿什么当判据、重启到底有没有用,是另一个问题,我在存活探针查依赖,等于把下游故障翻译成自己的重启里写过。