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()+"");//测试代码任意模拟一个伪唯一ID
                userAppMongo.setUserId(userId);
                userAppMongo.setAppMongoList(appFromMySQL2AppMongo(appFromMySQLList));
                userAppMongoList.add(userAppMongo);
            }
            // save List<UserAppMongo> to mongodb
            save2MongoDB(userAppMongoList);
        }
    }

    private static void save2MongoDB(List<UserAppMongo> userAppMongoList) throws Exception {
        // 模拟保存一次数据到mongodb中要5ms
        Thread.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 copy
            appMongoList.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     GCT
 29.81  82.88 100.00  39.35  61.05  61.52     40   16.274     7    6.756   23.030
 91.43  21.01 100.00  39.26  61.05  61.52     45   17.791     8    7.327   25.118
  0.00  90.53   0.00  88.47  61.05  61.52     47   18.694     9    7.327   26.021
 23.00   0.00 100.00  19.10  61.05  61.52     52   19.655    10    9.227   28.882
 93.29   0.00   0.00  90.25  61.05  61.52     56   21.326    11    9.227   30.553
 94.21   0.00   0.00  82.39  61.05  61.52     60   22.435    12   10.253   32.688
 93.23  93.23 100.00  71.09  61.05  61.52     64   23.223    12   11.027   34.250

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

  1. Old区涨的过快;
  2. FGC太频繁;

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

分析问题

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

[afei@node1 ~]# jstat -gcutil 121165 100
  S0     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.812
 96.58   0.00  18.00  34.05  58.25  51.76    289    7.937    63    2.921   10.858
 96.84   0.00   0.00  70.73  58.25  51.76    291    8.001    63    2.921   10.923
  0.00   0.00   0.00  27.31  58.25  51.76    291    8.033    64    2.978   11.010
  0.00  99.47   0.00  45.80  58.25  51.76    293    8.077    64    2.978   11.055
  0.00  96.84   0.00  83.17  58.25  51.76    295    8.144    65    2.978   11.121
 96.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:


headp dump

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

outgoing references

迁移程序比较简单,核心代码就那么几行,通过问题对象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);

这段代码的逻辑是:

  1. 得到一批用户ID;
  2. 然后遍历这些用户ID,取得每个用户已安装APP集合转换成MongoDB需要的数据模型;
  3. 批量保存到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     GCT
 35.87   0.00  54.00   3.64  61.16  61.52     52    3.894     0    0.000    3.894
  0.00  50.37  48.00   3.89  61.16  61.52     67    4.392     0    0.000    4.392
 12.41   0.00  46.00   4.14  61.16  61.52     80    4.990     0    0.000    4.990
  1.66  14.04 100.00   4.38  61.16  61.52     89    5.636     0    0.000    5.636
  0.00  27.05  24.00   4.63  61.16  61.52    103    6.146     0    0.000    6.146
?著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 214,029评论 6 493
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 91,238评论 3 388
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事?!?“怎么了?”我有些...
    开封第一讲书人阅读 159,576评论 0 349
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 57,214评论 1 287
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 66,324评论 6 386
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 50,392评论 1 292
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 39,416评论 3 412
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 38,196评论 0 269
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 44,631评论 1 306
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 36,919评论 2 328
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 39,090评论 1 342
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 34,767评论 4 337
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 40,410评论 3 322
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,090评论 0 21
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,328评论 1 267
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 46,952评论 2 365
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 43,979评论 2 351

推荐阅读更多精彩内容