search

bingoogolapple / bingoogolapple.github.io

个人主页。同时也通过 Issues 记录学习笔记
http://www.bingoogolapple.cn
86 stars 19 forks source link

GC 日志分析 - Parallel GC（并行 GC） #184

Open bingoogolapple opened 7 years ago

bingoogolapple commented 7 years ago 
Java HotSpot(TM) 64-Bit Server VM (25.131-b11) for bsd-amd64 JRE (1.8.0_131-b11), built on Mar 15 2017 01:32:22 by "java_re" with gcc 4.2.1 (Based on Apple Inc. build 5658) (LLVM build 2336.11.00)
Memory: 4k page, physical 8388608k(1864972k free)

/proc/meminfo:

CommandLine flags: -XX:InitialHeapSize=2147483648 -XX:MaxHeapSize=2147483648 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:ThreadStackSize=256 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC -XX:+UseParallelOldGC

2017-07-27T10:42:08.268-0800: 2.043: [GC (Allocation Failure)
  [PSYoungGen: 524800K->87031K(611840K)]
  524800K->499220K(2010112K),
0.3782684 secs]
[Times: user=0.25 sys=0.89, real=0.38 secs]

2017-07-27T10:42:10.265-0800: 4.040: [GC (Allocation Failure)
  [PSYoungGen: 611828K->86993K(611840K)]
  1024017K->1019869K(2010112K),
0.4596554 secs]
[Times: user=0.31 sys=1.02, real=0.46 secs]

2017-07-27T10:42:10.725-0800: 4.500: [Full GC (Ergonomics)
  [PSYoungGen: 86993K->0K(611840K)]
  [ParOldGen: 932875K->1019806K(1398272K)]
  1019869K->1019806K(2010112K),
  [Metaspace: 3136K->3136K(1056768K)],
0.2865243 secs]
[Times: user=0.73 sys=0.20, real=0.29 secs]

2017-07-27T10:42:12.266-0800: 6.041: [Full GC (Ergonomics)
  [PSYoungGen: 524800K->0K(611840K)]
  [ParOldGen: 1019806K->1331807K(1398272K)]
  1544606K->1331807K(2010112K),
  [Metaspace: 3143K->3143K(1056768K)],
0.5840146 secs]
[Times: user=0.80 sys=0.34, real=0.59 secs]

2017-07-27T10:42:14.361-0800: 8.136: [Full GC (Ergonomics)
  [PSYoungGen: 524800K->38149K(611840K)]
  [ParOldGen: 1331807K->1397990K(1398272K)]
  1856607K->1436139K(2010112K),
  [Metaspace: 3144K->3144K(1056768K)],
0.5602560 secs]
[Times: user=1.22 sys=0.08, real=0.56 secs]

2017-07-27T10:42:16.167-0800: 9.942: [Full GC (Ergonomics)
  [PSYoungGen: 524800K->133754K(611840K)]
  [ParOldGen: 1397990K->1397837K(1398272K)]
  1922790K->1531592K(2010112K),
  [Metaspace: 3145K->3145K(1056768K)],
0.4461326 secs]
[Times: user=1.40 sys=0.02, real=0.45 secs]

2017-07-27T10:42:17.667-0800: 11.441: [Full GC (Ergonomics)
  [PSYoungGen: 524773K->210564K(611840K)]
  [ParOldGen: 1397837K->1397855K(1398272K)]
  1922611K->1608420K(2010112K),
  [Metaspace: 3152K->3152K(1056768K)],
0.5489507 secs]
[Times: user=1.11 sys=0.08, real=0.55 secs]

2017-07-27T10:42:18.960-0800: 12.735: [Full GC (Ergonomics)
  [PSYoungGen: 524707K->272934K(611840K)]
  [ParOldGen: 1397855K->1397869K(1398272K)]
  1922563K->1670804K(2010112K),
  [Metaspace: 3154K->3154K(1056768K)],
0.4385230 secs]
[Times: user=1.02 sys=0.05, real=0.43 secs]

2017-07-27T10:42:19.866-0800: 13.641: [Full GC (Ergonomics)
  [PSYoungGen: 524773K->323121K(611840K)]
  [ParOldGen: 1397869K->1397980K(1398272K)]
  1922643K->1721101K(2010112K),
  [Metaspace: 3165K->3165K(1056768K)],
0.4720725 secs]
[Times: user=1.07 sys=0.02, real=0.47 secs]

2017-07-27T10:42:20.662-0800: 14.437: [Full GC (Ergonomics)
  [PSYoungGen: 524687K->358912K(611840K)]
  [ParOldGen: 1397980K->1398041K(1398272K)]
  1922667K->1756954K(2010112K),
  [Metaspace: 3165K->3165K(1056768K)],
0.6002612 secs]
[Times: user=0.86 sys=0.02, real=0.60 secs]

2017-07-27T10:42:21.298-0800: 15.072: [Full GC (Ergonomics)
  [PSYoungGen: 524775K->394914K(611840K)]
  [ParOldGen: 1398041K->1397893K(1398272K)]
  1922817K->1792807K(2010112K),
  [Metaspace: 3165K->3165K(1056768K)],
0.4212555 secs]
[Times: user=1.16 sys=0.02, real=0.42 secs]

Heap
 PSYoungGen      total 611840K, used 415882K [0x0000000795580000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 524800K, 79% used [0x0000000795580000,0x00000007aeba2ba0,0x00000007b5600000)
  from space 87040K, 0% used [0x00000007bab00000,0x00000007bab00000,0x00000007c0000000)
  to   space 87040K, 0% used [0x00000007b5600000,0x00000007b5600000,0x00000007bab00000)
 ParOldGen       total 1398272K, used 1397893K [0x0000000740000000, 0x0000000795580000, 0x0000000795580000)
  object space 1398272K, 99% used [0x0000000740000000,0x00000007955216a8,0x0000000795580000)
 Metaspace       used 3181K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 354K, capacity 386K, committed 512K, reserved 1048576K
bingoogolapple commented 7 years ago

取正数第二条来分析

2017-07-27T10:42:10.265-0800: 4.040: [GC (Allocation Failure)
  [PSYoungGen: 611828K->86993K(611840K)]
  1024017K->1019869K(2010112K),
0.4596554 secs]
[Times: user=0.31 sys=1.02, real=0.46 secs]
2017-07-27T10:42:10.265-0800（开始垃圾收集时的当前时间戳）: 4.040（JVM 启动后经过的时间，单位为秒）: [GC (Allocation Failure（导致 GC 的原因，这里是分配内存失败导致的）)
  [PSYoungGen（Parallel GC 年轻代内存区域名称，并行，多线程，标记-复制 Mark-Copy，STW）: 611828K（GC 前年轻代的使用量）->86993K（GC 前后轻代的使用量）(611840K（年轻代总大小）)]
  1024017K（GC 前整个堆的使用量）->1019869K（GC 后整个堆的使用量）(2010112K（整个堆的总大小）),
0.4596554（本次 GC 的总时间） secs]
[Times: user=0.31 sys=1.02, real=0.46 secs]
bingoogolapple commented 7 years ago

取正数第四条来分析

2017-07-27T10:42:12.266-0800: 6.041: [Full GC (Ergonomics)
  [PSYoungGen: 524800K->0K(611840K)]
  [ParOldGen: 1019806K->1331807K(1398272K)]
  1544606K->1331807K(2010112K),
  [Metaspace: 3143K->3143K(1056768K)],
0.5840146 secs]
[Times: user=0.80 sys=0.34, real=0.59 secs]
2017-07-27T10:42:12.266-0800（开始垃圾收集时的当前时间戳）: 6.041（JVM 启动后经过的时间，单位为秒）: [Full GC (Ergonomics（导致 GC 的原因，这里是 JVM 内部环境认为此时可以进行一次 GC）)
  [PSYoungGen（Parallel GC 年轻代内存区域名称，并行，多线程，标记-复制 Mark-Copy，STW）: 524800K（GC 前年轻代的使用量）->0K（GC 前后轻代的使用量）(611840K（年轻代总大小)]
  [ParOldGen（Parallel GC 老年代内存区域名称，并行，多线程，标记-清除-整理 Mark-Sweep-Compact，STW）: 1019806K（GC 前老年代的使用量）->1331807K（GC 后老年代的使用量）(1398272K（老年代代总大小）)]
  1544606K（GC 前整个堆的使用量）->1331807K（GC 后整个堆的使用量）(2010112K（整个堆的总大小）),
  [Metaspace: 3143K->3143K(1056768K)],
0.5840146 secs]
[Times: user=0.80 sys=0.34, real=0.59 secs]
shenjunlin commented 6 years ago

hehehe