Yong GC 突刺排查又让我涨知识了！

现象

下图是每分钟yong gc 所消耗的时间，没有规律的突刺。

年轻代gc 使用的是 ParNew 并发收集。

下图是每分钟yong gc 的次数，可以看出每分钟gc的频率比较稳定。

每分钟gc次数没有变化，gc时间增加了，说明某次gc时间变长了。

首先去机器上查看 GC 日志，可以看出年轻代都回收掉了，最后堆大小600多M主要是老年代，但是这里却用了 100ms。

[ParNew: 842033K->2719K(943744K), 0.1051401 secs]
  GC后年轻代 822M -> 2.6M

1516408K->677103K(1992320K), 0.1052194 secs]
   堆大小 1.4G -> 661M

[Times: user=0.26 sys=0.04, real=0.10 secs]
  时间用了 100ms
复制

一般程序有问题，可能是每次GC耗时都比较久，但是这种只是偶尔出现，并且没有规律，检查了代码排除了由于代码写的有问题造成的。

再看看系统的监控。下图是CPU使用率均值，压力不大。

下图是峰值，感觉不太稳定。

排查问题

结合 CPU 峰值不太稳定和GC不稳定，我们再去机器上用 jstack 看下 GC 线程数。

$ grep Gang jstack.log | awk '{print $3,$4,$5}' |uniq -c
  33  (Parallel GC Threads)"
   9  (Parallel CMS Threads)"
复制

这里介绍下背景，程序是在容器中运行的，容器是 4 核 CPU。这里年轻代GC的线程数远远超过了 CPU 的核数。

但是这个数字怎么算出来的呢？我们看下 GC 线程数据的计算规则

cpu 核数小于8 gc 线程数等于cpu核数，大于8的时候=8+(cpu数-8)*5/8

Parallel CMS Thread 并发的GC线程数(ParallelGCThreads+3)/4

这里我们宿主机是 48 核，带入上面的算法，刚好跟查询出来的数据一致。

这个时候我们猜测可能是线程数太多，在 GC 的时候进行了上下文切换，影响的 GC 的响应时间和 CPU 峰值。

验证猜测

根据上面的猜测，通过 jstack 查看线程id，nid线程id，0x412对应10进制1042，后面连续的几个线程 id 都是 GC 线程。

通过pidstat 查看进程下线程的上下文切换情况，自愿和非自愿切换都是非0。非自愿切换说明线程的时间片用完了，导致线程被迫进行了切换。

由于线程的非自愿切换导致 GC 时间受到了影响，然后每分钟 GC 耗时占比并不高所以均值没什么变化，但是对峰值造成了影响。

解决方案

在Docker中通过CGroup来限制内存和CPU，作为一种较新的技术，历史Java版本并不能自然的理解相应的资源限制。这个时候有2种解决方案：

方案二：

JDK 8u191 后的版本可以识别容器的CPU限制，升级容器的JDK版本

升级后的cpu峰值效果对比，可以看到比较稳定。

年轻代GC时间也比较稳定。