2023 年 10月 27 日，是一个风和日丽的周五，我正在开车上班的路上。难得不怎么堵车，原本心情还是很不错的。可时间来到 08:50 左右，飞书突然猛烈的弹出消息、告警电话响起，轻松的氛围瞬间被打破。我们的一个核心应用 bfe-customer-application-query-svc 的 RT 飙升，没过一会儿，整个 zone-2[1]陷入不可用的状态。随后便是紧张的应急处置，限流、回退配置、扩容...宛如抢救突然倒地不醒的病患，CPR、AED 除颤、肾上腺素静推... 最终经过十几分钟的努力，应用重新上线，zone-2 完全恢复。

“病人” 是暂时救回来了，但病因还未找到，随时都有可能再次陷入危急。到公司后，我便马不停蹄的开始定位本次故障的根因。

好消息是，在前面应急的过程中，已经掌握了不少有用的信息：

图 1：confirmEvaluate 故障当日 QPS（zone-1 和 zone-2 流量之和）

综合这些信息来看，Pod 节点数过少 + 切流导致流量增加 + 依赖耗时突发抖动，且最终通过扩容得以恢复，这叠满的 buff， 将故障原因指向了 “容量不足”。

但这只能算是一种定性的判断，就好比说一个人突然倒地不醒是因为心脏的毛病，但心脏（心血管）的疾病很多，具体是哪一种呢？在计算机科学的语境中提到 “容量” 这个词，可能泛指各种资源，例如算力（CPU）、存储(Mem) 等硬件资源，也可能是工作线程、网络连接等软件资源，那么，这次故障究竟是哪个或哪些资源不足了呢？还需要更细致的分析，才能解答。

通过 Pod 监控，轻易就能排除算力、存储等硬件资源耗尽的可能性[2]。该应用不依赖数据库，并未使用连接池来处理同步 I/O也不太可能是连接池耗尽[3]。因此，最有可能还是工作线程出了问题。

我们使用 tomcat 线程池来处理请求，工作线程的使用情况可以通过 “tomcat 线程池监控” 获得。如图2、图3，可以看到，Pod-1（..186.8）在 08:54:00 线程池的可用线程数（Available Threads）已经到了最大值（Max Threads）[4]，Pod-2（..188.173）则是在更早的 08:53:30 达到最大值。

图 2：tomcat 线程池使用情况（*.*.186.8）

图 3：tomcat 线程池使用情况（*.*.188.173）

为了更好的理解曲线变化的含义，我们需要认真分析一下 tomcat 线程池的扩容逻辑。

不过在这之前，先明确一下两个监控指标和下文将要讨论的代码方法名的映射关系：

实际上， tomcat线程池（org.apache.tomcat.util.threads.ThreadPoolExecutor）继承了java.util.concurrent.ThreadPoolExecutor，而且并没有重写线程池扩容的核心代码，而是复用了java.util.concurrent.ThreadPoolExecutor#execute方法中的实现，如图4。其中，第4行～第23行的代码注释，已经将这段扩容逻辑解释的非常清晰。即每次执行新任务（Runnable command）时：

图 4：tomcat 线程池扩容实现

比较 Tricky 的地方在于 tomcat 定制了第 30 行 workQueue 的实现，代码位于org.apache.tomcat.util.threads.TaskQueue类中。TaskQueue 继承自 LinkedBlockingQueue，并重写了offer方法，如图5。可以看到：

图 5：tomcat  TaskQueue offer() 方法实现

通过分析这两段代码，得到如图6的 tomcat 线程池扩容流程图。

图 6：tomcat 线程池扩容逻辑流程图

归纳一下，可以将 tomcat 线程池的扩容过程拆分为两个阶段。

可见，一旦进入到 “阶段 2”，线程池的处理能力就无法及时消费新到达的任务，于是这些任务就会开始在线程池队列（workQueue）中排队，甚至积压。而结合 图2、图3，我们可以得出结论，两个 Pod 先后都进入了 “阶段 2” 饱和状态，此时必然已经出现了任务的排队。对 tomcat 线程池来说，“任务” 这个词指的就是接收到的外部请求。

当前，该应用基于默认配置，使用 SpringBoot 的健康检查端口（Endpoint），即actuator/health，作为容器的存活探针。而问题就有可能出在这个存活探针上，k8s 会请求应用的actuator/health端口，而这个请求也需要提交给 tomcat 线程池执行。

设想如图7中的场景。Thread-1 ～ Thread-200 因处理业务请求而饱和，工作队列已经积压了一些待处理的业务请求（待处理任务 R1 ～ R4），此时 k8s 发出了探活请求（R5），但只能在队列中等待。对于任务 R5 来说，最好的情况是刚刚放入工作队列就立刻有5个工作线程从之前的任务中释放出来，R1～R5 被并行取出执行，探活请求被立即处理。但线程池因业务请求饱和时，并不存在这种理想情况。通过前文已经知道，confirmEvaluate 的耗时飙升到了 5s，排在 R5 前面的业务请求处理都很慢。因此比较坏的情况是，R5 需要等待 R1、R2、R3、R4 依次执行完成才能获得工作线程,将在任务队列中积压 20s()， 甚至更久。

图 7：在任务队列中等待的探活请求

而 bfe-customer-application-query-svc 的探活超时时间设置的是 1s，一旦发生积压的情况，则大概率会超时。此时 k8s 会接收到超时异常，因此判定探活失败。我在 《解决因主库故障迁移导致的核心服务不可用问题》一文中讨论过探活失败导致 Pod 重启引发雪崩的问题，看来这次故障，又是如出一辙。

果然，如图8、图9，通过查阅 Pod 事件日志，我发现 Pod-1（..186.8）在 08:53:59 记录了探活失败，随后触发了重启，Pod-2（..188.173）则是在 08:53:33 记录了探活失败，随后也触发了重启。而这两个时间正是在上文提到的 “线程池达到饱和" 的两个时间点附近（Pod-1 08:54:00 和 Pod-2 00:53:30）。

由于 zone-2 仅有 2 个 Pod，当 Pod-1 和 Pod-2 陆续重启后，整个 zone-2便没有能够处理请求的节点了，自然就表现出完全不可用的状态。

图 8：探活失败（*.*.186.8）

图 9：探活失败（*.*.188.173）

但为什么只有 zone-2 会整个不可用呢？于是，我又专门对比了 zone-1 的两个 Pod，如 图10到图13。从图10、图11可以看到，zone-1 的两个 Pod 在下游依赖抖动时也发生了类似 zone-2 的 tomcat 线程池扩容，不同之处在于，zone-1 两个 Pod 的线程池都没有达到饱和。从图12、图13也可以看到，zone-1 的两个 Pod 在  八点五十分前后这段时间内，没有任何探活失败导致重启的记录。

图 10：tomcat 线程池使用情况（*.*.92.140）

图 11：tomcat 线程池使用情况（*.*.167.148）

图 12：探活成功（*.*.92.140）

图 13：探活成功（*.*.167.148）

显然， zone-1 并没有置身事外，同样受到了耗时抖动的影响，同样进行了线程池扩容。但可用线程仍有余量，因此并没有遇到 zone-2 探活失败，进而触发 Pod 重启的问题。

现在，已经明确了 “tomcat 线程池饱和” 是导致这次容量问题的关键，但线程池为什么会饱和，还需要继续寻找原因。结合应急处置过程中获得的 #3 线索和过往经验，首先浮现在我脑中的推论是：SOA 调用下游 getTagInfo 耗时增加，导致 tomcat 线程陆续陷入等待，最终耗尽了所有可用线程。

1）与推论相矛盾的关键证据：WAITING状态线程数飙升

自从开始写这个系列文章，线程就是 “常驻嘉宾”。看过该系列前面几篇文章的读者，此时应该想到，既然怀疑是线程等待的问题，高低是要调查下线程状态机的。

以下图14、图15是 zone-2 两个 Pod 在故障时段的线程状态监控曲线（X 轴为时间，Y 轴为线程的数量）。

图 14：线程状态（*.*.186.8）

图 15：线程状态（*.*.188.173）

可以看到，不论 Pod-1（..186.8）还是 Pod-2（..188.173）在故障开始之初（08:52:0030s），都是WAITING状态的线程显著飙升。这有点出乎意料，因为如果开头的推测成立，下游 getTagInfo 耗时增加，线程的波动应该体现为TIMED_WAITING 状态的线程数飙升。

2）是推论站不住脚，还是错误理解了证据？深度溯源框架代码，拨开迷雾

感到意外也不是空穴来风，下方图16是通过 jstack 捕获的基于公司自研 SOA 框架（以下称作 hermes）的一个典型 tomcat 线程调用栈。其中，第 9 行 ～ 第 11 行栈信息清晰提示了一次 SOA 调用的执行过程。从图中第 2 行可以看到，此时线程此时处于TIMED_WAITING状态。

图 16：一个典型的 Tomcat 线程调用栈

但为了防止先入为主，代入错误的假设进行调查，我还是决定重新确认一遍 hermes 框架中执行 SOA 调用的代码实现。图16中的第11行，cn.huolala.arch.hermes.compatible.protocol.invoker.ConcreteInvocationInvoker#invoke是 SOA 调用的入口方法。该方法的核心代码如图17，其中最重要的是第8行和第12行。

Line 8：调用ConcreteInvocationInvoker类的另一个doInvoke方法获得response。真正发起调用的逻辑其实都是在这个doInvoke方法里实现的；

Line 12：调用 response的recreate()方法，并将结果包装为result。由于省略了非核心代码，Line 12 实际上就是线程调用栈中提示的的ConcreteInvocationInvoker.java 71行的代码；

图 17：ConcreteInvocationInvoker#invoke 方法定义

而 doInvoke方法做的最核心的事情，就是将请求交给 asyncClient 执行，这里asyncClient是org.apache.hc.client5.http.impl.async.CloseableHttpAsyncClient的实例（在 hermes 框架中，SOA 请求使用的低级通信协议是 HTTP）。代码如图18中第4行～第24行。

Line 4：执行 asyncClient.execute 方法，发起 HTTP 请求。execute方法有三个参数，此处只需要重点关注第三个参数。由于是异步客户端，调用 execute方法将立刻返回，待请求执行完成后，asyncClient 将通过第三个参数注册的回调（callback）逻辑，通知调用方执行结果。回调逻辑必须实现 org.apache.hc.core5.concurrent.FutureCallback接口，实际上就是自定义 3 个方法：

Line 11：我们重点关注正向流程，即 completed方法的实现。实际上就是解析（unpack） HTTP 的响应结果，然后调用 response.succeeded(result)；

图 18：ConcreteInvocationInvoker#doInvoke 方法定义

两段代码中的 response都是 cn.huolala.arch.hermes.compatible.protocol.handler.JsonRpcResponse的实例，它的实现如图19，重点关注图17中用到的 recreate 方法和图18中用到的 succeeded 方法在 JsonRpcResponse 中是如何定义的。我们会发现，JsonRpcResponse本质上就是对 CompletableFuture的一层包装：

Line 5：一上来就绑定了一个 future 对象；

Line 11：recreate 方法的核心，就是在 future 对象的 get 方法上等待；

Line 22：succeeded方法的核心，就是将值（从 HTTP 响应中解析出的调用结果）写入到 future；

图 19：JsonRpcResponse 定义

为了更方便理解，我将图17～图19 的三段代码整理为了如图20的序列图。通过序列图可以更清晰的观察到，调用过程分为 “发送请求” 和 “等待回调” 两个阶段。在发送请求阶段，asyncClient 将 I/O 任务注册到内部事件循环后就立刻返回[8]，tomcat 线程在这一阶段不存在任何等待。唯一会导致线程等待的，是在回调阶段的第 11 步 future.get(Integer.MAX_VALUE, TimeUnit.MILLISECONDS)调用。但调用 get 方法时指定了超时时间（Integer.MAX_VALUE 毫秒），线程将进入 TIMED_WAITING 状态。

图 20：客户端发起 SOA 调用序列图

更进一步，将 asyncClient 的内部实现展开，完整的 “线程池 + 连接池” 模型如图21：

图 21：SOA 调用客户端线程池、连接池模型

图 22：IOReactorWorker 线程内部的事件循环核心逻辑

通过上面的分析可以得出结论：一次标准的 SOA 调用，并不会导致 tomcat 线程进入 WAITING 状态。

虽然 tomcat 线程确实会在 HTTP 请求执行完成前，一直等待 future.get(Integer.MAX_VALUE, TimeUnit.MILLISECONDS) 返回，随着 SOA 调用耗时增加，等待的时间也会更久，从而导致可用线程逐渐耗尽。但正如最初的设想一样，此时应该 TIMED_WAITING状态的线程数飙升，与实际监控曲线的特征不符；

此外，IOReactorWorker 线程的嫌疑也可以排除。一是因为IOReactorWorker线程的数量在初始化 asyncClient 的时候就已经固定了下来，不会 “飙升”。二是不论this.selector.select(this.selectTimeoutMillis)（如图22，第5行）还是读写 I/O，线程状态都是 RUNNABLE，而非 WAITING。

3）弄巧成拙的业务代码

既然已经意识到 WAITING 状态线程数飙升的事实，不如基于这个事实给问题代码做个画像。那么，什么样的代码可能会导致线程进入WAITING状态呢？

还是在 《解决因主库故障迁移导致的核心服务不可用问题》 一文中（3.1 节），我曾详细分析了WAITING和 TIMED_WAITING 状态的区别。线程进入WAITING 或 TIMED_WAITING状态，通常是因为代码中执行了如下表格列出的方法。

或者，也有可能是执行了将这些方法进行过上层包装后的方法。例如，

当执行 CompletableFuture 实例的 future.get(timeout, unit)方法时，在 CompletableFuture 的底层实现中，最终会调用LockSupport.parkNanos(o, timeout)`方法；

而如果执行 CompletableFuture 实例的 future.get()方法（不指定超时时间），则最终会调用 LockSupport.park(o) 方法；

因此，执行 future.get(timeout, unit)方法将导致线程进入 TIMED_WAITING状态（正如前文讨论的框架代码一样），而执行 future.get()方法则会导致线程进入WAITING 状态。

Sherlock Holmes 有句名言：

尽管 bfe-customer-application-query-svc 的定位是业务聚合层的应用，主要是串行调用下游领域服务，编排产品功能，通常不太可能主动使用上面提到的这些方法来管理线程。但毕竟已经确定了框架代码中并无任何导致WAITING状态线程数飙升的证据，因此我还是决定到业务代码中一探究竟。

没想到很快就发现了蛛丝马迹。几乎没废什么功夫，就从 confirmEvaluate 方法中找到了一段高度符合画像的代码，经过精简后，如图23。当看到第 15 行和第 16 行的 future.get()调用时，我不禁眉头一紧。

图 23：confirmEvaluate 方法实现

和当时开发这段代码的同学了解了一下， 创作背景大致是这样的：

由于种种历史原因，在确认页估价时，需要根据 “是否到付”，分两次调用下游进行估价（即图23中第6行getArrivalPayConfirmEvaluateResult 和 第 10 行 getCommonConfirmEvaluateResult）。confirmEvaluate 的耗时主要受调用下游计价服务的耗时影响，原先日常 P95 约为 750ms，串行调用两次会导致 confirmEvaluate 方法的耗时 double，达到 1.5s 左右。考虑到用户体验，于是决定通过多线程并发执行来减少耗时。

虽然想法无可厚非，但具体到代码实现却有几个明显的问题：

尤其是看到使用了自定义线程池 BizExecutorsUtils.EXECUTOR 的时候，我第二次眉头一紧，心中预感问题找到了。BizExecutorsUtils.EXECUTOR 的定义如图24。

Line 16：可以看到线程池的最大线程数只有 20；

Line 19：工作队列却很大，可以允许 1K+ 个任务排队；

此外，一个平常看起来合情合理，但用在这里却雪上加霜的设计是，EXECUTOR 是静态初始化的，在同一个 JVM 进程中全局唯一。这里的线程池定义，很难不让我想到只有 3 个诊室，却排了 500 号病人的呼吸内科。

图 24：自建线程池定义

正是因为这个线程池的引入，导致了 “瓶颈效应”，如图25，显然 confirmEvaluate 的执行过程要比图21描绘的模型更加复杂。作为 SOA 请求的入口，方法本身确实是通过 tomcat 线程执行的。故障发生时，tomcat 线程池配置的最大线程数为 200（单个 Pod 最多能够并发处理 200 个请求）。但在方法内部，估价的核心逻辑被包装成了两个子任务，提交到了最大仅有 20 个工作线程的 EXECUTOR 自定义线程池执行。也就是说，EXECUTOR 自定义线程池的处理能力仅有 tomcat 线程池的 1/10，却需要处理 2 倍于 QPS 的任务量。

图 25：引入自定义线程池导致的 “瓶口效应”

我们不妨结合前文的信息做个粗略的估算：

显然，这是一个十分简单的计算模型，并不能反映现实中更加复杂的情况[12]，但并不妨碍说明问题（和 2.2 节中分析的案例一模一样的问题）。子任务可能在 EXECUTOR 线程池工作队列中排队很久， 从而导致 confirmEvaluate 方法在 future.get() 上等待（图23第15、16行），一直占用 tomcat 工作线程，新到达的请求只能不断创建新的 tomcat 线程来执行。同时，confirmEvaluate 响应变慢或超时错误，又会诱发用户重试，进一步带来请求量激增（如图1，抖动发生后，请求量飙升到了约 100 requests/s），导致 EXECUTOR 线程池的处理能力进一步恶化。如此恶性循环，最终彻底耗尽 tomcat 线程池的可用工作线程。

通过 Trace 跟踪，我们可以轻松找出支持 “瓶颈效应” 的证据，如图26。confirmEvaluate 方法首先会调用下游的 get_user_info 接口获取用户信息[13]。然后，该方法将构建两个子任务并将其提交至 EXECUTOR 线程池（图23 第 5～7 行、 第 9～11 行）。值得注意的是，get_user_info 调用完成后，到子任务被提交到 EXECUTOR 线程池的这段时间里，代码只做了一些参数包装和验证的简单逻辑辑[13]，因此这部分代码的执行时间基本可以忽略不计。我们可以近似的理解为，在 get_user_info 的调用完成后，子任务就立即提交给了 EXECUTOR 线程池。

图 26：子任务在 EXECUTOR 线程池工作队列中排队

当 EXECUTOR 线程池处理能力足够时，子任务被提交到 EXECUTOR 线程池后也应该迅速被执行，因此从 get_user_info 接口调用完成到子任务开始执行中间的间隔时间应该很短。但从 图26中给出的 Trace 链路可以看到[14]，从 get_user_info 接口调用，到子任务 1 和子任务 2 开始执行，间隔了约 6s 的时间[15]。而这 6s 反映的正是子任务在 EXECUTOR 线程池中等待执行的耗时。

至此，终于可以给出诊断结论：

本文的最后，来谈谈从这次故障中能获得怎样的经验教训？

不知大家在阅读前文时是否好奇过，为什么堂堂一个核心应用，每个 zone 只部署 2 个 Pod？

一个最基本的共识是，部署两个 Pod 是故障冗余的最低限度[16]。但对于核心应用而言，仅用两个 Pod 互为备份有点过于极限了。这是因为，核心应用通常需要处理更复杂的业务逻辑并承载更多的流量，当其中一个 Pod 故障时，剩下唯一的 Pod 将瞬间承载全部的正常流量和陡增的异常流量（往往会伴有用户重试的流量），很容易引发性能问题。

事实上，就在故障发生前不久，该应用在每个 zone 还部署有 4 个 Pod。按照 2.3.3 节的计算方式算一下就会发现，如果故障发生时的流量均匀分配到 8 个 Pod 上，单个 Pod 上 EXECUTOR 线程池每秒需要处理的子任务数量约为 18 个，工作线程还有余量，这次的故障有极大的可能就不会发生[17]。

那为什么 Pod 数量缩水了呢？因为在控制成本的大背景下，CI 团队多次找到应用的 Owner 并以 CPU 水位为唯一标准沟通缩容计划，最终两边达成一致，将每个 zone 的 Pod 数量缩容到了 2 个。回过头来看，这是一个非常错误的决策，原因至少有以下两点：

前者本质上是一个“成本（或预算）规划”的问题。通过系统缩容以减少整体运营成本，的确行之有效。但如果在执行过程中，各方过于追求 “节省成本”，便可能在不自知的情况下，削减了原本必要的开支。比如在本文讨论的场景中，部署额外的若干个 Pod 以增强应对异常情况（依赖耗时、流量等波动）的能力就是必要的投入，即提供基本业务功能以外的稳定性预算。

后者则反映出一个更为艰巨的问题：我们缺乏科学的方法（或统一的标准）来评估容量应该设定为多少。对于一个 I/O 密集型应用，许多有限资源均可能在 CPU 算力达到瓶颈之前先达到瓶颈，比如本文讨论的线程池，以及连接池、带宽等。因此，评估 I/O 密集型应用的容量并不是一件容易的事情。往往需要根据流量的预测值进行压测，同时根据线程池、连接池、带宽等有限资源的饱和度指标，结合接口响应时间（延迟），异常数量（错误）等健康度指标来综合分析判断。然而我们仍缺乏指导这种评估的最佳实践，下一节我们将继续讨论。

实际上，bfe-customer-application-query-svc 及其依赖的下游 bfe-commodity-core-svc 均为同一项目申请、同一批次上线的新应用。一般情况下，我们会对新上线的应用进行专门的压力测试。而正如上文讨论的，自定义线程池瓶颈问题在压力测试中应该很容易被触发。然而后来经过证实，只针对 bfe-commodity-core-svc 进行了压测，却并未对 bfe-customer-application-query-svc 进行压测，这让我感到难以理解。

进一步深入了解当时的上下文后，我发现在决定不对 bfe-customer-application-query-svc 进行压力测试的过程中，主要有两种观点：

首先，且不论第一种观点是否正确，它都不能作为不进行压测的充分理由。因为在当时我们并未具有现在的全知全览视野，压测的目的并不仅仅在于寻找本次发生的这一具体问题，而是揭示所有可能存在的、尚未明确的性能风险。我更倾向于将这一观点定性为事后为之前的过失找补的话术，而不是一个专业的技术性判断。

第二种观点则揭示了我们在日常工作中常有的偏见。相较于编码和功能测试，由于工期紧张、时间压力等因素，我们常常将那些非日常的任务，如压测，视为可有可无的附加项，主观上倾向于省略这项工作。然而，压测真的那么复杂吗？答案并非如此。举个例子，后期我们在预发环境通过压测复现此次故障的演练，包括前期准备工作和制定演练方案，几个小时内就可完成。

往根儿上说，这反映了我们在 “测试方案设计（或测试分析）” 工作上的不足，本质上还是在 “如何开展容量/性能评估“ 的问题上，缺少最佳实践、缺少科学的方法论指导。

另一个致命的假设，是在将流量比例从 50% 提升到 100% 的窗口前期做出的：

只论业务逻辑的正确性，这个假设或许没有太大的问题。但如果把容量因素纳入考虑，这个假设就过于想当然了，缺少了一次至关重要的压测论证。

其实，实践检验真理的粗浅道理每个人都懂。难的是在工作中不心存侥幸，踏踏实实的执行到位。

在稳定性工程中，我们常会谈到 “可监控” 这个词，指的是通过具有统计意义和显著性的可观测指标来反映系统运行状况。

对系统中的有限资源进行针对性监控往往大有裨益。主要有以下三点理由：

实际上，在大家熟知的那些被广泛使用的开源项目中，就有很多值得借鉴的例子。例如，通过图2、图3所示的监控指标，能够很好的帮助我们观察运行时 tomcat 线程池的饱和度。再比如 HikariCP，提供了十分丰富的监控指标，以便于观察连接池运行时的各种状态。

如果从一开始，能够效仿 tomcat 的做法，在引入 EXECUTOR 自定义线程池的时候，将繁忙线程数、最大线程数指标监控起来，是有机会在切流 50% 的时候就发现危机的。按 2.3.3 节讨论的方式粗略换算，切流 50% 时 EXECUTOR 线程池的繁忙线程占比将超过 80%[19]。任何素质过关的研发，此时都会审慎的评估容量风险

作为本系列的收官之作，本文继续延续了前面几篇的实践基础，深入探讨了源自真实生产环境的案例。我们致力于在全面的知识体系支撑下，对这些事件进行深入的技术性解读。正如在前几篇文章的结尾部分所讨论的，当前的技术交流趋势日益倾向于快速消费，这使得读者和听众越来越难以从中获得深刻的经验知识，以及思维能力的提升。为了提供与众不同的价值，我们在本系列的每篇文章中都力求内容的深度和实用性，希望能够为读者带来丰富的收获。如果您对本系列的先前文章也感兴趣，可以通过以下链接进行查阅：