JAVA进程CPU负载过高导致问题分析

问题描述

在测试环境发现页面打开速度越来越慢，特别卡。反馈后到服务器排查，发现当前java进程的CPU占用率达到了1000%多。然后进行后续排查。

问题排查

CPU和内存占用问题排查

通过 top 命令查看CPU和内存的占用情况。能看到具体各个进程的CPU使用情况。

通过top命令，发现PID，10520 的Java进程占用CPU高达900%，出现故障。

查看进程的执行文件

通过top命令获取到占用CPU较高的进程号之后，需要了解是哪个程序占用的。

ll /proc/10520

ll /proc/10520/exe

通过上面命令可以看到指定进程号 10520 的启动文件。

进一步排查

找到该进程后，如何定位具体线程或代码呢，首先显示线程列表，并按照CPU占用高的线程排序：

ps -mp 10520 -o THREAD,tid,time | sort -rn | head -n 10

结果

USER %CPU PRI SCNT WCHAN USER SYSTEM TID TIME
ubox 88.9 19 – futex_ – – 83032 08:21:49
ubox 88.9 19 – – – – 83031 08:21:49
ubox 88.9 19 – – – – 83030 08:21:49
ubox 88.9 19 – – – – 83028 08:21:49
ubox 88.9 19 – – – – 83027 08:21:49
ubox 88.9 19 – – – – 83025 08:21:49
ubox 88.9 19 – – – – 83024 08:21:49
ubox 88.9 19 – – – – 83023 08:21:49
ubox 712 – – – – – – 2-18:57:53

找到了耗时最高的线程83032，占用CPU时间超过8小时了！

线程ID转换为16进制

将需要的线程ID转换为16进制格式：

printf "%x\n" 83032

结果

14458

最后打印线程的堆栈信息

jstack 10520 | grep 14458 -A 50

显示内容也许GC进程，也许是正在执行的代码块。依据此再深度排查。

问题结论

最终发现的原因是，在一个列表查询中，有几个大文本字段被查询出来，导致内存占用过多引发频繁GC。最终修改SQL语句，将大文本字段从SQL中移除（列表中也不显示此字段，只是查询习惯写出来而已）。