引言: 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还有很多的类似参数,这个需要大家自行上网查找了。