JVM：第一章：设计一个刚好在一秒堆溢出的程序

创建了一个JVMDemo类：

package common;

import java.lang.management.ManagementFactory;
import java.lang.management.MemoryMXBean;
import java.util.ArrayList;
import java.util.List;

/**
 * @Author:Liaozhiwei
 * @Date: 2019/11/23 18:45
 */
public class JVMDemo {

    /**
     * JVM内存分配测试
     * 堆内存30M|Yong10M(Eden8M,from1M,to1M)|Old20M
     *初始堆大小:-Xms30m 最大堆大小:-Xmx30m
     * 让虚拟机在发生内存溢出时 Dump 出当前的内存堆转储快照，以便分析用:-XX:+HeapDumpOnOutOfMemoryError
     * 打印 GC 信息:-XX:+PrintGCDetails
     * 永久代(方法区)的最大值:-XX:MaxPermSize=20M
     */
    byte[] a = new byte[1024*1024*1];//1M
    public static void main(String[] args) {
        List<Object> list = new ArrayList<>();
        int i =1;
        MemoryMXBean memoryMXBean = ManagementFactory.getMemoryMXBean();
        System.out.println("初始化堆的当前内存使用量:"+memoryMXBean.getHeapMemoryUsage());
        System.out.println("初始化非堆内存的当前内存使用量:"+memoryMXBean.getNonHeapMemoryUsage());
        while (true){
            list.add(new JVMDemo());
            try {
                Thread.sleep(40);
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
//            System.out.println("非堆内存的当前内存使用量:"+memoryMXBean.getNonHeapMemoryUsage());
            System.out.println("堆内存的当前内存使用量:"+memoryMXBean.getHeapMemoryUsage());
            System.out.println(i++);
        }
    }
}

配置JVM：

-XX:MaxPermSize=20M -Xms30m -Xmx30m -XX:+HeapDumpOnOutOfMemoryError -XX:+PrintGCDetails -XX:HeapDumpPath=C:UsersAdministratorDesktoperror_logs

控制台输出：

初始化堆的当前内存使用量:init = 31457280(30720K) used = 2083952(2035K) committed = 30408704(29696K) max = 30408704(29696K)

可以看到我给设置了30M堆内存，初始化的时候已经被使用了2035k了，最大可使用的堆内存为29M，因为新生代from区与to区二个只能二选一，必须有一个为空的，所以最大可使用29M。

堆内存的当前内存使用量:init = 31457280(30720K) used = 3302664(3225K) committed = 30408704(29696K) max = 30408704(29696K)
1

进入循环，可以看到增加了1190k

堆内存的当前内存使用量:init = 31457280(30720K) used = 4351256(4249K) committed = 30408704(29696K) max = 30408704(29696K)
2

这次增加了1024k，也就是1M

堆内存的当前内存使用量:init = 31457280(30720K) used = 5399848(5273K) committed = 30408704(29696K) max = 30408704(29696K)
3

增加了1M

堆内存的当前内存使用量:init = 31457280(30720K) used = 6616232(6461K) committed = 30408704(29696K) max = 30408704(29696K)
4

增加了1188k

堆内存的当前内存使用量:init = 31457280(30720K) used = 7832592(7649K) committed = 30408704(29696K) max = 30408704(29696K)
5

增加了1188k，现在已经7649k了，离8m(8192k)只有543k的内存空间了

[GC (Allocation Failure) [PSYoungGen: 7649K->984K(9216K)] 7649K->6112K(29696K), 0.0019481 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

然后开始新生代gc，新生代已使用7649k，gc之后新生代已使用984k，新生代总大小9M，GC前Java堆已使用容量7649k，GC后Java堆已使用容量6112k，总堆的大小29M。

堆内存的当前内存使用量:init = 31457280(30720K) used = 7454896(7280K) committed = 30408704(29696K) max = 30408704(29696K)
6

从6112k，增加了1168k，到7280k

堆内存的当前内存使用量:init = 31457280(30720K) used = 8503488(8304K) committed = 30408704(29696K) max = 30408704(29696K)
7

增加了1M

堆内存的当前内存使用量:init = 31457280(30720K) used = 9552080(9328K) committed = 30408704(29696K) max = 30408704(29696K)
8

增加了1M

堆内存的当前内存使用量:init = 31457280(30720K) used = 10600672(10352K) committed = 30408704(29696K) max = 30408704(29696K)
9

增加了1M
堆内存的当前内存使用量:init = 31457280(30720K) used = 11649264(11376K) committed = 30408704(29696K) max = 30408704(29696K)
10

增加了1M
堆内存的当前内存使用量:init = 31457280(30720K) used = 12697856(12400K) committed = 30408704(29696K) max = 30408704(29696K)
11

增加了1M
堆内存的当前内存使用量:init = 31457280(30720K) used = 13746448(13424K) committed = 30408704(29696K) max = 30408704(29696K)
12

增加了1M
[GC (Allocation Failure) [PSYoungGen: 8296K->1000K(9216K)] 13424K->13296K(29696K), 0.0016737 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

开始新生代gc，新生代已使用8296k，gc之后新生代已使用1000k，新生代总大小9M，GC前Java堆已使用容量13424k，GC后Java堆已使用容量13296k，总堆的大小29M。
堆内存的当前内存使用量:init = 31457280(30720K) used = 14902416(14553K) committed = 30408704(29696K) max = 30408704(29696K)
13

从13296k增加了1257k到14553k

堆内存的当前内存使用量:init = 31457280(30720K) used = 15951008(15577K) committed = 30408704(29696K) max = 30408704(29696K)
14

增加了1M
堆内存的当前内存使用量:init = 31457280(30720K) used = 16999600(16601K) committed = 30408704(29696K) max = 30408704(29696K)
15

增加了1M
堆内存的当前内存使用量:init = 31457280(30720K) used = 18048192(17625K) committed = 30408704(29696K) max = 30408704(29696K)
16

增加了1M
堆内存的当前内存使用量:init = 31457280(30720K) used = 19096784(18649K) committed = 30408704(29696K) max = 30408704(29696K)
17

增加了1M
堆内存的当前内存使用量:init = 31457280(30720K) used = 20145376(19673K) committed = 30408704(29696K) max = 30408704(29696K)
18

增加了1M
堆内存的当前内存使用量:init = 31457280(30720K) used = 21193968(20697K) committed = 30408704(29696K) max = 30408704(29696K)
19

增加了1M
[GC (Allocation Failure) [PSYoungGen: 8401K->1016K(9216K)] 20697K->20488K(29696K), 0.0015551 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

开始新生代gc，新生代已使用8401k，gc之后新生代已使用1016k，新生代总大小9M，GC前Java堆已使用容量20697k，GC后Java堆已使用容量20488k，总堆的大小29M，剩余9208k，小于新生代9216k,触发FullGC

[Full GC (Ergonomics) [PSYoungGen: 1016K->0K(9216K)] [ParOldGen: 19472K->20243K(20480K)] 20488K->20243K(29696K), [Metaspace: 3416K->3416K(1056768K)], 0.0097494 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

新生代gc，新生代已使用1016k，gc之后新生代已使用0k，新生代总大小9M

老年代gc，老年代已使用19472k，gc之后老年代已使用20243k，老年代总大小20M

堆内存的当前内存使用量:init = 31457280(30720K) used = 21935136(21421K) committed = 30408704(29696K) max = 30408704(29696K)
20

增加了1178k
堆内存的当前内存使用量:init = 31457280(30720K) used = 22983728(22445K) committed = 30408704(29696K) max = 30408704(29696K)
21

增加了1M
堆内存的当前内存使用量:init = 31457280(30720K) used = 24032320(23469K) committed = 30408704(29696K) max = 30408704(29696K)
22

增加了1M
堆内存的当前内存使用量:init = 31457280(30720K) used = 25080912(24493K) committed = 30408704(29696K) max = 30408704(29696K)
23

增加了1M
堆内存的当前内存使用量:init = 31457280(30720K) used = 26129504(25517K) committed = 30408704(29696K) max = 30408704(29696K)
24

堆内存的当前内存使用量:init = 31457280(30720K) used = 27178096(26541K) committed = 30408704(29696K) max = 30408704(29696K)
25

增加了1M
堆内存的当前内存使用量:init = 31457280(30720K) used = 28226688(27565K) committed = 30408704(29696K) max = 30408704(29696K)
26

增加了1M
[Full GC (Ergonomics) [PSYoungGen: 7321K->7168K(9216K)] [ParOldGen: 20243K->20243K(20480K)] 27565K->27411K(29696K), [Metaspace: 3419K->3419K(1056768K)], 0.0087983 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

新生代gc，新生代已使用7321K，gc之后新生代已使用7168K，新生代总大小9M

老年代gc，老年代已使用20243K，gc之后老年代已使用20243K，老年代总大小20M
[Full GC (Allocation Failure) [PSYoungGen: 7168K->7168K(9216K)] [ParOldGen: 20243K->20225K(20480K)] 27411K->27394K(29696K), [Metaspace: 3419K->3419K(1056768K)], 0.0091156 secs] [Times: user=0.11 sys=0.00, real=0.02 secs]

新生代gc，新生代已使用7168K，gc之后新生代已使用7168K，新生代总大小9M

老年代gc，老年代已使用20243K，gc之后老年代已使用20225K，老年代总大小20M

三种时间类型：

• real： 程序从开始到结束所用的时钟时间。这个时间包括其他进程使用的时间片和进程阻塞的时间（比如等待 I/O 完成）。
• user：进程执行用户态代码（核心之外）所使用的时间。这是执行此进程所使用的实际 CPU 时间，其他进程和此进程阻塞的时间并不包括在内。在垃圾收集的情况下，表示 GC 线程执行所使用的 CPU 总时间。
• sys：进程在内核态消耗的 CPU 时间，即在内核执行系统调用或等待系统事件所使用的 CPU 时间。
• user + sys 时间告诉我们程序执行实际使用的 CPU 时间。注意这里指所有的 CPU，因此如果在进程里有多个线程的话，这个时间可能会超过 real 所表示的时钟时间。如果出现user + sys 时间的和比 real 时间要大，这主要是因为日志时间是从 JVM 中获得的，而这个 JVM 在多核的处理器上被配置了多个 GC 线程，由于多个线程并行地执行 GC，因此整个 GC 工作被这些线程共享，最终导致实际的时钟时间（real）小于总的 CPU 时间（user + sys）。

在做性能优化时，我们一般采用 real 时间来优化程序。因为最终用户只关心点击页面发出请求到页面上展示出内容所花的时间，也就是响应时间，而不关心你到底使用了多少个 GC 线程或者处理器。但并不是说 sys 和 user 两个时间不重要，当我们想通过增加 GC 线程或者 CPU 数量来减少 GC 停顿时间时，可以参考这两个时间。

所以可以根据使用（1秒 - real占用的时间）= 休眠的时间，这样休眠的时间加上GC使用的时间（real时间）就可以就可以设计出刚好一秒堆溢出

java.lang.OutOfMemoryError: Java heap space
Dumping heap to java_pid13144.hprof ...
Heap dump file created [28907711 bytes in 0.034 secs]
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
    at common.StringTool.<init>(StringTool.java:206)
    at common.JVMDemo.main(JVMDemo.java:30)
Heap
 PSYoungGen      total 9216K, used 7406K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
  eden space 8192K, 90% used [0x00000000ff600000,0x00000000ffd3bb20,0x00000000ffe00000)
  from space 1024K, 0% used [0x00000000ffe00000,0x00000000ffe00000,0x00000000fff00000)
  to   space 1024K, 0% used [0x00000000fff00000,0x00000000fff00000,0x0000000100000000)
 ParOldGen       total 20480K, used 20225K [0x00000000fe200000, 0x00000000ff600000, 0x00000000ff600000)
  object space 20480K, 98% used [0x00000000fe200000,0x00000000ff5c07e8,0x00000000ff600000)
 Metaspace       used 3451K, capacity 4564K, committed 4864K, reserved 1056768K
  class space    used 370K, capacity 388K, committed 512K, reserved 1048576K
Picked up JAVA_TOOL_OPTIONS: -Dfile.encoding=UTF-8
Java HotSpot(TM) 64-Bit Server VM warning: ignoring option MaxPermSize=20M; support was removed in 8.0

Process finished with exit code 1

问题：为啥每次加的都不是1M呢？

解释：每次加的都不是1M，原因一：ArrayList扩容影响的，通过ArrrayList空参构造器创建对象。底层创建一个长度为10的数组，当我们向数组中添加11个元素时，底层会进行扩容，扩容为原来的1.5倍(创建一个新的数组，长度为原数组长度的1.5倍，将原数组复制到新数组中)。改造ArrayList，验证想法：

运行之后，控制台打印：

初始化堆的当前内存使用量:init = 31457280(30720K) used = 3089664(3017K) committed = 30408704(29696K) max = 30408704(29696K)
堆内存的当前内存使用量:init = 31457280(30720K) used = 4138256(4041K) committed = 30408704(29696K) max = 30408704(29696K)
1
堆内存的当前内存使用量:init = 31457280(30720K) used = 5186848(5065K) committed = 30408704(29696K) max = 30408704(29696K)
2
堆内存的当前内存使用量:init = 31457280(30720K) used = 6235440(6089K) committed = 30408704(29696K) max = 30408704(29696K)
3
堆内存的当前内存使用量:init = 31457280(30720K) used = 7284032(7113K) committed = 30408704(29696K) max = 30408704(29696K)
4
堆内存的当前内存使用量:init = 31457280(30720K) used = 8332624(8137K) committed = 30408704(29696K) max = 30408704(29696K)
5
[GC (Allocation Failure) [PSYoungGen: 8137K->1023K(9216K)] 8137K->6252K(29696K), 0.0069038 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
堆内存的当前内存使用量:init = 31457280(30720K) used = 7613624(7435K) committed = 30408704(29696K) max = 30408704(29696K)
6
堆内存的当前内存使用量:init = 31457280(30720K) used = 8913912(8704K) committed = 30408704(29696K) max = 30408704(29696K)
7
堆内存的当前内存使用量:init = 31457280(30720K) used = 9962504(9729K) committed = 30408704(29696K) max = 30408704(29696K)
8
堆内存的当前内存使用量:init = 31457280(30720K) used = 11011096(10753K) committed = 30408704(29696K) max = 30408704(29696K)
9
堆内存的当前内存使用量:init = 31457280(30720K) used = 12059688(11777K) committed = 30408704(29696K) max = 30408704(29696K)
10
堆内存的当前内存使用量:init = 31457280(30720K) used = 13108280(12801K) committed = 30408704(29696K) max = 30408704(29696K)
11
堆内存的当前内存使用量:init = 31457280(30720K) used = 14156872(13825K) committed = 30408704(29696K) max = 30408704(29696K)
12
[GC (Allocation Failure) [PSYoungGen: 8596K->920K(9216K)] 13825K->13324K(29696K), 0.0025148 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
堆内存的当前内存使用量:init = 31457280(30720K) used = 14855728(14507K) committed = 30408704(29696K) max = 30408704(29696K)
13
堆内存的当前内存使用量:init = 31457280(30720K) used = 15904320(15531K) committed = 30408704(29696K) max = 30408704(29696K)
14
堆内存的当前内存使用量:init = 31457280(30720K) used = 16952912(16555K) committed = 30408704(29696K) max = 30408704(29696K)
15
堆内存的当前内存使用量:init = 31457280(30720K) used = 18085408(17661K) committed = 30408704(29696K) max = 30408704(29696K)
16
堆内存的当前内存使用量:init = 31457280(30720K) used = 19134000(18685K) committed = 30408704(29696K) max = 30408704(29696K)
17
堆内存的当前内存使用量:init = 31457280(30720K) used = 20182592(19709K) committed = 30408704(29696K) max = 30408704(29696K)
18
堆内存的当前内存使用量:init = 31457280(30720K) used = 21231184(20733K) committed = 30408704(29696K) max = 30408704(29696K)
19
[GC (Allocation Failure) [PSYoungGen: 8328K->1000K(9216K)] 20733K->20580K(29696K), 0.0023324 secs] [Times: user=0.06 sys=0.03, real=0.00 secs] 
[Full GC (Ergonomics) [PSYoungGen: 1000K->0K(9216K)] [ParOldGen: 19580K->20310K(20480K)] 20580K->20310K(29696K), [Metaspace: 3180K->3180K(1056768K)], 0.0108207 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
堆内存的当前内存使用量:init = 31457280(30720K) used = 22009368(21493K) committed = 30408704(29696K) max = 30408704(29696K)
20
堆内存的当前内存使用量:init = 31457280(30720K) used = 23057960(22517K) committed = 30408704(29696K) max = 30408704(29696K)
21
堆内存的当前内存使用量:init = 31457280(30720K) used = 24106552(23541K) committed = 30408704(29696K) max = 30408704(29696K)
22
堆内存的当前内存使用量:init = 31457280(30720K) used = 25155144(24565K) committed = 30408704(29696K) max = 30408704(29696K)
23
堆内存的当前内存使用量:init = 31457280(30720K) used = 26203736(25589K) committed = 30408704(29696K) max = 30408704(29696K)
24
堆内存的当前内存使用量:init = 31457280(30720K) used = 27252328(26613K) committed = 30408704(29696K) max = 30408704(29696K)
25
堆内存的当前内存使用量:init = 31457280(30720K) used = 28300920(27637K) committed = 30408704(29696K) max = 30408704(29696K)
26
[Full GC (Ergonomics) [PSYoungGen: 7326K->7168K(9216K)] [ParOldGen: 20310K->20310K(20480K)] 27637K->27478K(29696K), [Metaspace: 3182K->3182K(1056768K)], 0.0042343 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 
[Full GC (Allocation Failure) [PSYoungGen: 7168K->7168K(9216K)] [ParOldGen: 20310K->20296K(20480K)] 27478K->27464K(29696K), [Metaspace: 3182K->3182K(1056768K)], 0.0078410 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
java.lang.OutOfMemoryError: Java heap space
Dumping heap to C:UsersAdministratorDesktoperror_logs ...
Unable to create C:UsersAdministratorDesktoperror_logs: No such file or directory
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
	at utils.OneM.<init>(OneM.java:9)
	at utils.JVMDemo.main(JVMDemo.java:37)
Heap
 PSYoungGen      total 9216K, used 7409K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
  eden space 8192K, 90% used [0x00000000ff600000,0x00000000ffd3c738,0x00000000ffe00000)
  from space 1024K, 0% used [0x00000000ffe00000,0x00000000ffe00000,0x00000000fff00000)
  to   space 1024K, 0% used [0x00000000fff00000,0x00000000fff00000,0x0000000100000000)
 ParOldGen       total 20480K, used 20296K [0x00000000fe200000, 0x00000000ff600000, 0x00000000ff600000)
  object space 20480K, 99% used [0x00000000fe200000,0x00000000ff5d20b0,0x00000000ff600000)
 Metaspace       used 3214K, capacity 4556K, committed 4864K, reserved 1056768K
  class space    used 346K, capacity 392K, committed 512K, reserved 1048576K
Picked up JAVA_TOOL_OPTIONS: -Dfile.encoding=UTF-8
Disconnected from the target VM, address: '127.0.0.1:65390', transport: 'socket'
Java HotSpot(TM) 64-Bit Server VM warning: ignoring option MaxPermSize=20M; support was removed in 8.0

Process finished with exit code 1

可以看到基本都是1M了

问题2：为什么同一程序所花费的时间都不同？

解释：同样的程序每次运行的时间不一样，原因是：

                        1、与操作系统的调度有关

                        2、现在的CPU支持动态调频

所以每次执行程序运行的时间都不同

以上若有任何疑问或者错误欢迎在评论下面指出，我会及时更改