十秒钟搞定JVM GC分析和改善建议

摸鱼编程
336 阅读5分钟

笔者是一名工作10年的java程序员，现在在某大厂任职架构师，工作中解决过非常多的GC问题。基于这些经验，笔者打造了一款可以全自动分析jvm GC并给出改善建议的产品:SimpleGC,来帮助大家快速解析jvm GC 状况，并得到最佳的改善建议。

GC为什么重要

Java 相比C/C++等语言而言，其中一个最大的区别就是Java是一门带有自动内存管理的高级编程语言。和平时理解大家所理解的GC单纯回收对象不同，自动内存管理包含两个重要阶段：1. 内存分配 2. 内存回收

GC掌握着所有堆上对象的分配和回收，基本上意味着所有的操作都需要经过GC，而GC一旦出现问题就会导致整个程序的速度拖慢，甚至程序崩溃。同时GC还都会导致STW(Stop-The-World),这对于高并发高性能的程序也是非常大的影响，对于想要打造高并发高性能系统的程序员而言，GC是必学的一环。

GC关键指标

吞吐率(throughput)

吞吐率的计算方式为 吞吐率 = 1 - (GC STW 时间 / 程序运行时间).吞吐率表达的概念是 程序有多少时间能用于运行用户代码，而剩下就是时间就是JVM做GC所占用的时间。

一般健康的吞吐率为>99%.

延迟(latency)

延迟就是每次JVM做GC的暂停时间,不管是新生代的Young GC还是老年代的Major GC 还是全代的FULL GC，都会导致暂停。暂停时间是影响性能的关键因素。

暂停时间不能简单看平均值(avg),而是要使用类似直方图分布的方式来表达才最直观。

如何做GC分析

GC分析可以使用以下多种手段实现:

  1. jstat
  2. jmx
  3. promethus 埋点监控
  4. gc日志

其中只有gc日志是最精准的分析载体,但是也因为信息量最大，并且是非结构化的数据，分析成本也就最高。但别怕，本文就是给大家带来低成本的分析工具的。

jstat、jmx

jstat和jmx的用法，在另外一片文章中有过介绍 最常用的工具jstat居然错得离谱？一文重新学习gc诊断.

prometheus

prometheus 是目前最热门的可观测性metricx工具，java 客户端的地址为:github.com/prometheus/… .

其中 simpleclient_hotspot 就是对应现在Oracle JDK 和OpenJDK的监控组件。他俩的实现都是HotSpot VM。

说明方法也非常简单:

  1. pom.xml 引入以下组件
<dependency>
  <groupId>io.prometheus</groupId>
  <artifactId>simpleclient</artifactId>
  <version>0.16.0</version>
</dependency>
<!-- Hotspot JVM metrics-->
<dependency>
  <groupId>io.prometheus</groupId>
  <artifactId>simpleclient_hotspot</artifactId>
  <version>0.16.0</version>
</dependency>
<!-- Exposition HTTPServer-->
<dependency>
  <groupId>io.prometheus</groupId>
  <artifactId>simpleclient_httpserver</artifactId>
  <version>0.16.0</version>
</dependency>
  1. 代码中初始化
DefaultExports.initialize();

Server server = new Server(1234);
ServletContextHandler context = new ServletContextHandler();
context.setContextPath("/");
server.setHandler(context);

context.addServlet(new ServletHolder(new MetricsServlet()), "/metrics");

代码初始化完成后，即可通过 ip:1234/metrics 查看指标情况

通过prometheus方式埋点获取的GC数据只能获取到GC次数，GC耗时。并且因为上报是根据prometheus的抓取间隔上报，会导致数据被时间稀释，无法得到精确结果。

gc日志

GC日志包含最多的GC相关信息，并且有非常多的额外选项可以在特定场景输出特定事件数据。下面是一个典型的jdk8的G1GC日志，纯文本格式，需要经过处理才能提取出来我们分析所需要的指标。

2023-02-23T12:38:41.197+0800: 4293983.501: [SoftReference, 0 refs, 0.0011474 secs]2023-02-23T12:38:41.198+0800: 4293983.502: [WeakReference, 3 refs, 0.0008119 secs]2023-02-23T12:38:41.199+0800: 4293983.503: [FinalReference, 114 refs, 0.0006883 secs]2023-02-23T12:38:41.200+0800: 4293983.503: [PhantomReference, 2 refs, 0 refs, 0.0014310 secs]2023-02-23T12:38:41.201+0800: 4293983.505: [JNI Weak Reference, 0.0001310 secs], 0.0844675 secs] [Parallel Time: 71.7 ms, GC Workers: 10] [GC Worker Start (ms): Min: 4293983428.2, Avg: 4293983428.3, Max: 4293983428.5, Diff: 0.2] [Ext Root Scanning (ms): Min: 2.3, Avg: 3.6, Max: 9.3, Diff: 6.9, Sum: 35.6] [Update RS (ms): Min: 8.9, Avg: 14.5, Max: 15.8, Diff: 6.9, Sum: 145.3] [Processed Buffers: Min: 67, Avg: 96.4, Max: 123, Diff: 56, Sum: 964] [Scan RS (ms): Min: 0.2, Avg: 0.5, Max: 0.6, Diff: 0.4, Sum: 4.6] [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] [Object Copy (ms): Min: 52.3, Avg: 52.5, Max: 52.6, Diff: 0.3, Sum: 525.3] [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Termination Attempts: Min: 1, Avg: 1.1, Max: 2, Diff: 1, Sum: 11] [GC Worker Other (ms): Min: 0.1, Avg: 0.2, Max: 0.3, Diff: 0.2, Sum: 1.8] [GC Worker Total (ms): Min: 71.1, Avg: 71.3, Max: 71.5, Diff: 0.4, Sum: 712.7] [GC Worker End (ms): Min: 4293983499.5, Avg: 4293983499.6, Max: 4293983499.7, Diff: 0.2] [Code Root Fixup: 0.3 ms] [Code Root Purge: 0.0 ms] [Clear CT: 1.0 ms] [Other: 11.4 ms] [Choose CSet: 0.0 ms] [Ref Proc: 4.9 ms] [Ref Enq: 0.3 ms] [Redirty Cards: 0.3 ms] [Humongous Register: 0.3 ms] [Humongous Reclaim: 0.2 ms] [Free CSet: 2.8 ms] [Eden: 3530.0M(3530.0M)->0.0B(3532.0M) Survivors: 156.0M->154.0M Heap: 5118.0M(6144.0M)->1564.0M(6144.0M)] [Times: user=0.74 sys=0.00, real=0.09 secs]

手工分析GC日志的挑战：

  1. JDK版本差异。JDK8、JDK9等GC日志格式不同，手工分析需要掌握不同版本之间的区别
  2. GC算法类型多。日志格式也不同。常用的GC算法有Parallel GC、CMS GC、G1 GC、ZGC、ShenandoahGC，每一种格式都学习一遍，对于时间浪费非常严重，投入产出比不高
  3. 日志开关选项多。GC提供了相当多的额外事件日志开关选项，比如：-XX:+PrintAdaptiveSizePolicy -XX:+PrintTenuringDistribution -XX:+PrintReferenceGC,对于这些开关是否开启本身就是一个问题，同时开启以后，相应的日志如何分析又是另外一个难题。

SimpleGC

基于以上这些复杂的挑战，我们研发了SimpleGC产品,可以直接上传GC日志，SimpleGC会分析一下情况:

  1. JVM 参数配置是否合理，是否开启了一些无用的选项，是否存在更稳定效率更高的配置
  2. GC 关键指标：吞吐率和延迟，其中延迟会以多种统计指标展示
  3. GC 触发原因：根据GC触发的原因，可以更好地针对性优化
  4. long pause： 自动标注出暂停时间大于0.5s的GC事件，帮助用户一眼发现瓶颈
  5. 对象创建速率分析：自动分析出当前程序的对象创建速率
  6. 针对GC表现，给出改善建议

实践

  1. 首先打开该站点 image.png

  2. 在日志上传框中选择GC日志文件，点击分析按钮

  3. 结果查看

基本情况 image.png 改善建议

image.png

总结

simpleGC是一款智能，通用的JVM GC日志分析工具，可以分析所有JDK版本和所有GC日志，并给出关键指标分析和建议。

avatar
文章
阅读
粉丝