JVM调试追中参数设置

布满荆棘的人生 2022-09-24 14:18 17阅读 0赞

引言： JVM提供了诸多的参数配置，打印出当前JVm的各类信息，方便后续进行Java应用的排查，本文将详细介绍若干常用的JVM调试追踪参数。

测试环境说明： JVM JDK8, Windows 7, STS 3.8.0，

特别说明：  每一代的JDK打印出来的信息各有不同的差异，且GC本身也有差异，故需要注意这些区别不同。

1.  JVM调试跟踪之 打印简单的GC信息

参数: -verbose:gc, -XX:+PrintGC

日志样本：

[GC (Allocation Failure)  31744K->4734K(121856K), 0.0231062 secs]
    
      .   ____          _            __ _ _
     /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
    ( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
     \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
      '  |____| .__|_| |_|_| |_\__, | / / / /
     =========|_|==============|___/=/_/_/_/
     :: Spring Boot ::        (v1.3.6.RELEASE)
    
    2016-08-02 09:43:14.965  INFO 3620 --- [  restartedMain] com.rain.wx.WxDemoApplication            : Starting WxDemoApplication on 08-201412015324 with PID 3620 (E:\MyTechnicalStack\mytechnicalstack\application\WXDemo\target\classes started by 201412015324 in E:\MyTechnicalStack\mytechnicalstack\application\WXDemo)
    2016-08-02 09:43:14.968  INFO 3620 --- [  restartedMain] com.rain.wx.WxDemoApplication            : The following profiles are active: dev
    [GC (Allocation Failure)  36478K->9437K(121856K), 0.0260942 secs]
    [GC (Allocation Failure)  41181K->14749K(121856K), 0.0172923 secs]
    2016-08-02 09:43:15.604  INFO 3620 --- [  restartedMain] ationConfigEmbeddedWebApplicationContext : Refreshing org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@51db255f: startup date [Tue Aug 02 09:43:15 CST 2016]; root of context hierarchy
    [GC (Allocation Failure)  46493K->17476K(153600K), 0.0315685 secs]
    [GC (Metadata GC Threshold)  53905K->19667K(153600K), 0.0198172 secs]
    [Full GC (Metadata GC Threshold)  19667K->10919K(125952K), 0.0690072 secs]
    [GC (Allocation Failure)  74407K->13064K(170496K), 0.0192360 secs]

这里列出了GC的日志样本，截取一个样例进行分析：

[Full GC (Metadata GC Threshold)  19667K->10919K(125952K), 0.0690072 secs]
    [GC (Allocation Failure)  74407K->13064K(170496K), 0.0192360 secs]

Full GC 垃圾回收的一种方式， Metadata GC java类的元数据的阀值。  其对内存从19667k回收至10919k，释放了9M，剩余的堆内存占用为12592k，时间消耗为：0.0690072secs

第二个为内存分配失败，同时进行了内存回收操作。

2.   JVM调试跟踪之 打印详细的GC信息

参数： -XX:+PrintGCDetails, +XX:+PrintGCTimeStamps

应用场景： 查看更为详细的GC信息

日志样例：

10.595: [GC (Metadata GC Threshold) [PSYoungGen: 99723K->16630K(238592K)] 116636K->33542K(302592K), 0.0539425 secs] [Times: user=0.16 sys=0.01, real=0.05 secs] 
    10.649: [Full GC (Metadata GC Threshold) [PSYoungGen: 16630K->0K(238592K)] [ParOldGen: 16912K->25195K(87552K)] 33542K->25195K(326144K), [Metaspace: 34777K->34777K(1081344K)], 0.1994152 secs] [Times: user=0.47 sys=0.05, real=0.20 secs] 
    2016-08-02 09:49:10.497  INFO 9004 --- [  restartedMain] o.s.b.d.a.OptionalLiveReloadServer       : LiveReload server is running on port 35729
    2016-08-02 09:49:10.612  INFO 9004 --- [  restartedMain] o.s.j.e.a.AnnotationMBeanExporter        : Registering beans for JMX exposure on startup

样例分析：

10.649: [Full GC (Metadata GC Threshold) [PSYoungGen: 16630K->0K(238592K)] [ParOldGen: 16912K->25195K(87552K)] 33542K->25195K(326144K), [Metaspace: 34777K->34777K(1081344K)], 0.1994152 secs] [Times: user=0.47 sys=0.05, real=0.20 secs]

Full GC： 垃圾回收的方法，起因为MetaGC Threadhold触发了。

PSYoungGen：  年轻代的垃圾回收，

ParOldGen:  年老代的垃圾回收

Metaspace: 34777K->34777K(1081344K,   元数据空间没有发生内存的变化，即未收集到GC垃圾，内存使用状况不变。

后面的是各个阶段的时间消耗。

3. -Xlogger:logpath  设置gc的日志路径

参数设置： -Xlogger:log/gc.log， 将gc.log的路径设置到当前目录的log目录下.

应用场景： 将gc的日志独立写入日志文件，将GC日志与系统业务日志进行了分离，方便开发人员进行追踪分析。

4. JVM调试追踪之 -XX:+PrintHeapAtGC， 打印推信息

参数设置： -XX：+PrintHeapAtGC

应用场景： 获取Heap在每次垃圾回收前后的使用状况

日志样例：

{Heap before GC invocations=2 (full 0):
     PSYoungGen      total 36864K, used 36465K [0x00000000d6e00000, 0x00000000db600000, 0x0000000100000000)
      eden space 31744K, 100% used [0x00000000d6e00000,0x00000000d8d00000,0x00000000d8d00000)
      from space 5120K, 92% used [0x00000000d8d00000,0x00000000d919c4b0,0x00000000d9200000)
      to   space 5120K, 0% used [0x00000000db100000,0x00000000db100000,0x00000000db600000)
     ParOldGen       total 84992K, used 8K [0x0000000084a00000, 0x0000000089d00000, 0x00000000d6e00000)
      object space 84992K, 0% used [0x0000000084a00000,0x0000000084a02000,0x0000000089d00000)
     Metaspace       used 13833K, capacity 13978K, committed 14208K, reserved 1060864K
      class space    used 1762K, capacity 1820K, committed 1920K, reserved 1048576K
    3.946: [GC (Allocation Failure) [PSYoungGen: 36465K->5105K(68608K)] 36473K->9419K(153600K), 0.0104688 secs] [Times: user=0.00 sys=0.01, real=0.01 secs] 
    Heap after GC invocations=2 (full 0):
     PSYoungGen      total 68608K, used 5105K [0x00000000d6e00000, 0x00000000db600000, 0x0000000100000000)
      eden space 63488K, 0% used [0x00000000d6e00000,0x00000000d6e00000,0x00000000dac00000)
      from space 5120K, 99% used [0x00000000db100000,0x00000000db5fc510,0x00000000db600000)
      to   space 5120K, 0% used [0x00000000dac00000,0x00000000dac00000,0x00000000db100000)
     ParOldGen       total 84992K, used 4314K [0x0000000084a00000, 0x0000000089d00000, 0x00000000d6e00000)
      object space 84992K, 5% used [0x0000000084a00000,0x0000000084e36a20,0x0000000089d00000)
     Metaspace       used 13833K, capacity 13978K, committed 14208K, reserved 1060864K
      class space    used 1762K, capacity 1820K, committed 1920K, reserved 1048576K
    }

日志分析：

年轻代                         总共内存使用        已经使用             起始地址                                当前地址                                 地址上限

PSYoungGen      total 36864K, used 36465K [0x00000000d6e00000, 0x00000000db600000, 0x0000000100000000)
        伊甸区      占用100%               伊甸区域的起始地址       当前地址         最大地址上限
       eden space 31744K, 100% used [0x00000000d6e00000,0x00000000d8d00000,0x00000000d8d00000)
        S0区域     内存占用 百分比         地址信息
       from space 5120K, 92% used [0x00000000d8d00000,0x00000000d919c4b0,0x00000000d9200000)   
        S1区域     内存占用  百分比      地址信息
       to   space 5120K, 0% used [0x00000000db100000,0x00000000db100000,0x00000000db600000)

年老代的分析：

年老代                         总共占用                     目前使用                地址空间

ParOldGen       total 84992K, used 8K [0x0000000084a00000, 0x0000000089d00000, 0x00000000d6e00000)
        实际对象占用的内存情况
       object space 84992K, 0% used [0x0000000084a00000,0x0000000084a02000,0x0000000089d00000)

元数据区，存放class、方法/Main等静态信息

元数据区域               已经使用                  容量                                  提交                             预留

Metaspace       used 13833K, capacity 13978K, committed 14208K, reserved 1060864K
        类静态信息       已经使用    容量             已经提交                预留
       class space    used 1762K, capacity 1820K, committed 1920K, reserved 1048576K

5. JVM监控调试之类加载信息 -XX:+TraceClassLoading

参数方法：  -XX:+TraceClassLoading

应用场景：  在系统控制台信息中看到class加载的过程和具体的class信息，可用以分析类的加载顺序以及是否可进行精简操作。

日志样例：

[2m2016-08-02 10:21:51.282[0;39m [32m INFO[0;39m [35m12448[0;39m [2m---[0;39m [2m[  restartedMain][0;39m [36mo.s.c.support.DefaultLifecycleProcessor [0;39m [2m:[0;39m Starting beans in phase 0
    [Loaded org.springframework.jmx.export.naming.SelfNaming from file:/D:/M2Repository/repositories/org/springframework/spring-context/4.2.7.RELEASE/spring-context-4.2.7.RELEASE.jar]
    [Loaded org.springframework.jmx.support.ObjectNameManager from file:/D:/M2Repository/repositories/org/springframework/spring-context/4.2.7.RELEASE/spring-context-4.2.7.RELEASE.jar]
    [Loaded javax.management.modelmbean.ModelMBeanInfoSupport from C:\Program Files\Java\jre1.8.0_51\lib\rt.jar]
    [Loaded javax.management.DescriptorAccess from C:\Program Files\Java\jre1.8.0_51\lib\rt.jar]
    [Loaded javax.management.modelmbean.ModelMBeanAttributeInfo from C:\Program Files\Java\jre1.8.0_51\lib\rt.jar]
    [Loaded javax.management.modelmbean.ModelMBeanConstructorInfo from C:\Program Files\Java\jre1.8.0_51\lib\rt.jar]
    [Loaded javax.management.modelmbean.ModelMBeanNotificationInfo from C:\Program Files\Java\jre1.8.0_51\lib\rt.jar]
    [Loaded javax.management.modelmbean.ModelMBeanOperationInfo from C:\Program Files\Java\jre1.8.0_51\lib\rt.jar]
    [Loaded javax.management.modelmbean.DescriptorSupport from C:\Program Files\Java\jre1.8.0_51\lib\rt.jar]
    [Loaded sun.reflect.GeneratedConstructorAccessor32 from __JVM_DefineClass__]
    [Loaded com.sun.proxy.$Proxy76 from sun.misc.Launcher$AppClassLoader]
    [Loaded com.sun.proxy.$Proxy77 from sun.misc.Launcher$AppClassLoader]
    [Loaded org.springframework.jmx.export.metadata.AbstractJmxAttribute from file:/D:/M2Repository/repositories/org/springframework/spring-context/4.2.7.RELEASE/spring-context-4.2.7.RELEASE.jar]
    [Loaded org.springframework.jmx.export.metadata.ManagedResource from file:/D:/M2Repository/repositories/org/springframework/spring-context/4.2.7.RELEASE/spring-context-4.2.7.RELEASE.jar]
    [Loaded org.springframework.beans.annotation.AnnotationBeanUtils from file:/D:/M2Repository/repositories/org/springframework/spring-beans/4.2.7.RELEASE/spring-beans-4.2.7.RELEASE.jar]
    [Loaded org.springframework.jmx.export.annotation.ManagedAttribute from file:/D:/M2Repository/repositories/org/springframework/spring-context/4.2.7.RELEASE/spring-context-4.2.7.RELEASE.jar]
    [Loaded com.sun.proxy.$Proxy78 from sun.misc.Launcher$AppClassLoader]

6.  JVM追踪测试之-XX:+PrintHistogram 打印类的内存占用

参数方法：-XX:+PrintHistogram

应用场景： 分析各类内存对象的占用情况

使用方法：  ctrl+break window系统下， 令人懊恼的是，我竟然没有在我的笔记本上找到break键，好吧，就这样吧，了解一下算了。

7. 总结

以上只是简单介绍了一些调试打印的参数，其实JVM还有很多的类似参数，这个需要大家自行上网查找了。