通过 thread dump 分析找到高CPU耗用与内存溢出的Java代码

时间:2022-01-23 21:55:44

http://heylinux.com/archives/1085.html通过 thread dump 分析找到高CPU耗用与内存溢出的Java代码

首先,要感谢我的好朋友 钊花 的经验分享。

相信大家在实际的工作当中,肯定会遇到由代码所导致的高CPU耗用以及内存溢出的情况。
通常这种情况发生时,我们会认为这些问题理所当然的该由开发人员自己去解决,因为操作系统环境是没有任何问题的。

但实际上,我们是可以帮助他们的,效果好的话还可以定位到具体出问题的代码行数,思路如下:
1.通过对CPU与内存的耗用情况判断是否存在问题;
2.通过top命令找到可疑的线程的ID;
3.确认应用服务器的console信息的输出位置;
4.通过kill -3 ID 的方式获取thread dump信息;
5.备份console日志,并通过线程ID检查与代码相关的信息。

下面,我们开始具体的操作过程:

1.通过对CPU与内存的耗用情况判断是否存在问题;
判断CPU可以直接在top中查看CPU的 %us 数值就可以了,通常在50%以下都算正常,一旦超过60%甚至高到80-90且稳居不下,那么就肯定存在问题了;
判断内存时需要注意的是,直接看第一行Mem:的used数值是不准确的,因为通常在运行一段时间后,这个值都会非常大,这是因为Linux对内存的使用理念“内存就是拿来用的”,它会将空闲的内存尽可能的用于缓存,来提升性能,所以我们应该更多的参考 -/+ buffers/cache: 这一行的used数值,如果该值与第一行的used数值很接近且与内存总量相差很少的话,那么内存才算处于紧张的状态;
虚拟内存的耗用也值得参考,Linux只有在内存确实不够用的情况下才会大量使用虚拟内存,如果虚拟内存使用值为0或者100兆左右,那么可以确定物理内存尚且充足;
系统负载的数值也很值得参考,即top中的 load average,通常小于 1 代表非常良好,1-5之间代表正常,大于5 则表明系统处于负载的状态,超出的数值越大负载越大。

2.通过top命令找到可疑的线程的ID;
执行top命令,在这个Linux的“任务管理器”中输入大写的“H”来打开线程模式,然后所有线程会默认以CPU耗用高低排序;
如果想以内存进行排序,再敲入大写的“M”即可,其中“RES”看到的就是物理内存的耗用大小,但由于线程的共享内存原理,我们看到的每个线程的内存大小都和他们所属进程是一样的。

3.确认应用服务器的console信息的输出位置;
通常来说,应用服务器的console信息都会输出到log当中,比如Tomcat会输出到catalina.out文件中。
但jboss与weblogic就需要进行一些修改设置才行,其中:
jboss如果使用了官方的启动脚本,则需要修改启动脚本中的如下两行中的 /dev/null,将其改为指定的log文件位置,如 /opt/jboss_console.log,再重启jboss即可。
---------------------------------------------------------------------
JBOSS_CONSOLE="/dev/null"

JBOSS_CONSOLE=${JBOSS_CONSOLE:-"/dev/null"}
---------------------------------------------------------------------

weblogic则需要在console管理界面中的“域结构”-“环境”-“区域”-“服务器”-“AdminServer”-“日志记录”-“高级”- 勾选“已启动重定向标准输出日志记录”,再点击“激活更改”并重启weblogic即可。然后所有的console信息都会输出到logs目录下的AdminServer.log文件中。

4.通过kill -3 ID 的方式获取thread dump信息;
确认了应用服务器的console信息输出,并找到可疑的线程ID之后,执行 kill -3 ID 即可将该线程这一刻的所有thread dump信息输出到log当中。
建议多执行几次该命令,以便获取充足的信息。

5.备份console日志,并通过线程ID检查与代码相关的信息。
执行了thread dump信息输出之后,立刻使用cp命令备份log文件;
将log文件下载到本地,将进程ID换算成为十六进制,比如 29433 换算为十六进制就是 72f9;
打开log文件(建议使用UE或Notepad++等编辑器),搜索包含 72f9 的相关信息,然后仔细检查相关代码。

以我的实际情况为例:
下面这一段信息就包含了“nid=0x72f9”,表明与进程29433相关,所提到的 JIoEndpoint.java 则是实际的代码文件,后面的 442 则代表具体的行数。
---------------------------------------------------------------------
"http-0.0.0.0-80-78" daemon prio=10 tid=0x00000000686db800 nid=0x72f9 in Object.wait() [0x000000004cea6000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00002aab0bccd5b8> (a org.apache.tomcat.util.net.JIoEndpoint$Worker)
at java.lang.Object.wait(Object.java:485)
at org.apache.tomcat.util.net.JIoEndpoint$Worker.await(JIoEndpoint.java:416)
- locked <0x00002aab0bccd5b8> (a org.apache.tomcat.util.net.JIoEndpoint$Worker)
at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:442)
at java.lang.Thread.run(Thread.java:619)
---------------------------------------------------------------------

到此,实际的工作才刚刚开始,需要开发人员仔细检查所有类似的信息,然后找出有问题的代码。

有资料说,thread dump 的作用其实还有很多,可以从中发现很多应用程序的运行问题,比如死锁等;且有一个Eclipse插件的可视化分析工具“lockness” 可以对该类日志进行更专业的分析。
关于这个话题文章链接