JVM GC调优实战

从实例出发
新建一个空的 SpringBoot 项目, 比如 https://www.jianshu.com/p/2ba67caabcea

启动运行时加一些参数 -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -verbose:gc -Xloggc:gc.log

加 VM 参数

- XX:+PrintGCDetails 该选项用于记录 GC 运行时的详细数据信息并输出，是最基本、使用最普遍的一个选项。这个选项适用于所有 GC，输出内容主要包括新生成对象占用内存大小以及耗费时间、各个年 龄代的情况、每次回收的对应数据等。
-verbose:gc -Xloggc:gc.log 运行后会在项目文件夹下面生成一 个 gc.log 文件

启动项目，查看 gc.log 文件

gc.log

Parallel GC 是 JDK7 之后的默认 GC，它通过多线程方式减缓了独占式 GC 的副作用(停顿时间比较长)。年轻代和老年代在 Parallel GC 里都是并行执行且独占的，老年代也执行了压缩操作，这个压缩操作指的是移动存活对象到相邻位置，这样可以减少内存浪费，更好地实现内存布局 。
-XX:+UseCompressedOops 这个可以压缩指针，起到节 约内存占用的选项。 CompressedOops 的实现方式是在机器码中植入压缩与解压指令，可能会给 NM 增加额外的开销 。
-XX:+UseCompressedClassPointers 选项是在 JDK8 出现的，也是在永久 区消失之后出现的新的选项，主要用于对类的元数据进行压缩 。

GC 详细日志解读

日志释义

简单调优

下面是应用启动的日志

***
2018-10-11 14:47:44.561  INFO 9242 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2018-10-11 14:47:44.565  INFO 9242 --- [           main] com.example.gcdemo.GcDemoApplication     : Started GcDemoApplication in 4.139 seconds (JVM running for 4.801)
2018-10-11 14:47:44.944  INFO 9242 --- [on(4)-127.0.0.1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring FrameworkServlet 'dispatcherServlet'
2018-10-11 14:47:44.944  INFO 9242 --- [on(4)-127.0.0.1] o.s.web.servlet.DispatcherServlet        : FrameworkServlet 'dispatcherServlet': initialization started
***

应用启动花费了 4.139 秒，查看 gc.log 日志

应用启动 GC 日志

启动过程中总共进行了 10 次 GC, 包括两次 Full GC， YoungGen 进行了 4 次扩容，所以为了加快启动时间，尝试一下加大初始化内存大小，减少 GC 发生次数，启动参数添加 -Xms1536m -Xmx1536m

再次启动

***
2018-10-11 16:37:22.078  INFO 9422 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2018-10-11 16:37:22.081  INFO 9422 --- [           main] com.example.gcdemo.GcDemoApplication     : Started GcDemoApplication in 3.373 seconds (JVM running for 3.788)
***

gc.log

GC 次数减少了一半， 启动时间提升了 10%，感觉不明显

内存再加大一倍 -Xms3096m -Xmx3096m

2018-10-11 16:44:15.991  INFO 9431 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2018-10-11 16:44:15.994  INFO 9431 --- [           main] com.example.gcdemo.GcDemoApplication     : Started GcDemoApplication in 3.358 seconds (JVM running for 3.971)

gc.log

启动时间相比最开始提升了 19%

切换使用 G1GC

添加参数 -XX:+UseG1GC

2018-10-11 17:14:14.904  INFO 9517 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2018-10-11 17:14:14.908  INFO 9517 --- [           main] com.example.gcdemo.GcDemoApplication     : Started GcDemoApplication in 3.274 seconds (JVM running for 3.724)

又提升了一丢丢, 达到 21%, 不过 GC 日志就变得相当复杂了
gc.log
贴个外链
浅谈 G1 GC 日志格式