记一次线上tomcat服务器运行正常但是无响应问题排查

tomcat服务器无响应问题排查

• 事故现象

• 问题排查

• 首先查看了下Tomcat是否宕机

• 分析NGINX

• 分析问题

• 新的线索：MySQL异常信息

• 验证第一次分析结果

• 第二个月又一次出现假死

• 再次分析问题

• 解决并验证

事故现象

最近一段时间，请假系统每隔几天就会出现服务器无响应情况，访问URL后转半天，然后就显示请求失败。出现大量NGINX请求超时。重启服务器后业务又可以恢复正常，出问题又是不定时出现，没有一个确定的时间节点。

问题排查

首先查看了下Tomcat是否宕机

查看进程
ps指令查看进程存在，说明Tomcat并没有挂掉

查看Tomcat日志
catalina.out和localhost_access_log日志定格到某一时刻，并没有报错，也没有新的日志产生
查看CPU和内存
top指令查看，内存和cpu也没有异常情况

jinfo -flags 15183查看启动参数

 -XX:CICompilerCount=4 -XX:+DisableExplicitGC -XX:InitialHeapSize=262144000 -XX:MaxHeapSize=4164943872 -XX:MaxNewSize=1388314624 -XX:MaxTenuringThreshold=15 -XX:MinHeapDeltaBytes=524288 -XX:NewRatio=2 -XX:NewSize=87031808 -XX:OldSize=175112192 -XX:SurvivorRatio=10 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC

jmap指令生成dump 堆快照 堆内存显示正常

可以用 jvisualvm.exe 进行内存分析，或者采用 Eclipse Memory Analysis Tools (MAT)这个工具

jmap -dump:format=b,file=/neworiental/temp/dump.bin 15183

使用jstack 15183查看，没有发现死锁信息

分析NGINX

网页显示NGINX超时，说明NGINX是通的，可以正常访问，但是Tomcat没反应，猜测可能是NGINX到Tomcat通讯有问题
netstate -ano指令查看连接信息，发现大量NGINX到Tomcat请求处于time_wait状态,还有少部分Tomcat到MySQL的连接
netstat -n | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}'查看各状态连接数

netstat -n | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}'

返回结果示例：

TIME_WAIT 1057

分析问题

Tomcat使用的是默认配置，由于Tomcat默认并发连接数是200左右，所以超过的请求都被拒绝。
本来以为找到原因了，想着把这个值调大，就解决问题了，但是又仔细想了想，按道理系统的瞬时访问量不可能到200，总共6000员工，请假系统同时点击瞬时业务量达不到那么大量，所以根本原因不在这里，这时候分析陷入了僵局，思路有点断了。于是重启了服务器。

新的线索：MySQL异常信息

这时候我重启了服务器，突然有了新的线索，这次发现shutdown时日志动了，这时候出了一大堆MySQL断开的异常，结合上面netstat信息也存在很多MySQL连接，猜测会不会是MySQL慢查询语句导致请求不能及时返回，大量请求堆积导致Tomcat请求数量超过最大限制，出现假死状态。

验证第一次分析结果

系统是另一个人做的所以不知道哪些地方有慢查询语句，只能借助软件分析，这里使用durid连接池分析页面，通过SQL界面发现确实有好多慢查询语句，找到所有查询时间超过2秒的查询语录，在项目中找到并优化，优化过程有索引优化和查询语句结构优化，这里就不展开说了。

上线验证是否解决问题，运行了一个月没问题，第一次算是解决了问题。

第二个月又一次出现假死

本来以为问题已经解决，可是到了第二个月，又出现服务器假死情况，这次第一反应是不是还有慢查询上次没发现，想打开durid页面看看还有什么慢查询语句，但是出现问题时所有请求都被Tomcat拒之门外，durid页面也打不开。

再次分析问题

所以只好去MySQL查看连接状态，使用show PROCESSLIST指令查看链接状态，发现连接数只有5个，这时候想会不会是瞬时请求超过五个，连接数太少导致请求处理不过来，导致MySQL新请求被排队等待，从而出现阻塞，最终导致Tomcat连接数超载。于是打开MySQL配置文件，发现配置文件使用的是demo配置，最大连接数是5个。

[root@localhost][(none)]>show PROCESSLIST；
+--------+-----------------+--------------------+---------------+---------+----------+------------------------+------------------+
| Id     | User            | Host               | db            | Command | Time     | State                  | Info             |
+--------+-----------------+--------------------+---------------+---------+----------+------------------------+------------------+
| 158280 | leave_db        | 127.0.0.1:60594    | leaveapproval | Sleep   |        6 |                        | NULL             |
| 158282 | leave_db        | 127.0.0.1:60634    | leaveapproval | Sleep   |        6 |                        | NULL             |
| 158306 | leave_db        | 127.0.0.1:47244    | leaveapproval | Sleep   |        6 |                        | NULL             |
| 158309 | leave_db        | 127.0.0.1:48752    | leaveapproval | Sleep   |       48 |                        | NULL             |
| 158312 | leave_db        | 127.0.0.1:51522    | leaveapproval | Sleep   |        6 |                        | NULL             |
| 158315 | root            | localhost          | NULL          | Query   |        0 | starting               | show PROCESSLIST |
+--------+-----------------+--------------------+---------------+---------+----------+------------------------+------------------+
14 rows in set (0.00 sec)

解决并验证

打开MySQL配置文件，最大连接数是5个，调到50后上线验证，运行几个月后没有再出现，问题告一段落。打开durid页面查看峰值最大连接数是50，这里也验证了之前5个肯定是不够用的，这里为了保险起见改成了100个最大连接数，运行半年后发现偶尔数据库最大连接数会达到75。