一、抢救
2023 年 10月 27 日，是一个风和日丽的周五，我正在开车上班的路上。难得不怎么堵车，原本心情还是很不错的。可时间来到 08:50 左右，飞书突然猛烈的弹出消息、告警电话响起，轻松的氛围瞬间被打破。我们的一个核心应用 bfe-customer-application-query-svc 的 RT 飙升，没过一会儿，整个 zone-2[1]陷入不可用的状态。随后便是紧张的应急处置，限流、回退配置、扩容...宛如抢救突然倒地不醒的病患，CPR、AED 除颤、肾上腺素静推... 最终经过十几分钟的努力，应用重新上线，zone-2 完全恢复。
二、诊断病因
“病人” 是暂时救回来了，但病因还未找到，随时都有可能再次陷入危急。到公司后，我便马不停蹄的开始定位本次故障的根因。
好消息是，在前面应急的过程中，已经掌握了不少有用的信息：
bfe-customer-application-query-svc 是近期上线的新应用，故障发生时每个 zone 仅有 2 个 Pod 节点；
故障发生的前一天晚上，刚刚进行了确认订单页面二次估价接口（以下称作 confirmEvaluate）的切流（50% → 100%），故障发生时，该接口的 QPS 是前一天同时段的约 2 倍，如图1；
初步判断，故障可能是 confirmEvaluate 依赖的一个下游接口（以下称作 getTagInfo）超时抖动引起的（RT 上涨到了 500ms，正常情况下 P95 在 10ms 左右，持续约 1s）；
图 1：confirmEvaluate 故障当日 QPS（zone-1 和 zone-2 流量之和）
综合这些信息来看，Pod 节点数过少 + 切流导致流量增加 + 依赖耗时突发抖动，且最终通过扩容得以恢复，这叠满的 buff， 将故障原因指向了 “容量不足”。
但这只能算是一种定性的判断，就好比说一个人突然倒地不醒是因为心脏的毛病，但心脏（心血管）的疾病很多，具体是哪一种呢？在计算机科学的语境中提到 “容量” 这个词，可能泛指各种资源，例如算力（CPU）、存储(Mem) 等硬件资源，也可能是工作线程、网络连接等软件资源，那么，这次故障究竟是哪个或哪些资源不足了呢？还需要更细致的分析，才能解答。
1、初步定位异常指征：tomcat 线程池处理能力饱和，任务排队
通过 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 线程池的扩容逻辑。
不过在这之前，先明确一下两个监控指标和下文将要讨论的代码方法名的映射关系：
监控指标名
对应在代码中的定义
可用线程数（Available Threads）
getPoolSize()
最大线程数（Max Threads）
getMaximumPoolSize()
实际上， tomcat线程池（org.apache.tomcat.util.threads.ThreadPoolExecutor）继承了java.util.concurrent.ThreadPoolExecutor，而且并没有重写线程池扩容的核心代码，而是复用了java.util.concurrent.ThreadPoolExecutor#execute方法中的实现，如图4。其中，第4行～第23行的代码注释，已经将这段扩容逻辑解释的非常清晰。即每次执行新任务（Runnable command）时：
Line 25 - 26：首先判断当前池中工作线程数是否小于 corePoolSize，如果小于 corePoolSize 则直接新增工作线程执行该任务；
Line 30：否则，尝试将当前任务放入 workQueue；
Line 37：如果第 30 行未能成功将任务放入 workQueue，即 workerQueue.offer(command)返回 false，则继续尝试新增工作线程执行该任务（第 37 行）；
图 4：tomcat 线程池扩容实现
比较 Tricky 的地方在于 tomcat 定制了第 30 行 workQueue 的实现，代码位于org.apache.tomcat.util.threads.TaskQueue类中。TaskQueue 继承自 LinkedBlockingQueue，并重写了offer方法，如图5。可以看到：
Line 4：当线程池中的工作线程数已经达到最大线程数时，则直接将任务放入队列；
Line 6：否则，如果线程池中的工作线程数还未达到最大线程数，当提交的任务数（parent.getSubmittedCount()）小于池中工作线程数，即存在空闲的工作线程时，将任务放入队列。这种情况下，放入队列的任务，理论上将立刻被空闲的工作线程取出并执行；
Line 8：否则，只要当前池中工作线程数没有达到最大值，直接返回false。此时图 4第30行workQueue.offer(command) 就将返回false，这会导致execute方法执行第37行的addWorker(command, false)，对线程池进行扩容；
图 5：tomcat TaskQueue offer() 方法实现
通过分析这两段代码，得到如图6的 tomcat 线程池扩容流程图。
图 6：tomcat 线程池扩容逻辑流程图
归纳一下，可以将 tomcat 线程池的扩容过程拆分为两个阶段。
所处阶段
触发阈值
线程池处理能力
阶段 1
当前工作线程数 < 最大线程数
当 ”工作线程数<最大线程数“ 时，只要 ”提交的任务量>池中已有的工作线程数“，就会通过创建新的线程来处理新的任务。这是一种牺牲线程复用效率换取更大、更高效吞吐能力的 “野蛮生长” 模式，在这个过程中，不会有任务积压
阶段 2
当前工作线程数 = 最大线程数
当 “工作线程数” 达到线程池设定的 “最大线程数”时，将不能再通过创建新的工作线程的方式，来处理新提交的任务。在这种情况下，如果继续提交新任务，那该任务只能先放入队列，等待线程池中有线程空闲了，再来处理
可见，一旦进入到 “阶段 2”，线程池的处理能力就无法及时消费新到达的任务，于是这些任务就会开始在线程池队列（workQueue）中排队，甚至积压。而结合 图2、图3，我们可以得出结论，两个 Pod 先后都进入了 “阶段 2” 饱和状态，此时必然已经出现了任务的排队。对 tomcat 线程池来说，“任务” 这个词指的就是接收到的外部请求。
2、线程池处理能力饱和的后果：任务排队导致探活失败，引发 Pod 重启
当前，该应用基于默认配置，使用 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 重启的问题。
3、深度检查：寻找线程池处理能力恶化的根因
现在，已经明确了 “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 个方法：
void completed(T result)：HTTP 请求执行成功，如何处理结果（response）；
void failed(Exception ex)：请求执行失败，如何处理异常；
void cancelled()：如何处理请求取消；
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 调用客户端线程池、连接池模型
在 asyncClient 内部，专门定义了用于处理网络 I/O 的工作线程，即 IOReactorWorker Thread。注意它并不是一个线程池，仅仅是多个独立的 IOReactorWorker 线程，因此 IOReactorWorker 并不会动态扩容，线程数量是在asyncClient 初始化时就固定下来的。当请求被提交给 asyncClient 时，会根据一个特定的算法选择其中一个 IOReactorWorker 线程进行接收；
每个 IOReactorWorker 线程内部都绑定了一个请求队列（requestQueue） 和 一个该线程独享的 Selector，线程启动后，即开启 Selector 事件循环，代码如图22；
在 tomcat 线程中，SOA 调用最终会被包装成一个 HTTP 请求并投递到某个 IOReactorWorker 线程的请求队列里。随后 IOReactorWorker 在 Selector 事件循环中会不断的取出（poll）队列中的请求，包装为 Channel 注册到 Selector 循环中，即图22中代码的第19行。请求提交给 asyncClient 后，tomcat 线程就将在 future.get(Integer.MAX_VALUE, TimeUnit.MILLISECONDS)上等待回调；
IOReactorWorker 会从连接池中取出（lease）一个连接并执行请求。注意 asyncClient 的连接池管理方式比较特别，是根据 route（即不同的 host+port/domain 组合）进行分组的，每个 route 有一个独立的连接池；
请求执行完成后，IOReactorWorker 会通过 future.complete(value)将请求结果回写给 tomcat 线程，此时第 3 步中的get方法调用将返回；
图 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状态，通常是因为代码中执行了如下表格列出的方法。
进入 WAITING
状态
进入 TIMED_WAITING状态（o 表示锁定的对象，n 表示超时时间）
join()
park(o)
wait()
join(n)
parkNanos(o, n)
parkUntil(o, n)
wait(n)
sleep(n)
或者，也有可能是执行了将这些方法进行过上层包装后的方法。例如，
当执行 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 左右。考虑到用户体验，于是决定通过多线程并发执行来减少耗时。
虽然想法无可厚非，但具体到代码实现却有几个明显的问题：
在调用 future.get() 等待线程返回结果时，没有设置超时时间，这是非常不可取的错误实践；
getArrivalPayConfirmEvaluateResult 和 getCommonConfirmEvaluateResult 中包装了繁重的业务逻辑（且重复性极高），不仅会调用下游的计价服务，还会调用包括 getTagInfo 在内的多个其他下游服务的接口。而最初的目的仅仅是解决 “调用两次计价服务” 的问题；
使用了自定义线程池 BizExecutorsUtils.EXECUTOR 而不是框架推荐的动态线程池；
尤其是看到使用了自定义线程池 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：引入自定义线程池导致的 “瓶口效应”
我们不妨结合前文的信息做个粗略的估算：
首先，在 getTagInfo 耗时抖动前，请求量约为 75+ requests/s，负载均衡到 2 个 zone 的共 4 个 Pod 上，单个 Pod 的请求量约为 18 ～ 20 requests/s；
在 getTagInfo 耗时抖动前，一次估价流程的耗时约为 750ms，getTagInfo 耗时飙升后（10ms → 500ms），一次估价流程的耗时理论上增加到 1.3s 左右。由于 confirmEvaluate 内部拆分的子任务，几乎就是完整的估价流程，因此，两个子任务的执行耗时也需要 1.3s 左右；
在 getTagInfo 耗时抖动的 1s 内，虽然请求量无显著变化，但根据 2 倍关系，这 1s 内将会产生 36 ～ 40 个任务（单个 Pod），提交给 EXECUTOR 线程池执行；
由于单个子任务执行耗时 1s，也就是说，在这 1s 内提交到 EXECUTOR 线程池的任务都无法执行完，EXECUTOR 的 20 个工作线程，将全部饱和，大约有一半的任务正占用工作线程，另一半的任务在工作队列中等待；
显然，这是一个十分简单的计算模型，并不能反映现实中更加复杂的情况[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 线程池中等待执行的耗时。
4、诊断结论
至此，终于可以给出诊断结论：
根因
业务代码中不合理使用自定义线程池导致的 “瓶口效应”。
诱因
下游 getTagInfo 接口耗时抖动
其他次要因素
切流导致流量增加；
Pod 数量少；
探活机制脆弱；
用户重试导致流量异常增涨；
结论
业务代码中不合理使用自定义线程池导致 “瓶口效应”，间接限制了 tomcat 的吞吐能力。10 月 26 日晚切流后，请求量达到前一天的两倍，自定义线程池处理能力已经接近瓶颈（20 task/s）。碰巧遇到 10 月 27 日早晨 getTagInfo 耗时抖动，子任务执行耗时显著增加，自定义线程池处理能力迅速触动崩溃，进而导致 tomcat 处理请求排队。长时间积压在 tomcat 线程池工作队列中的探活请求超时，导致探活失败，触发 k8s 先后重启了 zone-2 仅有的 2 个 Pod，最终导致整个 zone-2 不可用。
三、医嘱和处方
本文的最后，来谈谈从这次故障中能获得怎样的经验教训？
1、稳定性预算要有保障，评估 I/O 密集型应用的容量时不能只看 CPU 水位
不知大家在阅读前文时是否好奇过，为什么堂堂一个核心应用，每个 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 个。回过头来看，这是一个非常错误的决策，原因至少有以下两点：
正如刚才所说，这是一个核心应用。每个 zone 仅部署 2 个 Pod 过于极限；
这是一个 I/O 密集型应用，不应该将 CPU 水位作为评估容量的唯一参考指标；
前者本质上是一个“成本（或预算）规划”的问题。通过系统缩容以减少整体运营成本，的确行之有效。但如果在执行过程中，各方过于追求 “节省成本”，便可能在不自知的情况下，削减了原本必要的开支。比如在本文讨论的场景中，部署额外的若干个 Pod 以增强应对异常情况（依赖耗时、流量等波动）的能力就是必要的投入，即提供基本业务功能以外的稳定性预算。
后者则反映出一个更为艰巨的问题：我们缺乏科学的方法（或统一的标准）来评估容量应该设定为多少。对于一个 I/O 密集型应用，许多有限资源均可能在 CPU 算力达到瓶颈之前先达到瓶颈，比如本文讨论的线程池，以及连接池、带宽等。因此，评估 I/O 密集型应用的容量并不是一件容易的事情。往往需要根据流量的预测值进行压测，同时根据线程池、连接池、带宽等有限资源的饱和度指标，结合接口响应时间（延迟），异常数量（错误）等健康度指标来综合分析判断。然而我们仍缺乏指导这种评估的最佳实践，下一节我们将继续讨论。
2、谨慎的对系统性能做出假设，压测结果才是检验性能的唯一方
实际上，bfe-customer-application-query-svc 及其依赖的下游 bfe-commodity-core-svc 均为同一项目申请、同一批次上线的新应用。一般情况下，我们会对新上线的应用进行专门的压力测试。而正如上文讨论的，自定义线程池瓶颈问题在压力测试中应该很容易被触发。然而后来经过证实，只针对 bfe-commodity-core-svc 进行了压测，却并未对 bfe-customer-application-query-svc 进行压测，这让我感到难以理解。
进一步深入了解当时的上下文后，我发现在决定不对 bfe-customer-application-query-svc 进行压力测试的过程中，主要有两种观点：
压测也难以发现导致本次故障的问题；
confirmEvaluate 是由旧应用迁移过来的。旧应用运行稳定且没有任何问题，新应用也会同样运行良好；
首先，且不论第一种观点是否正确，它都不能作为不进行压测的充分理由。因为在当时我们并未具有现在的全知全览视野，压测的目的并不仅仅在于寻找本次发生的这一具体问题，而是揭示所有可能存在的、尚未明确的性能风险。我更倾向于将这一观点定性为事后为之前的过失找补的话术，而不是一个专业的技术性判断。
第二种观点则揭示了我们在日常工作中常有的偏见。相较于编码和功能测试，由于工期紧张、时间压力等因素，我们常常将那些非日常的任务，如压测，视为可有可无的附加项，主观上倾向于省略这项工作。然而，压测真的那么复杂吗？答案并非如此。举个例子，后期我们在预发环境通过压测复现此次故障的演练，包括前期准备工作和制定演练方案，几个小时内就可完成。
往根儿上说，这反映了我们在 “测试方案设计（或测试分析）” 工作上的不足，本质上还是在 “如何开展容量/性能评估“ 的问题上，缺少最佳实践、缺少科学的方法论指导。
另一个致命的假设，是在将流量比例从 50% 提升到 100% 的窗口前期做出的：
“50% 流量运行了很多天都没问题，放量到 100% 应该稳了。”
只论业务逻辑的正确性，这个假设或许没有太大的问题。但如果把容量因素纳入考虑，这个假设就过于想当然了，缺少了一次至关重要的压测论证。
其实，实践检验真理的粗浅道理每个人都懂。难的是在工作中不心存侥幸，踏踏实实的执行到位。
3、将有限资源纳入监控
在稳定性工程中，我们常会谈到 “可监控” 这个词，指的是通过具有统计意义和显著性的可观测指标来反映系统运行状况。
对系统中的有限资源进行针对性监控往往大有裨益。主要有以下三点理由：
有限资源的耗竭往往是许多性能问题的根本原因。因此，针对性的监控将大大加速性能问题的排查；
有限资源经常也是跨越多个业务场景的“共享资源”。因此，一旦这些资源引发性能问题，可能迅速导致整个系统的崩溃；
有限资源的耗竭过程通常伴随着流量的增加。但在达到瓶颈之前，常规的业务指标很难反映出这一趋势；
实际上，在大家熟知的那些被广泛使用的开源项目中，就有很多值得借鉴的例子。例如，通过图2、图3所示的监控指标，能够很好的帮助我们观察运行时 tomcat 线程池的饱和度。再比如 HikariCP，提供了十分丰富的监控指标，以便于观察连接池运行时的各种状态。
如果从一开始，能够效仿 tomcat 的做法，在引入 EXECUTOR 自定义线程池的时候，将繁忙线程数、最大线程数指标监控起来，是有机会在切流 50% 的时候就发现危机的。按 2.3.3 节讨论的方式粗略换算，切流 50% 时 EXECUTOR 线程池的繁忙线程占比将超过 80%[19]。任何素质过关的研发，此时都会审慎的评估容量风险
四、结语
作为本系列的收官之作，本文继续延续了前面几篇的实践基础，深入探讨了源自真实生产环境的案例。我们致力于在全面的知识体系支撑下，对这些事件进行深入的技术性解读。正如在前几篇文章的结尾部分所讨论的，当前的技术交流趋势日益倾向于快速消费，这使得读者和听众越来越难以从中获得深刻的经验知识，以及思维能力的提升。为了提供与众不同的价值，我们在本系列的每篇文章中都力求内容的深度和实用性，希望能够为读者带来丰富的收获。如果您对本系列的先前文章也感兴趣，可以通过以下链接进行查阅：
文章链接
分流线程池Reject问题根因分析
>>>>****
脚注
[1] 基于现有架构，我们的应用部署拆分成了两个 zone，zone 的概念在这里不做展开，可以简单理解为两个异地机房，流量按照接近 1:1 的比例均分到两个 zone 中；
[2] zone-2 两个 Pod 的 CPU 利用率、内存利用率等指标都处于低水位。注意文中将 CPU、内存 称作硬件资源只是为了叙述方便，实际上它们都是基于真实硬件资源 “虚拟化“ 之后的 ”配额”；
[3] 我在《解决因主库故障迁移导致的核心服务不可用问题》一文中讨论过连接池耗尽的问题，如果你感兴趣，可以看一看这篇文章；
[4] 图3、图4中的曲线含义：① Max Threads，即图中的蓝色曲线，表示由人为配置的 tomcat 线程池的最大线程数，该应用的最大线程数被设置为 200。② Available Threads，即图中的橙色曲线，表示当前线程池中已经创建的线程数。③Busy Threads，即图中的绿色曲线，表示当前线程池中正在处理任务的繁忙线程数；
[5] 这里实际上还判断了线程池是否仍在运行（isRunning(c))，为了表述重点，省略了对这段代码的解释；
[6] 也有可能是线程池已经被 shutdown，即 isRunning(c) 返回了 false。同[4]，为了表述重点，省略了对这种可能性的解释；
[7] 这个过程主要是读取 HTTP 响应的 body（JSON String），反序列化为 Java POJO。这部分代码不在这里展开；
[8] 这个表达为了能更简单的说明问题，其实并不准确。更准确的是请求被放入 IOReactorWorker 线程的请求队列后立即返回。下文会通过更清晰的模型来解释这个逻辑；
[9] 通过 IOReactorConfig 类的 ioThreadCount属性设置，通常是 CPU 核数的 2 倍；
[10] 实现代码在org.apache.hc.core5.reactor.IOWorkers#newSelector 方法中，有两种实现 PowerOfTwoSelector 和 GenericSelector，在这里不做详细展开；
[11] 实际上，除了直接处理请求的 tomcat 线程，框架代码还创建并管理着一些其他的工作线程，但这类线程的饱和度、扩缩容通常并不会受到业务流量变化的影响。例如 consulCacheScheduledCallback 线程，主要和依赖的下游 SOA 应用的数量有关。因此，这类线程的嫌疑也可以排除；
[12] 例如，在这个计算模型中，getTagInfo 抖动前后，一次估价流程耗时分别为 750ms 和 1.3s，增加的耗时是由 getTagInfo 接口的响应时长唯一决定的，这是一种理想状态。实际上，一旦线程池处理能力衰退，会有相当一部分请求的耗时，远远大于 1.3s 这个值，耗时并不仅仅只受 getTagInfo 接口的影响；
[13] 这部分的代码并未在图23中展示，包含在了第 3 行 [Ellipis Java code] 省略的代码中；
[14] 需要注意的是，尽管图26中我标注了 子任务 1（getArrivalPayConfirmEvaluateResult）在前、子任务 2（getCommonConfirmEvaluateResult）在后，但在并发状态下，实际的执行顺序并不一定是这样。这里仅仅是为了叙述方便；
[15] 严谨的说，最后一列时间戳（Timestamp）表示的是 “开始执行” 的时间，因此 6s 实际上是 get_user_info 调用开始执行到子任务开始执行的间隔时间，包含了 get_user_info 调用的耗时。但这里 get_user_info 调用耗时只有 10ms，相对于 6s 而言，完全可以忽略不计；
[16] 单一 Pod 发生故障的概率是非常高的，而两个 Pod 同时发生故障的概率则会大大降低，因此，至少部署两个 Pod 以防止在单一 Pod 故障时整个应用都不可用。同时，两个 Pod 也是为了更好的实现平滑发布；
[17] 注意，这里并不是说一定不会发生。实际上每秒 18 个任务对于 EXECUTOR 线程池来说也已经比较极限，即便躲过了这一次故障，也未必能躲过下一次；
[18] 这就好比在急性心梗发病前，患者的心电图通常不会有太显著的异常。但如果进行冠状动脉造影就能够更早的发现心梗风险。更进一步，通过定期体检检测血脂、胆固醇等指标，也能够更早体现疾病发生的趋势；
[19] 注意，这只是一个参考：34 reqeusts/s ÷ 4 pods × 2 ÷ 20(max pool size) × 100% = 85%;
作者丨货运研发部
来源丨公众号：货拉拉技术（ID：huolalatech）
dbaplus社群欢迎广大技术人员投稿，投稿邮箱：editor@dbaplus.cn
