这篇文章主要介绍“Dubbo线程池事故排查的方法步骤”，在日常操作中，相信很多人在Dubbo线程池事故排查的方法步骤问题上存在疑惑，小编查阅了各式资料，整理出简单好用的操作方法，希望对大家解答”Dubbo线程池事故排查的方法步骤”的疑惑有所帮助！接下来，请跟着小编一起来学习吧！
问题
在一天早上突然手机收到公司服务告警短信，线程池耗尽了?在去公司的路上首先回想的就是最近公司有活动?流量突增?大早上就有人在发布系统?还是某歪趁我不在又点坏了我的系统?
怀着种种思考在公司的群里看着同步信息，以上种种可能都被反驳!!!
以下就是当时的告警信息：
RejectedExecutionException:Thread pool is EXHAUSTED （线程池耗尽了）! Thread Name: DubboServerHandler-xx.xx.xxx:2201, Pool Size: 300 (active: 283, core: 300, max: 300, largest: 300)
Q：这个问题怎么出现的呢?是不是我们扩大线程池就能解决问题呢?dubbo里面线程池默认实现是什么呢?
A：我们在排查问题的时候一定要有一种必须查出因果关系的思想才能对自己有一定的提升，凭借着这种思想我们一步一步向下揭开谜底。
带着问题，接下来我们去查看dubbo的代码配置，了解dubbo底层实现，只有了解底层实现我们才能更加准确的发现问题，处理问题，提升自己......
首先我们看下我们代码配置：
<dubbo:protocol name="dubbo" port="${service.protocol.dubbo.port}" threads="${service.protocol.dubbo.threads}" register="${service.protocol.dubbo.register}" />从抛出的异常上我们已经设置的线程池的大小为300了
言归正传我们开始看下撸点源码，这里我们以 2.7.19的版本为例
我们可以看到ThreadPool接口是个扩展点，然后默认实现是fixed，然后里面有个getExecutor方法，被@Adaptive注解修饰。
在dubbo中ThreadPool有4个实现类
1.CachedThreadPool 缓存线程池，超过keepAliveTime时间删除，使用的时候再创建
2.FixedThreadPool 固定线程数量线程池，一旦建立，一直持有。
3.LimitedThreadPool 可伸缩线程池，线程只增长不收缩。
4.EagerThreadPool 当core线程数忙的时候，创建新线程，而不是将任务放入阻塞队列。这个使用自己队列TaskQueue。
这里我们就直接看默认实现FixedThreadPool
异常处理机制
从代码中我们可以发现：
dubbo线程池采用jdk的ThreadPoolExecutor，默认threads数为200，并且默认采用了SynchronousQueue队列，而如果用户配置的队列长度大于0时，则会采用LinkedBlockingQueue队列。
如果某个线程因为执行异常而结束，那么线程池会添加一个新的线程。
所以由于dubbo默认采用了直接提交的SynchronousQueue工作队列，所以，所有的task会直接提交给线程池中的某一worker线程，如果没有可用线程，那么会拒绝任务的处理然后抛出我们当前现在遇到的问题
以下说明下我们创建一个线程池的必要参数 ：
corePoolSize - 池中所保存的线程数，包括空闲线程。
maximumPoolSize-池中允许的最大线程数。
keepAliveTime - 当线程数大于核心时，此为终止前多余的空闲线程等待新任务的最长时间。
unit - keepAliveTime 参数的时间单位。
workQueue - 执行前用于保持任务的队列。此队列仅保持由 execute方法提交的 Runnable任务。
threadFactory - 执行程序创建新线程时使用的工厂。
handler 由于超出线程范围和队列容量而使执行被阻塞时所使用的处理程序。ThreadPoolExecutor是Executors类的底层实现。
好，看了这么多源码，从上面我们已经了解这个异常来的来源了，那是什么原因导致我遇到的这次的线程池耗尽呢?
排查思路
第一阶段：
由于10.33.xx.xxx这台机器出现线程池耗尽的时候，伴随出现了一次时间比较久的ygc;所以怀疑是因为ygc时间较长，导致了机器资源紧张，从而拖垮了线程池;
2021-03-26T10:14:45.476+0800: 64922.846: [GC (Allocation Failure) 2021-02-24T11:17:45.477+0800: 64922.847: [ParNew: 1708298K->39822K(1887488K), 3.9215459 secs] 4189242K->2521094K(5033216K), 3.9225545 secs] [Times: user=12.77 sys=0.00, real=3.92 secs]
所以就一直在思考什么原因导致YGC时间这么长：
这里给大家简单说明下为什么IO高会导致GC时间长
1.JVM GC需要通过发起系统调用write()，来记录GC行为。
2.write()调用可以被后台磁盘IO所阻塞。
3.记录GC日志属于JVM停顿的一部分，因此write()调用的时间也会被计算在JVM STW的停顿时间内。
通过GC日志可以看到新生代在进行垃圾回收的时候停顿时间是在3.92s;对于新生代空间在1.8G左右的显然是不正常的;ParNew收集器的工作过程中会出现以下步骤：
(1)标记-标记出来活着的对象 ----> (2) 将对象从eden区复制到survior区 -----> (3)清理eden区
理论上来说第三步的时间是一定的，那可能时间会比较久的要么在第一步，要么在第二步
如果是第一步标记时间过长，就意味着本次GC之前，eden区存在大量的小对象(因为eden区大小是一定的)，量级应该是正常的对象数量的数十倍
如果是第二步时间过长的话，那么存在以下可能：
1.标记完之后，eden区还有大量的对象(表现是回收之后新生代的对象占用内存仍然很大)，这个从gclog可以排除(回收之后新生代的大小还有39M)
2.标记完之后仍然有大量碎片化的小对象存在
3.YGC出发了fullGC，但是我们没有查看到有关日志
此时以上的情况都指向一种可能，那就是新生代存在大量的碎片化的小对象;
为了验证这个论据，那就只有一种办法就是去分析一下堆快照，但是我们那个时候刚好机器被重起，无法查明原因
在我们无法验证的时候，第二台机器出现了同样的问题，准备再次jump日志的时候，回过头来看了一下GC日志，发现GC正常。所以推翻阶段一结论
这里给大家介绍一些我们常用的服务器命令：
top : 这是最常用的，也是展示信息最全的，可以看到负载，内存，cpu等很多东西
比如使用top常见分析步奏：
1.top -Hp命令，查看具体是哪个线程占用率较高 2.使用printf命令查看这个线程的16进制 3.使用jstack命令查看当前线程正在执行的方法
使用jmap查看内存情况，并分析是否存在内存泄露。
jmap -heap 3331：查看java 堆(heap)使用情况
jmap -histo 3331：查看堆内存(histogram)中的对象数量及大小
jmap -histo:live 3331：JVM会先触发gc，然后再统计信息
jmap -dump:format=b,file=heapDump 3331：将内存使用的详细情况输出到文件
当然还有很多其他的命令比如 jstack,jinfo，uptime 等等很多命令。。。
开启阶段二的排查：
第二次出现异常的机器伴随着各种redis查询超时，从而导致所有的查询 都走到了DB，从而导致数据库压力大增，慢SQl告警等等。
所以又再次去查询什么原因导致我们的redis查询超时呢?
第一步肯定都是去查看redis服务的各项性能指标是不是出现异常，结果也没有很大的变化，那么问题肯定是在服务器本身.
查看本身指标发现：
那就是在报警时间段，cpu，cpu_iowait, 指标会飙升，磁盘IO则呈现不间断锯齿状，其余指标基本不存在波动
但是什么原因引起的CPU波动呢?cpu波动跟线程池耗尽之间又有什么因果关系呢?
因此似乎得到了答案磁盘IO较高，导致cpu_iowait变高，cpu等IO，瞬间分配不到时间片，rt就会抖动。
最后我们发现跟我们的磁盘IO较高的原因时又跟我们的日志采集系统有关，相信现在很大一部分的公司都会用TRACE作为服务的全程链路最终管理。
再采用异步方式把记录在内存中trace日志一次性写入磁盘，所以会出现IO抖动。
接下来我们看下trace 他到底是怎么工作的。
重点： trace 模块将上述信息组织成二进制格式写入内存中，直到停止 trace 跟踪，才将上述内存中的信息导出为二进制文件
这个只是给大家提供一个思路，每个人遇到问题或者场景都不一样那得到的结论也都不一样，只能是给大家作为一个参考吧!!!
到此，关于“Dubbo线程池事故排查的方法步骤”的学习就结束了，希望能够解决大家的疑惑。理论与实践的搭配能更好的帮助大家学习，快去试试吧！若想继续学习更多相关知识，请继续关注天达云网站，小编会继续努力为大家带来更多实用的文章！