梧·枝

• 于 JVM, 深入理解JAVA虚拟机, 读书笔记 Read

【JVM】JDK10的G1日志浅谈

最近学习《深入理解Java虚拟机》，书中使用的是JDK1.7，垃圾收集器使用CMS；而笔者环境为JDK10，垃圾收集默认使用G1。G1与CMS之间的差异挺大，日志格式也截然不同，而目前主流的是G1收集器，故重点学习G1。笔者最近入门学习JVM，以下理解有错的烦请指出，不甚感激～

测试一

  1. 测试代码
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
package main.GCtest;

public class testAllocation {

    private static final int _1MB = 1024 * 1024;

    /**
     * VM参数： -Xms20M -Xmx20M -Xmn10M -Xlog:gc*
     * -Xmn10M 指分配10M给新生代，Java堆剩余的分配给老年代
     * -Xlog:gc* 发生垃圾收集时打印内存回收日志，并在进程退出时输出当前的内存各区域分配情况
     */
    public static void testAllocation() {
        byte[] allocation1, allocation2, allocation3, allocation4,allocation5,allocation6;
        allocation1 = new byte[2 * _1MB];
        allocation2 = new byte[2 * _1MB];
        allocation3 = new byte[2 * _1MB];
        allocation4 = new byte[4 * _1MB];
    }

    public static void main(String[] args){
        testAllocation();
    }
}
  1. 堆内存监控，每行代码断点几秒种，以便出现分层

堆内存监控

  1. GC日志
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
#堆每块1M大小
[0.013s][info][gc,heap] Heap region size: 1M
#使用G1垃圾收集器
[0.014s][info][gc     ] Using G1
#堆地址、大小
[0.014s][info][gc,heap,coops] Heap address: 0x00000007bec00000, size: 20 MB, Compressed Oops mode: Zero based, Oop shift amount: 3
#初始标记开始，引发GC的原因是Humongous Allocation
[0.206s][info][gc,start     ] GC(0) Pause Initial Mark (G1 Humongous Allocation)
[0.206s][info][gc,task      ] GC(0) Using 4 workers of 4 for evacuation
[0.208s][info][gc,phases    ] GC(0)   Pre Evacuate Collection Set: 0.0ms
[0.208s][info][gc,phases    ] GC(0)   Evacuate Collection Set: 2.2ms
[0.208s][info][gc,phases    ] GC(0)   Post Evacuate Collection Set: 0.1ms
[0.208s][info][gc,phases    ] GC(0)   Other: 0.1ms
#Eden区回收3个region
[0.208s][info][gc,heap      ] GC(0) Eden regions: 3->0(3)
#Survivor区增加2个region
[0.208s][info][gc,heap      ] GC(0) Survivor regions: 0->2(2)
[0.208s][info][gc,heap      ] GC(0) Old regions: 0->0
#Humongous区仍然是9个region
[0.208s][info][gc,heap      ] GC(0) Humongous regions: 9->9
#元空间不变
[0.208s][info][gc,metaspace ] GC(0) Metaspace: 5242K->5242K(1056768K)
#初始标记完成，11M减为10M
[0.208s][info][gc           ] GC(0) Pause Initial Mark (G1 Humongous Allocation) 11M->10M(20M) 2.464ms
#初始标记耗时
[0.208s][info][gc,cpu       ] GC(0) User=0.00s Sys=0.01s Real=0.00s
#并发周期
[0.208s][info][gc           ] GC(1) Concurrent Cycle
#并发清除已标记的？
[0.208s][info][gc,marking   ] GC(1) Concurrent Clear Claimed Marks
[0.208s][info][gc,marking   ] GC(1) Concurrent Clear Claimed Marks 0.006ms
[0.208s][info][gc,marking   ] GC(1) Concurrent Scan Root Regions
[0.209s][info][gc,marking   ] GC(1) Concurrent Scan Root Regions 0.764ms
[0.209s][info][gc,marking   ] GC(1) Concurrent Mark (0.209s)
#并发标记
[0.209s][info][gc,marking   ] GC(1) Concurrent Mark From Roots
#使用一个进程标记
[0.209s][info][gc,task      ] GC(1) Using 1 workers of 1 for marking
[0.209s][info][gc,marking   ] GC(1) Concurrent Mark From Roots 0.055ms
[0.209s][info][gc,marking   ] GC(1) Concurrent Mark (0.209s, 0.209s) 0.073ms
#重新标记
[0.211s][info][gc,start     ] GC(1) Pause Remark
#还看不懂string and symbol table
[0.211s][info][gc,stringtable] GC(1) Cleaned string and symbol table, strings: 3207 processed, 0 removed, symbols: 23766 processed, 0 removed
[0.211s][info][gc            ] GC(1) Pause Remark 15M->15M(20M) 0.727ms
[0.211s][info][gc,cpu        ] GC(1) User=0.00s Sys=0.00s Real=0.00s
[0.211s][info][gc,marking    ] GC(1) Concurrent Create Live Data
[0.211s][info][gc,marking    ] GC(1) Concurrent Create Live Data 0.034ms
#清除垃圾
[0.211s][info][gc,start      ] GC(1) Pause Cleanup
[0.212s][info][gc            ] GC(1) Pause Cleanup 15M->15M(20M) 0.087ms
[0.212s][info][gc,cpu        ] GC(1) User=0.00s Sys=0.00s Real=0.00s
[0.212s][info][gc,marking    ] GC(1) Concurrent Cleanup for Next Mark
[0.212s][info][gc,marking    ] GC(1) Concurrent Cleanup for Next Mark 0.252ms
[0.212s][info][gc            ] GC(1) Concurrent Cycle 3.593ms
[0.212s][info][gc,heap,exit  ] Heap
#目前堆内存使用情况
[0.212s][info][gc,heap,exit  ]  garbage-first heap   total 20480K, used 15547K [0x00000007bec00000, 0x00000007c0000000)
#各个区使用的内存情况
[0.212s][info][gc,heap,exit  ]   region size 1024K, 3 young (3072K), 2 survivors (2048K)
[0.212s][info][gc,heap,exit  ]  Metaspace       used 5279K, capacity 5352K, committed 5632K, reserved 1056768K
[0.212s][info][gc,heap,exit  ]   class space    used 445K, capacity 460K, committed 512K, reserved 1048576K

测试二

  1. 测试代码
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
package main.GCtest;

public class testAllocation {

    private static final int _1MB = 1024 * 1024;

    /**
     * VM参数：-verbose:gc -Xms20M -Xmx20M -Xmn10M -Xlog:gc* -XX:SurvivorRatio=8
     * verbose:gc 显示GC的操作内容
     * -Xmn10M 指分配10M给新生代，Java堆剩余的分配给老年代
     * -Xlog:gc* 发生垃圾收集时打印内存回收日志，并在进程退出时输出当前的内存各区域分配情况
     * -XX:SurvivorRatio=8 定义新生代中Eden区与Survivor区的空间比例是8：1
     */
    public static void testAllocation() {
        byte[] allocation1, allocation2, allocation3, allocation4,allocation5,allocation6;
        allocation1 = new byte[_1MB / 3];
        allocation2 = new byte[_1MB / 3];
        allocation3 = new byte[_1MB / 3];
        allocation1 = new byte[_1MB / 3];
        allocation2 = new byte[_1MB / 3];
        allocation3 = new byte[_1MB / 3];
        allocation1 = new byte[_1MB / 3];
        allocation2 = new byte[_1MB / 3];
        allocation3 = new byte[_1MB / 3];
        allocation1 = new byte[_1MB / 3];
        allocation2 = new byte[_1MB / 3];
        allocation3 = new byte[_1MB / 3];
        allocation1 = new byte[_1MB / 3];
        allocation2 = new byte[_1MB / 3];
        allocation3 = new byte[_1MB / 3];
        allocation1 = new byte[_1MB / 3];
        allocation2 = new byte[_1MB / 3];
        allocation3 = new byte[_1MB / 3];
        allocation4 = new byte[4 * _1MB];
        allocation5 = new byte[4 * _1MB];// 出现一次Minor GC
    }

    public static void main(String[] args){
        testAllocation();
    }

}
  1. 堆内存监控

堆内存监控

  1. GC日志

    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    14
    15
    16
    17
    18
    19
    20
    21
    22
    23
    24
    25
    26
    27
    28
    29
    30
    31
    32
    33
    34
    35
    36
    37
    38
    39
    40
    41
    42
    43
    44
    45
    46
    47
    48
    49
    50
    51
    52
    53
    54
    55
    56
    57
    58
    59
    60
    61
    [0.016s][info][gc,heap] Heap region size: 1M
    [0.017s][info][gc     ] Using G1
    [0.017s][info][gc,heap,coops] Heap address: 0x00000007bec00000, size: 20 MB, Compressed Oops mode: Zero based, Oop shift amount: 3
    #年轻代回收
    [0.242s][info][gc,start     ] GC(0) Pause Young (G1 Evacuation Pause)
    [0.242s][info][gc,task      ] GC(0) Using 4 workers of 4 for evacuation
    [0.245s][info][gc,phases    ] GC(0)   Pre Evacuate Collection Set: 0.0ms
    [0.245s][info][gc,phases    ] GC(0)   Evacuate Collection Set: 2.7ms
    [0.245s][info][gc,phases    ] GC(0)   Post Evacuate Collection Set: 0.1ms
    [0.245s][info][gc,phases    ] GC(0)   Other: 0.1ms
    #Eden回收9个region
    [0.245s][info][gc,heap      ] GC(0) Eden regions: 9->0(8)
    [0.245s][info][gc,heap      ] GC(0) Survivor regions: 0->2(2)
    [0.245s][info][gc,heap      ] GC(0) Old regions: 0->1
    [0.245s][info][gc,heap      ] GC(0) Humongous regions: 0->0
    [0.245s][info][gc,metaspace ] GC(0) Metaspace: 5296K->5296K(1056768K)
    #年轻代回收内存
    [0.245s][info][gc           ] GC(0) Pause Young (G1 Evacuation Pause) 9M->2M(20M) 3.005ms
    [0.245s][info][gc,cpu       ] GC(0) User=0.00s Sys=0.00s Real=0.01s
    #初始标记
    [0.248s][info][gc,start     ] GC(1) Pause Initial Mark (G1 Humongous Allocation)
    [0.248s][info][gc,task      ] GC(1) Using 4 workers of 4 for evacuation
    [0.249s][info][gc,phases    ] GC(1)   Pre Evacuate Collection Set: 0.0ms
    [0.249s][info][gc,phases    ] GC(1)   Evacuate Collection Set: 1.3ms
    [0.249s][info][gc,phases    ] GC(1)   Post Evacuate Collection Set: 0.1ms
    [0.249s][info][gc,phases    ] GC(1)   Other: 0.1ms
    [0.249s][info][gc,heap      ] GC(1) Eden regions: 3->0(5)
    [0.249s][info][gc,heap      ] GC(1) Survivor regions: 2->2(2)
    [0.249s][info][gc,heap      ] GC(1) Old regions: 1->2
    [0.249s][info][gc,heap      ] GC(1) Humongous regions: 5->5
    [0.249s][info][gc,metaspace ] GC(1) Metaspace: 5341K->5341K(1056768K)
    #初始标记完成
    [0.249s][info][gc           ] GC(1) Pause Initial Mark (G1 Humongous Allocation) 9M->7M(20M) 1.488ms
    [0.249s][info][gc,cpu       ] GC(1) User=0.01s Sys=0.00s Real=0.00s
    [0.249s][info][gc           ] GC(2) Concurrent Cycle
    [0.249s][info][gc,marking   ] GC(2) Concurrent Clear Claimed Marks
    [0.249s][info][gc,marking   ] GC(2) Concurrent Clear Claimed Marks 0.006ms
    [0.249s][info][gc,marking   ] GC(2) Concurrent Scan Root Regions
    [0.249s][info][gc,marking   ] GC(2) Concurrent Scan Root Regions 0.046ms
    [0.249s][info][gc,marking   ] GC(2) Concurrent Mark (0.249s)
    [0.249s][info][gc,marking   ] GC(2) Concurrent Mark From Roots
    [0.249s][info][gc,task      ] GC(2) Using 1 workers of 1 for marking
    [0.251s][info][gc,marking   ] GC(2) Concurrent Mark From Roots 1.738ms
    [0.251s][info][gc,marking   ] GC(2) Concurrent Mark (0.249s, 0.251s) 1.772ms
    [0.252s][info][gc,start     ] GC(2) Pause Remark
    [0.254s][info][gc,stringtable] GC(2) Cleaned string and symbol table, strings: 3241 processed, 0 removed, symbols: 23981 processed, 0 removed
    [0.254s][info][gc            ] GC(2) Pause Remark 12M->12M(20M) 2.252ms
    [0.254s][info][gc,cpu        ] GC(2) User=0.01s Sys=0.00s Real=0.01s
    [0.254s][info][gc,marking    ] GC(2) Concurrent Create Live Data
    [0.255s][info][gc,marking    ] GC(2) Concurrent Create Live Data 0.333ms
    [0.258s][info][gc,start      ] GC(2) Pause Cleanup
    [0.258s][info][gc            ] GC(2) Pause Cleanup 12M->12M(20M) 0.103ms
    [0.258s][info][gc,cpu        ] GC(2) User=0.00s Sys=0.00s Real=0.00s
    [0.258s][info][gc,marking    ] GC(2) Concurrent Cleanup for Next Mark
    [0.258s][info][gc,marking    ] GC(2) Concurrent Cleanup for Next Mark 0.240ms
    [0.258s][info][gc            ] GC(2) Concurrent Cycle 8.979ms
    [0.261s][info][gc,heap,exit  ] Heap
    [0.261s][info][gc,heap,exit  ]  garbage-first heap   total 20480K, used 12827K [0x00000007bec00000, 0x00000007c0000000)
    [0.261s][info][gc,heap,exit  ]   region size 1024K, 3 young (3072K), 2 survivors (2048K)
    [0.261s][info][gc,heap,exit  ]  Metaspace       used 5393K, capacity 5448K, committed 5632K, reserved 1056768K
    [0.261s][info][gc,heap,exit  ]   class space    used 460K, capacity 492K, committed 512K, reserved 1048576K

疑问点

  1. 每个Region大小为1M，代码中的所有对象都大于1M，应该存放Humongous，可为什么有部分存入Eden和Survivor？
  2. 从堆内存监控可以看出，在没有生成局部标量前有2M的堆内存，这部分除了Metaspace和class space外，还存储什么内容？
Newer Post

【ARTS-0】准备开始 ARTS

虽然加入耗子叔的极客时间专栏有一段时间，但一直没有细看，知晓 ARTS 也是最近两天的事情，准备的不太充分，今天只达到了一部分目标，算是一次试练吧 Algorithm 题目（leetcode15） 给定一个包含 n 个整数的数组 nums，判断 nums 中是否存在三个元素 a，b，c ，使得 a …

• 于 ARTS, Algorithm, 读书笔记 继续阅读
Older Post

【JVM】MAC下IDEA集成插件VisualVM Launcher的简单介绍

《深入理解 Java 虚拟机》书中以及网上大部分博客对于堆转储文件分析使用的工具都是 Eclipse Memory Analyzer，搜索许久终于找到IDEA集成的一个内存映像分析插件 VisualVM Launcher（需先安装 VisualVM ）。 环境准备 macOS 系统版本：10.13 …

• 于 JVM, 深入理解JAVA虚拟机, 读书笔记 继续阅读