实战总结｜记一次消息队列堆积的问题排查官网

吉多阿里开发者号于2023年7月18日09: 01在浙江发布。

本文记录了一个问题调查过程，从中可以学习到很多通用的方法论和经验教训，因此我们做一个总结。（文末有活动）

一.背景

该问题涉及的系统环节如上图所示，每个系统的基本职责是：

代理：提供请求代理服务。统一通过代理发送给下游系统的各种请求，使上游系统不需要知道下游服务使用的差异；同时提供限流、导流等精细化服务特性；Latour SDK:为所有存储平台提供统一的映像下载功能。

它通常与图像算法模型串联布置；预测引擎：提供模型推理服务。支持各种机器学习和深度学习算法模型的工程化部署；二、问题调查描述：本文使用的消息队列称为MetaQ。

外部开源版本是RocketMQ，以下统称为“MQ”。2.1问题描述一天早上，我收到报警通知，提示代理系统入口处的MQ被堆积。打开控制台，发现在500台代理机器中，

一台机器堆积严重，而其他机器运行正常：

2.2一句话的根本原因开门见山，直接谈问题的根本原因（详细调查过程请参考以下内容）:

个别机器堆积：有一个消耗线程卡在这台机器上，虽然其他线程正常消耗，但MQ机制确定消耗站点不前进；HTTP下载卡住：使用的HttpClient版本存在bug，超时在特定情况下不会生效。

可能导致线程一直被卡住；2.3故障排除流程1。这台机器的消耗速度是不是太慢了？第一反应是这台机器的消耗太慢了。其他机器可以快速消化相同数量的新闻，但由于消费缓慢，新闻一直在堆积。但是，在MQ控制台中进行详细比较后，

发现该机器的业务处理时间和TPS消耗与其他机器相似，并且不同机器的规格相同：

其次，观察阿尔萨斯绘制的火焰图，右边两个细长的火焰是我们系统的业务逻辑（火焰更高是因为RPC的调用堆栈更深）。从图中可以看出，火焰图中没有明显的“平顶效应”，火焰的宽度相对较窄。

也可以说明机器在执行业务逻辑时没有明显的耗时症结，这也可以证明机器没有因业务处理缓慢而堆积：

2.系统指标是否正常？登录机器，发现CPU、MEM和负载都正常，接近正常机器，没有发现明显的线索：

并且该机器没有明显的全GC:

3.限流引起的？

提示：代理请求时代理会限制流量机制，超过限制的流量会触发阻塞等待，从而保护下游同步服务。

因此，如果今天系统流量非常大，超过了下游服务可以承受的限制，超出的请求将触发速率限制器来限制流量并阻止流量。因此，大量MQ消费者线程被阻塞，因此代理系统的整体消息消费速度将会减慢。

最后的结果就是入口话题积累。

但是，无论您查看机器的日志还是监视器，由于电流限制造成的阻塞现象都不严重且相对平稳：

其次，如果真的是今天系统入口流量大导致的，所有代理机器（MQ消费者）的积累程度应该差不多。不应该都堆在同一台机器上，而其他499台机器都正常。因此，

检查系统入口流量是否过大。4.MQ数据倾斜？预计500台代理机器应该平等地共享MQ中的消息。有没有可能是数据分发出现了倾斜，导致这台机器分发的消息过多？

其他机器几乎没有消息？检查代理上游系统的代码。系统在向代理发送消息时没有自定义随机播放，因此它将使用MQ的默认selectOneMessageQueue策略。

此策略会将当前消息发送到基于索引% queue_size选择的队列。进一步观察index的逻辑，发现它在初始化时以一个随机数开始，每次访问它时都会增加1:

综合以上两点，效果是：将消息从左到右平均分配到每个队列中，并通过%实现自动循环：

总而言之，MQ的默认shuffle策略是：将消息平均划分到队列中。因此，我们可以排除我们的代理机器因为MQ发送的消息数据倾斜而堆积的可能性。5、CPU偷跑？

提示：CPU占用率表示虚拟机中运行的进程被主机上其他进程/虚拟机占用的CPU时间百分比。高CPU占用率值通常意味着虚拟机中进程的性能下降。

比如机器规格本身是4C，偷换后实际只能用2C。因此，结果是单个请求的RT没有明显变化（不同C之间的差异很小），但C的数量较少。

因此，该机器的整体吞吐量变小，消耗能力变弱，导致堆积。然而，调查发现st是正常的，并且排除了这种可能性：

6、找到线索：MQ消费场所没有变化！绕了一圈没发现什么异常点。因为问题现象是MQ累积，所以我认为可以查看中间件日志来找到线索。果然，通过定向搜索卡住机器的queueId，

发现这个队列的消费站点很久没有推广了，一直卡在某个位置：

提示：MQ拉取消息的机制是，拉取的消息将存储在内存中容量为1000的缓存中，然后内存中的消息将由消费线程消费。当缓存已满时，不会将其从队列中取出。

因此，不确定本地缓存是否总是满的，因为代理消耗停止或消耗极其缓慢，因此MQ将停止将消息拉至队列，因此偏移量没有改变。但是如上所述，

无论从MQ控制台、系统监控指示灯和机器日志来看，这台机器都是正常的，与其他机器没有什么不同。那为什么机器的消耗点就是不动，导致堆积越来越严重呢？7.找到根本原因：一个消费者线程被卡住了。

提示：对于本地缓存中的消息，MQ将打开多个线程（线程数量由用户指定）来拉取消费。而且为了保证消息不丢失，offset只记录第一条消息。

首先，这个机制是合理的。因为在至少一次语义下，消息允许被多次消费但不允许被错过。假设现在有两个线程同时提取第一条和第二条消息，后一条消息先被执行。

因为前一条消息的执行可能异常，所以不能直接用后一条消息的偏移量更新偏移量，否则消费失败的消息就找不回来了。因此，

消费站点偏移的含义是该位置及其之前的所有消息都已被正确消费（有点类似于Flink的水印机制）。根据上述机制，回到这个问题，

如果该代理机器的任何一个MQ消费线程被阻塞，整个队列的消费站点将始终停留在与阻塞消息对应的偏移量处。此时，尽管其他线程继续正常消耗，

但它不能提前抵消。另一方面，由于上游仍在向队列发送消息，消息只能进入和退出，累积量=最新进入消息的偏移量-消费点偏移量只增不减。

反映在中控台上就是堆积越来越严重了！基于此分析，通过jstack检查所有MQ消费线程的状态，确实发现线程251始终处于可运行状态！

有理由怀疑这是一个卡住的消费者线程。因为在代理系统的业务场景中，大部分耗时都是在RPC同步调用深度学习模型的过程中（快了几百毫秒，也许慢了几秒），

因此，线程大部分时间应该处于等待状态，等待同步调用返回！而这里的251线程总是可运行的，肯定有问题。进一步打印详细信息，找到线程被卡住的具体代码位置：

这里，getImageDetail方法将通过HTTP下载图片，以便深度学习模型可以做出估计。其次，搜索业务日志也发现找不到该线程的日志。因为昨晚10点被困后，

该线程不会生成任何新日志。随着机器日志的滚动清理，所有日志现在都将包含该线程的内容：

至此，代理系统中个别机器出现严重MQ堆积问题的根本原因找到了：该机器的一个消费线程在通过HTTP下载图片时已被卡住，导致整个队列的消费站点无法推进，从而继续堆积。

8.为什么HTTP总是卡死？此时，虽然积累的根本原因已经找到，并且经过尝试，可以在短时间内通过应用程序重启/机器离线的方式暂时解决。但从长远来看，隐患总是存在的，因为近期每隔几天就会不时出现同样的问题。

有必要彻底找出HTTP阻塞的根本原因，以便从根本上解决这一问题。经过几次蹲守，我发现了一些会导致线程卡住的图片URL。我发现不是内部图片地址，地址打不开，也不是jpg结尾的格式：

https://ju1.vmhealthy.cnhttps://978.vmhealthy.cnhttps://xiong.bhjgkjhhb.shop但问题是，即便是输入这种打不开的极端URL，

由于我们对HttpClient 设置了5s 超时，顶多也就会卡住5s 啊，为什么好像超时机制没生效，一直卡住了十多个小时？

Tip：HTTP 会需要先建立连接，再进行数据传输。由此对应着两种超时：1、连接超时，针对建立连接这一阶段；2、socket 超时，针对数据传输过程中的超时。

经检查，目前代码中只设置了socket timeout，没设置connection timeout，因此怀疑上面那些请求直接卡在了前面的connect 阶段，

而又由于没设置connect 超时，所以请求一直卡住？然而，修改代码后重新尝试请求这些地址，发现还是会一直卡住，需要进一步排查。9、找到HTTP 卡住的根因

Tip：找到根因。在特定版本的HttpClient 中，基于SSL 连接的请求有bug：实际会先尝试建立连接，再设置超时时长，先后顺序反了。因此若在连接时卡住，超时还没来得及设置，

本次HTTP 请求就会一直卡下去.

再回过头看上面那几个卡住的URL，无一例外都是https开头的！破案了，原来是项目用的HttpClient 有bug。在升级了HttpClient 版本后，重新在预发构造测试请求，

线程不再卡住，且全部发到线上环境后，近期频繁出现的少量机器堆积问题再也没有出现过。至此，经历了许多曲折，问题终于彻底解决。2.4 通盘梳理从最外层Proxy 个别机器堆积的表象，

不断往内层排查中经历了许多关键节点，直到找到根源。目前所有问题已全部查清，现在站在上帝视角，从内向外完整的因果链条如下：-- Proxy 系统会基于HttpClient 去下载图片，

然后调用图像类模型做预估-- 所使用HttpClient 版本有bug，在访问https 地址时，超时不会生效-- Proxy 系统恰好遇到了少量https 地址，且恰好卡住（低概率事件），

于是会因超时不生效而一直卡住-- 基于MQ 的At Least Once 机制，

消费位点将一直停留在卡住消息所对应的offset 处（尽管其余线程都在正常消费）-- 上游系统仍然源源不断向Proxy 发送消息，于是消息只进不出，堆积越来越严重-- 堆积量超过一定阈值，

触发监控报警，用户察觉

三、总结本次问题的排查过程略微曲折，但也能学到不少共性的方法论和经验教训，在本节统一提炼归纳：

善用排查工具：学会使用jstack、Arthas、jprofile 等利器，在不同情景下善用合适的工具，能高效地发现异常点，找到线索，

从而逐步找到问题根因；异常的敏感度：有时一些发现问题的线索其实早早就展现在了眼前，但当时因为各种原因（比如最初对问题的疑团很多，未排除的干扰因素多等）导致并不能立马发现线索，

还需多积累经验；广泛查阅资料：除了内网查文档、找相关人员咨询，还要学会去外部英文网站查第一手资料；困难时要坚持：对一些隐蔽的问题，很多时候不是出现一次就能立马发现问题并解决的。

可能需要前前后后经历了几轮排查，最终才能找到根因；补充底层知识：如果最开始能知道MQ 的offset 机制，一些问题就不会走那么多弯路了。后续在用各种中间件的过程中，

要多去了解它们的底层原理；没有玄学问题：代码和机器不会骗人，一切“玄学”问题的背后，都有一套严谨又合理的成因；

参考：HttpClient Bug：https://issues.apache.org/jira/browse/HTTPCLIENT-1478Connection timeout v.s Socket timeout：https://stackoverflow.com/questions/7360520/connectiontimeout-versus-sockettimeout