JVM-线程暴增问题排查-真实案例

1、案发现场的事情经过：

  由于一些特殊缘由项目早上9点左右集群重启了一下，结果公司的监控平台发来报警线程数过多（如图1）、到了中午12点半左右有所降低下降了很多（图2）、晚上的时候由于基本没人用回到了正常水平。比对了下正常情况的线程数明显不对（正常情况如图3）

图1

图2

 

图3

 

这种情况就比较有意思，引起了我的好奇，由于是重启，排除最近代码导致的可能，于是打算探究一番。

以下是我排查的思路和过程，基本适用于jvm排查多线程问题的大部分场景：

1、预先分析-定位大致方向 

  排除掉最近代码上线导致的可能后，那么诱发线程暴增的原因只有可能是重启，先分析业务场景，平时上线都是晚上调用量较少的时候，早上9点半启动后便出现了明显的增高，并且是调用量较多的时间点，12点半由于是午休时间，调用量少，线程数明显下降，到了晚上趋于正常，有可能是重启导致某个业务短时间内处理不过来发生了阻塞，导致线程激增。

2、使用方便的分析工具-截取jvm日志信息

本次使用了两个jvm分析工具以及java自带的jvm的基本工具：

（一）首先上服务器通过jvm的分析工具（jmap jstack指令）截取两个jvm文件如图4（我是在中午11点左右截取的正好在线程暴增的那段时间，你应该懂的）：

      jstack文件 (记录了jvm线程运行状态，建议截取前后相隔几秒两个时间点的文件，好做前后对比，并把这两个文件打包到zip)

      jmap_dump文件（记录了对象信息文件）

图4

 

（二）线上线程分析网址：https://gceasy.io/index.jsp （真是好用呀，基本靠他就可以了）

（三）VisualVM 软件（辅助分析，下载链接百度吧）工具介绍：http://www.belonk.com/c/visualvm_intro.html

3、分析步骤

（一）首先将打包好的间隔几秒的jstack zip文件上传到线上线程分析网址获取分析报告，如图（ps:分析报告中的线程数比图1多，特殊原因请忽略）：

图5

图6

 

  看到图5左上角分别有两个时间点的对比报告和两个时间点线程的分析报告，点开其中一个时间点的线程分析报告发现TIMED_WAITING的线程数量多达633个，很显然这些就是导致线程数量暴增的源头，其中大部分是tomcat中卡特琳娜（分析报告的英文被我直接中文翻译了 呵呵 英语水平不行）相关的线程，点开找到其中的一个线程信息，没有很多业务信息，这个时候就需要用到VisualVM 软件辅助分析下对应线程涉及到的对象信息

（二）用VisualVM 软件 load打开jmap_dump.hprof（这个文件比较大，建议用VisualVM 软件本地分析），分析Object。

图7

 

   如图7，用过滤器过滤Thread 发现tomcat中的TaskThread数量有599个，正好是分析报告中定时等待的599个卡特琳娜线程数，找到其中一个线程的引用，发现了导致了线程数暴增的源头-jedis线程池（基本到这分析工具已经找到了问题，最后发现是由于项目由于设置的redis线程较大，且重启后，由于某个设计问题，导致redis处理不过来，线程池持续扩大新的等待线程，导致线程数过多告警）

  最后再来夸一夸线上线程分析网址：在对比报告中，网址直接告诉了导致线程增多的原因，还给出了一些建议（这也是我建议大家截取前后两个时间段的jstack文件并打包上传的原因）。点开图8中提示的阻塞线程再点开图9中的问题提示就可以看到建议了 

图8

图9

 

图10