记一次服务器正常但tomcat无响应问题

ゞ浴缸里的玫瑰 2023-06-20 12:58 9阅读 0赞

# 缘起 #

日前有客户反应，系统出现网页打不开，无响应的问题，经过了一天的排查已经定位到问题所在，特此记录，以备查阅。

# 初步排查过程 #

网页打不开，第一时间怀疑的是会不会服务器被重启了或者tomcat的进程被关了之类的情况，所以先排查服务的运行情况，连上服务器后采用如下命令。

ps -ef|grep java

![在这里插入图片描述][20191210151829541.png]  
发现tomcat服务正常  
既然服务是正常的，那么会不会是内存或者CPU被耗尽导致的呢？通过如下命令查看内存占用情况

free -g

![在这里插入图片描述][20191210151845651.png]  
发现内存正常  
通过如下命令查看cpu占用情况

top -bn 1 -i -c

![在这里插入图片描述][20191210152146813.png]  
发现cpu占用67.5%。虽然有点高，但也没爆。  
那么这就很奇怪了，进程，内存，cpu均正常，但是tomcat却没有响应了。  
**这个时候基本上可以肯定不是服务器的问题，而是java程序本身的问题了，比如说tomcat线程池被占满，或者说内存泄漏等情况**

# 最终排查过程 #

先分析堆内存占用情况

我们前面已经通过如下命令取到java进程的PID为12945

ps -ef|grep java

![在这里插入图片描述][20191210151829541.png]  
接下来通过jmap工具分析堆内存情况

jmap -heap 12945

![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI_size_16_color_FFFFFF_t_70]  
果然发现问题了，老年代占用居然达到了99.99%。要了解为什么老年代会到99.99%需要先了解一下关于分代回收算法的的基本知识。

在 Java 中，堆被划分成两个不同的区域：新生代 ( Young )、老年代 ( Old )。新生代 ( Young ) 又被划分为三个区域：Eden、From Survivor、To Survivor。  
**新生代的回收算法：**  
每当新创建一个对象时优先在Eden区分配，而此时Eden区内存不足的时候，就会进行Minor GC，然后Eden区仍然活着的对象会复制到to Survivor区，而from Survivor区中年龄超过阀值的对象会保存到老年代中，没有超过阀值的对象会保存到to Survivor区中，然后to Survivor区和from Survivor区互换位置，保证每次都有一块Survivor区是空闲的。  
**老年代的回收算法：**  
在进行Minor GC之前，JVM会先检查老年代最大可用连续空间是否大于新生代历次晋升到老年代对象的平均大小，如果大于，将尝试进行一次Minor GC，否则就进行Full GC（全局GC）。说人话就是老年代会根据以前新生代给的数据量的一个平均值来评估剩下的空间能不能放下下一次新生代给的数据量，如果不能那就要先回收一下自己。

**为什么老年代没有被回收？**  
老年代是99.99%，很显然是老年代的内存没有回收掉，那么为什么没有回收掉呢？我们先看看GC线程的情况

jstat -gcutil 12945 1000 10

1000为统计的间隔，单位为毫秒，10为统计的次数，输出如下：  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI_size_16_color_FFFFFF_t_70 1]  
从输出中同样可以看到E（Eden）区与O（Old）区都已经被占满了。其他几个输出项的含义如下：

*  YGC: 从启动到采样时Young Generation GC的次数
 *  YGCT: 从启动到采样时Young Generation GC所用的时间 (s).
 *  FGC: 从启动到采样时Old Generation GC的次数.
 *  FGCT: 从启动到采样时Old Generation GC所用的时间 (s).
 *  GCT: 从启动到采样时GC所用的总时间 (s).

可以看到JVM一直在尝试回收老年代，但是一直没能将内存回收回来。

接下来看看java进程的pid的cpu情况

top -p 12945 -H

![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI_size_16_color_FFFFFF_t_70 2]  
\-p用于指定进程，-H用于获取每个线程的信息，从top输出的内容，可以看到有很多线程占用了非常高的CPU：  
**高占用cpu的线程在干嘛？**  
jstack是java虚拟机自带的一种堆栈跟踪工具，用于打印出给定的java进程ID或core file或远程调试服务的Java堆栈信息。使用下面命令，将java进程的堆栈信息打印到文件中：

jstack -l 12945 > stack.log

在线程堆栈信息中，线程id是使用十六进制来表示的。将上面几个线程的id转化为16进制然后去stack.log中搜索  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI_size_16_color_FFFFFF_t_70 3]  
可以看到这几个线程是GC线程，那么就可以确定了，回收器一直在尝试回收内存，但是因为某种原因又一直回收不掉，回收器线程就把cpu占满了。而老年代回收不掉，那么系统就没法运行，也就是表现出来cpu会占用100%并且tomcat没有响应的情况。

**为什么垃圾收集器一直在运行但老年代没法被回收？**  
要知道为什么没法被回收我们要先知道具体是哪些顽固对象导致垃圾处理器回收不掉。我们需要先把当前的堆情况导出来，然后使用工具进行分析。

jmap -dump:live,format=b,file=headInfo.hprof 12945

live这个参数表示我们需要抓取的是目前在生命周期内的内存对象，也就是说GC收不走的对象，在这种场景下，我们需要的就是这些内存的信息。

**小插曲：有些时候你使用这个命令会报错**

Unable to open socket file: target process not responding or HotSpot VM not loaded

那么这是什么原因呢？其实解决这个问题最好的办法就是程序重启。但想必你也想到了，如果程序重启的话那么当前的堆栈信息也都没有了。那么有什么好的解决办法呢？可以看看[这篇文章][Link 1]，其大意是说，java的pid文件可能已经被系统给删除了。linux系统有个删除管理机制：系统每天会用tmpwatch命令检查并删除 /tmp 下超过240小时未访问过的文件和目录。  
我们需要去修改这个机制，否则pid文件就可能被删除。  
但是：我在/etc/cron.daily下面并没有找到什么tmpwatch文件。

最终，通过百度很多文章的启示，找到了解决方案，解决方案我另起一篇文章讲述，欢迎看

[亲测解决dump导出JAVA堆内存文件报错：Unable to open socket file: target process not responding or HotSpot VM not lo][dump_JAVA_Unable to open socket file_ target process not responding or HotSpot VM not lo]

**导出分析**

生成了hprof文件后，可以拉回到本地进行分析了。生成的hprof文件会很大，我们可以先采用如下命令压缩再拉回本地

gzip -7 headInfo.hprof

\-7代表压缩比例，数值越大压缩出来的文件越小但压缩所需时间会越高，最大值为9。

拉回本地后，就可以使用VisualVM或者MemoryAnalyzer来对文件进行分析，这两个内存分析工具的下载链接我会放到文末。  
VisualVM分析得如下  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI_size_16_color_FFFFFF_t_70 4]  
可以看到主要是这些YXXXX,YXXXX的字符串占用了大量的内存，那么这些YXXXX,YXXXX是什么就是具体和你自己的业务有关的了。  
个人觉得MemoryAnalyzer更好用一点，下面重点介绍MemoryAnalyzer的分析结果  
MemoryAnalyzer分析一下得如下结果  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI_size_16_color_FFFFFF_t_70 5]  
点这里可以看到哪些东西占用了最大的内存  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI_size_16_color_FFFFFF_t_70 6]  
也可以看到是这些YXXXX,YXXXX的组合串占用了比较大的内存，那么这些YXXXX,YXXXX的组合串是哪里产生的呢？可以通过点击如下地方跟踪到具体的代码，这些代码也是可能造成内存泄漏的地方  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI_size_16_color_FFFFFF_t_70 7]  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI_size_16_color_FFFFFF_t_70 8]  
点击这里跟踪堆栈代码  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI_size_16_color_FFFFFF_t_70 9]  
这里很清晰的列出了，IncompatibilityServiceImpl这个类的combination这个方法造成了这些字符串的分配问题。我们来看这里的代码是有什么问题。

public List<String> combination(List<RecipeItem> recipeItems) { 
        List<String> list = new ArrayList<>();
        int n = recipeItems.size();
        int nbit = 1 << n;
        for (int i = 0; i < nbit; i++) { 
            StringBuilder x =new StringBuilder("");
            for (int j = 0; j < n; j++) { 
                int tmp = 1 << j;
                if ((tmp & i) != 0 && i != tmp) { 
                    x.append(",").append(recipeItems.get(j).getDrugCode());
                }
            }
            if (!"".equals(x.toString())) { 
            	list.add(x.toString().substring(1));
            }
        }
        return list;
    }

这里是一个排列组合算法，是需要把一堆的字符串排列组合，比如用户输入ABC。我需要组合成AB,AC,BC,ABC这种。

# 总结 #

问题到这里基本上全部明确了  
这个算法在需要组合的字符串量不大的时候组合的结果倒是不多，但是一旦字符串多的时候就很可怕了，组合结果将随着字符串的增多呈指数倍增长。  
我测试过，当需要组合20个字符串时，组合情况竟达到了104W之多。这么多字符组合串因为后续还需要一个个去数据库查询，会导致这个线程需要执行很久很久才能执行完毕，但是在线程执行的时候这些字符组合串对象都是不能被回收的，那么就可能导致内存被耗尽，也就是前面说显现的老年代被占满的而又没法回收的情况。

# 文章中工具的下载链接 #

[visualvm143][]  
[MemoryAnalyzer][]

参考及部分内容摘抄自：https://www.cnblogs.com/QG-whz/p/9647614.html

[20191210151829541.png]: https://img-blog.csdnimg.cn/20191210151829541.png
[20191210151845651.png]: https://img-blog.csdnimg.cn/20191210151845651.png
[20191210152146813.png]: https://img-blog.csdnimg.cn/20191210152146813.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI_size_16_color_FFFFFF_t_70]: https://img-blog.csdnimg.cn/20191210152755131.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI=,size_16,color_FFFFFF,t_70
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI_size_16_color_FFFFFF_t_70 1]: https://img-blog.csdnimg.cn/2019121015451688.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI=,size_16,color_FFFFFF,t_70
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI_size_16_color_FFFFFF_t_70 2]: https://img-blog.csdnimg.cn/20191210154844681.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI=,size_16,color_FFFFFF,t_70
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI_size_16_color_FFFFFF_t_70 3]: https://img-blog.csdnimg.cn/20191210155211321.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI=,size_16,color_FFFFFF,t_70
[Link 1]: https://blog.51cto.com/zhangshaoxiong/1310166
[dump_JAVA_Unable to open socket file_ target process not responding or HotSpot VM not lo]: https://bxoon.blog.csdn.net/article/details/111881528
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI_size_16_color_FFFFFF_t_70 4]: https://img-blog.csdnimg.cn/20191210162703375.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI=,size_16,color_FFFFFF,t_70
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI_size_16_color_FFFFFF_t_70 5]: https://img-blog.csdnimg.cn/20191210163148321.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI=,size_16,color_FFFFFF,t_70
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI_size_16_color_FFFFFF_t_70 6]: https://img-blog.csdnimg.cn/2019121016333120.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI=,size_16,color_FFFFFF,t_70
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI_size_16_color_FFFFFF_t_70 7]: https://img-blog.csdnimg.cn/20191210163442593.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI=,size_16,color_FFFFFF,t_70
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI_size_16_color_FFFFFF_t_70 8]: https://img-blog.csdnimg.cn/20191210163621489.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI=,size_16,color_FFFFFF,t_70
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI_size_16_color_FFFFFF_t_70 9]: https://img-blog.csdnimg.cn/2019121016373518.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3FxMzI5MzM0MzI=,size_16,color_FFFFFF,t_70
[visualvm143]: https://download.csdn.net/download/qq32933432/12024187
[MemoryAnalyzer]: https://download.csdn.net/download/qq32933432/12024181