java fgc_java Metaspace频繁FGC问题定位

问题描述

数据服务是通过SQL对外提供数据查询的服务平台，底层存储支持HBase和MySQL两种。用户首先在管理平台上配置好接口的SQL详情

SQL接口配置

业务方通过微服务接口根据生成的ID以及接口参数来完成数据的查询，由于HBase不支持SQL引擎的查询，我们基于calcite实现了一套简单的SQL On HBase解析逻辑。

查看笔者前面的文章可以看到堆空间内存泄露的文章，可以了解相关的详情。但是不巧的是，堆内存泄露问题解决后，更恼火的问题又出现了，这次Old区的频繁GC被解决了，但是有些机器会有Metaspace的FGC出现。没办法，遇到问题解决问题呗，不然还能怎么办？

问题现象描述

程序JVM的启动参数描述如下，其中Metaspace的空间和最大空间均设置为512M，老年代开启CMS的垃圾回收策略。采用的JDK版本是1.8

Java(TM) SE Runtime Environment (build 1.8.0_131-b11)

Java HotSpot(TM) 64-Bit Server VM (build 25.131-b11, mixed mode)

JVM启动参数:

-Xmn1024m -Xms2500m -Xmx2500m -XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction=70 -XX:MaxDirectMemorySize=512m -XX:+UseCMSInitiatingOccupancyOnly -XX:SurvivorRatio=8 -XX:+ExplicitGCInvokesConcurrent -XX:MetaspaceSize=512m -XX:MaxMetaspaceSize=512m -XX:-OmitStackTraceInFastThrow -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/var/www/logs/gc-%t.log -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=10m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/var/www/logs -Djava.io.tmpdir=/var/www/tmp -Dsaffron.default.charset=UTF-16LE

系统运行一段时间后，GC日志开始频繁出现FGC的情况

2018-10-09T16:18:04.362+0800: 712.106: [Full GC (Metadata GC Threshold) 2018-10-09T16:18:04.362+0800: 712.106: [CMS: 188082K->208919K(1511424K), 0.9099363 secs] 829279K->208919K(2455168K), [Metaspace: 297357K->297357K(1284096K)], 0.9108698 secs] [Times: user=0.90 sys=0.00, real=0.91 secs]

2018-10-09T16:18:05.273+0800: 713.016: [Full GC (Last ditch collection) 2018-10-09T16:18:05.273+0800: 713.017: [CMS: 208919K->199979K(1511424K), 0.7405391 secs] 208919K->199979K(2455168K), [Metaspace: 297357K->297357K(1284096K)], 0.7412885 secs] [Times: user=0.74 sys=0.00, real=0.75 secs]

2018-10-09T16:18:08.263+0800: 716.007: [GC (CMS Initial Mark) [1 CMS-initial-mark: 199979K(1511424K)] 200219K(2455168K), 0.0288286 secs] [Times: user=0.04 sys=0.00, real=0.02 secs]

2018-10-09T16:18:08.292+0800: 716.036: [CMS-concurrent-mark-start]

2018-10-09T16:18:08.321+0800: 716.064: [Full GC (Metadata GC Thr