万字概览 Java 虚拟机 (8)

CreateTask.java

public class CreateTask implements Runnable { private List<Programmer> programmers = new ArrayList<>(); @Override public void run() { for (int i = 0; i < 100000000; i++) { programmers.add(create()); } } private Programmer create() { Random random = new Random(); long id = (long) random.nextInt(99999999); String name = "brandon.p.gan"; int age = random.nextInt(150); boolean male = age % 2 == 0; return new Programmer(id, name, age, male); } }

Main.java

public class Main { public static void main(String[] args) throws Exception { Thread[] threads = new Thread[8]; for (int i = 0; i < 8; i++) { threads[i] = new Thread(new CreateTask()); } for (int i = 0; i < 8; i++) { threads[i].start(); } TimeUnit.DAYS.sleep(1); } } JVM 参数 -Xms20M -Xmx20M -XX:+UseConcMarkSweepGC -XX:+UseCMSInitiatingOccupancyOnly -XX:CMSInitiatingOccupancyFraction=70 -XX:+CMSScavengeBeforeRemark -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=http://www.likecs.com/Users/brandon.p.gan/Desktop/jvmdemo/oom/logs -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/Users/brandon.p.gan/Desktop/jvmdemo/oom/logs/gc.log Young GC 日志 2019-04-09T15:01:38.575-0800: 0.932: [GC (Allocation Failure) 2019-04-09T15:01:38.575-0800: 0.933: [ParNew: 5504K->639K(6144K), 0.0057317 secs] 5504K->1449K(19840K), 0.0058849 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]

2019-04-09T15:01:38.575-0800 是日志打印时间;

0.932 是一个相对时间,即 JVM 从启动到现在所经过的时间;

[GC (Allocation Failure) 2019-04-09T15:01:38.575-0800: 0.933 表示本次 GC 是由于内存分配失败导致的,后面的时间是 GC 触发的时间和相对时间。

[ParNew: 5504K->639K(6144K), 0.0057317 secs] 表示这是 Young GC,内存统计信息模式为:GC前->GC后(Young区大小),接着是回收 Young 区的耗时。

[Times: user=0.01 sys=0.00, real=0.01 secs] user 是用户态 CPU 时间,sys 是内核态 CPU 事件和操作的墙钟时间,real 是最终的实际耗时。

​ 墙钟时间包括非运算等待耗时,比如线程阻塞等待时间、磁盘I/O 等。

​ 多线程情况下 user 和 sys 时间可能会叠加,所以输出中可能会超过 real 时间。

CMS GC 日志 [GC (CMS Initial Mark) [1 CMS-initial-mark: 11317K(13696K)] 12040K(19840K), 0.0016389 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

GC (CMS Initial Mark) CMS GC 分为四个阶段,这是一次 CMS GC 的一个阶段,初始标记。

CMS-initial-mark: 11317K(13696K) 出师标记时 Old 区使用量和总量。

12040K(19840K), 0.0016389 secs 整个堆当前用量和总量,以及本次初始标记耗时。

2019-04-09T15:01:38.783-0800: 1.141: [CMS-concurrent-mark-start] 2019-04-09T15:01:38.792-0800: 1.150: [GC (Allocation Failure) 2019-04-09T15:01:38.792-0800: 1.150: [ParNew: 6144K->6144K(6144K), 0.0000375 secs]2019-04-09T15:01:38.792-0800: 1.150: [CMS2019-04-09T15:01:38.803-0800: 1.161: [CMS-concurrent-mark: 0.020/0.020 secs] [Times: user=0.04 sys=0.00, real=0.02 secs]

GC (Allocation Failure) 结合上一条并发标记日志,表示这是在并发标记过程中 YGC 发生。

(concurrent mode failure): 11317K->13695K(13696K), 0.0506163 secs] 17461K->14595K(19840K), [Metaspace: 3407K->3407K(1056768K)], 0.0507949 secs] [Times: user=0.05 sys=0.00, real=0.05 secs]

并发标记中 YGC 发生导致对象晋升,Old 区空间不足,出现 CMF。

[Full GC (Allocation Failure) 2019-04-09T15:01:38.851-0800: 1.209: [CMS: 13695K->13695K(13696K), 0.0442915 secs] 19839K->17237K(19840K), [Metaspace: 3407K->3407K(1056768K)], 0.0444186 secs] [Times: user=0.05 sys=0.00, real=0.04 secs]

Full GC (Allocation Failure) 由于 CMF 出现,转入 Full GC。

CMS: 13695K->13695K(13696K), 0.0442915 secs] 19839K->17237K(19840K) 这次 Full GC 的结果是 Old 区没有对象被回收,Young 区回收了 2M 左右。

怎么选择垃圾回收器

单核只能用串行;

看吞吐量用并行;

看停顿时间用并发;

不会选可以把堆的大小设置好,交给 JVM 帮你选。

什么时候会触发 FullGC

System.gc() 调用
虽然该方法调用并不一定触发 Full GC,但很大概率下都会触发,可以使用 -XX:+ DisableExplicitGC 来禁止通过这个方法触发 FullGC。

Old 区空间不足
在 Old 区分配大数组大对象失败时触发 Full GC 尝试腾出空间

Metaspace 空间不足
类加载过多、自定义类加载器过多,以及反射操作都会导致这里空间不足

Promotion Failed 晋升失败
根据历次晋升数据大小的平均值计算,如果 Old 区空间不足以容纳本次晋升对象,则触发 Full GC 腾空间

CMS 出现 CMF
CMF 的出现是因为 GC 线程和应用线程在「并发清理」阶段是并行的,如果 GC 线程不能及时回收完对象腾出足够的内存空间,当回收过程中出现对象晋升失败或者大对象分配失败,就会出现 CMF,这时候会转为 Serial Old GC 进行 FullGC。

内存溢出问题排查

内容版权声明:除非注明,否则皆为本站原创文章。

转载注明出处:https://www.heiqu.com/zygjjy.html