最近写了一个多线程程序,并发量峰值有五六千,甚至八九千个线程。经过几番调试,程序终于能够正常运行起来了,而实际上“正常运行”的背后却是“暗藏玄机”。在程序运行4、5个小时之后,会发现电脑机箱非常热,风扇转地异常快。打开任务管理器,发现程序的CPU飙到了90%上下,内存占用4G左右。程序看似正常,但检查log文件就会发现有问题,数据丢失地非常多。
我猜测可能是因为CPU被占满,线程切换不过来而导致的数据丢失。那么为什么CPU会占满呢?在网上查了无数资料后,开始我的找bug路程了:
1、利用任务管理器或者jps命令找到我的程序的进程ID
在cmd控制台下输入jps命令,即可列出当前电脑运行的java程序的所有进程,我的程序的进程ID为26028
2、利用jstack命令列出进程的所有信息
使用命令jstack 26028 > 26028.txt列出进程ID为26028的进程信息,并输出到26028.txt文本文件中。
之后打开这个文件可以看到当前进程的所有线程信息,包括线程的状态、线程的ID号以及堆栈信息等。
在文件的最后,我们会看到几个负责GC的线程,nid就是线程的ID:
3、使用pslist工具查看进程的所有线程的详细信息
在cmd控制台输入pslist,如果命令不被识别,则表示当前电脑上没有安装pslist这个工具,可以到windows官方网站:
https://technet.microsoft.com/en-us/sysinternals/bb896682.aspx下载,下载完成后将其解压到C:\Windows\System32路径下即可使用,或者将其配置到环境变量中亦可。
安装完成后,使用pslist -dmx 26028 > 26028_pslist.txt命令,可以列出进程ID为26028的进程下的所有线程的详细信息(线程ID、上下文切换,状态等)。
打开输出的文件,可以看到:
从这个文件所列的信息中,我们可以找到最耗资源的线程。然后将其Tid(线程ID)转换成十六进制(直接利用windows下的计算器即可),到使用jstack命令产生的文件中查找,可以查到具体哪一个线程在干什么,为什么这么耗资源?
最后,我发现我的程序最耗资源的线程是所有GC线程,而程序中我的工作线程基本上都处于阻塞状态(以上截图并没有体现,进程26028是正常运行时我截的图)。那么为什么GC这么耗资源呢?一开始我认为是哪一个资源忘记释放了,于是我将打开的字节流、socket资源等都确认关闭了一遍。可是重新运行程序4、5个小时之后依然出现了同样的问题。显然问题并没有解决。
4、jmap+MAT分析
MAT工具的安装以及使用,网上有很多资料,这里就不做赘述了。
运行程序,当问题出现时,使用jmap指令将内存dump到文件,命令是:jmap -dump:format=b,file=jmap.bin 26028.
然后使用MAT工具加载该dump文件即jmap.bin,进行分析。
最后发现有一种数据库连接对象在内存中积累,占据了将近3G的内存,奇怪的是这段代码我在很多程序中复用过,都没有出现过问题。所以我判断应该是由于高并发造成的问题,数据库可能承受不了这么大的压力。
我将存入数据库的代码先注释掉,改成存储到文件之后,就一切正常了。
好了,bug是找到了,接下来我该去看看高并发的数据库设计了。
接下来我再介绍调bug过程中用到的几款工具。
5、jconsole和jvisualvm工具
这两个工具都是JDK自带的监控java程序的工具,可以监控本地进程和远程进程。jvisualvm提供的信息更多一点。
直接在cmd控制台输入jconsole和jvisualvm就可以调出这两个工具。
jconsole的界面如下:
jvisualvm的界面如下:
6、windows提供的process explorer工具
该工具可以到网上下载,它提供比任务管理器更详细的进程信息,并且可以查看每个进程下的线程:
————————————————
版权声明:本文为CSDN博主「KLeonard」的原创文章,遵循CC 4.0 BY-SA版权协议,转载请附上原文出处链接及本声明。
原文链接:https://blog.csdn.net/gavin_john/article/details/52458542