系统运行缓慢，CPU 100%%uFF0C以及Full GC次数过多问题的排查思路
发布时间：2024-06-11 点击：100
服务器
来源：http://t.cn/ei9jdbu
处理过线上问题的同学基本上都会遇到系统突然运行缓慢，cpu 100%%uff0c以及full gc次数过多的问题。当然，这些问题的最终导致的直观现象就是系统运行缓慢，并且有大量的报警。本文主要针对系统运行缓慢这一问题，提供该问题的排查思路，从而定位出问题的代码点，进而提供解决该问题的思路。
对于线上系统突然产生的运行缓慢问题，如果该问题导致线上系统不可用，那么首先需要做的就是，导出jstack和内存信息，然后重启系统，尽快保证系统的可用性。这种情况可能的原因主要有两种：
代码中某个位置读取数据量较大，导致系统内存耗尽，从而导致full gc次数过多，系统缓慢；
代码中有比较耗cpu的操作，导致cpu过高，系统运行缓慢；
相对来说，这是出现频率最高的两种线上问题，而且它们会直接导致系统不可用。另外有几种情况也会导致某个功能运行缓慢，但是不至于导致系统不可用：
代码某个位置有阻塞性的操作，导致该功能调用整体比较耗时，但出现是比较随机的；
某个线程由于某种原因而进入waiting状态，此时该功能整体不可用，但是无法复现；
由于锁使用不当，导致多个线程进入死锁状态，从而导致系统整体比较缓慢。
对于这三种情况，通过查看cpu和系统内存情况是无法查看出具体问题的，因为它们相对来说都是具有一定阻塞性操作，cpu和系统内存使用情况都不高，但是功能却很慢。下面我们就通过查看系统日志来一步一步甄别上述几种问题。
1. full gc次数过多
相对来说，这种情况是最容易出现的，尤其是新功能上线时。对于full gc较多的情况，其主要有如下两个特征：
线上多个线程的cpu都超过了100%%uff0c通过jstack命令可以看到这些线程主要是垃圾回收线程
通过jstat命令监控gc情况，可以看到full gc次数非常多，并且次数在不断增加。
首先我们可以使用 top命令查看系统cpu的占用情况，如下是系统cpu较高的一个示例：
top - 08:31:10 up 30 min, 0 users, load average: 0.73, 0.58, 0.34
kib mem: 2046460 total, 1923864 used, 122596 free, 14388 buffers
kib swap: 1048572 total, 0 used, 1048572 free. 1192352 cached mem
pid user pr ni virt res shr s %cpu %mem time command
9 root 20 0 2557160 288976 15812 s 98.0 14.1 0:42.60 java
可以看到，有一个java程序此时cpu占用量达到了98.8%%uff0c此时我们可以复制该进程id 9，并且使用如下命令查看呢该进程的各个线程运行情况：
top-hp9该进程下的各个线程运行情况如下：
top - 08:31:16 up 30 min, 0 users, load average: 0.75, 0.59, 0.35
threads: 11 total, 1 running, 10 sleeping, 0 stopped, 0 zombie
%cpu(s): 3.5 us, 0.6 sy, 0.0 ni, 95.9 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
kib mem: 2046460 total, 1924856 used, 121604 free, 14396 buffers
kib swap: 1048572 total, 0 used, 1048572 free. 1192532 cached mem
pid user pr ni virt res shr s %cpu %mem time command
10 root 20 0 2557160 289824 15872 r 79.3 14.2 0:41.49 java
11 root 20 0 2557160 289824 15872 s 13.2 14.2 0:06.78 java
可以看到，在进程为 9的java程序中各个线程的cpu占用情况，接下来我们可以通过jstack命令查看线程id为 10的线程为什么耗费cpu最高。需要注意的是，在jsatck命令展示的结果中，线程id都转换成了十六进制形式。可以用如下命令查看转换结果，也可以找一个科学计算器进行转换：
root@a39de7e7934b:/#printf"%x\\\\n"10a这里打印结果说明该线程在jstack中的展现形式为 0xa，通过jstack命令我们可以看到如下信息：
"main" #1 prio=5 os_prio=0 tid=0x00007f8718009800 nid=0xb runnable [0x00007f871fe41000]
java.lang.thread.state: runnable
at com.aibaobei.chapter2.eg2.userdemo.main(userdemo.java:9)
"vm thread" os_prio=0 tid=0x00007f871806e000 nid=0xa runnable
这里的vm thread一行的最后显示 nid=0xa，这里nid的意思就是操作系统线程id的意思。而vm thread指的就是垃圾回收的线程。这里我们基本上可以确定，当前系统缓慢的原因主要是垃圾回收过于频繁，导致gc停顿时间较长。我们通过如下命令可以查看gc的情况：
root@8d36124607a0:/#jstat-gcutil9100010s0s1eomccsygcygctfgcfgctgct0.000.000.0075.0759.0959.6032590.91965177.7158.6350.000.000.000.0859.0959.6033060.93066117.8228.7520.000.000.000.0859.0959.6033510.94367017.9248.8670.000.000.000.0859.0959.6033970.95567938.0298.984可以看到，这里fgc指的是full gc数量，这里高达6793，而且还在不断增长。从而进一步证实了是由于内存溢出导致的系统缓慢。那么这里确认了内存溢出，但是如何查看你是哪些对象导致的内存溢出呢，这个可以dump出内存日志，然后通过eclipse的mat工具进行查看，如下是其展示的一个对象树结构：
经过mat工具分析之后，我们基本上就能确定内存中主要是哪个对象比较消耗内存，然后找到该对象的创建位置，进行处理即可。这里的主要是printstream最多，但是我们也可以看到，其内存消耗量只有12.2%%u3002也就是说，其还不足以导致大量的full gc，此时我们需要考虑另外一种情况，就是代码或者第三方依赖的包中有显示的 system.gc()调用。这种情况我们查看dump内存得到的文件即可判断，因为其会打印gc原因：
[fullgc(system.gc())[tenured:262546k->262546k(349568k),0.0014879secs]262546k->262546k(506816k),[metaspace:3109k->3109k(1056768k)],0.0015151secs][times:user=0.00sys=0.00,real=0.01secs][gc(allocationfailure)[defnew:2795k->0k(157248k),0.0001504secs][tenured:262546k->402k(349568k),0.0012949secs]265342k->402k(506816k),[metaspace:3109k->3109k(1056768k)],0.0014699secs][times:user=0.00比如这里第一次gc是由于 system.gc()的显示调用导致的，而第二次gc则是jvm主动发起的。总结来说，对于full gc次数过多，主要有以下两种原因：
代码中一次获取了大量的对象，导致内存溢出，此时可以通过eclipse的mat工具查看内存中有哪些对象比较多；
内存占用不高，但是full gc次数还是比较多，此时可能是显示的system.gc()调用导致gc次数过多，这可以通过添加-xx: disableexplicitgc来禁用jvm对显示gc的响应。
2. cpu过高
在前面第一点中，我们讲到，cpu过高可能是系统频繁的进行full gc，导致系统缓慢。而我们平常也肯能遇到比较耗时的计算，导致cpu过高的情况，此时查看方式其实与上面的非常类似。首先我们通过 top命令查看当前cpu消耗过高的进程是哪个，从而得到进程id；然后通过 top-hp<pid>
华为智慧屏能安装云极光吗 华为智慧屏怎么下载云极光
云服务器ip共享和独立有什么区别
域名最短多少位
阿里云服务器什么时候优惠的
Linux操作系统的基础知识
管家皮服务器如何挂接云数据库
俄罗斯 云服务器哪个好
seo优化知识：seo排名的5大缺点
来源：http://t.cn/ei9jdbu
处理过线上问题的同学基本上都会遇到系统突然运行缓慢，cpu 100%%uff0c以及full gc次数过多的问题。当然，这些问题的最终导致的直观现象就是系统运行缓慢，并且有大量的报警。本文主要针对系统运行缓慢这一问题，提供该问题的排查思路，从而定位出问题的代码点，进而提供解决该问题的思路。
对于线上系统突然产生的运行缓慢问题，如果该问题导致线上系统不可用，那么首先需要做的就是，导出jstack和内存信息，然后重启系统，尽快保证系统的可用性。这种情况可能的原因主要有两种：
代码中某个位置读取数据量较大，导致系统内存耗尽，从而导致full gc次数过多，系统缓慢；
代码中有比较耗cpu的操作，导致cpu过高，系统运行缓慢；
相对来说，这是出现频率最高的两种线上问题，而且它们会直接导致系统不可用。另外有几种情况也会导致某个功能运行缓慢，但是不至于导致系统不可用：
代码某个位置有阻塞性的操作，导致该功能调用整体比较耗时，但出现是比较随机的；
某个线程由于某种原因而进入waiting状态，此时该功能整体不可用，但是无法复现；
由于锁使用不当，导致多个线程进入死锁状态，从而导致系统整体比较缓慢。
对于这三种情况，通过查看cpu和系统内存情况是无法查看出具体问题的，因为它们相对来说都是具有一定阻塞性操作，cpu和系统内存使用情况都不高，但是功能却很慢。下面我们就通过查看系统日志来一步一步甄别上述几种问题。
1. full gc次数过多
相对来说，这种情况是最容易出现的，尤其是新功能上线时。对于full gc较多的情况，其主要有如下两个特征：
线上多个线程的cpu都超过了100%%uff0c通过jstack命令可以看到这些线程主要是垃圾回收线程
通过jstat命令监控gc情况，可以看到full gc次数非常多，并且次数在不断增加。
首先我们可以使用 top命令查看系统cpu的占用情况，如下是系统cpu较高的一个示例：
top - 08:31:10 up 30 min, 0 users, load average: 0.73, 0.58, 0.34
kib mem: 2046460 total, 1923864 used, 122596 free, 14388 buffers
kib swap: 1048572 total, 0 used, 1048572 free. 1192352 cached mem
pid user pr ni virt res shr s %cpu %mem time command
9 root 20 0 2557160 288976 15812 s 98.0 14.1 0:42.60 java
可以看到，有一个java程序此时cpu占用量达到了98.8%%uff0c此时我们可以复制该进程id 9，并且使用如下命令查看呢该进程的各个线程运行情况：
top-hp9该进程下的各个线程运行情况如下：
top - 08:31:16 up 30 min, 0 users, load average: 0.75, 0.59, 0.35
threads: 11 total, 1 running, 10 sleeping, 0 stopped, 0 zombie
%cpu(s): 3.5 us, 0.6 sy, 0.0 ni, 95.9 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
kib mem: 2046460 total, 1924856 used, 121604 free, 14396 buffers
kib swap: 1048572 total, 0 used, 1048572 free. 1192532 cached mem
pid user pr ni virt res shr s %cpu %mem time command
10 root 20 0 2557160 289824 15872 r 79.3 14.2 0:41.49 java
11 root 20 0 2557160 289824 15872 s 13.2 14.2 0:06.78 java
可以看到，在进程为 9的java程序中各个线程的cpu占用情况，接下来我们可以通过jstack命令查看线程id为 10的线程为什么耗费cpu最高。需要注意的是，在jsatck命令展示的结果中，线程id都转换成了十六进制形式。可以用如下命令查看转换结果，也可以找一个科学计算器进行转换：
root@a39de7e7934b:/#printf"%x\\\\n"10a这里打印结果说明该线程在jstack中的展现形式为 0xa，通过jstack命令我们可以看到如下信息：
"main" #1 prio=5 os_prio=0 tid=0x00007f8718009800 nid=0xb runnable [0x00007f871fe41000]
java.lang.thread.state: runnable
at com.aibaobei.chapter2.eg2.userdemo.main(userdemo.java:9)
"vm thread" os_prio=0 tid=0x00007f871806e000 nid=0xa runnable
这里的vm thread一行的最后显示 nid=0xa，这里nid的意思就是操作系统线程id的意思。而vm thread指的就是垃圾回收的线程。这里我们基本上可以确定，当前系统缓慢的原因主要是垃圾回收过于频繁，导致gc停顿时间较长。我们通过如下命令可以查看gc的情况：
root@8d36124607a0:/#jstat-gcutil9100010s0s1eomccsygcygctfgcfgctgct0.000.000.0075.0759.0959.6032590.91965177.7158.6350.000.000.000.0859.0959.6033060.93066117.8228.7520.000.000.000.0859.0959.6033510.94367017.9248.8670.000.000.000.0859.0959.6033970.95567938.0298.984可以看到，这里fgc指的是full gc数量，这里高达6793，而且还在不断增长。从而进一步证实了是由于内存溢出导致的系统缓慢。那么这里确认了内存溢出，但是如何查看你是哪些对象导致的内存溢出呢，这个可以dump出内存日志，然后通过eclipse的mat工具进行查看，如下是其展示的一个对象树结构：
经过mat工具分析之后，我们基本上就能确定内存中主要是哪个对象比较消耗内存，然后找到该对象的创建位置，进行处理即可。这里的主要是printstream最多，但是我们也可以看到，其内存消耗量只有12.2%%u3002也就是说，其还不足以导致大量的full gc，此时我们需要考虑另外一种情况，就是代码或者第三方依赖的包中有显示的 system.gc()调用。这种情况我们查看dump内存得到的文件即可判断，因为其会打印gc原因：
[fullgc(system.gc())[tenured:262546k->262546k(349568k),0.0014879secs]262546k->262546k(506816k),[metaspace:3109k->3109k(1056768k)],0.0015151secs][times:user=0.00sys=0.00,real=0.01secs][gc(allocationfailure)[defnew:2795k->0k(157248k),0.0001504secs][tenured:262546k->402k(349568k),0.0012949secs]265342k->402k(506816k),[metaspace:3109k->3109k(1056768k)],0.0014699secs][times:user=0.00比如这里第一次gc是由于 system.gc()的显示调用导致的，而第二次gc则是jvm主动发起的。总结来说，对于full gc次数过多，主要有以下两种原因：
代码中一次获取了大量的对象，导致内存溢出，此时可以通过eclipse的mat工具查看内存中有哪些对象比较多；
内存占用不高，但是full gc次数还是比较多，此时可能是显示的system.gc()调用导致gc次数过多，这可以通过添加-xx: disableexplicitgc来禁用jvm对显示gc的响应。
2. cpu过高
在前面第一点中，我们讲到，cpu过高可能是系统频繁的进行full gc，导致系统缓慢。而我们平常也肯能遇到比较耗时的计算，导致cpu过高的情况，此时查看方式其实与上面的非常类似。首先我们通过 top命令查看当前cpu消耗过高的进程是哪个，从而得到进程id；然后通过 top-hp<pid>
华为智慧屏能安装云极光吗 华为智慧屏怎么下载云极光
云服务器ip共享和独立有什么区别
域名最短多少位
阿里云服务器什么时候优惠的
Linux操作系统的基础知识
管家皮服务器如何挂接云数据库
俄罗斯 云服务器哪个好
seo优化知识：seo排名的5大缺点
上一篇：企业云服务器怎么修改镜像