OMG！又一个频繁FullGC的案例

将用户已安装APP数据从MySQL中迁移到MongoDB中。MySQL中存储方式比较简单，每个用户每个已安装的APP一行记录，且数据模型对应AppFromMySQL。迁移到MongoDB中，我们想更好的利用MongoDB的优势，所以其对应的数据模型为UserAppMongo，如果用JSON表示则如下所示：

{"id": "201811040001","userId": "12","appMongoList": [{"appName": "支付宝","packageName": "com.alipay","iconUrl": "http://s3.domain.com/12/12/com.alipay.jpg"},{"appName": "淘宝","packageName": "com.alibaba.taobao","iconUrl": "http://s3.domain.com/12/12/com.alibaba.taobao.jpg"}]
}

问题重现

按照惯例，为了方便重现问题，将代码浓缩一下：

class AppMongo {private String appName;private String packageName;private int versionCode;private Date installTime;private String iconUrl;private String downloadUrl;private String remark;private Long size;private String developer;
}
// 需要保存到MongoDB中的用户已安装app信息，这样保存的好处就是MongoDB中installed_apps这张表的user_id能设置唯一键约束，查询性能相比RDBMS中数据平铺要高不少
class UserAppMongo {private String id;private Long userId;private List<AppMongo> appMongoList;
}
// 关系型数据库中用户已安装app
class AppFromMySQL {private int id;private Long userId;private String packageName;private int versionCode;private Date installTime;private String appName;private String iconUrl;private String downloadUrl;private String remark;private Long size;private String developer;
}public class FullGCSample {public static void main(String[] args) throws Exception{for (int pageNo = 0; pageNo < 10000; pageNo++) {List<Long> userList = getUserIdByPage(pageNo);List<UserAppMongo> userAppMongoList = new ArrayList<>(userList.size());for (Long userId:userList){List<AppFromMySQL> appFromMySQLList = getUserInstalledAppList(userId);UserAppMongo userAppMongo = new UserAppMongo();userAppMongo.setId(System.nanoTime()+"");//测试代码任意模拟一个伪唯一IDuserAppMongo.setUserId(userId);userAppMongo.setAppMongoList(appFromMySQL2AppMongo(appFromMySQLList));userAppMongoList.add(userAppMongo);}// save List<UserAppMongo> to mongodbsave2MongoDB(userAppMongoList);}}private static void save2MongoDB(List<UserAppMongo> userAppMongoList) throws Exception {// 模拟保存一次数据到mongodb中要5msThread.sleep(5);}private static List<AppMongo> appFromMySQL2AppMongo(List<AppFromMySQL> list){List<AppMongo> appMongoList = new ArrayList<>();for (AppFromMySQL app:list){AppMongo appMongo = new AppMongo();//TODO bean copyappMongoList.add(appMongo);}return appMongoList;}private static List<AppFromMySQL> getUserInstalledAppList(Long useId){List<AppFromMySQL> appFromMySQLList = new ArrayList<>();// 假设用户手机上安装的app数量在50~200之间int size = 50 + new Random().nextInt(150);for (int i = 0; i < size; i++) {AppFromMySQL appFromMySQL = new AppFromMySQL(i, (long)i, "com.afei.android"+i, i, new Date(), "appName"+i);appFromMySQL.setIconUrl(String.valueOf(i));appFromMySQL.setDownloadUrl(String.valueOf(i));appFromMySQL.setRemark(String.valueOf(i));appFromMySQL.setSize((long)i);appFromMySQL.setDeveloper(String.valueOf(i));appFromMySQLList.add(appFromMySQL);}return appFromMySQLList;}private static List<Long> getUserIdByPage(int pageNo){List<Long> userList = new ArrayList<>();// 取数据时每一页1000个用户for (int i = 0; i < 2000; i++) {userList.add((long)i);}return userList;}
}

配套的JVM参数如下（由于是迁移程序，没必要配置CMS甚至G1，默认的PS垃圾回收即可）：

-Xmx400m -Xms400m -Xmn150m -verbose:gc -XX:+PrintGCDetails

运行后jstat -gcutil 57408 2s的结果如下：

  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT29.81  82.88 100.00  39.35  61.05  61.52     40   16.274     7    6.756   23.03091.43  21.01 100.00  39.26  61.05  61.52     45   17.791     8    7.327   25.1180.00  90.53   0.00  88.47  61.05  61.52     47   18.694     9    7.327   26.02123.00   0.00 100.00  19.10  61.05  61.52     52   19.655    10    9.227   28.88293.29   0.00   0.00  90.25  61.05  61.52     56   21.326    11    9.227   30.55394.21   0.00   0.00  82.39  61.05  61.52     60   22.435    12   10.253   32.68893.23  93.23 100.00  71.09  61.05  61.52     64   23.223    12   11.027   34.250

这里有两个比较严重的问题：

Old区涨的过快；
FGC太频繁；

事实上第二个问题就是第一个问题引起的。

分析问题

这个案例比较特殊，虽然FGC频繁，但是每次FGC后，Old都能降下去。这种情况下，我们不好通过jmap -dump得到dump文件，或者通过jmap -histo得到Java对象柱状图，因为极大可能是Old区的使用率很低的时候生成的结果，这种结果没多大参考价值：

[afei@node1 ~]# jstat -gcutil 121165 100S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT   0.00   0.00  40.00  15.71  58.25  51.76    287    7.891    63    2.921   10.81296.58   0.00  18.00  34.05  58.25  51.76    289    7.937    63    2.921   10.85896.84   0.00   0.00  70.73  58.25  51.76    291    8.001    63    2.921   10.9230.00   0.00   0.00  27.31  58.25  51.76    291    8.033    64    2.978   11.0100.00  99.47   0.00  45.80  58.25  51.76    293    8.077    64    2.978   11.0550.00  96.84   0.00  83.17  58.25  51.76    295    8.144    65    2.978   11.12196.91   0.00   0.00  21.68  58.25  51.76    296    8.157    65    3.026   11.183

那么我们有其他办法在Old区使用率很大，甚至发生FGC前生成dump文件吗？当然有，这里介绍两个参数：-XX:+HeapDumpAfterFullGC和-XX:+HeapDumpBeforeFullGC。看命名就知道，这两个参数是在FGC前后生成dump文件。需要注意的是，一定是发生FGC，而不是CMS GC或者G1这种并发GC。加上-XX:+HeapDumpBeforeFullGC这个参数后，再次运行，我们看到如下这样的GC日志，即在FGC之前生成dump文件：

[GC (Allocation Failure) [PSYoungGen: 94016K->42816K(102400K)] 236438K->227942K(358400K), 0.0661795 secs] [Times: user=0.62 sys=0.88, real=0.07 secs]
[GC (Allocation Failure) [PSYoungGen: 94016K->42752K(102400K)] 279142K->270606K(358400K), 0.0711319 secs] [Times: user=0.60 sys=1.01, real=0.07 secs]
[Heap Dump (before full gc): Dumping heap to java_pid121598.hprof ...
Heap dump file created [366886452 bytes in 1.878 secs]
, 1.8782650 secs][Full GC (Ergonomics) [PSYoungGen: 42752K->0K(102400K)] [ParOldGen: 227854K->41341K(256000K)] 270606K->41341K(358400K), [Metaspace: 2828K->2828K(1056768K)], 0.1720676 secs] [Times: user=3.72 sys=0.07, real=0.17 secs]

对dump文件进行分析，结果如下，两个比较靠前的对象是UserAppMongo和AppMongo：

而通过TOP1的对象UserAppMongo的"List Objects"->"with outgoing references"，得到如下图所示，由图可知，UserAppMongo这个对象属性里包含了List<AppMongo>对象（appMongoList），其本质是Object数组，每个AppMongo对象又是由appName，packageName，installTime等属性组成，所以Histogram视图中排名前几位的UserAppMongo，Object[]，ArrayList，AppMongo事实上都是UserAppMongo这一个对象：

迁移程序比较简单，核心代码就那么几行，通过问题对象UserAppMongo，review代码的过程中，我们很快就怀疑到了下面这段代码：

List<Long> userList = getUserIdByPage(pageNo);
List<UserAppMongo> userAppMongoList = new ArrayList<>(userList.size());
for (Long userId:userList){List<AppFromMySQL> appFromMySQLList = getUserInstalledAppList(userId);UserAppMongo userAppMongo = new UserAppMongo();userAppMongo.setId(System.nanoTime()+"");userAppMongo.setUserId(userId);userAppMongo.setAppMongoList(appFromMySQL2AppMongo(appFromMySQLList));userAppMongoList.add(userAppMongo);
}
// save List<UserAppMongo> to mongodb
save2MongoDB(userAppMongoList);

这段代码的逻辑是：

得到一批用户ID；
然后遍历这些用户ID，取得每个用户已安装APP集合转换成MongoDB需要的数据模型；
批量保存到MongoDB中；

我们仔细分析一下这段代码就会发现，遍历每一页的过程中，总计有pageSize*n*2个对象直到保存到MongoDB后，遍历下一页时这些对象才会得到释放，其中pageSize是每一页的用户数量（方法getUserIdByPage中），n是用户平均安装APP的数量，之所以乘以2是因为有一半是MySQL数据模型对象，另一半是MongoDB数据模型对象。假设每一页1000个用户，用户平均安装的APP数量为100个。那么处理每一页时总计有20w个对象一直常驻，且无法被GC掉。

如何解决

了解了问题的本质后，就比较好解决了，而且有很多种方法可以解决。

方法1-增大Young区

方法1就是增大Young区大小，准确的说是增大Eden区大小，大到能容忍20w个对象。那如果迁移程序将pageSize改为2000，那么就需要增大Eden区直到能容下40w个对象。

方法2-优化代码

方法1优化办法的JVM参数还得跟pageSize参数值耦合，有点约束。我们能否优化成无论pageSize多大。每次内存中最大常驻对象数量是一定的呢？当然可以，请看下面这段优化后的代码：

List<Long> userList = getUserIdByPage(pageNo);
List<UserAppMongo> userAppMongoList = new ArrayList<>(userList.size());for (Long userId:userList){List<AppFromMySQL> appFromMySQLList = getUserInstalledAppList(userId);UserAppMongo userAppMongo = new UserAppMongo();userAppMongo.setId(System.nanoTime()+"");userAppMongo.setUserId(userId);userAppMongo.setAppMongoList(appFromMySQL2AppMongo(appFromMySQLList));userAppMongoList.add(userAppMongo);// 核心优化代码if (userAppMongoList.size()>=threshold){save2MongoDB(userAppMongoList);userAppMongoList.clear();}
}
// save List<UserAppMongo> to mongodb
save2MongoDB(userAppMongoList);

说明：

核心优化代码的threshold的值，取一个合理的值即可。这样的话，无论getUserIdByPage()时pageSize多大，整个堆中不可GC的驻留对象只会多几个userId而已。

假设threshold设置为500，那么在遍历到下一页之前整个堆中不可GC的驻留对象个数为：500*100*2=10000，其中100是平均每个用户安装APP的数量。

这样优化以后，无论getUserIdByPage()中批量取用户时pageSize为1000，还是5000，还是20000。JVM参数都不需要调整，且非常稳定。jstat -gcutil 56436 2s结果如下所示，运行一段时间都没有FGC，并且Old涨幅基本可以接受：

  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT35.87   0.00  54.00   3.64  61.16  61.52     52    3.894     0    0.000    3.8940.00  50.37  48.00   3.89  61.16  61.52     67    4.392     0    0.000    4.39212.41   0.00  46.00   4.14  61.16  61.52     80    4.990     0    0.000    4.9901.66  14.04 100.00   4.38  61.16  61.52     89    5.636     0    0.000    5.6360.00  27.05  24.00   4.63  61.16  61.52    103    6.146     0    0.000    6.146