诊断由 System.gc() 导致的 CPU 飙升和 GC overhead alert

在六月一个炎炎烈日的周六, 我坐在凉爽的空调房里, 突然发现生产环境有个机器 CPU 一直狂转, 我想着: 这可不行, 本来地球就够热的了, 为了保护环境, 一定要把它的 CPU 降下来.

它是一个 java 应用程序, 进一步查看其它指标, 发现这货还一直报 GC overhead alert, 原来有个二货工程师写的新 bug, 一定要把它找出来.

下载 verbose GC log, 通过 log viewer 一看, 哇, 神奇: 无论老年代, 还是年轻代, 都有非常多的空闲内存. 如下图, 只有放大到 500 倍才能看清楚, 否则都是 Full GC 的黑线....

那么下一步怀疑老年代被占满了, 可是, 还是很失望: 老年代空闲内存多的是

2019-06-15T00:40:55.978-0700: 53291.378: [Full GC2019-06-15T00:40:55.978-0700: 53291.378: [CMS: 168666K->168666K(1433600K), 0.3949710 secs] 172644K->168666K(2170880K), [CMS Perm : 123793K->123793K(524288K)], 0.3951790 secs] [Times: user=0.39 sys=0.00, real=0.39 secs] 
2019-06-15T00:40:56.479-0700: 53291.879: [Full GC2019-06-15T00:40:56.479-0700: 53291.880: [CMS: 168666K->168665K(1433600K), 0.3926360 secs] 171687K->168665K(2170880K), [CMS Perm : 123793K->1237