60 一次 ParallelGC 的调试
Posted 蓝风9
tags:
篇首语：本文由小常识网(cha138.com)小编为大家整理，主要介绍了60 一次 ParallelGC 的调试相关的知识，希望对你有一定的参考价值。
前言
最近看到了这一篇文章, [草稿] GC 参数设置的一些疑问 PS + SERIALOLD, 因此 我也想调试一下这里的场景, 作为练习吧
当然 也还是有所收获, 至少是 大致看了一下 psScavenge 的代码, 呵呵 之前我的理解是和 serialNew, serialOld 有很大的区别, 所以 一直没有看, 但是 今天看了一下, 核心思路 是差不多的嘛, 不过 有很多细节的不同的地方
一下内容没有特殊说明, 基于 jdk9
测试用例
package com.hx.test04;
import java.util.ArrayList;
import java.util.List;
/**
* AboutGc
*
* @author Jerry.X.He <970655147@qq.com>
* @version 1.0
* @date 2020-04-08 19:15
*/
public class Test30AboutGc
// Test30AboutGc
// -Xms20M -Xmx20M -Xmn10M -XX:SurvivorRatio=6 -verbose:gc -XX:+PrintGCDetails -XX:+UseParallelGC
// refer : https://hllvm-group.iteye.com/group/topic/39065
public static void main(String[] args) throws Exception
//Thread.sleep(15000);
List list = new ArrayList();
for (int i = 0; i < 10; i++)
list.add(new MemoryObject(1024 * 1024));
Thread.sleep(1000);
System.out.println(i);
// System.gc();
// System.gc();
Thread.sleep(2000);
list.clear();
for (int i = 0; i < 10 ; i++)
list.add(new MemoryObject(1024 * 1024));
if(i % 3 == 0)
list.remove(0);
Thread.sleep(1000);
System.out.println(i);
System.out.println("list size is " + list.size());
Thread.sleep(2000);
// MemoryObject
static class MemoryObject
byte [] b ;
public MemoryObject(int b)
this.b = new byte[b];
因为一些特殊的原因, 注释掉了 这里的两行 System.gc, 不过 这个对于我们这里的调试来说 影响不是太大
程序运行下来 在我本地 jdk8 的环境下面日志信息如下
0
1
2
3
Heap before GC invocations=1 (full 0):
PSYoungGen total 9216K, used 7676K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 93% used [0x00000007bf600000,0x00000007bfd7f070,0x00000007bfe00000)
from space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
to space 1024K, 0% used [0x00000007bfe00000,0x00000007bfe00000,0x00000007bff00000)
ParOldGen total 10240K, used 0K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 0% used [0x00000007bec00000,0x00000007bec00000,0x00000007bf600000)
Metaspace used 2952K, capacity 4556K, committed 4864K, reserved 1056768K
class space used 312K, capacity 392K, committed 512K, reserved 1048576K
[GC (Allocation Failure) [PSYoungGen: 7676K->906K(9216K)] 7676K->5010K(19456K), 0.0052738 secs] [Times: user=0.03 sys=0.01, real=0.01 secs]
Heap after GC invocations=1 (full 0):
PSYoungGen total 9216K, used 906K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 0% used [0x00000007bf600000,0x00000007bf600000,0x00000007bfe00000)
from space 1024K, 88% used [0x00000007bfe00000,0x00000007bfee2820,0x00000007bff00000)
to space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
ParOldGen total 10240K, used 4104K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 40% used [0x00000007bec00000,0x00000007bf002040,0x00000007bf600000)
Metaspace used 2952K, capacity 4556K, committed 4864K, reserved 1056768K
class space used 312K, capacity 392K, committed 512K, reserved 1048576K
4
5
6
7
8
9
0
Heap before GC invocations=2 (full 0):
PSYoungGen total 9216K, used 8396K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 91% used [0x00000007bf600000,0x00000007bfd50a08,0x00000007bfe00000)
from space 1024K, 88% used [0x00000007bfe00000,0x00000007bfee2820,0x00000007bff00000)
to space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
ParOldGen total 10240K, used 4104K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 40% used [0x00000007bec00000,0x00000007bf002040,0x00000007bf600000)
Metaspace used 2954K, capacity 4556K, committed 4864K, reserved 1056768K
class space used 312K, capacity 392K, committed 512K, reserved 1048576K
[GC (Allocation Failure) [PSYoungGen: 8396K->672K(9216K)] 12500K->4784K(19456K), 0.0023019 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
Heap after GC invocations=2 (full 0):
PSYoungGen total 9216K, used 672K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 0% used [0x00000007bf600000,0x00000007bf600000,0x00000007bfe00000)
from space 1024K, 65% used [0x00000007bff00000,0x00000007bffa8000,0x00000007c0000000)
to space 1024K, 0% used [0x00000007bfe00000,0x00000007bfe00000,0x00000007bff00000)
ParOldGen total 10240K, used 4112K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 40% used [0x00000007bec00000,0x00000007bf004040,0x00000007bf600000)
Metaspace used 2954K, capacity 4556K, committed 4864K, reserved 1056768K
class space used 312K, capacity 392K, committed 512K, reserved 1048576K
1
2
3
4
5
6
7
Heap before GC invocations=3 (full 0):
PSYoungGen total 9216K, used 8080K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 90% used [0x00000007bf600000,0x00000007bfd3c068,0x00000007bfe00000)
from space 1024K, 65% used [0x00000007bff00000,0x00000007bffa8000,0x00000007c0000000)
to space 1024K, 0% used [0x00000007bfe00000,0x00000007bfe00000,0x00000007bff00000)
ParOldGen total 10240K, used 4112K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 40% used [0x00000007bec00000,0x00000007bf004040,0x00000007bf600000)
Metaspace used 2955K, capacity 4556K, committed 4864K, reserved 1056768K
class space used 312K, capacity 392K, committed 512K, reserved 1048576K
[GC (Allocation Failure) [PSYoungGen: 8080K->688K(9216K)] 12192K->9920K(19456K), 0.0053730 secs] [Times: user=0.02 sys=0.02, real=0.01 secs]
Heap after GC invocations=3 (full 0):
PSYoungGen total 9216K, used 688K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 0% used [0x00000007bf600000,0x00000007bf600000,0x00000007bfe00000)
from space 1024K, 67% used [0x00000007bfe00000,0x00000007bfeac010,0x00000007bff00000)
to space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
ParOldGen total 10240K, used 9232K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 90% used [0x00000007bec00000,0x00000007bf504090,0x00000007bf600000)
Metaspace used 2955K, capacity 4556K, committed 4864K, reserved 1056768K
class space used 312K, capacity 392K, committed 512K, reserved 1048576K
Heap before GC invocations=4 (full 1):
PSYoungGen total 9216K, used 688K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 0% used [0x00000007bf600000,0x00000007bf600000,0x00000007bfe00000)
from space 1024K, 67% used [0x00000007bfe00000,0x00000007bfeac010,0x00000007bff00000)
to space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
ParOldGen total 10240K, used 9232K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 90% used [0x00000007bec00000,0x00000007bf504090,0x00000007bf600000)
Metaspace used 2955K, capacity 4556K, committed 4864K, reserved 1056768K
class space used 312K, capacity 392K, committed 512K, reserved 1048576K
[Full GC (Ergonomics) [PSYoungGen: 688K->0K(9216K)] [ParOldGen: 9232K->5649K(10240K)] 9920K->5649K(19456K), [Metaspace: 2955K->2955K(1056768K)], 0.0059068 secs] [Times: user=0.03 sys=0.00, real=0.00 secs]
Heap after GC invocations=4 (full 1):
PSYoungGen total 9216K, used 0K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 0% used [0x00000007bf600000,0x00000007bf600000,0x00000007bfe00000)
from space 1024K, 0% used [0x00000007bfe00000,0x00000007bfe00000,0x00000007bff00000)
to space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
ParOldGen total 10240K, used 5649K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 55% used [0x00000007bec00000,0x00000007bf184738,0x00000007bf600000)
Metaspace used 2955K, capacity 4556K, committed 4864K, reserved 1056768K
class space used 312K, capacity 392K, committed 512K, reserved 1048576K
8
9
list size is 6
Heap
PSYoungGen total 9216K, used 2288K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 27% used [0x00000007bf600000,0x00000007bf83c230,0x00000007bfe00000)
from space 1024K, 0% used [0x00000007bfe00000,0x00000007bfe00000,0x00000007bff00000)
to space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
ParOldGen total 10240K, used 5649K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 55% used [0x00000007bec00000,0x00000007bf184738,0x00000007bf600000)
Metaspace used 2962K, capacity 4556K, committed 4864K, reserved 1056768K
class space used 313K, capacity 392K, committed 512K, reserved 1048576K
总共发生了 三次 minor gc, 一次 full gc
从这里 我们或许只能从 第一次 minor gc 之后的情况作为参照开始看, 并且 第一次 minior gc 之后的数据 所以 看起来 还不是那么清晰
因此 我们接下来 在每一次的 数组分配 之前输出一下 堆 的详细信息, 这样 我们就可以 看清楚 整个堆的变化的始末了
数组分配调试日志
[0.017s][warning][gc] -XX:+PrintGCDetails is deprecated. Will use -Xlog:gc* instead.
Signal: SIGSEGV (signal SIGSEGV)
[3.050s][info ][gc] Using Parallel
[3.050s][info ][gc,heap,coops] Heap address: 0x00000007bec00000, size: 20 MB, Compressed Oops mode: Zero based, Oop shift amount: 3
PSYoungGen total 9216K, used 4518K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 55% used [0x00000007bf600000,0x00000007bfa69aa0,0x00000007bfe00000)
from space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
to space 1024K, 0% used [0x00000007bfe00000,0x00000007bfe00000,0x00000007bff00000)
ParOldGen total 10240K, used 0K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 0% used [0x00000007bec00000,0x00000007bec00000,0x00000007bf600000)
Metaspace used 5504K, capacity 5628K, committed 5760K, reserved 1056768K
class space used 545K, capacity 577K, committed 640K, reserved 1048576K
Universe::heap()->print() = (void)
0
PSYoungGen total 9216K, used 5542K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 67% used [0x00000007bf600000,0x00000007bfb69ab0,0x00000007bfe00000)
from space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
to space 1024K, 0% used [0x00000007bfe00000,0x00000007bfe00000,0x00000007bff00000)
ParOldGen total 10240K, used 0K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 0% used [0x00000007bec00000,0x00000007bec00000,0x00000007bf600000)
Metaspace used 5504K, capacity 5628K, committed 5760K, reserved 1056768K
class space used 545K, capacity 577K, committed 640K, reserved 1048576K
Universe::heap()->print() = (void)
1
PSYoungGen total 9216K, used 6566K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 80% used [0x00000007bf600000,0x00000007bfc69ac0,0x00000007bfe00000)
from space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
to space 1024K, 0% used [0x00000007bfe00000,0x00000007bfe00000,0x00000007bff00000)
ParOldGen total 10240K, used 0K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 0% used [0x00000007bec00000,0x00000007bec00000,0x00000007bf600000)
Metaspace used 5504K, capacity 5628K, committed 5760K, reserved 1056768K
class space used 545K, capacity 577K, committed 640K, reserved 1048576K
Universe::heap()->print() = (void)
2
PSYoungGen total 9216K, used 7590K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 92% used [0x00000007bf600000,0x00000007bfd69ad0,0x00000007bfe00000)
from space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
to space 1024K, 0% used [0x00000007bfe00000,0x00000007bfe00000,0x00000007bff00000)
ParOldGen total 10240K, used 0K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 0% used [0x00000007bec00000,0x00000007bec00000,0x00000007bf600000)
Metaspace used 5504K, capacity 5628K, committed 5760K, reserved 1056768K
class space used 545K, capacity 577K, committed 640K, reserved 1048576K
Universe::heap()->print() = (void)
[21.777s][info ][gc,start ] GC(0) Pause Young (Allocation Failure)
[21.794s][info ][gc,heap ] GC(0) PSYoungGen: 7590K->992K(9216K)
[21.794s][info ][gc,heap ] GC(0) ParOldGen: 0K->3224K(10240K)
[21.794s][info ][gc,metaspace ] GC(0) Metaspace: 5504K->5504K(1056768K)
[21.795s][info ][gc ] GC(0) Pause Young (Allocation Failure) 7M->4M(19M) 17.952ms
[21.795s][info ][gc,cpu ] GC(0) User=0.09s Sys=0.00s Real=0.02s
// 0, 1, 2 gc 之后移动到 old 去了, 因为 to 装不下
3
PSYoungGen total 9216K, used 2176K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 14% used [0x00000007bf600000,0x00000007bf728088,0x00000007bfe00000)
from space 1024K, 96% used [0x00000007bfe00000,0x00000007bfef8020,0x00000007bff00000)
to space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
ParOldGen total 10240K, used 3224K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 31% used [0x00000007bec00000,0x00000007bef26030,0x00000007bf600000)
Metaspace used 5504K, capacity 5628K, committed 5760K, reserved 1056768K
class space used 545K, capacity 577K, committed 640K, reserved 1048576K
Universe::heap()->print() = (void)
4
PSYoungGen total 9216K, used 3200K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 26% used [0x00000007bf600000,0x00000007bf828098,0x00000007bfe00000)
from space 1024K, 96% used [0x00000007bfe00000,0x00000007bfef8020,0x00000007bff00000)
to space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
ParOldGen total 10240K, used 3224K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 31% used [0x00000007bec00000,0x00000007bef26030,0x00000007bf600000)
Metaspace used 5504K, capacity 5628K, committed 5760K, reserved 1056768K
class space used 545K, capacity 577K, committed 640K, reserved 1048576K
Universe::heap()->print() = (void)
5
PSYoungGen total 9216K, used 4224K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 39% used [0x00000007bf600000,0x00000007bf9280a8,0x00000007bfe00000)
from space 1024K, 96% used [0x00000007bfe00000,0x00000007bfef8020,0x00000007bff00000)
to space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
ParOldGen total 10240K, used 3224K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 31% used [0x00000007bec00000,0x00000007bef26030,0x00000007bf600000)
Metaspace used 5504K, capacity 5628K, committed 5760K, reserved 1056768K
class space used 545K, capacity 577K, committed 640K, reserved 1048576K
Universe::heap()->print() = (void)
6
PSYoungGen total 9216K, used 5248K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 51% used [0x00000007bf600000,0x00000007bfa280b8,0x00000007bfe00000)
from space 1024K, 96% used [0x00000007bfe00000,0x00000007bfef8020,0x00000007bff00000)
to space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
ParOldGen total 10240K, used 3224K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 31% used [0x00000007bec00000,0x00000007bef26030,0x00000007bf600000)
Metaspace used 5504K, capacity 5628K, committed 5760K, reserved 1056768K
class space used 545K, capacity 577K, committed 640K, reserved 1048576K
Universe::heap()->print() = (void)
7
PSYoungGen total 9216K, used 6272K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 64% used [0x00000007bf600000,0x00000007bfb280c8,0x00000007bfe00000)
from space 1024K, 96% used [0x00000007bfe00000,0x00000007bfef8020,0x00000007bff00000)
to space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
ParOldGen total 10240K, used 3224K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 31% used [0x00000007bec00000,0x00000007bef26030,0x00000007bf600000)
Metaspace used 5504K, capacity 5628K, committed 5760K, reserved 1056768K
class space used 545K, capacity 577K, committed 640K, reserved 1048576K
Universe::heap()->print() = (void)
8
PSYoungGen total 9216K, used 7296K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 76% used [0x00000007bf600000,0x00000007bfc280d8,0x00000007bfe00000)
from space 1024K, 96% used [0x00000007bfe00000,0x00000007bfef8020,0x00000007bff00000)
to space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
ParOldGen total 10240K, used 3224K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 31% used [0x00000007bec00000,0x00000007bef26030,0x00000007bf600000)
Metaspace used 5504K, capacity 5628K, committed 5760K, reserved 1056768K
class space used 545K, capacity 577K, committed 640K, reserved 1048576K
Universe::heap()->print() = (void)
9
PSYoungGen total 9216K, used 8320K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 89% used [0x00000007bf600000,0x00000007bfd280e8,0x00000007bfe00000)
from space 1024K, 96% used [0x00000007bfe00000,0x00000007bfef8020,0x00000007bff00000)
to space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
ParOldGen total 10240K, used 3224K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 31% used [0x00000007bec00000,0x00000007bef26030,0x00000007bf600000)
Metaspace used 5504K, capacity 5628K, committed 5760K, reserved 1056768K
class space used 545K, capacity 577K, committed 640K, reserved 1048576K
Universe::heap()->print() = (void)
[36.167s][info ][gc,start ] GC(1) Pause Young (Allocation Failure)
[36.179s][info ][gc,heap ] GC(1) PSYoungGen: 8320K->992K(9216K)
[36.179s][info ][gc,heap ] GC(1) ParOldGen: 3224K->3280K(10240K)
[36.179s][info ][gc,metaspace ] GC(1) Metaspace: 5504K->5504K(1056768K)
[36.179s][info ][gc ] GC(1) Pause Young (Allocation Failure) 11M->4M(19M) 12.244ms
[36.179s][info ][gc,cpu ] GC(1) User=0.06s Sys=0.00s Real=0.02s
0
PSYoungGen total 9216K, used 2177K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 14% used [0x00000007bf600000,0x00000007bf728460,0x00000007bfe00000)
from space 1024K, 96% used [0x00000007bff00000,0x00000007bfff8020,0x00000007c0000000)
to space 1024K, 0% used [0x00000007bfe00000,0x00000007bfe00000,0x00000007bff00000)
ParOldGen total 10240K, used 3280K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 32% used [0x00000007bec00000,0x00000007bef34030,0x00000007bf600000)
Metaspace used 5504K, capacity 5628K, committed 5760K, reserved 1056768K
class space used 545K, capacity 577K, committed 640K, reserved 1048576K
Universe::heap()->print() = (void)
1
PSYoungGen total 9216K, used 3201K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 26% used [0x00000007bf600000,0x00000007bf828470,0x00000007bfe00000)
from space 1024K, 96% used [0x00000007bff00000,0x00000007bfff8020,0x00000007c0000000)
to space 1024K, 0% used [0x00000007bfe00000,0x00000007bfe00000,0x00000007bff00000)
ParOldGen total 10240K, used 3280K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 32% used [0x00000007bec00000,0x00000007bef34030,0x00000007bf600000)
Metaspace used 5504K, capacity 5628K, committed 5760K, reserved 1056768K
class space used 545K, capacity 577K, committed 640K, reserved 1048576K
Universe::heap()->print() = (void)
2
PSYoungGen total 9216K, used 4225K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 39% used [0x00000007bf600000,0x00000007bf928480,0x00000007bfe00000)
from space 1024K, 96% used [0x00000007bff00000,0x00000007bfff8020,0x00000007c0000000)
to space 1024K, 0% used [0x00000007bfe00000,0x00000007bfe00000,0x00000007bff00000)
ParOldGen total 10240K, used 3280K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 32% used [0x00000007bec00000,0x00000007bef34030,0x00000007bf600000)
Metaspace used 5504K, capacity 5628K, committed 5760K, reserved 1056768K
class space used 545K, capacity 577K, committed 640K, reserved 1048576K
Universe::heap()->print() = (void)
3
PSYoungGen total 9216K, used 5249K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 51% used [0x00000007bf600000,0x00000007bfa28490,0x00000007bfe00000)
from space 1024K, 96% used [0x00000007bff00000,0x00000007bfff8020,0x00000007c0000000)
to space 1024K, 0% used [0x00000007bfe00000,0x00000007bfe00000,0x00000007bff00000)
ParOldGen total 10240K, used 3280K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 32% used [0x00000007bec00000,0x00000007bef34030,0x00000007bf600000)
Metaspace used 5504K, capacity 5628K, committed 5760K, reserved 1056768K
class space used 545K, capacity 577K, committed 640K, reserved 1048576K
Universe::heap()->print() = (void)
4
PSYoungGen total 9216K, used 6273K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 64% used [0x00000007bf600000,0x00000007bfb284a0,0x00000007bfe00000)
from space 1024K, 96% used [0x00000007bff00000,0x00000007bfff8020,0x00000007c0000000)
to space 1024K, 0% used [0x00000007bfe00000,0x00000007bfe00000,0x00000007bff00000)
ParOldGen total 10240K, used 3280K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 32% used [0x00000007bec00000,0x00000007bef34030,0x00000007bf600000)
Metaspace used 5504K, capacity 5628K, committed 5760K, reserved 1056768K
class space used 545K, capacity 577K, committed 640K, reserved 1048576K
Universe::heap()->print() = (void)
5
PSYoungGen total 9216K, used 7297K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 76% used [0x00000007bf600000,0x00000007bfc284b0,0x00000007bfe00000)
from space 1024K, 96% used [0x00000007bff00000,0x00000007bfff8020,0x00000007c0000000)
to space 1024K, 0% used [0x00000007bfe00000,0x00000007bfe00000,0x00000007bff00000)
ParOldGen total 10240K, used 3280K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 32% used [0x00000007bec00000,0x00000007bef34030,0x00000007bf600000)
Metaspace used 5504K, capacity 5628K, committed 5760K, reserved 1056768K
class space used 545K, capacity 577K, committed 640K, reserved 1048576K
Universe::heap()->print() = (void)
6
PSYoungGen total 9216K, used 8321K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 89% used [0x00000007bf600000,0x00000007bfd284c0,0x00000007bfe00000)
from space 1024K, 96% used [0x00000007bff00000,0x00000007bfff8020,0x00000007c0000000)
to space 1024K, 0% used [0x00000007bfe00000,0x00000007bfe00000,0x00000007bff00000)
ParOldGen total 10240K, used 3280K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 32% used [0x00000007bec00000,0x00000007bef34030,0x00000007bf600000)
Metaspace used 5504K, capacity 5628K, committed 5760K, reserved 1056768K
class space used 545K, capacity 577K, committed 640K, reserved 1048576K
Universe::heap()->print() = (void)
[48.439s][info ][gc,start ] GC(2) Pause Young (Allocation Failure)
[48.455s][info ][gc,heap ] GC(2) PSYoungGen: 8321K->1008K(9216K)
[48.455s][info ][gc,heap ] GC(2) ParOldGen: 3280K->7384K(10240K)
[48.455s][info ][gc,metaspace ] GC(2) Metaspace: 5504K->5504K(1056768K)
[48.455s][info ][gc ] GC(2) Pause Young (Allocation Failure) 11M->8M(19M) 16.070ms
[48.455s][info ][gc,cpu ] GC(2) User=0.07s Sys=0.00s Real=0.02s
[48.457s][info ][gc,start ] GC(3) Pause Full (Ergonomics)
[48.457s][info ][gc,phases,start] GC(3) Marking Phase
[48.484s][info ][gc,phases ] GC(3) Marking Phase 26.647ms
[48.484s][info ][gc,phases,start] GC(3) Summary Phase
[48.484s][info ][gc,phases ] GC(3) Summary Phase 0.073ms
[48.484s][info ][gc,phases,start] GC(3) Adjust Roots
[48.494s][info ][gc,phases ] GC(3) Adjust Roots 9.863ms
[48.494s][info ][gc,phases,start] GC(3) Compaction Phase
[48.531s][info ][gc,phases ] GC(3) Compaction Phase 37.430ms
[48.532s][info ][gc,phases,start] GC(3) Post Compact
[48.533s][info ][gc,phases ] GC(3) Post Compact 1.172ms
[48.533s][info ][gc,heap ] GC(3) PSYoungGen: 1008K->0K(9216K)
[48.533s][info ][gc,heap ] GC(3) ParOldGen: 7384K->5116K(10240K)
[48.533s][info ][gc,metaspace ] GC(3) Metaspace: 5504K->5499K(1056768K)
[48.533s][info ][gc ] GC(3) Pause Full (Ergonomics) 8M->4M(19M) 76.075ms
[48.533s][info ][gc,cpu ] GC(3) User=0.38s Sys=0.00s Real=0.08s
7
PSYoungGen total 9216K, used 1184K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 14% used [0x00000007bf600000,0x00000007bf728348,0x00000007bfe00000)
from space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
to space 1024K, 0% used [0x00000007bfe00000,0x00000007bfe00000,0x00000007bff00000)
ParOldGen total 10240K, used 5116K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 49% used [0x00000007bec00000,0x00000007bf0ff1d8,0x00000007bf600000)
Metaspace used 5499K, capacity 5620K, committed 5760K, reserved 1056768K
class space used 543K, capacity 573K, committed 640K, reserved 1048576K
Universe::heap()->print() = (void)
8
PSYoungGen total 9216K, used 2208K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 26% used [0x00000007bf600000,0x00000007bf828358,0x00000007bfe00000)
from space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
to space 1024K, 0% used [0x00000007bfe00000,0x00000007bfe00000,0x00000007bff00000)
ParOldGen total 10240K, used 5116K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 49% used [0x00000007bec00000,0x00000007bf0ff1d8,0x00000007bf600000)
Metaspace used 5499K, capacity 5620K, committed 5760K, reserved 1056768K
class space used 543K, capacity 573K, committed 640K, reserved 1048576K
Universe::heap()->print() = (void)
9
list size is 6
[57.199s][info ][gc,heap,exit ] Heap
[57.199s][info ][gc,heap,exit ] PSYoungGen total 9216K, used 3397K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
[57.199s][info ][gc,heap,exit ] eden space 8192K, 41% used [0x00000007bf600000,0x00000007bf951438,0x00000007bfe00000)
[57.199s][info ][gc,heap,exit ] from space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
[57.199s][info ][gc,heap,exit ] to space 1024K, 0% used [0x00000007bfe00000,0x00000007bfe00000,0x00000007bff00000)
[57.199s][info ][gc,heap,exit ] ParOldGen total 10240K, used 5116K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
[57.199s][info ][gc,heap,exit ] object space 10240K, 49% used [0x00000007bec00000,0x00000007bf0ff1d8,0x00000007bf600000)
[57.199s][info ][gc,heap,exit ] Metaspace used 5505K, capacity 5620K, committed 5760K, reserved 1056768K
[57.199s][info ][gc,heap,exit ] class space used 544K, capacity 573K, committed 640K, reserved 1048576K
[57.202s][info ][gc,verify,start] Verifying
[57.236s][info ][gc,verify ] Verifying 34.608ms结合 上面的 详细的日志, 我相信 大家应该能够看明白 这几次 minor gc 发生的原因了吧
然后 需要有一些地方 需要特殊说明
1. 第一次 minor gc 的时候 之前分配的 0, 1, 2 索引对应的字节数组是 promotion 到了 oldGen(to 装不下), 这个是可以调试证明的
2. 第二次 minor gc 的时候, 是在第二个循环创建对象的开始的时候, 此时 list 已经清空, 第一个循环的 10 个 1m 的字节数组的情况是, 7 个在 youngGen, 3 个在 oldGen, minor gc 之后, 7 个在 youngGen 的对象被清理了, oldGen 的3个还在
3. 第三次 minor gc 的时候, 第二次循环创建的 7 个 1m 的字节数组都存在 youngGen, 但是 其中三个(索引为0, 3, 6)是垃圾, 因此 还存在的 4 个 1m 的字节数组 promotion 到 oldGen
4. 第一次 full gc 发生的原因是, gc 统计分析下一次 minor gc 最坏的情况 oldGen 需要保证有 5.8m 来担保, 然后 当时 oldGen 的空间 仅剩 3m 左右, 因此 触发了 full gc
呵呵 一下内容为个人理解, 可能存在理解的不足的地方
policy 里面有一个 gcStatus里面有一个 avg_promoted(AdaptiveWeightedAverage), 里面的 average 统计了(根据一定的算法 compute_adaptive_average)每一次 minor gc 的存活的对象的"平均"信息, 然后 deviation 也统计了每一次 minor gc 的"平均"偏差信息(current - average), _padded_avg 为模拟计算 下一次 gc oldGen 最坏的情况下大概需要多少空间
AdaptiveWeightedAverage 中更新 average, dedeviation, _padded_avg 的相关计算逻辑如下
传入的 new_sample, youngGen 存货的对象的大小(sizeInBytes)
完
参考
[草稿] GC 参数设置的一些疑问 PS + SERIALOLD
以上是关于60 一次 ParallelGC 的调试的主要内容，如果未能解决你的问题，请参考以下文章