JVM之GC回收信息详解

一、-xx:+printgcdetails 打印gc日志

参数配置：-xms10m -xmx10m -xx:+printgcdetails -xx:+printgcdatestamps -xx:+printgctimestamps  -xloggc:f:\gc1.log

-xloggc：输出到文件

2020-01-03t14:13:18.866+0800: 0.224: [gc (allocation failure) [psyounggen: 2048k->496k(2560k)] 2048k->744k(9728k), 0.0128127 secs] [times: user=0.00 sys=0.00, real=0.01 secs] 
2020-01-03t14:13:18.881+0800: 0.229: [gc (system.gc()) [psyounggen: 565k->496k(2560k)] 813k->752k(9728k), 0.0009625 secs] [times: user=0.02 sys=0.00, real=0.00 secs] 
2020-01-03t14:13:18.882+0800: 0.230: [full gc (system.gc()) [psyounggen: 496k->0k(2560k)] [paroldgen: 256k->675k(7168k)] 752k->675k(9728k), [metaspace: 3460k->3460k(1056768k)], 0.0053436 secs] [times: user=0.00 sys=0.00, real=0.01 secs] 
2020-01-03t14:13:19.889+0800: 1.236: [gc (system.gc()) [psyounggen: 117k->128k(2560k)] 793k->803k(9728k), 0.0006856 secs] [times: user=0.00 sys=0.00, real=0.00 secs] 
2020-01-03t14:13:19.889+0800: 1.237: [full gc (system.gc()) [psyounggen: 128k->0k(2560k)] [paroldgen: 675k->696k(7168k)] 803k->696k(9728k), [metaspace: 3475k->3475k(1056768k)], 0.0057842 secs] [times: user=0.00 sys=0.00, real=0.01 secs] 
heap
 psyounggen      total 2560k, used 59k [0x00000000ffd00000, 0x0000000100000000, 0x0000000100000000)
  eden space 2048k, 2% used [0x00000000ffd00000,0x00000000ffd0ecc0,0x00000000fff00000)
  from space 512k, 0% used [0x00000000fff00000,0x00000000fff00000,0x00000000fff80000)
  to   space 512k, 0% used [0x00000000fff80000,0x00000000fff80000,0x0000000100000000)
 paroldgen       total 7168k, used 696k [0x00000000ff600000, 0x00000000ffd00000, 0x00000000ffd00000)
  object space 7168k, 9% used [0x00000000ff600000,0x00000000ff6ae138,0x00000000ffd00000)
 metaspace       used 3481k, capacity 4500k, committed 4864k, reserved 1056768k
  class space    used 381k, capacity 388k, committed 512k, reserved 1048576k

第一行：2020-01-03t14:13:18.866+0800: 0.224: [gc (allocation failure) [psyounggen: 2048k->496k(2560k)] 2048k->744k(9728k), 0.0128127 secs] [times: user=0.00 sys=0.00, real=0.01 secs]

gc (allocation failure)：gc表示younggc年轻代垃圾回收；(allocation failure)表示内存分配失败；

[psyounggen: 2048k->496k(2560k)]：psyounggen表示年轻代使用的垃圾回收器是paralle scavenge  ；2048k表示年轻代垃圾回收前内存占用大小；496k表示年轻代垃圾回收后内存占用大小；(2560k)表示年轻代总大小；

2048k->744k(9728k)：2048k表示堆内存垃圾回收前内存占用大小；744k表示堆内存垃圾回收后内存占用大小；(9728k)表示堆内存总大小；

0.0128127 secs：表示younggc耗时，单位秒

[times: user=0.00 sys=0.00, real=0.01 secs]：user=0.00表示用户耗时，sys=0.00表示系统耗时，real=0.01表示真实耗时，secs表示时间单位秒
第二行：2020-01-03t14:13:18.881+0800: 0.229: [gc (system.gc()) [psyounggen: 565k->496k(2560k)] 813k->752k(9728k), 0.0009625 secs] [times: user=0.02 sys=0.00, real=0.00 secs] 
 [gc (system.gc())：表示系统显示调用gc
第三行：2020-01-03t14:13:18.882+0800: 0.230: [full gc (system.gc()) [psyounggen: 496k->0k(2560k)] [paroldgen: 256k->675k(7168k)] 752k->675k(9728k), [metaspace: 3460k->3460k(1056768k)], 0.0053436 secs]
 [full gc (system.gc())：full gc表示younggc+oldgc（年轻代垃圾回收+年老代垃圾回收）即整个jvm内存的回收（除了方法区或者元空间）；system.gc()表示系统显示调用gc

[psyounggen: 496k->0k(2560k)]：psyounggen表示年轻代使用的垃圾回收器是paralle scavenge  ；496k表示full gc垃圾回收前内存占用大小；0k表示full gc垃圾回收后内存占用大小（0是因为年轻代使用的是复制算法）；(2560k)表示年轻代总大小；

752k->675k(9728k)：752k表示full gc垃圾回收前堆内存占用大小；675k表示full gc垃圾回收后堆内存占用大小；(9728k)表示堆内存总大小；

paroldgen: 256k->675k(7168k)：paroldgen表示老年代使用的垃圾回收器parallel old，256k表示full gc垃圾回收前内存占用大小；675k表示full gc垃圾回收后内存占用大小；(7168k)表示老年代总大小；

[metaspace: 3460k->3460k(1056768k)]：metaspace表示元空间本文使用jdk1.8，3460k：表示full gc垃圾回收前metaspace占用大小，3460k表示full gc垃圾回收后metaspace占用大小；(1056768k)表示metaspace总大小。

full gc分析下可以得出结论：
    新生代变化：496k-0l=496k 新生代减少了496k

    老年代变化：256k-675k=-419k（老年代增加了419k）
    heap区变化：752k-675k=77k 整个堆减少了 77k
    496k – 77k =419k，说明该次共有419k内存从年轻代移到了老年代，可以看出来数量不少，说明大部分对象的生命周期较长。由于full gc会引发stop  the word ，所以我们要尽量避免full gc的发生，让对象尽可能的在老年代多呆会，所以这里可以增加老年轻代的大小。

第五行：

heap
 psyounggen      total 2560k, used 59k [0x00000000ffd00000, 0x0000000100000000, 0x0000000100000000)
  eden space 2048k, 2% used [0x00000000ffd00000,0x00000000ffd0ecc0,0x00000000fff00000)
  from space 512k, 0% used [0x00000000fff00000,0x00000000fff00000,0x00000000fff80000)
  to   space 512k, 0% used [0x00000000fff80000,0x00000000fff80000,0x0000000100000000)
 paroldgen       total 7168k, used 696k [0x00000000ff600000, 0x00000000ffd00000, 0x00000000ffd00000)
  object space 7168k, 9% used [0x00000000ff600000,0x00000000ff6ae138,0x00000000ffd00000)
 metaspace       used 3481k, capacity 4500k, committed 4864k, reserved 1056768k
  class space    used 381k, capacity 388k, committed 512k, reserved 1048576k

psyounggen total 2560k, used 59k：total 年轻代占用的总内存大小2560k，used：表示当前使用量
eden space 2048k, 2% used：年轻代的eden区占用的总内存大小2048k，used：已经使用2%
from space 512k, 0% used：年轻代的 from s1区占用的总内存大小512k，used：已经使用0%
to space 512k, 0% used：年轻代的 from s2区占用的总内存大小512k，used：已经使用0%
paroldgen total 7168k：老年代的总内存大小
object space 7168k, 9% used：老年已使用9%

 -xx:newratio=2：年轻代与老年代的比值1:2， 但是根据实际数据显然年轻代没有占到整个堆的三分之一，很是费解？不知这种误差是否合理，在这里不吝赐教，求大神指点迷津。