加入收藏 | 设为首页 | 会员中心 | 我要投稿 济南站长网 (https://www.0531zz.com/)- 科技、建站、经验、云计算、5G、大数据,站长网!
当前位置: 首页 > 运营中心 > 网站设计 > 教程 > 正文

一次性搞清楚线上CPU100%,频繁FullGC排查套路

发布时间:2019-06-25 09:44:08 所属栏目:教程 来源:爱宝贝丶
导读:副标题#e# 处理过线上问题的同学基本上都会遇到系统突然运行缓慢,CPU 100%,以及 Full GC 次数过多的问题。 当然,这些问题最终导致的直观现象就是系统运行缓慢,并且有大量的报警。 本文主要针对系统运行缓慢这一问题,提供该问题的排查思路,从而定位出

这里打印结果说明该线程在 jstack 中的展现形式为 0xa,通过 jstack 命令我们可以看到如下信息:

  1. "main" #1 prio=5 os_prio=0 tid=0x00007f8718009800 nid=0xb runnable [0x00007f871fe41000] 
  2.    java.lang.Thread.State: RUNNABLE 
  3.     at com.aibaobei.chapter2.eg2.UserDemo.main(UserDemo.java:9) 
  4.  
  5. "VM Thread" os_prio=0 tid=0x00007f871806e000 nid=0xa runnable 

这里的 VM Thread 一行的最后显示 nid=0xa,这里 nid 的意思就是操作系统线程 id 的意思,而 VM Thread 指的就是垃圾回收的线程。

这里我们基本上可以确定,当前系统缓慢的原因主要是垃圾回收过于频繁,导致 GC 停顿时间较长。

我们通过如下命令可以查看 GC 的情况:

  1. root@8d36124607a0:/# jstat -gcutil 9 1000 10 
  2.   S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT 
  3.   0.00   0.00   0.00  75.07  59.09  59.60   3259    0.919  6517    7.715    8.635 
  4.   0.00   0.00   0.00   0.08  59.09  59.60   3306    0.930  6611    7.822    8.752 
  5.   0.00   0.00   0.00   0.08  59.09  59.60   3351    0.943  6701    7.924    8.867 
  6.   0.00   0.00   0.00   0.08  59.09  59.60   3397    0.955  6793    8.029    8.984 

可以看到,这里 FGC 指的是 Full GC 数量,这里高达 6793,而且还在不断增长。从而进一步证实了是由于内存溢出导致的系统缓慢。

那么这里确认了内存溢出,但是如何查看你是哪些对象导致的内存溢出呢,这个可以 Dump 出内存日志,然后通过 Eclipse 的 Mat 工具进行查看。

如下图是其展示的一个对象树结构:

一次性搞清楚线上CPU100%,频繁FullGC排查套路

经过 Mat 工具分析之后,我们基本上就能确定内存中主要是哪个对象比较消耗内存,然后找到该对象的创建位置,进行处理即可。

这里主要是 PrintStream 最多,但是我们也可以看到,其内存消耗量只有 12.2%。

也就是说,其还不足以导致大量的 Full GC,此时我们需要考虑另外一种情况,就是代码或者第三方依赖的包中有显示的 System.gc() 调用。

这种情况我们查看 Dump 内存得到的文件即可判断,因为其会打印 GC 原因:

  1. [Full GC (System.gc()) [Tenured: 262546K->262546K(349568K), 0.0014879 secs] 262546K->262546K(506816K), [Metaspace: 3109K->3109K(1056768K)], 0.0015151 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]  
  2. [GC (Allocation Failure) [DefNew: 2795K->0K(157248K), 0.0001504 secs][Tenured: 262546K->402K(349568K), 0.0012949 secs] 265342K->402K(506816K), [Metaspace: 3109K->3109K(1056768K)], 0.0014699 secs] [Times: user=0.00 

比如这里第一次 GC 是由于 System.gc() 的显示调用导致的,而第二次 GC 则是 JVM 主动发起的。

总结来说,对于 Full GC 次数过多,主要有以下两种原因:

  • 代码中一次获取了大量的对象,导致内存溢出,此时可以通过 Eclipse 的 Mat 工具查看内存中有哪些对象比较多。
  • 内存占用不高,但是 Full GC 次数还是比较多,此时可能是显示的 System.gc() 调用导致 GC 次数过多,这可以通过添加 -XX:+DisableExplicitGC 来禁用 JVM 对显示 GC 的响应。

CPU 过高

在前面第一点中,我们讲到,CPU 过高可能是系统频繁的进行 Full GC,导致系统缓慢。

而我们平常也肯定能遇到比较耗时的计算,导致 CPU 过高的情况,此时查看方式其实与上面的非常类似。

首先我们通过 top 命令查看当前 CPU 消耗过高的进程是哪个,从而得到进程 id;然后通过 top -Hp 来查看该进程中有哪些线程 CPU 过高,一般超过 80% 就是比较高的,80% 左右是合理情况。

这样我们就能得到 CPU 消耗比较高的线程 id。接着通过该线程 id 的十六进制表示在 jstack 日志中查看当前线程具体的堆栈信息。

在这里我们就可以区分导致 CPU 过高的原因具体是 Full GC 次数过多还是代码中有比较耗时的计算了。

如果是 Full GC 次数过多,那么通过 jstack 得到的线程信息会是类似于 VM Thread 之类的线程。

而如果是代码中有比较耗时的计算,那么我们得到的就是一个线程的具体堆栈信息。

(编辑:济南站长网)

【声明】本站内容均来自网络,其相关言论仅代表作者个人观点,不代表本站立场。若无意侵犯到您的权利,请及时与联系站长删除相关内容!

热点阅读