eclipse设置查看GC日志和如何理解GC日志

eclipse的gc日志配置可以在eclipse.ini中加入参数实现,不过打印的日志是整个eclipse的内存回收情况,如何实现

准确的看一个java应用的gc日志呢.

1. Run as -> Run configurations -> java应用名 -> arguments ->VM arguments,加入jvm参数就行


2. 测试代码

[java] view plain copy
  1. package cn.erong.test;  
  2.   
  3. public class Jtest {  
  4.     private static final int _1M = 1024*1024;  
  5.     public static void main(String[] args) {  
  6.         byte[] allocation1,allocation2,allocation3,allocation4;  
  7.         allocation1 = new byte[_1M/4];  
  8.         allocation2 = new byte[_1M/4];  
  9.         allocation3 = new byte[4*_1M];  
  10.         allocation4 = new byte[4*_1M];  
  11.         allocation4 = null;  
  12.         allocation4 = new byte[4*_1M];  
  13.           
  14.     }  
  15. }     

3.  测试看下,在vm arguments 中加入

[java] view plain copy
  1. -Xms20m --jvm堆的最小值  
  2. -Xmx20m --jvm堆的最大值  
  3. -XX:+PrintGCTimeStamps -- 打印出GC的时间信息  
  4. -XX:+PrintGCDetails  --打印出GC的详细信息  
  5. -verbose:gc --开启gc日志  
  6. -Xloggc:d:/gc.log -- gc日志的存放位置  
  7. -Xmn10M -- 新生代内存区域的大小  
  8. -XX:SurvivorRatio=8 --新生代内存区域中Eden和Survivor的比例  

4 . run  看下日志,到d盘找到 gc.log,如下

[plain] view plain copy
  1. Java HotSpot(TM) Client VM (25.151-b12) for windows-x86 JRE (1.8.0_151-b12), built on Sep  5 2017 19:31:49 by "java_re" with MS VC++ 10.0 (VS2010)  
  2. Memory: 4k page, physical 3567372k(982296k free), swap 7133056k(3042564k free)  
  3. CommandLine flags: -XX:InitialHeapSize=20971520 -XX:MaxHeapSize=20971520 -XX:MaxNewSize=10485760 -XX:NewSize=10485760 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:-UseLargePagesIndividualAllocation   
  4. 0.091: [GC (Allocation Failure) 0.091: [DefNew: 5427K->995K(9216K), 0.0036445 secs] 5427K->5091K(19456K), 0.0038098 secs] [Times: user=0.00 sys=0.02, real=0.00 secs]   
  5. 0.095: [GC (Allocation Failure) 0.095: [DefNew: 5091K->0K(9216K), 0.0012412 secs] 9187K->5090K(19456K), 0.0012908 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]   
  6. Heap  
  7.  def new generation   total 9216K, used 4260K [0x04000000, 0x04a00000, 0x04a00000)  
  8.   eden space 8192K,  52% used [0x04000000, 0x044290e8, 0x04800000)  
  9.   from space 1024K,   0% used [0x04800000, 0x04800000, 0x04900000)  
  10.   to   space 1024K,   0% used [0x04900000, 0x04900000, 0x04a00000)  
  11.  tenured generation   total 10240K, used 5090K [0x04a00000, 0x05400000, 0x05400000)  
  12.    the space 10240K,  49% used [0x04a00000, 0x04ef8ac0, 0x04ef8c00, 0x05400000)  
  13.  Metaspace       used 84K, capacity 2242K, committed 2368K, reserved 4480K  

理解GC日志

[plain] view plain copy
  1. 217.539: [GC (Allocation Failure) 217.539: [DefNew: 102646K->10770K(102976K), 0.0415902 secs] 239776K->153169K(331528K), 0.0416785 secs] [Times: user=0.03 sys=0.02, real=0.04 secs]   
  2. 221.383: [Full GC (System.gc()) 221.383: [Tenured: 142398K->92063K(228552K), 0.3029342 secs] 193477K->92063K(331528K), [Metaspace: 65120K->65120K(68992K)], 0.3031417 secs] [Times: user=0.30 sys=0.00, real=0.30 secs]   
  3. 281.396: [Full GC (System.gc()) 281.396: [Tenured: 92063K->93342K(228552K), 0.2394086 secs] 129487K->93342K(331528K), [Metaspace: 65137K->65137K(68992K)], 0.2395739 secs] [Times: user=0.23 sys=0.00, real=0.24 secs]   

1. 最前面的数字217.539:代表GC发生的时间,从虚拟机启动开始算起

2. GC日志开头的[GC和FULL GC]说明这次垃圾收集的停顿类型,而不是区分新生代和老年代的。

FULL GC : 说明这次GC是发生了线程停顿Stop-The-World,如果是System.gc()方法所触发的收集,,那么在这里将显示[Full GC (System)

3. [DefNew,[Tenured,[Perm表示GC发生的区域,这里显示的区域名称和使用的垃圾收集器是密切相关的

1>在Serial收集器中新生代名为Default New Generation ,显示就是DefNew

2>垃圾收集器ParNew中新生代名称就会变为[Parnew,意思为Parallel New Generation 

3>如果采用Parrallel Scavenge收集器,那么它配套的新生代名称为PSYongGen

老年代和永久代同理,名称由垃圾收集器决定

4.[DefNew: 102646K->10770K(102976K), 0.0415902 secs] 239776K->153169K(331528K), 0.0416785 secs] [Times: user=0.03 sys=0.02, real=0.04 secs] 就这段而言,

1>方括号内部102646K->10770K(102976K)的含义是GC前改内存区域已使用内存->GC后改内存区域使用容量(该内存区域总容量)

2>方括号外 239776K->153169K(331528K)表示GC前java堆已使用容量->GC后java堆已使用容量(java堆总容量)

3>在往后时间表示该内存区域gc清理用的时间

4>[Times: user=0.03 sys=0.02, real=0.04 secs]

这里面的user、sys和real与linux的time命令所输出的时间含义一致,分别表示用户态消耗的CPU时间、内核态消耗的CPU事件和操作从开始到结束经历的墙钟时间

墙钟时间和CPU时间的区别是,墙钟时间包括各种非运算的等待耗时(i/o,线程阻塞),而CPU时间不包括这些,但是如果是多核,

多线程会叠加这些CPU时间,此时user或sys时间超过real时间完全是正常的

-------------------------------------------------------------------------------------------------------------

博客内容来自书籍和互联网,加上自己的一些总结

展开阅读全文

没有更多推荐了,返回首页