记一次 GC 优化

现象

近一段时间,项目 account-service 出现高峰期经常性报警的问题,且发布越久情况愈发严重。

从 Service Metrics 图表 来看,报警的时段 account-service 确实存在大量接口超时的情况,且单一时间集中于某一个 Pod 上。

观察 Grafana 上的图标,发现在该时间段 Pod 出现 Major GC 时间增加的情况,高达几秒,猜测是由于 GC 所引发的接口超时现象。

1
2
// prometheus 查询
increase(jvm_gc_pause_seconds_sum{kubernetes_pod_name=~"$app_name-$env-.+", action="end of major GC"}[2m])

那么接下来我们要解决两个问题,一是 GC 为什么会花费这么长的时间,二是情况为什么会变得严重。

GC

GC,也就是垃圾收集器,是有很多选择的,比较常见的有 Serial GC、CMS、Parallel GC、G1 等。Java 8 中 server 模式下默认的 GC 为 Parallel GC,由于 account-service 未对 GC 做任何特殊的配置,所以这也是 account-service 所使用的 GC。

Parallel GC 又被称作吞吐量优先的 GC,其特点是新生代和老年代 GC 都是并行进行的。而 CMS、G1 是以停顿时间优先考虑的,会为了减少停顿时间而牺牲一定的性能。

这话怎么理解呢?打个简单的比方,使用 Parallel GC 的话,一分钟可以处理请求 100 个,但最长时间的 GC 可能高达 1s。而使用 CMS、G1 的话处理的请求只有 90 个,但最长时间的 GC 控制在 200ms 以内。PS:以上数据仅做说明,不具实际意义。

而 account-service 作为 API server,响应时间的优先更高,为了避免 GC 带来的数秒停顿的问题,应该选择 CMS 或 G1。其实 Java 8 API server 都需要更换默认的 GC,因为高达秒级别的停顿基本不可承受。而 Java 9 之后就没这种坑了,默认的 GC 变成了 G1。

那么 CMS 和 G1 我们应该选哪个呢?我做了本地测试,发现在 account-service 上 CMS、G1 性能上没有大的差异,由于 CMS 在 Java 9 之后被标记成 deprecated,所以选择了 G1。

通过如下的启动命令切换 GC 到 G1。PS:不要显式设置新生代的大小,这会导致 G1 目标时间这个参数失效。

1
java -XX:+UseG1GC -jar $APP_JAR

上线后观察了一段时间,目前 GC 均在 200ms 以内,高峰期因为 GC 而报警的情况没有再出现了。

深挖

目前为止我们解决了第一个问题,接下来深挖第二个问题。

如果说报警是由于 GC 带来的长时间停顿影响的,那么报警变得频繁很有可能是因为 GC 变得更加频繁了。这时在 Grafana 观察到,随着时间, Live Data 越来越高。Live Data 表示老年代在 full GC 后所占用的空间,一直上涨表明 Server 可能存在内存泄漏问题,有一部内存无法释放且随着时间占用的空间越来越大。

1
2
// prometheus 查询
jvm_gc_live_data_size_bytes{kubernetes_pod_name=~"$app_name-$env-.+"}

从线上 dump heap 并通过 MAT 分析。PS:线上 dump heap 会引发线上服务一段时间内停止工作,可以通过灰度发布进行流量分配的方式降低对线上的影响。

发现主要有两个问题,一是 org.hibernate.internal.SessionFactoryImp 占用了 120 MB 的内存。二是其中一个 ThreadPool 中的 Thread 的 ThreadLocalMap 在不断增长。

查询完相关资料后,发现第一个问题是因为 Hibernate 的 QueryPlanCache。Hibernate 内部维护了 HQL 到 Query Plan 的缓存,默认大小 2048 个。但是 in 查询参数数量的不同会导致多个不同的 Query Plan。比如 select from User where id in (:id0) 和 select from User where id in (:id0, id1) 是两个 Query Plan。而 account-service 本身 in 查询的数量不少,使得这块占用了不小的堆内存。这问题可以通过配置 spring.jpa.properties.hibernate.query.in_clause_parameter_padding=true(hibernate 5.2.18 及以上生效),使 Hibernate 的 in 查询根据 2 的倍数,也就是 1-2-4-8-16 生成 Query Plan,减少相关内存占用。关于该问题的详细分析,可参考 Query Plan Cache Memory usageHow to improve statement caching efficiency with IN clause parameter padding

第二个通过 MAT 查到 ThreadLocalMap 中的 io.opentracing.util.ThreadLocalScope 没有释放,每一次 AysncTask 的执行都会使得 ThreadLocalScope 增加一个 span。由于 account-service 没有使用到 jaeger 的相应功能,是老版本基础库的依赖引入了相关的包。新版本的基础库将 opentracing 相关的功能独立成另一个包,通过升级解决了这个内存泄漏问题。

总结

  1. Java Server 可以通过切换 GC 为 G1 或 CMS 来降低停顿时间。
  2. 使用 Hibernate 并且 in 查询很多的 Server 可以通过配置 spring.jpa.properties.hibernate.query.in_clause_parameter_padding 来降低 QueryPlanCache 所占用的内存。
  3. 通过 Live Data Size 观察是否有内存泄漏情况,通过 MAT 分析内存泄漏的原因。