jvm 内存变化监控测试，观察Eden 内存增长到最大，触发GC、堆内存越来越高，触发FullGC，直到最后内存溢出。打印GC日志 -XX:+PrintGC -XX:+PrintGCDetails -

标签：0.00 XX secs GC 内存 15872K

1 测试准备

1）写一个程序，创建一个二维的直接数组，长度为10000，用于存放生成的数据；

2）写一个while 循环，每秒向二维数组中放入1个 1M 的字节数组；

package com.spqin.jvm;

/**
 * @author Spqin
 * @version 1.0
 * @Date 2022-09-11 19:52
 */
public class JvmTest {
    public static void main(String[] args) {
        byte[][] byteArray = new byte[10000][];
        int n = 0;
        while(true){
            try {
                //每秒50M 数据,放入到字节数组的数组中
                byteArray[n] = new byte[1024 * 1024 * 1];
                n++;
                Thread.sleep(1000);
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
        }
    }
}

3）运行时设置最大堆内存和最小堆内存为 4G，运行程序。

-Xms4G -Xmx4G -XX:+PrintGC

2 监测过程

2.1 查看内存结构

通过jmap 查看内存非配信息，5296 是jvm的进程Id，可以通过 jps 或 jconsole 查看

jmap -heap 5296

可以查看默认jvm 默认的配置信息

NewRatio = 2，默认年轻代和老年代比率是1:2，通过NewRatio设置，默认值是2，代表1:2 的意思

由于最大堆内存 4G = 4096M，年轻代占 1/3 ，4096 ÷ 3 = 1365.333 ≈ 1365.0M，老年代占 2/3，4096 × 2 ÷ 3 = 2730.667 ≈ 2731.0M

SurvivorRatio = 8 ，这个值是幸存者区在整个新生代中的占比，即新生代分成个8份，两个幸存者区各占1份，Eden 区占6份，Eden：From：To = 6:1:1

由于年轻代已知是1365M，所以Eden 区是 1365 M 的 0.75，1365 × 0.75 = 1023.75 ≈ 1024.0M，2个生存者区都是（1365 - 1024）÷ 2 = 170.5M

通过下面的信息得以验证

2.2 查看堆内存使用情况

通过jstat 监测查看堆内存使用过程

jstat -gcutil pid 毫秒数 # 周期性查看堆内存各组成的使用率
jstat -gcnew pid 毫秒数 # 周期性查看堆内存中 年轻代使用情况
jstat -gcold pid 毫秒数 # 周期性查看堆内存中 老年代使用情况

1）刚开始查看结果，幸存者区使用都是0，使用率肯定也是0，Eden 区每秒增加1M数据，使用率按每秒 1%~2% 增长

2）当Eden 区内存增长到（或超过）了最大值 1024M 时，就触发GC

日志查看及分析（这里是我查看到一个代时间片段的资料，主要看有的信息就行，带日期的是另外一个命令打印的）

通过GC 日志分析，该区域总容量 = 4091712K = 3925.5M，是整个清理区域的内存，大于年轻代总内存，小于年轻代＋老年代总内存，说明这是一次并发收集，即收集了 Eden + From（或者To）+Old = 4096 - 170.5 = 3925.5 ，刚好验证了我们的结论。

清理前只有Eden 区有数据，是1047809k，清理后Eden 区还有796163K ，即清理了1047809k - 796163K = 251646k ≈245.748M，清理后剩余的数据796163K，放入到幸存者1区，放不下，只放了174561.7k（占用了幸存者区的174561.7k ÷ 174592 = 0.99982 ≈ 99.98%），剩下的数据放到了老年代 621601.5k（占用了老年代的621601.5Kk÷ 2796544k = 0.222274 ≈ 22.23%）

和上文的截图一致。

3）GC后，Eden 区内存继续增长，再次增长到（或超过）了最大值 1024M 时，就再次触发GC，如下如所示

GC 前的数据1843950k ，这一部分数据应该有上次清理后剩余的数据 796163k ,Eden 区的数据是 1843950k - 796163k = 1047787k 和上次清理前Eden 区的数据 1047809k 接近（相差22k）,清理之后的内存是1738265k，其中174561.8k 放入到幸存者2区，剩余1563703.9 放到了，老年代，清空幸存者1区和Eden 区。

幸存者区占比还是99.98%，老年代占比上升到 1563703.9 ÷ 2796544 = 0.559155 ≈ 55.92%

4）GC后，Eden 区内存继续增长，再次增长到（或超过）了最大值 1024M 时，就第3次触发GC，如下如所示

GC 前的数据2786841k = 2.65G ，这一部分数据应该有上次清理后剩余的数据 796163k ,Eden 区的数据是 2786841k - 1738265 k = 1048576 k 和上次清理前Eden 区的数据 1047787k 接近（相差789k）,清理之后的内存是2711072 k ≈ 2.59G，清理后的数据都放进了老年代，清空幸存者1区、2区和Eden 区。

幸存者区占比变成0，老年代占比上升到 2710908.7 ÷ 2796544 = 0.969377 ≈ 96.94%

5）GC后，Eden 区内存继续增长，再次增长到（或超过）了最大值 1024M 时，开始触发Full GC，如下如所示

GC 前，由于老年代已经达到了96.94%，Eden 区又产生了1024M 的数据，老年代放不下新生成的数据了，触发了Full GC，但是内存是清理不掉多少，清理后Eden 区的数据有一部分被转移到了了老年代，老年代内存上升到了99.96%，Eden 区内存占用也达到了 88.39%，此时程序还在继续产生数据，每秒1M,很快又达到了1024M

接下来就是频繁的Full GC，但是能清理掉的数据也是越来越少，清空越来越严重，连续出现Full GC ，内存溢出了，Eden 直接到了 100%，老年代也到了99.96%，清理越来越赶不上增长，最后挽救不了了，最后爆炸了。

3 更详细的日志打印

3.1 -verbose:gc 参数和-XX:+PrintGC 效果一样

打印效果都是

[GC (Allocation Failure) 3203K->1767K(15872K), 0.0013214 secs]
[GC (Allocation Failure) 4917K->4855K(15872K), 0.0008501 secs]
[GC (Allocation Failure) 7997K->7975K(15872K), 0.0010062 secs]
[Full GC (Ergonomics) 7975K->7842K(15872K), 0.0062387 secs]
[GC (Allocation Failure) 11070K->10914K(15872K), 0.0009302 secs]
[Full GC (Ergonomics) 10914K->10899K(15872K), 0.0068005 secs]

3.2 -XX:+PrintGCDetails 参数，打印的更详细

想看详细的信息用 -XX:+PrintGCDetails，想看简单的信息用 -XX:+PrintGC

打印效果如下

[GC (Allocation Failure) [PSYoungGen: 3972K->495K(4608K)] 3972K->2195K(15872K), 0.0007601 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[GC (Allocation Failure) [PSYoungGen: 3634K->503K(4608K)] 5335K->5291K(15872K), 0.0008066 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[GC (Allocation Failure) [PSYoungGen: 3638K->471K(4608K)] 8426K->8331K(15872K), 0.0010018 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[Full GC (Ergonomics) [PSYoungGen: 471K->0K(4608K)] [ParOldGen: 7860K->8234K(11264K)] 8331K->8234K(15872K), [Metaspace: 3744K->3744K(1056768K)], 0.0096754 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
[Full GC (Ergonomics) [PSYoungGen: 3141K->0K(4608K)] [ParOldGen: 8234K->11219K(11264K)] 11375K->11219K(15872K), [Metaspace: 3745K->3745K(1056768K)], 0.0087364 secs] [Times: user=0.13 sys=0.00, real=0.01 secs] 
[Full GC (Ergonomics) [PSYoungGen: 3217K->3072K(4608K)] [ParOldGen: 11219K->11219K(11264K)] 14437K->14291K(15872K), [Metaspace: 3745K->3745K(1056768K)], 0.0080702 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
[Full GC (Allocation Failure) [PSYoungGen: 3072K->3072K(4608K)] [ParOldGen: 11219K->11219K(11264K)] 14291K->14291K(15872K), [Metaspace: 3745K->3745K(1056768K)], 0.0023664 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap
 PSYoungGen      total 4608K, used 3182K [0x00000000ffb00000, 0x0000000100000000, 0x0000000100000000)
  eden space 4096K, 77% used [0x00000000ffb00000,0x00000000ffe1b880,0x00000000fff00000)
  from space 512K, 0% used [0x00000000fff00000,0x00000000fff00000,0x00000000fff80000)
  to   space 512K, 0% used [0x00000000fff80000,0x00000000fff80000,0x0000000100000000)
 ParOldGen       total 11264K, used 11219K [0x00000000ff000000, 0x00000000ffb00000, 0x00000000ffb00000)
  object space 11264K, 99% used [0x00000000ff000000,0x00000000ffaf4e00,0x00000000ffb00000)
 Metaspace       used 3776K, capacity 4536K, committed 4864K, reserved 1056768K
  class space    used 415K, capacity 428K, committed 512K, reserved 1048576K
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
    at com.spqin.jvm.gclog.JvmGcPrintTest.main(JvmGcPrintTest.java:15)

3.3 -XX:+PrintGCTimeStamps 可以打印出GC 时间戳

-XX:+PrintGCTimeStamps 打印时间戳，此时间戳为打印GC 日志时，JVM 启动的时间。

1.124: [GC (Allocation Failure) [PSYoungGen: 3972K->495K(4608K)] 3972K->2235K(15872K), 0.0011614 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4.147: [GC (Allocation Failure) [PSYoungGen: 3634K->479K(4608K)] 5375K->5291K(15872K), 0.0010732 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
7.163: [GC (Allocation Failure) [PSYoungGen: 3614K->511K(4608K)] 8426K->8411K(15872K), 0.0014633 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
7.164: [Full GC (Ergonomics) [PSYoungGen: 511K->0K(4608K)] [ParOldGen: 7900K->8234K(11264K)] 8411K->8234K(15872K), [Metaspace: 3745K->3745K(1056768K)], 0.0101831 secs] [Times: user=0.13 sys=0.00, real=0.01 secs] 
10.190: [Full GC (Ergonomics) [PSYoungGen: 3141K->0K(4608K)] [ParOldGen: 8234K->11219K(11264K)] 11375K->11219K(15872K), [Metaspace: 3745K->3745K(1056768K)], 0.0081231 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
13.222: [Full GC (Ergonomics) [PSYoungGen: 3217K->3072K(4608K)] [ParOldGen: 11219K->11219K(11264K)] 14437K->14291K(15872K), [Metaspace: 3745K->3745K(1056768K)], 0.0097859 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
13.232: [Full GC (Allocation Failure) [PSYoungGen: 3072K->3072K(4608K)] [ParOldGen: 11219K->11219K(11264K)] 14291K->14291K(15872K), [Metaspace: 3745K->3745K(1056768K)], 0.0027274 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap
 PSYoungGen      total 4608K, used 3182K [0x00000000ffb00000, 0x0000000100000000, 0x0000000100000000)
  eden space 4096K, 77% used [0x00000000ffb00000,0x00000000ffe1b880,0x00000000fff00000)
  from space 512K, 0% used [0x00000000fff00000,0x00000000fff00000,0x00000000fff80000)
  to   space 512K, 0% used [0x00000000fff80000,0x00000000fff80000,0x0000000100000000)
 ParOldGen       total 11264K, used 11219K [0x00000000ff000000, 0x00000000ffb00000, 0x00000000ffb00000)
  object space 11264K, 99% used [0x00000000ff000000,0x00000000ffaf4e30,0x00000000ffb00000)
 Metaspace       used 3777K, capacity 4536K, committed 4864K, reserved 1056768K
  class space    used 415K, capacity 428K, committed 512K, reserved 1048576K
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
    at com.spqin.jvm.gclog.JvmGcPrintTest.main(JvmGcPrintTest.java:15)

3.4 -XX:+PrintGCDateStamps 打印日期戳

-XX:+PrintGCDateStamps 打印日期戳，这里日期戳打印的当前系统时间，具体到秒

2025-01-23T23:07:47.360+0800: 1.120: [GC (Allocation Failure) [PSYoungGen: 3934K->503K(4608K)] 3934K->2203K(15872K), 0.0009505 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2025-01-23T23:07:50.378+0800: 4.137: [GC (Allocation Failure) [PSYoungGen: 3642K->487K(4608K)] 5342K->5331K(15872K), 0.0012393 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2025-01-23T23:07:53.400+0800: 7.159: [GC (Allocation Failure) [PSYoungGen: 3622K->487K(4608K)] 8466K->8419K(15872K), 0.0013130 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2025-01-23T23:07:53.401+0800: 7.160: [Full GC (Ergonomics) [PSYoungGen: 487K->0K(4608K)] [ParOldGen: 7932K->8235K(11264K)] 8419K->8235K(15872K), [Metaspace: 3746K->3746K(1056768K)], 0.0089178 secs] [Times: user=0.13 sys=0.00, real=0.01 secs] 
2025-01-23T23:07:56.425+0800: 10.184: [Full GC (Ergonomics) [PSYoungGen: 3141K->0K(4608K)] [ParOldGen: 8235K->11219K(11264K)] 11376K->11219K(15872K), [Metaspace: 3746K->3746K(1056768K)], 0.0084256 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2025-01-23T23:07:59.467+0800: 13.226: [Full GC (Ergonomics) [PSYoungGen: 3217K->3072K(4608K)] [ParOldGen: 11219K->11219K(11264K)] 14437K->14291K(15872K), [Metaspace: 3746K->3746K(1056768K)], 0.0078200 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2025-01-23T23:07:59.475+0800: 13.234: [Full GC (Allocation Failure) [PSYoungGen: 3072K->3072K(4608K)] [ParOldGen: 11219K->11219K(11264K)] 14291K->14291K(15872K), [Metaspace: 3746K->3746K(1056768K)], 0.0023979 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap
 PSYoungGen      total 4608K, used 3182K [0x00000000ffb00000, 0x0000000100000000, 0x0000000100000000)
  eden space 4096K, 77% used [0x00000000ffb00000,0x00000000ffe1b8d0,0x00000000fff00000)
  from space 512K, 0% used [0x00000000fff00000,0x00000000fff00000,0x00000000fff80000)
  to   space 512K, 0% used [0x00000000fff80000,0x00000000fff80000,0x0000000100000000)
 ParOldGen       total 11264K, used 11219K [0x00000000ff000000, 0x00000000ffb00000, 0x00000000ffb00000)
  object space 11264K, 99% used [0x00000000ff000000,0x00000000ffaf4e60,0x00000000ffb00000)
 Metaspace       used 3778K, capacity 4536K, committed 4864K, reserved 1056768K
  class space    used 415K, capacity 428K, committed 512K, reserved 1048576K
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
    at com.spqin.jvm.gclog.JvmGcPrintTest.main(JvmGcPrintTest.java:15)

3.5 -Xloggc:path/gc.log

上述都是把日志打印到控制台，把日志打印到当前目录下的path 目录下的gc.log 文件中，打印之前要确保文件出在，不然会报错。

-Xloggc:E:\study\javase-demo\gclogs/gc.log

查看日志文件

3.6 GC 日志查看

3.6.1 Minor GC 年轻代GC

3.6.2 Full GC 年轻代GC

3.5 上述文件的代码

源码在 javase-demo 下的jvm 文件夹中。

package com.spqin.jvm.gclog;

/**
 * -Xms16m -Xmx16m -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps
 * 解释
 * -XX:+PrintGC 参数和 -verbose 参数效果一样
 * -XX:+PrintGCDetails 替代 -XX:+PrintGC，打印的更详细
 * -XX:+PrintGCTimeStamps 记录打印日志时 JVM 启动了多久，单位S,例如 1.120秒
 * -XX:+PrintGCDateStamps 记录打印日志时 当前系统的时间，例如 2025-01-23T23:07:47.360+0800:
 * @author Spqin
 * @version 1.0
 * @Date 2022-09-11 19:52
 */
public class JvmGcPrintTest {
    public static void main(String[] args) {
        byte[][] byteArray = new byte[10000][];
        int n = 0;
        while(true){
            try {
                //每秒50M 数据,放入到字节数组的数组中
                byteArray[n] = new byte[1024 * 1024 * 1];
                n++;
                Thread.sleep(1000);
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
        }
    }
}

标签：0.00,XX,secs,GC,内存,15872K
From： https://www.cnblogs.com/spqin/p/18687563