【Java虚拟机】JVM日志分析和可视化工具实操

1.JVM垃圾GC日志参数配置实战

• Java虚拟机中垃圾收集器在运行过程中输出的日志信息
• 主要用于分析垃圾收集器的运行状态、优化垃圾收集器的工作效率以及定位垃圾收集相关的问题
• GC日志会包含以下内容
  • 垃圾收集器的名称和版本信息。
  • 垃圾收集器的运行时间、开始时间和结束时间。
  • 垃圾收集器的运行模式、垃圾收集算法和垃圾收集器的参数设置。
  • 垃圾收集器的运行情况，包括垃圾收集的次数、垃圾收集的时间、垃圾回收的内存空间等
• 常见参数

• 测试代码

/**
 * 模拟OOM测试
 * @author lixiang
 * @date 2023/5/4 20:53
 */
public class JVMTest {
    public static void main(String[] args) throws InterruptedException {
        List<Object> objects = new ArrayList<>();
        while(true){
            objects.add(new Object());
        }
    }
}

• 配置案例实战，JDK11版本，G1垃圾收集器

-XX:+UseG1GC -XX:MaxGCPauseMillis=100 -Xms524m -Xmx524m -XX:+PrintCommandLineFlags -Xlog:gc:gc.log

• 新版GC日志输出的组成部分

  • 时间戳：记录GC发生的时间戳，精确到毫秒

  • 日志级别：日志的级别，包括debug、trace、info、warning、error等

  • 日志标签：日志的标签，用于区分不同类型的日志

  • 日志内容：记录GC相关的信息，包括GC算法、GC的时间、GC前后的内存使用情况、回收的对象数量等。

• 新版GC日志配置格式 -Xlog:[selectors]:[output]:[decorators][:output-options]

  • JVM 采用的是 <tag-set>=<level>的形式来表示 selectors
  • 默认情况下 tag 为all，表示所有的 tag，level 为 INFO
  • selector 可以进行组合的，不同的 selector 之间用逗号分隔
    • 同时输出 gc 和 gc+metaspace 这两类 tag 的日志 -Xlog:gc=debug,gc+metaspace:gc.log

  -XX:+UseG1GC -XX:MaxGCPauseMillis=100 -Xms524m -Xmx524m -XX:+PrintCommandLineFlags  -Xlog:gc=debug,gc+metaspace:gc.log
  

  

  • JVM 提供了通配符 * 来解决精确匹配的问题，比如想要所有 tag 为 gc 的debug级别日志 -Xlog:gc*=debug

  -XX:+UseG1GC -XX:MaxGCPauseMillis=100 -Xms524m -Xmx524m -XX:+PrintCommandLineFlags  -Xlog:gc*=debug:gc.log
  
  # gc*=debug：指定输出GC相关日志，级别为debug，*表示所有的GC标签都会输出日志。
  

  

• 日志文件解读

-XX:+UseG1GC -XX:MaxGCPauseMillis=100 -Xms524m -Xmx524m -XX:+PrintCommandLineFlags -Xlog:gc=info:gc.log

日志内容
[24.575s][info][gc] GC(0) Pause Young (Concurrent Start) (G1 Humongous Allocation) 240M->238M(528M) 5.888ms

字段拆解
  [24.575s]：GC发生的时间戳，表示程序运行的时间
  [info]：日志级别，表示这是一条信息级别的日志
  [gc]：日志标签，表示这是一条GC相关的日志
  GC(0)：GC的编号，表示这是第一次GC
  
  Pause Young (Concurrent Start) (G1 Humongous Allocation)：
    GC的类型，表示这是一次Young GC，同时也是一次 Humongous Allocation的GC，其中Concurrent Start表示并发启动的GC。
    
  240M->238M(528M)：
    GC前后堆内存的使用情况，其中240M表示GC前的已使用内存，238M表示GC后的已使用内存，528M表示堆内存的总大小
  
  5.888ms：GC的耗时，表示这次GC的执行时间
  
  这条GC日志记录了程序运行了24.575秒时发生的一次Young GC，回收了2M的内存空间，耗时5.888毫秒
  
————————————————————————————————————————————————————————
  
日志内容
[24.783s][info][gc] GC(3) Concurrent Cycle
[24.784s][info][gc] GC(3) Pause Remark 242M->242M(528M) 0.383ms
[24.784s][info][gc] GC(3) Pause Cleanup 242M->242M(528M) 0.066ms
[24.785s][info][gc] GC(3) Concurrent Cycle 2.374ms

字段拆解
	[24.783s][info][gc] GC(3) Concurrent Cycle：
  Mixed GC的相关信息，表示这是一次Mixed GC的开始。

	[24.784s][info][gc] GC(3) Pause Remark 242M->242M(528M) 0.383ms
  Mixed GC的相关信息，表示这是一次Remark阶段的GC，回收了0M的内存空间，耗时0.383毫秒。

	[24.784s][info][gc] GC(3) Pause Cleanup 242M->242M(528M) 0.066ms：
  Mixed GC的相关信息，表示这是一次Cleanup阶段的GC，回收了0M的内存空间，耗时0.066毫秒。

	[24.785s][info][gc] GC(3) Concurrent Cycle 2.374ms：
  Mixed GC的相关信息，表示这是一次Mixed GC的结束，耗时2.374毫秒。

  这段GC日志记录了程序运行了24.783秒一次Mixed GC，Mixed GC回收了0M的内存空间，耗时2.374毫秒

• 使用技巧

  • GC日志输出到文件中 -Xlog:gc=info:file=/path/app.log

  • 指定日志切割的大小和方式 -Xlog:gc=info:file=/path/app.log:filesize=104857600,filecount=5

    • filesize=104857600：指定单个日志文件大小为100MB，超过这个大小会自动切换到新的日志文件。
    • filecount=5：指定日志文件数量不超过5个，超过这个数量会删除最早的日志文件。

  • 配置实操

-XX:+UseG1GC -XX:MaxGCPauseMillis=100 -Xms524m -Xmx524m -XX:+PrintCommandLineFlags -Xlog:gc*=info:file=portal_gc.log:utctime,level,tags:filecount=5,filesize=1M

• 详细解释字段

-XX:+UseG1GC：使用G1垃圾回收器

-XX:MaxGCPauseMillis=100：设置最大垃圾回收暂停时间为100毫秒

-Xms524m：设置JVM堆的初始大小为524MB

-Xmx524m：设置JVM堆的最大大小为524MB

-XX:+PrintCommandLineFlags：打印JVM启动参数

-Xlog:gc*=info:file=portal_gc.log:utctime,level,tags:filecount=5,filesize=1M：
  Xlog：指定日志输出方式为日志文件。
  gc*：指定日志输出类型为GC相关的日志。
  info：指定输出日志的级别为info级别。
  file=portal_gc.log：指定日志输出的文件名为portal_gc.log。
  utctime：指定日志输出的时间戳使用UTC时间。
  level,tags：指定日志输出的格式包含级别和标签信息。
  filecount=5：指定最多保存5个日志文件。
  filesize=1M：指定每个日志文件的大小为1MB。

• 该配置使用G1垃圾回收器，设置最大垃圾回收器暂停时间为100毫秒，JVM堆的初始堆大小和最大堆大小均为524MB，并打印JVM启动参数和输出GC日志到文件portal_gc.log中，文件数量为5个，每个文件大小为1MB，日志格式为info级别，包含时间戳、级别和标签。

2.JVM内存OOM堆栈快照配置实战

• 配置OOM时的堆栈快照信息

  • -XX:+HeapDumpOnOutOfMemoryError：当发生OOM时，自动生成堆栈快照文件。

  • -XX:HeapDumpPath=<path>：指定堆栈快照文件的输出路径。

  • -XX:OnOutOfMemoryError="<cmd>；<cmd>"：当发生OOM时，执行指定的命令

  • 案例-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=heapdump.hprof

-XX:+UseG1GC -XX:MaxGCPauseMillis=100 -Xms524m -Xmx524m -XX:+PrintCommandLineFlags -Xlog:gc*=info:file=portal_gc.log:utctime,level,tags:filecount=5,filesize=1M -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=heapdump.hprof

• 将在发生OOM时生成一个名为heapdump.hprof的堆栈快照文件，并将其保存到当前项目的目录下

• heapdump.hprof 文件可以使用多种工具进行分析

• 在线分析工具：https://heaphero.io

• 堆分析工具可能需要大量的内存和计算资源来加载和分析heapdump.hprof文件

• 建议在高配置的机器上运行堆分析工具，并为其分配足够的内存和计算资源

• 生产环境配置案例

  • 服务器配置是8核16g内存，需要部署一个springboot写的电商项目，日访问量100万左右的UV
  • 给一份生产环境配置的jvm参数的值，要求基于jdk11+配置oom时的堆栈快照信息

-server
-Xms8g
-Xmx8g
-XX:+UseG1GC
-XX:MaxGCPauseMillis=200
-XX:G1HeapRegionSize=32M
-XX:ActiveProcessorCount=8
-XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=heapdump.hprof
-XX:+PrintCommandLineFlags 
-Xlog:gc*=info:file=portal_gc.log:utctime,level,tags:filecount=50,filesize=100M

参数说明

  -Xms8g：指定JVM堆内存最小值为8G。

  -Xmx8g：指定JVM堆内存最大值为8G。

  -XX:+UseG1GC：指定使用G1垃圾收集器。

  -XX:MaxGCPauseMillis=200：指定最大垃圾回收暂停时间为200毫秒。

  -XX:G1HeapRegionSize=32M：指定G1垃圾收集器的堆区域大小为32MB。

  -XX:ActiveProcessorCount=8：指定并行垃圾回收器的线程数为8，在JDK 9及之后的版本中，ParallelGCThreads参数已被替代为-XX:ActiveProcessorCount参数，用于自动计算并行垃圾回收线程数
  
  -server：指定JVM使用服务器模式运行，优化性能。

  -XX:+HeapDumpOnOutOfMemoryError：指定在发生内存溢出时生成堆转储文件。

  -XX:HeapDumpPath=/var/log/heapdump.hprof：指定堆转储文件的路径。

  -Xlog:gc*=info:file=portal_gc.log:utctime,level,tags:filecount=50,filesize=100M：指定GC日志的输出格式和位置，记录GC相关信息。
  
  -XX:+PrintCommandLineFlags：打印JVM启动时的命令行参数，可以去除
   
方便测试OOM，可以调整 -Xms524m -Xmx524m

• 注意：使用G1收集器的时候，不用指定-Xmn

• 在G1中，堆内存被划分为多个区域，每个区域都可以作为年轻代或老年代的一部分
• G1的年轻代采用了不同于传统的基于分代的HotSpot垃圾收集器的方式，因此不需要指定-Xmn参数来设置年轻代的大小
• G1利用自适应的内存分配策略来动态地调整年轻代的大小
  • 根据堆的使用情况来确定哪些区域应该作为年轻代，以及年轻代的大小
  • G1垃圾收集器不需要显式地指定-Xmn参数，通过自适应的方式来优化内存的使用和垃圾收集的效率

3.可视化GC日志分析工具GCEasy实战

• GC Easy一个在线GC日志分析工具，可以帮助用户快速分析Java应用程序的GC日志，诊断内存泄漏和性能问题

• 支持多种GC日志格式，包括HotSpot、JRockit、IBM、Azul等。

• 自动分析GC日志，并生成易于阅读和理解的报告，包括GC统计信息、GC时长、GC频率、堆内存使用情况、内存泄漏等。

• 提供多种分析工具和图表，例如内存使用情况图、GC时长图、GC频率图、内存泄漏图等。

• 提供建议和最佳实践，帮助用户优化Java应用程序的性能和内存使用。

• 使用GCEasy的步骤

  • 收集Java应用程序的GC日志。

  • 将GC日志文件上传到GCEasy网站。

  • 点击“开始分析”按钮，等待分析结果。

  • 查看分析结果和建议，根据需要进行优化。

• 地址：https://gceasy.io/