full gc 次数_记一次由于GC导致的系统卡顿问题

前置说明：

1. 文中A系统，是几年前开发的，和目前开发的系统没有任何关系，使用化名主要为了防范风险；

2. A系统中的示例代码和功能做了一些修改，避免掺杂太多不必要的干扰信息；

---

之前在登录A系统后，发现订单列表总是打开很慢，有很明显的卡顿情况，上一次出现这种情况还是mysql锁表，然后订单卡在Actor(里面有个队列)里面，所以起初以为是订单量过大的问题(虽然隐约觉得不是。。。后来发现真的不是)，后来想到可能是内存占用过多，GC(垃圾回收)频繁导致的。

GC为什么会导致系统卡顿呢？

由于JVM的设计，对象被放在不同的区域(代)，对于一般创建的对象，会被放在新生代，假如新生代没有回收成功，会落入到老年代。一般情况下，新生代的回收由YGC完成(y=young)，老年代(和其他区域)的回收由FGC(f=full)完成。新生代中的对象寿命比较短，回收速度快，而老年代的对象一般非常大，回收特别慢，所以做一次FGC会停顿很长时间，这直接导致系统出现卡顿，俗称：STW，即Stop The World。(GC相关的内容，可以参考之前我写的另外一篇文章：聊聊JVM内存&GC)

首先，我在服务器上通过jps查到A服务的进程id，然后使用jstat查看gc情况：

jstat -gcutil 4322 2000

-gcutil是常用的参数，4322是当时A服务的进程id，2000表示2秒钟输出一次gc信息，如图：

解释：

S0: 新生代中Survivor space 0区已使用空间的百分比

S1: 新生代中Survivor space 1区已使用空间的百分比

E: 新生代已使用空间的百分比

O: 老年代已使用空间的百分比

M: 永久带已使用空间的百分比

YGC: 从应用程序启动到当前，发生Yang GC 的次数

YGCT: 从应用程序启动到当前，Yang GC所用的时间

FGC: 从应用程序启动到当前，发生Full GC的次数

FGCT: 从应用程序启动到当前，Full GC所用的时间

GCT: 从应用程序启动到当前，用于垃圾回收的总时间

其中E、O 、YGC、YGCT、FGC、FGCT几列非常重要。

从图中可以看出，新生代和老年代使用率都在100%，而且即使垃圾回收了(YGC和FGC可以看到GC次数)，还是不能下降，此时我看使用如下命令看一下Java堆内存的情况，想确认下到底是不是由于堆太小导致容易达到上限：

jmap -heap 4322

结果如图所示：

MaxHepSize是堆内存大小，可以看到，差不多4G，然后该100%的差不多也都100%了。。。当然，实际上我们的空间确实不大，一个比较可行的方式是加启动参数设置内存。但是，我个人认为还行需要从源头解决问题，所以想知道是哪些对象占用了内存。所以我继续使用jmap查看存活对象的计数和大小统计，如下：

jmap -histo:live 4322> jmapinfo

由于这个输出比较大，所以导入到一个jmapinfo的文件里面，打开文件如下：

会看到我们系统自己的两个业务对象(马赛克的那两位)非常多，经过询问，这两个优化空间

不大，另外也看到，排名第一的是

org.apache.commons.collections.map.AbstractHashedMap这个，用了1个多g，而这个类之前没听说在系统里面使用过，后面排查代码，发现很多误用的，而最关键是：这么多Map对象不释放，肯定会耗尽资源，按道理，假如一个对象是局部变量，不太可能不释放不了的情况，所以唯一的解释是：这些对象变成公共的了，所以继续查找代码，发现在某个常驻内存的对象里面，含有大量的AbstractHashedMap成员变量。后面，我们通过优化数据结构解决了这个问题。

说点题外话：

1. 在设置成员变量的时候一定要小心几个问题：宿主对象会不会是单例的或者被多线程共享的，假如被共享的话，会出现多线程不安全问题(本例也存在该问题)；宿主对象假如是长期被持有的，那么连带这个对象的所有成员变量就不会释放；

2. 在创建对象的时候，最好对对象的个数有一个大致的预估，这样出了问题方便排查；

3. 系统卡顿可能是多种原因造成的，比如网络延时、数据库性能不佳或锁表、各种锁(or 同步操作)、CPU飙高(比如计算密集)，而STW是其中比较容易忽略原因之一；