JVM虚拟机调优实战(3)进阶调优篇

Stella981
• 阅读 581

1.JVM内存分配与回收

1.1Minor Gc和Full GC 有什么不同呢?

   新生代GC(Minor GC):指发生新生代的的垃圾收集动作,Minor GC非常频繁,回收速度一般也比较快。

   老年代GC(Major GC/Full GC):指发生在老年代的GC,出现了Major GC经常会伴随至少一次的Minor GC(并非绝对),Major GC的速度一般会比Minor GC的慢10倍以上。

1.2对象优先在Eden区进行分配

解释:大多数情况下,对象在新生代中 Eden 区分配。当 Eden 区没有足够空间进行分配时,虚拟机将发起一次Minor GC。

测试实例:

代码

public class GCTest {
   
   
    public static void main(String[] args) throws InterruptedException {
   
   
        byte[] allocation1/*, allocation2, allocation3, allocation4, allocation5, allocation6*/;
        allocation1 = new byte[30231 * 1024];
        /*allocation2 = new byte[900*1024];
        allocation3 = new byte[1000*1024];
        allocation4 = new byte[1000*1024];
        allocation5 = new byte[1000*1024];
        allocation6 = new byte[1000*1024];*/
        //Thread.sleep(Integer.MAX_VALUE);
    }
}

idea启动虚拟机添加参数:
JVM虚拟机调优实战(3)进阶调优篇
添加的参数: -XX:+PrintGCDetails

结果:
JVM虚拟机调优实战(3)进阶调优篇
从上图我们可以看出eden区内存几乎已经被分配完全(即使程序什么也不做,新生代也会使用至少2000多k内存)。


假如我们再为allocation2,3,4,5分配内存会出现什么情况呢?
JVM虚拟机调优实战(3)进阶调优篇
因为给allocation2,3,4,5分配内存的时候eden区内存几乎已经被分配完了,我们刚刚讲了当Eden区没有足够空间进行分配时,虚拟机将发起一次Minor GC.GC期间虚拟机又发现allocation1无法存入Survior空间,所以只好通过 分配担保机制 把新生代的对象提前转移到老年代中去,老年代上的空间足够存放allocation1,所以不会出现Full GC。执行Minor GC后,后面分配的对象如果能够存在eden区的话,还是会在eden区分配内存

1.3 大对象直接进入老年代

测试代码:

public class GCTest {
   
    
    public static void main(String[] args) throws InterruptedException {
   
    
        byte[] allocation1;
        allocation1 = new byte[90231 * 1024];

    }
}

结果:
JVM虚拟机调优实战(3)进阶调优篇

大对象就是需要大量连续内存空间的对象(比如:字符串、数组)。从上边的测试实例来看,这个allocation1超大对象并没有进新生代,而是直接进入了老年代。

1.4长期存活的对象将进入老年代

既然虚拟机采用了分代收集的思想来管理内存,那么内存回收时就必须能识别那些对象应放在新生代,那些对象应放在老年代中。为了做到这一点,虚拟机给每个对象一个对象年龄(Age)计数器。
如果对象在 Eden 出生并经过第一次 Minor GC 后仍然能够存活,并且能被 Survivor 容纳的话,将被移动到 Survivor 空间中,并将对象年龄设为1.对象在 Survivor 中每熬过一次 MinorGC,年龄就增加1岁,当它的年龄增加到一定程度(默认为15岁),就会被晋升到老年代中。对象晋升到老年代的年龄阈值,可以通过参数 -XX:MaxTenuringThreshold 来设置。一般不建议修改。

2.如何判断对象可以被回收

堆中几乎放着所有的对象实例,对堆垃圾回收前的第一步就是要判断那些对象已经死亡(即不能再被任何途径使用的对象)。

2.1引用计数法

给对象中添加一个引用计数器,每当有一个地方引用它,计数器就加1;当引用失效,计数器就减1;任何时候计数器为0的对象就是不可能再被使用的。
这个方法实现简单,效率高,但是目前主流的虚拟机中并没有选择这个算法来管理内存,其最主要的原因是它很难解决对象之间相互循环引用的问题。 所谓对象之间的相互引用问题,如下面代码所示:除了对象objA 和 objB 相互引用着对方之外,这两个对象之间再无任何引用。但是他们因为互相引用对方,导致它们的引用计数器都不为0,于是引用计数算法无法通知 GC 回收器回收他们。

示例代码

public class ReferenceCountingGc {
   
    
    Object instance = null;

    public static void main(String[] args) {
   
    
        ReferenceCountingGc A = new ReferenceCountingGc();
        ReferenceCountingGc B = new ReferenceCountingGc();
        A.instance = B;
        B.instance = A;
        A = null;
        B = null;
    }
}

图例解释:
JVM虚拟机调优实战(3)进阶调优篇
两对象互相引用对方,但是有无其他引用,所以这个对象为废对象,但是引用值都是1,所以无法GC;

2.2可达性分析算法

解释:这个算法的基本思想就是通过一系列的称为 “GC Roots” 的对象作为起点,从这些节点开始向下搜索,节点所走过的路径称为引用链,当一个对象到 GC Roots 没有任何引用链相连的话,则证明此对象是不可用的。
GC Roots根节点:类加载器、Thread、虚拟机栈的本地变量表、static成员、常量引用、本地方法栈的变量等等

JVM虚拟机调优实战(3)进阶调优篇

2.3 如何判断一个常量是废弃常量?

运行时常量池主要回收的是废弃的常量。那么,我们如何判断一个常量是废弃常量呢?
假如在常量池中存在字符串 “abc”,如果当前没有任何String对象引用该字符串常量的话,就说明常量 “abc” 就是废弃常量,如果这时发生内存回收的话而且有必要的话,“abc” 就会被系统清理出常量池。

2.4 如何判断一个类是无用的类?

方法区主要回收的是无用的类,那么如何判断一个类是无用的类的呢?
判定一个常量是否是“废弃常量”比较简单,而要判定一个类是否是“无用的类”的条件则相对苛刻许多。类需要同时满足下面3个条件才能算是 “无用的类” :
    该类所有的实例都已经被回收,也就是 Java 堆中不存在该类的任何实例。
    加载该类的 ClassLoader 已经被回收。
    该类对应的 java.lang.Class 对象没有在任何地方被引用,无法在任何地方通过反射访问该类的方法。
虚拟机可以对满足上述3个条件的无用类进行回收,这里说的仅仅是“可以”,而并不是和对象一样不使用了就会必然被回收。

3.finalize()方法最终判定对象是否存活

即使在可达性分析算法中不可达的对象,也并非是“非死不可”的,这时候它们暂时处于“缓刑”阶段,要真正宣告一个对象死亡,至少要经历再次标记过程。标记的前提是对象在进行可达性分析后发现没有与GC Roots相连接的引用链。

  1. 第一次标记并进行一次筛选。
    筛选的条件是此对象是否有必要执行finalize()方法。当对象没有覆盖finalize方法,或者finzlize方法已经被虚拟机调用过,虚拟机将这两种情况都视为“没有必要执行”,对象被回收。

  2. 第二次标记
    如果这个对象被判定为有必要执行finalize()方法,那么这个对象将会被放置在一个名为:F-Queue的队列之中,并在稍后由一条虚拟机自动建立的、低优先级的Finalizer线程去执行。这里所谓的“执行”是指虚拟机会触发这个方法,但并不承诺会等待它运行结束。这样做的原因是,如果一个对象finalize()方法中执行缓慢,或者发生死循环(更极端的情况),将很可能会导致F-Queue队列中的其他对象永久处于等待状态,甚至导致整个内存回收系统崩溃。
    finalize()方法是对象脱逃死亡命运的最后一次机会,稍后GC将对F-Queue中的对象进行第二次小规模标记,如果对象要在finalize()中成功拯救自己----只要重新与引用链上的任何的一个对象建立关联即可,譬如把自己赋值给某个类变量或对象的成员变量,那在第二次标记时它将移除出“即将回收”的集合。如果对象这时候还没逃脱,那基本上它就真的被回收了。

4.垃圾收集算法

4.1 主要算法

标记-清除,复制算法,标记-整理,分带收集

4.2 标记-清除算法

解释:GCRoot完毕以后,对垃圾对象进行标记,标记完清除垃圾对象
弊端:产生垃圾碎片,清理内存时要遍历整个内存格,浪费算力
图例:
JVM虚拟机调优实战(3)进阶调优篇

4.2 复制算法
解释:将内存分成A和B两块内存区域,B块不使用,对象会首先存到在A区,再将A块内存垃圾对象进行回收,等回收完毕后,将A块存活对象并连续放到B快上。
优势:不会产生垃圾碎片=>适用于年轻代的survival的From和To区
图例:
JVM虚拟机调优实战(3)进阶调优篇
4.3标记-整理算法
解释:根据老年代的特点特出的一种标记算法,标记过程仍然与“标记-清除”算法一样,但后续步骤不是直接对可回收对象回收,而是让所有存活的对象向一段移动,然后直接清理掉端边界以外的内存。
图例:
JVM虚拟机调优实战(3)进阶调优篇
4.4 分代收集算法

解释:当前虚拟机的垃圾收集都采用分代收集算法,这种算法没有什么新的思想,只是根据对象存活周期的不同将内存分为几块。一般将java堆分为新生代和老年代,这样我们就可以根据各个年代的特点选择合适的垃圾收集算法。

举例:在新生代中,每次收集都会有大量对象死去,所以可以选择复制算法,只需要付出少量对象的复制成本就可以完成每次垃圾收集。而老年代的对象存活几率是比较高的,而且没有额外的空间对它进行分配担保,所以我们必须选择“标记-清除”或“标记-整理”算法进行垃圾收集。

4.垃圾收集器

前置知识:
(1)垃圾收集器是垃圾收集算法的具体实现,不同场景选用不同的垃圾回收器
(2)并行:多条垃圾回收线程并行工作     并发:应用线程(用户线程)与垃圾收集器线程同时执行(收集过程不一定是并行,有可能是交替执行)
(3)虽然我们对各个收集器进行比较,但并非为了挑选出一个最好的收集器。因为直到现在为止还没有最好的垃圾收集器出现,更加没有万能的垃圾收集器,我们能做的就是根据具体应用场景选择适合自己的垃圾收集器。试想一下:如果有一种四海之内、任何场景下都适用的完美收集器存在,那么我们的HotSpot虚拟机就不会实现那么多不同的垃圾收集器了。

4.1 Serial收集器

Serial(串行)收集器收集器是最基本、历史最悠久的垃圾收集器了。大家看名字就知道这个收集器是一个单线程收集器了。它的 “单线程” 的意义不仅仅意味着它只会使用一条垃圾收集线程去完成垃圾收集工作,更重要的是它在进行垃圾收集工作的时候必须暂停其他所有的工作线程( “Stop The World” ),直到它收集结束。

新生代采用复制算法,老年代采用标记-整理算法。
JVM虚拟机调优实战(3)进阶调优篇

虚拟机的设计者们当然知道Stop The World带来的不良用户体验,所以在后续的垃圾收集器设计中停顿时间在不断缩短(仍然还有停顿,寻找最优秀的垃圾收集器的过程仍然在继续)。
但是Serial收集器有没有优于其他垃圾收集器的地方呢?当然有,它简单而高效(与其他收集器的单线程相比)。Serial收集器由于没有线程交互的开销,自然可以获得很高的单线程收集效率。

4.2 ParNew收集器

ParNew收集器其实就是Serial收集器的多线程版本,除了使用多线程进行垃圾收集外,其余行为(控制参数、收集算法、回收策略等等)和Serial收集器完全一样。

新生代采用复制算法,老年代采用标记-整理算法。
JVM虚拟机调优实战(3)进阶调优篇
它是许多运行在Server模式下的虚拟机的首要选择,除了Serial收集器外,只有它能与CMS收集器(真正意义上的并发收集器,后面会介绍到)配合工作。

4.3 Parallel Scavenge收集器(jdk8默认垃圾收集器

Parallel Scavenge 收集器类似于ParNew 收集器,是Server 模式(内存大于2G,2个cpu)下的默认收集器,那么它有什么特别之处呢?

Parallel Scavenge收集器关注点是吞吐量(高效率的利用CPU)。CMS等垃圾收集器的关注点更多的是用户线程的停顿时间(提高用户体验)。所谓吞吐量就是CPU中用于运行用户代码的时间与CPU总消耗时间的比值。 Parallel Scavenge收集器提供了很多参数供用户找到最合适的停顿时间或最大吞吐量,如果对于收集器运作不太了解的话,可以选择把内存管理优化交给虚拟机去完成也是一个不错的选择。
新生代采用复制算法,老年代采用标记-整理算法。
JVM虚拟机调优实战(3)进阶调优篇
4.4 Serial Old收集器

Serial收集器的老年代版本,它同样是一个单线程收集器。它主要有两大用途:一种用途是在JDK1.5以及以前的版本中与Parallel Scavenge收集器搭配使用,另一种用途是作为CMS收集器的后备方案。

4.5 Parallel Old收集器

Parallel Scavenge收集器的老年代版本。使用多线程和“标记-整理”算法。在注重吞吐量以及CPU资源的场合,都可以优先考虑 Parallel Scavenge收集器和Parallel Old收集器。

4.6 CMS收集器(-XX:+UseConcMarkSweepGC(主要是old区使用))

CMS(Concurrent Mark Sweep)收集器是一种以获取最短回收停顿时间为目标的收集器。它而非常符合在注重用户体验的应用上使用,它是HotSpot虚拟机第一款真正意义上的并发收集器,它第一次实现了让垃圾收集线程与用户线程(基本上)同时工作。
从名字中的Mark Sweep这两个词可以看出,CMS收集器是一种 “标记-清除”算法实现的,它的运作过程相比于前面几种垃圾收集器来说更加复杂一些。整个过程分为四个步骤:
初始标记: 暂停所有的其他线程(STW),并记录下直接与GCRoot相连的对象,速度很快 ;
并发标记: 同时开启GC和用户线程,用一个闭包结构去记录可达对象。但在这个阶段结束,这个闭包结构并不能保证包含当前所有的可达对象。因为用户线程可能会不断的更新引用域,所以GC线程无法保证可达性分析的实时性。所以这个算法里会跟踪记录这些发生引用更新的地方。
重新标记: 重新标记阶段就是为了修正并发标记期间因为用户程序继续运行而导致标记产生变动的那一部分对象的标记记录,这个阶段的停顿时间一般会比初始标记阶段的时间稍长,远远比并发标记阶段时间短(重新标记的意义就是在再并发标记过程当中,因为垃圾回收线程与用户线程或者是说程序线程是并行的,所以在这个过程当中又会产生垃圾对象,所以要重新标记)
并发清除: 开启用户线程,同时GC线程开始对未标记的区域做清扫。
JVM虚拟机调优实战(3)进阶调优篇

从它的名字就可以看出它是一款优秀的垃圾收集器,主要优点:并发收集、低停顿。但是它有下面三个明显的缺点:
对CPU资源敏感(会和服务抢资源);
无法处理浮动垃圾(在java业务程序线程与垃圾收集线程并发执行过程中又产生的垃圾,这种浮动垃圾只能等到下一次gc再清理了);
它使用的回收算法-“标记-清除”算法会导致收集结束时会有大量空间碎片产生。
CMS的相关参数
-XX:+UseConcMarkSweepGC 启用cms
-XX:ConcGCThreads:并发的GC线程数(并非STW时间,而是和服务一起执行的线程数)
-XX:+UseCMSCompactAtFullCollection:FullGC之后做压缩(减少碎片)
-XX:CMSFullGCsBeforeCompaction:多少次FullGC之后压缩一次(因压缩非常的消耗时间,所以不能每次FullGC都做)
-XX:CMSInitiatingOccupancyFraction:触发FulGC条件(默认是92)
-XX:+UseCMSInitiatingOccupancyOnly:是否动态调节
-XX:+CMSScavengeBeforeRemark:FullGC之前先做YGC(一般这个参数是打开的)
-XX:+CMSClassUnloadingEnabled:启用回收Perm区(jdk1.7及以前)

4.7 G1收集器(-XX:+UseG1GC)

G1 (Garbage-First)是一款面向服务器的垃圾收集器,主要针对配备多颗处理器及大容量内存的机器. 以极高概率满足GC停顿时间要求的同时,还具备高吞吐量性能特征.

JVM虚拟机调优实战(3)进阶调优篇
JVM虚拟机调优实战(3)进阶调优篇

特点:
(1)并行与并发:G1能充分利用CPU、多核环境下的硬件优势,使用多个CPU(CPU或者CPU核心)来缩短Stop-The-World停顿时间。部分其他收集器原本需要停顿Java线程来执行GC动作,G1收集器仍然可以通过并发的方式让java程序继续执行。
(2)分代收集:虽然G1可以不需要其他收集器配合就能独立管理整个GC堆,但是还是保留了分代的概念。
(3)空间整合:与CMS的“标记–清理”算法不同,G1从整体来看是基于“标记整理”算法实现的收集器;从局部上来看是基于“复制”算法实现的。
(4)可预测的停顿:这是G1相对于CMS的另一个大优势,降低停顿时间是G1 和 CMS 共同的关注点,但G1 除了追求低停顿外,还能建立可预测的停顿时间模型,能让使用者明确指定在一个长度为M毫秒的时间片段内完成垃圾收集。

GC步骤:
初始标记(initial mark,STW):在此阶段,G1 GC 对根进行标记。该阶段与常规的 (STW) 年轻代垃圾回收密切相关。
并发标记(Concurrent Marking):G1 GC 在整个堆中查找可访问的(存活的)对象。
最终标记(Remark,STW):该阶段是 STW 回收,帮助完成标记周期。
筛选回收(Cleanup,STW):筛选回收阶段首先对各个Region的回收价值和成本进行排序,根据用户所期望的GC停顿时间来制定回收计划,这个阶段其实也可以做到与用户程序一起并发执行,但是因为只回收一部分Region,时间是用户可控制的,而且停顿用户线程将大幅提高收集效率。
JVM虚拟机调优实战(3)进阶调优篇
G1收集器在后台维护了一个优先列表,每次根据允许的收集时间,优先选择回收价值最大的Region(这也就是它的名字Garbage-First的由来)。这种使用Region划分内存空间以及有优先级的区域回收方式,保证了GF收集器在有限时间内可以尽可能高的收集效率。

G1垃圾收集分类:
YoungGC
新对象进入Eden区
存活对象拷贝到Survivor区
存活时间达到年龄阈值时,对象晋升到Old区
MixedGC
不是FullGC,回收所有的Young和部分Old(根据期望的GC停顿时间确定old区垃圾收集的优先顺序)
global concurrent marking (全局并发标记)
Initial marking phase:标记GC Root,STW
Root region scanning phase:标记存活Region
Concurrent marking phase:标记存活的对象
Remark phase :重新标记,STW
Cleanup phase:部分STW
相关参数
G1MixedGCLiveThresholdPercent Old区的region被回收的时候的存活对象占比
G1MixedGCCountTarget:一次global concurrent marking之后,最多执行Mixed GC的次数
G1OldCSetRegionThresholdPercent 一次Mixed GC中能被选入CSet的最多old区的region数量
触发的时机
InitiatingHeapOccupancyPercent:堆占有率达到这个值则触发global concurrent marking,默认45%
G1HeapWastePercent:在global concurrent marking结束之后,可以知道区有多少空间要被回收,在每次YGC之后和再次发生Mixed GC之前,会检查垃圾占比是否达到了此参数,只有达到了,下次才会发生Mixed GC

5. 如何选择垃圾收集器

优先调整堆的大小让服务器自己来选择
如果内存小于100M,使用串行收集器
如果是单核,并且没有停顿时间的要求,串行或JVM自己选择
如果允许停顿时间超过1秒,选择并行或者JVM自己选
如果响应时间最重要,并且不能超过1秒,使用并发收集器
下图有连线的可以搭配使用,官方推荐使用G1,因为性能高
JVM虚拟机调优实战(3)进阶调优篇

6. 虚拟机实战调优

6.1 主要调优方向

停顿时间: 垃圾收集器做垃圾回收中断应用执行的时间。 -XX:MaxGCPauseMillis
吞吐量:垃圾收集的时间和总时间的占比:1/(1+n),吞吐量为1-1/(1+n) 。
-XX:GCTimeRatio=n

6.2 GC调优步骤

第一步:打印GC日志 在启动Java类上或者jar包上添加-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -Xloggc:./gc.log
第二步:分析日志得到关键性指标(这里可以直接点开生成文件进行分析,或者直接使用gcessy进行分析https://www.gceasy.io/
第三步:分析不同的GC原因,调优JVM参数

6.3分析不同垃圾收集器的log日志

6.3.1 Parallel Scavenge收集器(jdk8默认垃圾收集器)

使用命令:java -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -Xloggc:./gc-Parallel.log -jar jar包包名

生成文件:

Java HotSpot(TM) 64-Bit Server VM (25.261-b12) for windows-amd64 JRE (1.8.0_261-b12), built on Jun 18 2020 06:56:32 by "" with unknown MS VC++:1916
Memory: 4k page, physical 12421516k(8723388k free), swap 14911884k(10572880k free)
CommandLine flags: -XX:InitialHeapSize=198744256 -XX:MaxHeapSize=3179908096 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers 
-XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC 
2020-10-13T20:24:36.336+0800: 0.790: [GC (Allocation Failure) [PSYoungGen: 49152K->3781K(56832K)] 49152K->3789K(186880K), 0.0037607 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-13T20:24:37.447+0800: 1.901: [GC (Allocation Failure) [PSYoungGen: 52933K->3267K(56832K)] 52941K->3283K(186880K), 0.0092661 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-13T20:24:37.673+0800: 2.127: [GC (Allocation Failure) [PSYoungGen: 52419K->3932K(56832K)] 52435K->3956K(186880K), 0.0043522 secs] [Times: user=0.06 sys=0.00, real=0.00 secs] 
2020-10-13T20:24:37.799+0800: 2.253: [GC (Allocation Failure) [PSYoungGen: 53084K->4465K(105984K)] 53108K->4497K(236032K), 0.0045214 secs] [Times: user=0.06 sys=0.00, real=0.00 secs] 
2020-10-13T20:24:38.060+0800: 2.514: [GC (Allocation Failure) [PSYoungGen: 102769K->6127K(105984K)] 102801K->6167K(236032K), 0.0073281 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] 
2020-10-13T20:24:38.448+0800: 2.901: [GC (Allocation Failure) [PSYoungGen: 104431K->6115K(201728K)] 104471K->6479K(331776K), 0.0087878 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-13T20:24:38.810+0800: 3.264: [GC (Metadata GC Threshold) [PSYoungGen: 115257K->5100K(202752K)] 115621K->7866K(332800K), 0.0093521 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-10-13T20:24:38.820+0800: 3.274: [Full GC (Metadata GC Threshold) [PSYoungGen: 5100K->0K(202752K)] [ParOldGen: 2766K->7381K(77312K)] 7866K->7381K(280064K), 
[Metaspace: 20835K->20835K(1069056K)], 0.0398476 secs] [Times: user=0.08 sys=0.00, real=0.04 secs] 
2020-10-13T20:24:40.396+0800: 4.850: [GC (Allocation Failure) [PSYoungGen: 195584K->3879K(310784K)] 202965K->11269K(388096K), 0.0044406 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-13T20:24:41.644+0800: 6.098: [GC (Allocation Failure) [PSYoungGen: 310567K->7167K(395264K)] 317957K->16293K(472576K), 0.0184908 secs] [Times: user=0.08 sys=0.02, real=0.02 secs] 
2020-10-13T20:24:44.059+0800: 8.514: [GC (Allocation Failure) [PSYoungGen: 395263K->8680K(415232K)] 404389K->24965K(492544K), 0.0216513 secs] [Times: user=0.06 sys=0.00, real=0.02 secs] 
2020-10-13T20:24:45.681+0800: 10.134: [GC (Metadata GC Threshold) [PSYoungGen: 385705K->6605K(418816K)] 401990K->31483K(496128K), 0.0258426 secs] [Times: user=0.05 sys=0.01, real=0.03 secs] 
2020-10-13T20:24:45.706+0800: 10.160: [Full GC (Metadata GC Threshold) [PSYoungGen: 6605K->0K(418816K)] [ParOldGen: 24877K->24437K(134656K)] 31483K->24437K(553472K), 
[Metaspace: 34873K->34873K(1081344K)], 0.1252288 secs] [Times: user=0.39 sys=0.02, real=0.13 secs] 
2020-10-13T20:24:47.241+0800: 11.695: [GC (Allocation Failure) [PSYoungGen: 406528K->5168K(530944K)] 430965K->29613K(665600K), 0.0218360 secs] [Times: user=0.03 sys=0.00, real=0.02 secs] 
2020-10-13T20:24:51.189+0800: 15.642: [GC (Allocation Failure) [PSYoungGen: 530480K->6580K(545280K)] 554925K->34797K(679936K), 0.0271547 secs] [Times: user=0.05 sys=0.03, real=0.03 secs] 
2020-10-13T20:24:54.730+0800: 19.184: [GC (Allocation Failure) [PSYoungGen: 540596K->11240K(676352K)] 568813K->43242K(811008K), 0.0191988 secs] [Times: user=0.05 sys=0.02, real=0.02 secs] 
Heap
 PSYoungGen      total 676352K, used 260893K [0x0000000780d00000, 0x00000007ab300000, 0x00000007c0000000)
  eden space 665088K, 37% used [0x0000000780d00000,0x00000007900cd530,0x00000007a9680000)
  from space 11264K, 99% used [0x00000007aa400000,0x00000007aaefa050,0x00000007aaf00000)
  to   space 13824K, 0% used [0x00000007a9680000,0x00000007a9680000,0x00000007aa400000)
 ParOldGen       total 134656K, used 32002K [0x0000000702600000, 0x000000070a980000, 0x0000000780d00000)
  object space 134656K, 23% used [0x0000000702600000,0x0000000704540aa0,0x000000070a980000)
 Metaspace       used 47342K, capacity 48044K, committed 48128K, reserved 1091584K
  class space    used 6126K, capacity 6317K, committed 6400K, reserved 1048576K

生成文件分析:

JVM虚拟机调优实战(3)进阶调优篇

easyGC分析:此处发现easyGC给出了一个方案进行优化,55%的时间使用原空间的gc上。
JVM虚拟机调优实战(3)进阶调优篇
解决方案:

第一次调优,设置Metaspace大小:增大元空间大小-XX:MetaspaceSize=64M -XX:MaxMetaspaceSize=64M

第二次调优,增大年轻代动态扩容增量,默认是20(%),可以减少young gc:-XX:YoungGenerationSizeIncrement=30

6.3.2 CMS收集器

使用命令:java -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseConcMarkSweepGC -XX:+PrintGCDateStamps -Xloggc:./gc-cms.log -jar jar包包名

生成文件:

Java HotSpot(TM) 64-Bit Server VM (25.261-b12) for windows-amd64 JRE (1.8.0_261-b12), built on Jun 18 2020 06:56:32 by "" with unknown MS VC++:1916
Memory: 4k page, physical 12421516k(7900700k free), swap 14911884k(9400336k free)
CommandLine flags: -XX:InitialHeapSize=198744256 -XX:MaxHeapSize=3179908096 -XX:MaxNewSize=348966912 -XX:MaxTenuringThreshold=6 -XX:OldPLABSize=16 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:-UseLargePagesIndividualAllocation -XX:+UseParNewGC 
2020-10-12T20:27:56.377+0800: 1.821: [GC (Allocation Failure) 2020-10-12T20:27:56.377+0800: 1.821: [ParNew: 51904K->3711K(58368K), 0.0057649 secs] 51904K->3711K(188096K), 0.0059787 secs] [Times: user=0.02 sys=0.03, real=0.01 secs] 
2020-10-12T20:27:57.783+0800: 3.227: [GC (Allocation Failure) 2020-10-12T20:27:57.783+0800: 3.227: [ParNew: 55615K->2476K(58368K), 0.0126847 secs] 55615K->4727K(188096K), 0.0127688 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] 
2020-10-12T20:27:58.167+0800: 3.611: [GC (Allocation Failure) 2020-10-12T20:27:58.167+0800: 3.611: [ParNew: 54380K->2729K(58368K), 0.0022000 secs] 56631K->4980K(188096K), 0.0022973 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:27:58.313+0800: 3.757: [GC (Allocation Failure) 2020-10-12T20:27:58.313+0800: 3.757: [ParNew: 54633K->2827K(58368K), 0.0026017 secs] 56884K->5077K(188096K), 0.0026982 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:27:58.429+0800: 3.873: [GC (Allocation Failure) 2020-10-12T20:27:58.429+0800: 3.873: [ParNew: 54731K->2856K(58368K), 0.0029748 secs] 56981K->5107K(188096K), 0.0030499 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:27:58.691+0800: 4.134: [GC (Allocation Failure) 2020-10-12T20:27:58.691+0800: 4.134: [ParNew: 54760K->3336K(58368K), 0.0052064 secs] 57011K->5587K(188096K), 0.0052964 secs] [Times: user=0.05 sys=0.00, real=0.01 secs] 
2020-10-12T20:27:58.849+0800: 4.293: [GC (Allocation Failure) 2020-10-12T20:27:58.849+0800: 4.293: [ParNew: 55240K->3398K(58368K), 0.0043610 secs] 57491K->5649K(188096K), 0.0044512 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:27:59.145+0800: 4.589: [GC (Allocation Failure) 2020-10-12T20:27:59.145+0800: 4.589: [ParNew: 55302K->4295K(58368K), 0.0044396 secs] 57553K->6801K(188096K), 0.0045450 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:27:59.525+0800: 4.969: [GC (Allocation Failure) 2020-10-12T20:27:59.525+0800: 4.969: [ParNew: 56199K->5380K(58368K), 0.0057412 secs] 58705K->8376K(188096K), 0.0058236 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:27:59.812+0800: 5.256: [GC (Allocation Failure) 2020-10-12T20:27:59.812+0800: 5.256: [ParNew: 57284K->4631K(58368K), 0.0074203 secs] 60280K->8742K(188096K), 0.0075285 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-10-12T20:27:59.820+0800: 5.264: [GC (CMS Initial Mark) [1 CMS-initial-mark: 4111K(129728K)] 8742K(188096K), 0.0013292 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:27:59.821+0800: 5.265: [CMS-concurrent-mark-start]
2020-10-12T20:27:59.865+0800: 5.308: [CMS-concurrent-mark: 0.043/0.043 secs] [Times: user=0.19 sys=0.00, real=0.04 secs] 
2020-10-12T20:27:59.865+0800: 5.308: [CMS-concurrent-preclean-start]
2020-10-12T20:27:59.866+0800: 5.310: [CMS-concurrent-preclean: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:27:59.866+0800: 5.310: [CMS-concurrent-abortable-preclean-start]
2020-10-12T20:28:01.145+0800: 6.589: [CMS-concurrent-abortable-preclean: 0.308/1.280 secs] [Times: user=0.72 sys=0.14, real=1.28 secs] 
2020-10-12T20:28:01.146+0800: 6.589: [GC (CMS Final Remark) [YG occupancy: 33649 K (58368 K)]2020-10-12T20:28:01.146+0800: 6.589: [Rescan (parallel) , 0.0047357 secs]2020-10-12T20:28:01.150+0800: 6.594: [weak refs processing, 0.0000330 secs]2020-10-12T20:28:01.151+0800: 6.594: [class unloading, 0.0032122 secs]2020-10-12T20:28:01.154+0800: 6.598: [scrub symbol table, 0.0031940 secs]2020-10-12T20:28:01.157+0800: 6.601: [scrub string table, 0.0003669 secs][1 CMS-remark: 4111K(129728K)] 37760K(188096K), 0.0120370 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:01.158+0800: 6.602: [CMS-concurrent-sweep-start]
2020-10-12T20:28:01.159+0800: 6.603: [CMS-concurrent-sweep: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:01.159+0800: 6.603: [CMS-concurrent-reset-start]
2020-10-12T20:28:01.162+0800: 6.606: [CMS-concurrent-reset: 0.003/0.003 secs] [Times: user=0.03 sys=0.02, real=0.00 secs] 
2020-10-12T20:28:01.250+0800: 6.694: [GC (Allocation Failure) 2020-10-12T20:28:01.250+0800: 6.694: [ParNew: 56535K->3918K(58368K), 0.0041580 secs] 60532K->8185K(188096K), 0.0042565 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:01.592+0800: 7.036: [GC (Allocation Failure) 2020-10-12T20:28:01.592+0800: 7.036: [ParNew: 55822K->4870K(58368K), 0.0046292 secs] 60089K->9138K(188096K), 0.0047309 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:01.698+0800: 7.141: [GC (Allocation Failure) 2020-10-12T20:28:01.698+0800: 7.141: [ParNew: 56774K->4910K(58368K), 0.0075001 secs] 61042K->9958K(188096K), 0.0075926 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:01.919+0800: 7.363: [GC (Allocation Failure) 2020-10-12T20:28:01.919+0800: 7.363: [ParNew: 56814K->4181K(58368K), 0.0050461 secs] 61862K->9228K(188096K), 0.0051386 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:02.096+0800: 7.540: [GC (Allocation Failure) 2020-10-12T20:28:02.096+0800: 7.540: [ParNew: 56085K->4940K(58368K), 0.0060481 secs] 61132K->11188K(188096K), 0.0061327 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:02.259+0800: 7.703: [GC (Allocation Failure) 2020-10-12T20:28:02.259+0800: 7.703: [ParNew: 56844K->5600K(58368K), 0.0061835 secs] 63092K->12282K(188096K), 0.0062934 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:02.500+0800: 7.944: [GC (Allocation Failure) 2020-10-12T20:28:02.500+0800: 7.944: [ParNew: 57504K->4325K(58368K), 0.0074456 secs] 64186K->11797K(188096K), 0.0075449 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:02.960+0800: 8.403: [GC (Allocation Failure) 2020-10-12T20:28:02.960+0800: 8.403: [ParNew: 56229K->5301K(58368K), 0.0046992 secs] 63701K->12881K(188096K), 0.0047937 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:03.599+0800: 9.043: [GC (Allocation Failure) 2020-10-12T20:28:03.599+0800: 9.043: [ParNew: 57205K->5776K(58368K), 0.0079695 secs] 64785K->14400K(188096K), 0.0080647 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:03.814+0800: 9.258: [GC (Allocation Failure) 2020-10-12T20:28:03.814+0800: 9.258: [ParNew: 57680K->5516K(58368K), 0.0059135 secs] 66304K->15267K(188096K), 0.0060049 secs] [Times: user=0.05 sys=0.02, real=0.01 secs] 
2020-10-12T20:28:03.964+0800: 9.407: [GC (Allocation Failure) 2020-10-12T20:28:03.964+0800: 9.407: [ParNew: 57420K->3552K(58368K), 0.0049078 secs] 67171K->13747K(188096K), 0.0050155 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:04.140+0800: 9.584: [GC (Allocation Failure) 2020-10-12T20:28:04.140+0800: 9.584: [ParNew: 55456K->4806K(58368K), 0.0080380 secs] 65651K->15000K(188096K), 0.0081439 secs] [Times: user=0.05 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:04.979+0800: 10.422: [GC (Allocation Failure) 2020-10-12T20:28:04.979+0800: 10.422: [ParNew: 56710K->6117K(58368K), 0.0064917 secs] 66904K->16828K(188096K), 0.0066100 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:05.306+0800: 10.751: [GC (Allocation Failure) 2020-10-12T20:28:05.306+0800: 10.751: [ParNew: 58021K->6464K(58368K), 0.0088427 secs] 68732K->19366K(188096K), 0.0089534 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:05.601+0800: 11.045: [GC (Allocation Failure) 2020-10-12T20:28:05.601+0800: 11.045: [ParNew: 58368K->4962K(58368K), 0.0103327 secs] 71270K->23976K(188096K), 0.0104832 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:05.876+0800: 11.321: [GC (Allocation Failure) 2020-10-12T20:28:05.889+0800: 11.333: [ParNew: 56866K->2053K(58368K), 0.0023822 secs] 75880K->21067K(188096K), 0.0149285 secs] [Times: user=0.01 sys=0.00, real=0.02 secs] 
2020-10-12T20:28:06.708+0800: 12.152: [GC (Allocation Failure) 2020-10-12T20:28:06.708+0800: 12.152: [ParNew: 53957K->4781K(58368K), 0.0051989 secs] 72971K->23795K(188096K), 0.0052956 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:06.991+0800: 12.435: [GC (Allocation Failure) 2020-10-12T20:28:06.991+0800: 12.435: [ParNew: 56685K->3541K(58368K), 0.0053836 secs] 75699K->23848K(188096K), 0.0054906 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:07.109+0800: 12.553: [GC (Allocation Failure) 2020-10-12T20:28:07.109+0800: 12.553: [ParNew: 55445K->2720K(58368K), 0.0030331 secs] 75752K->23028K(188096K), 0.0031466 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:07.419+0800: 12.864: [GC (Allocation Failure) 2020-10-12T20:28:07.419+0800: 12.864: [ParNew: 54624K->3846K(58368K), 0.0042669 secs] 74932K->24153K(188096K), 0.0043840 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:07.758+0800: 13.201: [GC (Allocation Failure) 2020-10-12T20:28:07.758+0800: 13.201: [ParNew: 55750K->4086K(58368K), 0.0040793 secs] 76057K->24394K(188096K), 0.0041977 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:08.100+0800: 13.543: [GC (Allocation Failure) 2020-10-12T20:28:08.100+0800: 13.543: [ParNew: 55990K->3118K(58368K), 0.0059216 secs] 76298K->24959K(188096K), 0.0060311 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:08.344+0800: 13.788: [GC (Allocation Failure) 2020-10-12T20:28:08.344+0800: 13.788: [ParNew: 55022K->2554K(58368K), 0.0057652 secs] 76863K->24395K(188096K), 0.0058705 secs] [Times: user=0.05 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:08.592+0800: 14.036: [GC (Allocation Failure) 2020-10-12T20:28:08.592+0800: 14.036: [ParNew: 54458K->2927K(58368K), 0.0048231 secs] 76299K->25248K(188096K), 0.0049281 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:09.060+0800: 14.504: [GC (Allocation Failure) 2020-10-12T20:28:09.060+0800: 14.504: [ParNew: 54831K->3917K(58368K), 0.0059150 secs] 77152K->26402K(188096K), 0.0060336 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:09.066+0800: 14.510: [GC (CMS Initial Mark) [1 CMS-initial-mark: 22485K(129728K)] 26402K(188096K), 0.0015225 secs] [Times: user=0.05 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:09.068+0800: 14.511: [CMS-concurrent-mark-start]
2020-10-12T20:28:09.118+0800: 14.562: [CMS-concurrent-mark: 0.050/0.051 secs] [Times: user=0.16 sys=0.00, real=0.05 secs] 
2020-10-12T20:28:09.119+0800: 14.562: [CMS-concurrent-preclean-start]
2020-10-12T20:28:09.120+0800: 14.563: [CMS-concurrent-preclean: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:09.120+0800: 14.563: [CMS-concurrent-abortable-preclean-start]
2020-10-12T20:28:09.255+0800: 14.699: [GC (Allocation Failure) 2020-10-12T20:28:09.255+0800: 14.699: [ParNew: 55821K->3271K(58368K), 0.0045993 secs] 78306K->26144K(188096K), 0.0047071 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:09.429+0800: 14.872: [GC (Allocation Failure) 2020-10-12T20:28:09.429+0800: 14.872: [ParNew: 55175K->4557K(58368K), 0.0050840 secs] 78048K->27692K(188096K), 0.0051880 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:09.607+0800: 15.052: [CMS-concurrent-abortable-preclean: 0.286/0.488 secs] [Times: user=1.58 sys=0.03, real=0.49 secs] 
2020-10-12T20:28:09.608+0800: 15.052: [GC (CMS Final Remark) [YG occupancy: 56461 K (58368 K)]2020-10-12T20:28:09.608+0800: 15.052: [Rescan (parallel) , 0.0084743 secs]2020-10-12T20:28:09.617+0800: 15.060: [weak refs processing, 0.0000302 secs]2020-10-12T20:28:09.617+0800: 15.060: [class unloading, 0.0077605 secs]2020-10-12T20:28:09.625+0800: 15.068: [scrub symbol table, 0.0105767 secs]2020-10-12T20:28:09.635+0800: 15.079: [scrub string table, 0.0009116 secs][1 CMS-remark: 23134K(129728K)] 79596K(188096K), 0.0284155 secs] [Times: user=0.09 sys=0.00, real=0.03 secs] 
2020-10-12T20:28:09.637+0800: 15.080: [CMS-concurrent-sweep-start]
2020-10-12T20:28:09.646+0800: 15.090: [CMS-concurrent-sweep: 0.010/0.010 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:09.646+0800: 15.090: [CMS-concurrent-reset-start]
2020-10-12T20:28:09.650+0800: 15.094: [CMS-concurrent-reset: 0.004/0.004 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:09.656+0800: 15.100: [GC (Allocation Failure) 2020-10-12T20:28:09.656+0800: 15.100: [ParNew: 56461K->4964K(58368K), 0.0047764 secs] 77696K->26371K(188096K), 0.0048847 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:09.800+0800: 15.244: [GC (Allocation Failure) 2020-10-12T20:28:09.800+0800: 15.244: [ParNew: 56868K->4574K(58368K), 0.0053163 secs] 78275K->26318K(188096K), 0.0054317 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:09.947+0800: 15.391: [GC (Allocation Failure) 2020-10-12T20:28:09.947+0800: 15.392: [ParNew: 56478K->5003K(58368K), 0.0060490 secs] 78222K->27231K(188096K), 0.0062042 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:10.085+0800: 15.528: [GC (Allocation Failure) 2020-10-12T20:28:10.085+0800: 15.528: [ParNew: 56907K->3982K(58368K), 0.0051563 secs] 79135K->26849K(188096K), 0.0052584 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:10.315+0800: 15.759: [GC (Allocation Failure) 2020-10-12T20:28:10.315+0800: 15.759: [ParNew: 55886K->4953K(58368K), 0.0055548 secs] 78753K->28267K(188096K), 0.0056609 secs] [Times: user=0.06 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:10.478+0800: 15.922: [GC (Allocation Failure) 2020-10-12T20:28:10.479+0800: 15.922: [ParNew: 56857K->4415K(58368K), 0.0075027 secs] 80171K->28582K(188096K), 0.0076109 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:10.602+0800: 16.045: [GC (Allocation Failure) 2020-10-12T20:28:10.602+0800: 16.045: [ParNew: 56319K->3329K(58368K), 0.0046973 secs] 80486K->27932K(188096K), 0.0047916 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:10.709+0800: 16.153: [GC (Allocation Failure) 2020-10-12T20:28:10.709+0800: 16.153: [ParNew: 55233K->3891K(58368K), 0.0043043 secs] 79836K->28976K(188096K), 0.0044113 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:12.027+0800: 17.471: [GC (Allocation Failure) 2020-10-12T20:28:12.027+0800: 17.471: [ParNew: 55795K->3230K(58368K), 0.0047349 secs] 80880K->28650K(188096K), 0.0048530 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:12.178+0800: 17.622: [GC (Allocation Failure) 2020-10-12T20:28:12.178+0800: 17.622: [ParNew: 55134K->4272K(58368K), 0.0050017 secs] 80554K->29974K(188096K), 0.0051122 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:13.411+0800: 18.854: [GC (Allocation Failure) 2020-10-12T20:28:13.411+0800: 18.854: [ParNew: 56176K->5095K(58368K), 0.0081708 secs] 81878K->31252K(188096K), 0.0083310 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:13.774+0800: 19.218: [GC (Allocation Failure) 2020-10-12T20:28:13.774+0800: 19.218: [ParNew: 56999K->5067K(58368K), 0.0061007 secs] 83156K->31767K(188096K), 0.0062212 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:13.908+0800: 19.352: [GC (Allocation Failure) 2020-10-12T20:28:13.908+0800: 19.352: [ParNew: 56971K->5604K(58368K), 0.0055308 secs] 83671K->32617K(188096K), 0.0056613 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:14.025+0800: 19.469: [GC (Allocation Failure) 2020-10-12T20:28:14.025+0800: 19.469: [ParNew: 57508K->5765K(58368K), 0.0062822 secs] 84521K->33182K(188096K), 0.0064433 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:14.129+0800: 19.573: [GC (Allocation Failure) 2020-10-12T20:28:14.129+0800: 19.573: [ParNew: 57669K->4145K(58368K), 0.0058154 secs] 85086K->32393K(188096K), 0.0059254 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:14.242+0800: 19.686: [GC (Allocation Failure) 2020-10-12T20:28:14.242+0800: 19.686: [ParNew: 56049K->3992K(58368K), 0.0049823 secs] 84297K->32840K(188096K), 0.0050760 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:14.407+0800: 19.851: [GC (Allocation Failure) 2020-10-12T20:28:14.407+0800: 19.851: [ParNew: 55896K->3473K(58368K), 0.0048509 secs] 84744K->32969K(188096K), 0.0049603 secs] [Times: user=0.06 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:14.668+0800: 20.112: [GC (Allocation Failure) 2020-10-12T20:28:14.668+0800: 20.112: [ParNew: 55377K->5082K(58368K), 0.0056753 secs] 84873K->35007K(188096K), 0.0057792 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:14.779+0800: 20.223: [GC (Allocation Failure) 2020-10-12T20:28:14.779+0800: 20.223: [ParNew: 56986K->4213K(58368K), 0.0048347 secs] 86911K->34635K(188096K), 0.0049332 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:14.968+0800: 20.412: [GC (Allocation Failure) 2020-10-12T20:28:14.968+0800: 20.412: [ParNew: 56117K->3743K(58368K), 0.0054312 secs] 86539K->34524K(188096K), 0.0055131 secs] [Times: user=0.05 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:15.184+0800: 20.628: [GC (Allocation Failure) 2020-10-12T20:28:15.184+0800: 20.628: [ParNew: 55647K->5375K(58368K), 0.0067280 secs] 86428K->36533K(188096K), 0.0068435 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:16.693+0800: 22.137: [GC (Allocation Failure) 2020-10-12T20:28:16.693+0800: 22.137: [ParNew: 57279K->6464K(58368K), 0.0106137 secs] 88437K->38568K(188096K), 0.0107156 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:17.010+0800: 22.454: [GC (Allocation Failure) 2020-10-12T20:28:17.010+0800: 22.454: [ParNew: 58368K->4436K(58368K), 0.0168918 secs] 90472K->41749K(188096K), 0.0170152 secs] [Times: user=0.05 sys=0.00, real=0.02 secs] 
2020-10-12T20:28:17.248+0800: 22.692: [GC (Allocation Failure) 2020-10-12T20:28:17.248+0800: 22.692: [ParNew: 56340K->1205K(58368K), 0.0019107 secs] 93653K->38518K(188096K), 0.0020041 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:17.519+0800: 22.963: [GC (Allocation Failure) 2020-10-12T20:28:17.519+0800: 22.963: [ParNew: 53109K->2038K(58368K), 0.0027892 secs] 90422K->39350K(188096K), 0.0029034 secs] [Times: user=0.06 sys=0.00, real=0.00 secs] 
Heap
 par new generation   total 58368K, used 37613K [0x0000000702600000, 0x0000000706550000, 0x00000007172c0000)
  eden space 51904K,  68% used [0x0000000702600000, 0x00000007048bdeb8, 0x00000007058b0000)
  from space 6464K,  31% used [0x00000007058b0000, 0x0000000705aad820, 0x0000000705f00000)
  to   space 6464K,   0% used [0x0000000705f00000, 0x0000000705f00000, 0x0000000706550000)
 concurrent mark-sweep generation total 129728K, used 37312K [0x00000007172c0000, 0x000000071f170000, 0x00000007c0000000)
 Metaspace       used 47336K, capacity 48044K, committed 48352K, reserved 1091584K
  class space    used 6130K, capacity 6317K, committed 6372K, reserved 1048576K

文件分析:

2020-10-12T20:28:09.066+0800: 14.510: [GC (CMS Initial Mark) [1 CMS-initial-mark: 22485K(129728K)] 26402K(188096K), 0.0015225 secs] [Times: user=0.05 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:09.068+0800: 14.511: [CMS-concurrent-mark-start]
2020-10-12T20:28:09.118+0800: 14.562: [CMS-concurrent-mark: 0.050/0.051 secs] [Times: user=0.16 sys=0.00, real=0.05 secs] 
2020-10-12T20:28:09.119+0800: 14.562: [CMS-concurrent-preclean-start]
2020-10-12T20:28:09.120+0800: 14.563: [CMS-concurrent-preclean: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:09.120+0800: 14.563: [CMS-concurrent-abortable-preclean-start]
2020-10-12T20:28:09.255+0800: 14.699: [GC (Allocation Failure) 2020-10-12T20:28:09.255+0800: 14.699: [ParNew: 55821K->3271K(58368K), 0.0045993 secs] 78306K->26144K(188096K), 0.0047071 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:09.429+0800: 14.872: [GC (Allocation Failure) 2020-10-12T20:28:09.429+0800: 14.872: [ParNew: 55175K->4557K(58368K), 0.0050840 secs] 78048K->27692K(188096K), 0.0051880 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:09.607+0800: 15.052: [CMS-concurrent-abortable-preclean: 0.286/0.488 secs] [Times: user=1.58 sys=0.03, real=0.49 secs] 
2020-10-12T20:28:09.608+0800: 15.052: [GC (CMS Final Remark) [YG occupancy: 56461 K (58368 K)]2020-10-12T20:28:09.608+0800: 15.052: [Rescan (parallel) , 0.0084743 secs]2020-10-12T20:28:09.617+0800: 15.060: [weak refs processing, 0.0000302 secs]2020-10-12T20:28:09.617+0800: 15.060: [class unloading, 0.0077605 secs]2020-10-12T20:28:09.625+0800: 15.068: [scrub symbol table, 0.0105767 secs]2020-10-12T20:28:09.635+0800: 15.079: [scrub string table, 0.0009116 secs][1 CMS-remark: 23134K(129728K)] 79596K(188096K), 0.0284155 secs] [Times: user=0.09 sys=0.00, real=0.03 secs] 
2020-10-12T20:28:09.637+0800: 15.080: [CMS-concurrent-sweep-start]
2020-10-12T20:28:09.646+0800: 15.090: [CMS-concurrent-sweep: 0.010/0.010 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:09.646+0800: 15.090: [CMS-concurrent-reset-start]

这里是对cms垃圾收集器的一种合理解释,会发现有多个步骤

6.3.3 G1收集器

生成文件命令:java -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseConcMarkSweepGC -XX:+PrintGCDateStamps -Xloggc:./gc-G1.log -jar jar包包名

日志分析:
young GC:[GC pause (G1 Evacuation Pause) (young)
initial-mark:[GC pause (Metadata GC Threshold) (young) (initial-mark) (参数:InitiatingHeapOccupancyPercent)
mixed GC:[GC pause (G1 Evacuation Pause) (mixed) (参数:G1HeapWastePercent)
full GC:[Full GC (Allocation Failure) (无可用region)
(G1内部,前面提到的混合GC是非常重要的释放内存机制,它避免了G1出现Region没有可用的情况,否则就会触发Full GC事件。
CMS、Parallel、Serial GC都需要通过Full GC去压缩老年代并在这个过程中扫描整个老年代。G1的Full GC算法和Serial GC收集器完全一致。当一个Full GC发生时,整个Java堆执行一个完整的压缩,这样确保了最大的空余内存可用。G1的Full GC是一个单线程,它可能引起一个长时间的停顿时间,G1的设计目标是减少Full GC,满足应用性能目标。)

调优方法:
第一次调优,设置Metaspace大小:增大元空间大小-XX:MetaspaceSize=64M -XX:MaxMetaspaceSize=64M(解释:原空间会有一个水位线,当原空间大小不足时,原空间会按照一定比例将水位线进行提升,当原空间充足时,水位线会下降,在原空间不足时,适当扩大原空间增加比例,减少项目启动时间)

第二次调优,添加吞吐量和停顿时间参数:-XX:GCTimeRatio=80 -XX:MaxGCPauseMillis=100 (这就是上边所讲G1的阈值)

7. 虚拟机实战调优总结

调优其实要一定的经验,本篇文章之举了简单的三个调优例子和一些垃圾收集器。垃圾收集器在一定的环境下和不同的内存区域(新生代,老年代),jvm会使用不同的垃圾收集器,所以一般情况下我们么快又必要去更改jdk的jvm垃圾收集器,除非在性能等有极端要求情况下,再去更改垃圾收集器。其他情况下可按照easyGC提出的方案进行参数的调优。笔者对常用的参数在8上进行了总结

8. 虚拟机实战调优调优相关参数

8.1常用参数
a) -XX:+UseG1GC 开启G1
b) -XX:G1HeapRegionSize=n,region的大小,1-32M,2048个
c) -XX:MaxGCPauseMillis=200 最大停顿时间
d) -XX:G1NewSizePercent -XX:G1MaxNewSizePercent
e) -XX:G1ReservePercent=10 保留防止to space溢出()
f) -XX:ParallelGCThreads=n SWT线程数(停止应用程序)
g) -XX:ConcGCThreads=n 并发线程数=1/4*并行
8.2最佳实践
h) 轻代大小:避免使用-Xmn、-XX:NewRatio等显示设置Young区大小,会覆盖暂停时间目标(常用参数3)
i) 暂停时间目标:暂停时间不要太严苛,其吞吐量目标是90%的应用程序时间和10%的垃圾回收时间,太严苛会直接影响到吞吐量
8.3是否需要切换到G1
j) 50%以上的堆被存活对象占用
k) 对象分配和晋升的速度变化非常大
l) 垃圾回收时间特别长,超过1秒
8.4G1调优目标
m) 6GB以上内存
n) 停顿时间是500ms以内
o) 吞吐量是90%以上

8.5 GC常用参数
堆栈设置
-Xss:每个线程的栈大小
-Xms:初始堆大小,默认物理内存的1/64
-Xmx:最大堆大小,默认物理内存的1/4
-Xmn:新生代大小
-XX:NewSize:设置新生代初始大小
-XX:NewRatio:默认2表示新生代占年老代的1/2,占整个堆内存的1/3。
-XX:SurvivorRatio:默认8表示一个survivor区占用1/8的Eden内存,即1/10的新生代内存。
-XX:MetaspaceSize:设置元空间大小
-XX:MaxMetaspaceSize:设置元空间最大允许大小,默认不受限制,JVM Metaspace会进行动态扩展。
垃圾回收统计信息
-XX:+PrintGC
-XX:+PrintGCDetails
-XX:+PrintGCTimeStamps
-Xloggc:filename
8.6收集器设置
-XX:+UseSerialGC:设置串行收集器
-XX:+UseParallelGC:设置并行收集器
-XX:+UseParallelOldGC:老年代使用并行回收收集器
-XX:+UseParNewGC:在新生代使用并行收集器
-XX:+UseParalledlOldGC:设置并行老年代收集器
-XX:+UseConcMarkSweepGC:设置CMS并发收集器
-XX:+UseG1GC:设置G1收集器
-XX:ParallelGCThreads:设置用于垃圾回收的线程数
8.7并行收集器设置
-XX:ParallelGCThreads:设置并行收集器收集时使用的CPU数。并行收集线程数。
-XX:MaxGCPauseMillis:设置并行收集最大暂停时间
-XX:GCTimeRatio:设置垃圾回收时间占程序运行时间的百分比。公式为1/(1+n)
-XX:YoungGenerationSizeIncrement:年轻代gc后扩容比例,默认是20(%)
8.8CMS收集器设置
-XX:+UseConcMarkSweepGC:设置CMS并发收集器
-XX:+CMSIncrementalMode:设置为增量模式。适用于单CPU情况。
-XX:ParallelGCThreads:设置并发收集器新生代收集方式为并行收集时,使用的CPU数。并行收集线程数。
-XX:CMSFullGCsBeforeCompaction:设定进行多少次CMS垃圾回收后,进行一次内存压缩
-XX:+CMSClassUnloadingEnabled:允许对类元数据进行回收
-XX:UseCMSInitiatingOccupancyOnly:表示只在到达阀值的时候,才进行CMS回收
-XX:+CMSIncrementalMode:设置为增量模式。适用于单CPU情况
-XX:ParallelCMSThreads:设定CMS的线程数量
-XX:CMSInitiatingOccupancyFraction:设置CMS收集器在老年代空间被使用多少后触发
-XX:+UseCMSCompactAtFullCollection:设置CMS收集器在完成垃圾收集后是否要进行一次内存碎片的整理
8.9G1收集器设置
-XX:+UseG1GC:使用G1收集器
-XX:ParallelGCThreads:指定GC工作的线程数量
-XX:G1HeapRegionSize:指定分区大小(1MB~32MB,且必须是2的幂),默认将整堆划分为2048个分区
-XX:GCTimeRatio:吞吐量大小,0-100的整数(默认9),值为n则系统将花费不超过1/(1+n)的时间用于垃圾收集
-XX:MaxGCPauseMillis:目标暂停时间(默认200ms)
-XX:G1NewSizePercent:新生代内存初始空间(默认整堆5%)
-XX:G1MaxNewSizePercent:新生代内存最大空间
-XX:TargetSurvivorRatio:Survivor填充容量(默认50%)
-XX:MaxTenuringThreshold:最大任期阈值(默认15)
-XX:InitiatingHeapOccupancyPercen:老年代占用空间超过整堆比IHOP阈值(默认45%),超过则执行混合收集
-XX:G1HeapWastePercent:堆废物百分比(默认5%)
-XX:G1MixedGCCountTarget:参数混合周期的最大总次数(默认8)

点赞
收藏
评论区
推荐文章
blmius blmius
2年前
MySQL:[Err] 1292 - Incorrect datetime value: ‘0000-00-00 00:00:00‘ for column ‘CREATE_TIME‘ at row 1
文章目录问题用navicat导入数据时,报错:原因这是因为当前的MySQL不支持datetime为0的情况。解决修改sql\mode:sql\mode:SQLMode定义了MySQL应支持的SQL语法、数据校验等,这样可以更容易地在不同的环境中使用MySQL。全局s
Wesley13 Wesley13
2年前
java中的GC和内存泄漏
java中的GC1.GC是什么?为什么要有GC? GC是垃圾回收的意思。是指JVM清理不再使用的对象释放内存。垃圾回收可以有效的防止内存泄露,有效的使用可以使用的内存.2\.需要GC的内存区域垃圾回收区域:主要针对无用堆对象回
Stella981 Stella981
2年前
JVM(6):JVM 调优
JVM(6):JVM调优从Eclipse开始来源:纯洁的微笑,www.cnblogs.com/ityouknow/p/5647513.html概述什么是jvm调优呢?jvm调优就是根据gc日志分析jvm内存分配、回收的情况来调整各区域内存比例或者gc回收的策略;更深一层就是根据dump出来的内存结构和线程栈来
Stella981 Stella981
2年前
JVM基本配置与调优
JVM基本配置与调优JVM调优,一般都是针对堆内存配置调优。如图:堆内存分新生代和老年代,新生代又划分为eden区、from区、to区。!(https://oscimg.oschina.net/oscnet/5b30ad2de1851315e10f5d9e0a57395208c.png)一、区域释义
Stella981 Stella981
2年前
JVM调优
概述  什么是jvm调优呢?jvm调优就是根据gc日志分析jvm内存分配、回收的情况来调整各区域内存比例或者gc回收的策略;更深一层就是根据dump出来的内存结构和线程栈来分析代码中不合理的地方给予改进。eclipse优化主要涉及的是前者,通过gc日志来分析。本文主要是通过分析eclipsegc日志为例来示例如何根据gc日志来分析jvm内存而进
Stella981 Stella981
2年前
JVM调优思路
一、jvm内存调优(Gc 和Fullgc)hotspot\Xms40m 最小堆内存\Xmx512m最大值内存\verboose:gc\XX:PrintGCDetails\XX:printGCDateStamps\Xloggc:D:/gc/gc.log调优主要调到Gc\PSYoungGen:
Stella981 Stella981
2年前
JVM系列【6】GC与调优1
JVM系列笔记目录虚拟机的基础概念class文件结构class文件加载过程jvm内存模型JVM常用指令GC与调优GC基础知识什么是垃圾​没有任何引用指向的一个对象或多个对象(循环引用)!file(https:
Stella981 Stella981
2年前
JVM系列【6】GC与调优3
JVM系列笔记目录虚拟机的基础概念class文件结构class文件加载过程jvm内存模型JVM常用指令GC与调优调优前的基础概念1.吞吐量:用户代码时间/(用户代码执行时间垃圾回收时间)2.响应时间:STW越短,响应时间越好3.
Stella981 Stella981
2年前
JVM 参数学习
一、JVM1、JVM产生GC的位置Eden(新生代)MinorGC算法(复制)Oldtenure(老年代) Major(Full)GC(整理压缩)算法2、JVM堆(Heap)内存大小参数\Xmn新生代8:1:1比例\Xms设置初始化堆内存大小 \Xmx设置堆内存最大大小 产生java.lang.
Stella981 Stella981
2年前
JVM学习总结(六)内存分配与回收策略
_对象优先在新生代Eden区中分配_当Eden区没有足够空间进行分配时,虚拟机将发起一次MinorGC,虚拟机提供了XX:PrintGCDetails这个收集器日志参数。MinorGC与FullGC比较:新生代GC(MinorGC)指发生在新生代的垃圾回收,Java对象大多具备朝生熄灭的特性,所以MinorGC非常频