做JAVA开发的同学一定遇到过的爆表问题，看这里解决

欢迎大家前往腾讯云+社区，获取更多腾讯海量技术实践干货哦~

本文由净地发表于云+社区专栏

记一次java线上服务器cpu过载问题的排查过程，详解排查过程中用到的java性能监测工具：jvisualvm、jstack、jstat、jmap。

背景：java线上服务运行一周后，某个周六晚上cpu使用率突然持续99%，java进程处于假死状态，不响应请求。秉着先恢复服务再排查问题的原则，在我连接vpn采用重启大法后，cpu使用率恢复正常，服务也正常响应了，如下图一所示：

（图一）cpu使用率图

但是，当晚的并发量也没有比平时高出许多，为什么会突然出现这种cpu爆表的情况？带着这个疑问，我走上了问题排查的道路。

首先，我查了相关的错误日志，发现故障的时间段内有大量的ckv请求超时，但请求超时并不是ckv server的问题，而是ckv client的请求并没有发出去。那么，为什么ckv client的请求没有发出去呢？日志并没有提供更多的信息给我。

于是，我在java服务上开启了jmx，本地采用jvisualvm来观察java进程运行时的堆栈内存、线程使用情况。jmx（java management extensions，即java管理扩展）是java平台上为应用程序、设备、系统等植入管理功能的框架；jvisualvm是jdk内置的性能分析工具，位于jdk根目录的bin文件夹下面，它可以通过jmx从java程序获取运行时的实时数据，从而进行动态的性能分析，如图二所示：

（图二）jvisualvm

通过观察heap内存的使用情况，发现其是缓慢增加的，每隔一小段时间被gc回收，图形呈锯齿状，似乎没有什么问题；threads也没有存在死锁的问题，线程运行良好；在sampler查看thread cpu time的时候发现，log4j的异步日志线程占用的cpu时间是最多的。于是，初步怀疑这是log4j的锅。接着，我对项目代码进行了review，发现某些接口打印了大量的无用日志，日志级别使用也不规范。最后，我对项目的日志进行了整体的梳理，优化后发布上线，并继续观察。

我本以为问题已经解决了。然而，几天后又出现了cpu爆表的情况，这时，我才发现自己错怪了log4j。与上次爆表的情况不同，这次我在公司（表示很淡定），于是我机智地保留了一台机器来做观察，其他机器做重启处理。现在，要开始我的表演了，具体如下：

（1）登陆机器，用 top 命令查看进程资源占用情况。不出所料，java进程把cpu撑爆了，如下图三所示：

（图三）进程资源占用情况

（2）java进程把cpu都占用完了，那么具体是进程内的哪些线程占用的呢？于是，我用了 top -h -p6902 （6902是java进程的pid）命令找出了具体的线程资源占用情况，如下图四所示：

（图四）java线程资源占用情况

图四中的pid为java线程的id，可以看到id为6904、6905、6906、6907这四个线程基本把cpu资源全部吃完了。

（3）现在，我们已经拿到耗尽cpu资源的线程id了。这时，我们就可以使用jstack来查找这些id对应的具体线程堆栈信息了。jstack是jdk内置的堆栈跟踪工具，位于jdk根目录的bin文件夹下面，可用于打印的java堆栈信息。我用命令 jstack 6902 > jstack.txt （6902是java进程的pid）打印出了java进程的堆栈信息放到jstack.txt文件了；由于堆栈打印的线程的native id是十六机制的，所以，我把十进制的线程id（6904、6905、6906、6907）转化成十六进制（0x1af8、0x1af9、0x1afa、0x1afb）；最后，通过 cat jstack.txt | grep -c 20 0x1af8 命令找到了具体的线程信息，如下图五所示：

（图五）线程堆栈信息

通过图五可以发现，把cpu占满的线程是gc的线程，java的垃圾回收把cpu的资源耗尽了。

（4）现在，我们已经定位到是gc的问题了。那么，我们就来看看gc的回收情况，我们可以通过jstat来观察。jstat是jdk内置的jvm检测统计工具，位于jdk根目录的bin文件夹下面，可以对堆内存的使用情况进行实时统计。我使用了命令 jstat -gcutil 6902 2000 10 （6902是java进程的pid）来观察gc的运行信息，如下图六所示：

（图六）gc运行信息

通过图六可以知道，e（eden区）跟o（old区）的内存已经被耗尽了，fgc（full gc）的次数高达6989次，fgct（full gc time）的时间高达36453秒，即平均每次fgc的时间为：36453/6989 ≈ 5.21秒。也就是说，java进程都把时间花在gc上了，所以就没有时间来处理其他事情。

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

（图七）java内存占用信息

由图七可以得到，占用内存资源的top10类（[c 是指char[]，string类内部使用char[]来保存数据）的名称、实例数以及占用内存大小（单位：byte），于是问题排查就变得非常简单了。最后，通过review代码确定了问题所在：

1. 部分接口使用到了l5qospacket这个l5的工具类没有做单例，每次请求接口都会生成一个新的实例，浪费了大量的内存。
2. 代码里边用到的一个第三方提供的qcclient客户端存在内存泄露问题，代码中不恰当地new了大量的对象，而且对存储在concurrenthashmap的数据没有做清除清理，从而导致数据一直累计，内存占用持续增加。

解决以上两个问题后，heap内存的占用维持在2.5g左右，已经没有持续增长的迹象了，业务已正常运行。

以上就是我排查问题的整个过程，以及在这个过程中用到的一些java性能监测工具。除了本文提及的jvisualvm、jstack、jstat、jmap这些工具，在jdk根目录的bin文件夹下面还有其他许多非常有用的工具，例如：使用 jinfo 查看java进程相关信息，感兴趣的童鞋可以去研究下。

相关阅读
wcf系列教程之wcf服务配置
php异步执行
黑客用python：检测并绕过web应用程序防火墙
【每日课程推荐】机器学习实战！快速入门在线广告业务及ctr相应知识

此文已由作者授权腾讯云+社区发布，更多原文请点击

搜索关注公众号「云加社区」，第一时间获取技术干货，关注后回复1024 送你一份技术课程大礼包！

海量技术实践经验，尽在云加社区！