Java进程运行时堆栈内存、线程使用情况的分析方法

（图1）CPU使用率图

不过当晚的并发量并没有比平时高出多少。 为什么CPU会突然爆炸呢？ 带着这个问题，我踏上了排查之路。

首先查看相关错误日志，发现故障期间出现大量ckv请求超时。 不过，请求超时并不是ckv的问题，而是ckv请求没有发出去。 那么，为什么ckv请求没有发出去呢？ 日志没有向我提供任何更多信息。

如果你想学习Java工程、高性能和分布式，就简单解释一下。 对微服务、Netty源码分析感兴趣的朋友可以加入我的Java高级交流：群里有阿里巴巴大牛直播讲解技术，还有Java大规模互联网技术的视频免费分享给大家。

于是，我在Java服务上启用了JMX，并在本地使用它来观察Java进程运行时的堆栈内存和线程使用情况。 JMX（Java，Java ）是Java平台上的一个框架，嵌入了对应用程序、设备、系统等的管理功能； 它是JDK内置的性能分析工具，位于JDK根目录的bin文件夹下。 可以通过 JMX 从 Java 程序中获取运行时实时数据来进行动态性能分析，如图 2 所示：

（图二）

通过观察Heap内存的使用情况，我们发现它增长缓慢，并且每隔很短的时间就会被GC回收。 图形有锯齿，看起来没有问题； 不存在死锁问题，线程运行良好； 检查CPU Time后发现log4j的异步日志线程占用CPU时间最多。 因此，我最初怀疑这是log4j的错。 然后，我回顾了项目代码，发现一些接口打印了大量无用的日志，并且日志级别的使用不规范。 最后我把项目日志整体整理了一下，优化了一下，发布到网上，继续观察。

我以为问题已经解决了。 然而几天后，CPU再次爆炸。 这时候我才意识到自己错怪了log4j。 与上次情况爆炸不同，这次我在公司（可见我很冷静），所以我明智地保留了一台机器进行观察，并重新启动了其他机器。 现在，我要开始我的表演了，如下：

（1）登录机器，使用top命令查看进程的资源使用情况。 正如预期的那样，Java 进程压垮了 CPU，如下图 3 所示：

（图3）进程资源使用情况

（2）Java进程已经占用了所有CPU，那么进程中哪些线程正在占用它呢？ 于是，我使用top -H -p6902（6902是Java进程的PID）命令来查看具体的线程资源使用情况，如下图4所示：

（图4）Java线程资源使用情况

图4中的PID是Java线程的ID。 可以看到ID为6904、6905、6906、6907的4个线程基本上已经消耗掉了所有的CPU资源。

(3) 现在，我们已经得到了耗尽CPU资源的线程id。 这时候我们就可以利用它来查找这些ID对应的具体线程堆栈信息。 它是 JDK 中内置的堆栈跟踪工具。 它位于JDK根目录下的bin文件夹下，可用于打印Java堆栈信息。 我使用命令6902 > .txt（6902是Java进程的PID）打印出Java进程的堆栈信息，并放入.txt文件中； 由于堆栈打印的线程ID是十六进制的，所以我把十进制的线程ID（6904,6905,6906,6907）转换成十六进制（,,,）； 最后通过cat.txt | 找到具体的线程信息 grep -C 20 命令，如下图5所示：

（图5）线程堆栈信息

从图5中我们可以看到，占满CPU的线程都是GC线程，Java的垃圾回收耗尽了CPU的资源。

(4) 现在，我们已经定位到GC问题了。 那么，我们来看看GC回收的情况。 我们可以通过jstat来观察。 jstat是JDK内置的JVM检测和统计工具。 它位于JDK根目录的bin文件夹下，可以对堆内存使用情况进行实时统计。 我使用命令jstat - 6902 2000 10（6902是Java进程的PID）来观察GC的运行信息，如下图6所示：

（图6）GC运行信息

从图6可以知道E（Eden区）和O（Old区）的内存已经耗尽，FGC（Full GC）次数高达6989次，FGCT（Full GC Time）时间高达36453秒，即平均每次FGC的时间为：36453/6989 ≈ 5.21秒。 也就是说，Java进程把时间都花在了GC上，所以没有时间处理其他事情。

（5）如果出现图6所示的GC情况，基本可以确认程序存在内存泄漏问题。 那么，如何确定是哪个代码导致了问题呢？ 这时候我们就可以使用jmap来查看Java的内存使用信息。 jmap是JDK内置的内存映射工具，位于JDK根目录的bin文件夹下。 可以用来获取java进程的内存映射信息。 通过命令jmap -histo 6902（6902是Java进程的PID），打印Java的内存使用信息，如下图7所示：

（图7）Java内存使用信息

从图7中我们可以得到占用内存资源的TOP10类的名称、实例数量以及占用内存大小（单位：byte）（[C指的是char[]，char[]用于类内部保存数据），这样问题就变得很简单了。 最后通过代码确定了问题所在：

有些接口使用这个L5工具类并且不使用单例。 每次请求接口都会生成一个新的实例，浪费大量内存。 代码中使用的第三方提供的客户端存在内存泄漏问题。 代码中不恰当的new大量的对象，存储的数据没有被清除，导致数据不断积累，内存占用不断增加。

解决以上两个问题后，Heap内存使用量保持在2.5G左右。 没有持续增长的迹象，业务运行正常。

以上就是我排查问题的整个过程，以及过程中用到的一些Java性能监控工具。 除了本文提到的工具jstat、jmap之外，JDK根目录的bin文件夹下还有很多其他非常有用的工具。 例如，使用jinfo查看Java进程相关信息。 有兴趣的孩子可以研究一下。

如果你想学习Java工程、高性能和分布式，就简单解释一下。 涉及微服务、Netty源码分析的朋友可以加入我的Java高级交流：群里有阿里巴巴大牛直播讲解技术，还有Java大规模互联网技术的视频免费分享给大家。