C++通过析构函来做“清理善后”的事情,Java则通过虚拟机的垃圾收集器(Carbage Collection, GC)来清除掉“已死”的对象,这里的“已死”是指不能再被任何途径使用的对象。如何判断一个对象是否已死,则要看他的引用了。如果一个对象的引用数为零,那么就他可以在空间非常紧张的情况下被清除。
Java垃圾收集器就在做三件事:1.判断哪些对象可以被清理;2.什么时候清理;3.怎么清理。
1.哪些对象可以被清理?
“在内存空间还足够时,则能保留在内存之中;如果内存空间在进行垃圾收集后还是非常紧张,则可以抛弃这些对象。”,即可清理的对象可以是没有引用了或者有的是无用的引用。
怎么判断可以清理这些对象?
1.引用计数为0;
2.从GC Roots到这个对象不可达。
引用计数为0的话,一般会使用引用计数算法:给对象添加一个引用计数器,每当有一个地方引用它时,计数器值就加1;当引用失效时,计数器值就减1,当计数器值为0时,则表示该对象可以被清理。此种算法的缺点是无法解决循环引用的问题。
从GC Roots开始的可达性分析:通过一系列的“GC Roots”的对象作为起始点,从这些节点开始向下搜索,搜索所走过的路径成为引用链,当一个对象到GC Roots没有任何引用链相连时,则证明此对象是不可用的。
可达性分析中真正宣告一个对象死亡,至少要经历两次标记过程:如果对象在进行可达性分析后发现没有与GC Roots相连接的引用链,那它将会被第一次标记并且进行一次筛选,筛选的条件是此对象是否有必要执行finalize()方法。当对象没有覆盖finalize()方法,或者finalize()方法已经被虚拟机调用过,虚拟机将这两种情况都视为“没有必要执行”。
2.什么时候清理?
1.程序调用System.gc()时可以触发(只是建议JVM进行垃圾回收,不代表一定会进行GC);
2.系统自身决定GC触发的时机:当内存空间(主要是堆和方法区,同时JVM规范也说了方法区可以不做垃圾回收,因为方法区的垃圾回收效率比较低)大小不足时,则会触发GC。
3.怎么清理?
目前垃圾清理的算法:
标记-清除算法;
复制算法;
标记-整理算法。
关于的Heap的垃圾回收,目前商用的JVM都是采用分代收集的方式,即把堆区分为年轻代和老年代。
年轻代和老年代的GC都是各自独立运行的。
年轻代GC(Minor GC):指发生在新生代的垃圾收集动作,因为 Java 对象大多都具
备朝生夕灭的特性,所以 Minor GC 非常频繁,一般回收速度也比较快。
老年代GC(Major GC):指发生在老年代的 GC,MajorGC 的速度一般会比 Minor GC 慢 10
倍以上。
年轻代GC基本是使用复制算法,因为Java98%的对象具有“朝生夕死”的特点,将内存空间分为一块较大的Eden区和两块比较小的Survivor区,每次使用Eden和其中一块Survivor区即可,当Eden区空间不够大,需要垃圾回收时,只需要将Eden和Survivor中还存活的对象一次性地复制到另一块Survivor区,最后清理掉Eden区和刚才使用过的Survivor空间。
为什么需要两块Survivor区呢?两个Survivor区可以让Survivor区的对象也可以来回复制,而不是马上进入老年代。主要是为了保证老年代的增大速率的缓慢,从而降低老年代GC的次数,保证整个JVM的GC效率。
垃圾收集算法实现
1.从GC Roots可达性分析的一致性说明:指在整个分析期间整个执行系统看起来就像被冻结在某个时间点,不可以出现分析过程中对象引用关系还在不断变化的情况,该点不满足的话分析结果准确性就无法得到保证。
2.CMS收集器
老年代使用CMS收集器与年轻代ParNew收集器配合使用。
ParNew收集器采用的是复制算法,并且采用多个GC线程的方式进行并行收集(此时用户线程仍然处于等待状态,并行的方式是提高了GC速度)。
CMS(Concurrent Mark Sweep)收集器:获取最短回收停顿时间为目标的收集器。
GC日志详解
143514.439: [GC (Allocation Failure) 143514.439: [ParNew (promotion failed): 1109666K->1244160K(1244160K), 2.5495020 secs]143516.988: [CMS: 2493592K->908854K(2508800K), 3.8376205 secs] 3310458K->908854K(3752960K), [Metaspace: 183919K->183589K(1226752K)], 6.3878347 secs] [Times: user=10.48 sys=0.72, real=6.39 secs]
143522.172: [GC (Allocation Failure) 143522.172: [ParNew: 1105920K->138240K(1244160K), 1.0588337 secs] 2014774K->1599284K(3752960K), 1.0592778 secs] [Times: user=3.67 sys=0.04, real=1.06 secs]
143523.234: [GC (CMS Initial Mark) [1 CMS-initial-mark: 1461044K(2508800K)] 1602492K(3752960K), 0.0335833 secs] [Times: user=0.12 sys=0.00, real=0.03 secs]
143523.268: [CMS-concurrent-mark-start]
143524.209: [CMS-concurrent-mark: 0.942/0.942 secs] [Times: user=1.80 sys=0.20, real=0.94 secs]
143524.209: [CMS-concurrent-preclean-start]
143524.225: [CMS-concurrent-preclean: 0.015/0.015 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
143524.225: [CMS-concurrent-abortable-preclean-start]
143525.127: [GC (Allocation Failure) 143525.127: [ParNew: 1244160K->138240K(1244160K), 0.7197909 secs] 2705204K->1988877K(3752960K), 0.7202266 secs] [Times: user=2.62 sys=0.01, real=0.72 secs]
143526.861: [CMS-concurrent-abortable-preclean: 1.901/2.635 secs] [Times: user=9.40 sys=0.41, real=2.64 secs]
143526.863: [GC (CMS Final Remark) [YG occupancy: 747147 K (1244160 K)]143526.863: [Rescan (parallel) , 0.1912562 secs]143527.054: [weak refs processing, 0.0000446 secs]143527.054: [class unloading, 0.0670853 secs]143527.121: [scrub symbol table, 0.0349644 secs]143527.156: [scrub string table, 0.0033321 secs][1 CMS-remark: 1850637K(2508800K)] 2597785K(3752960K), 0.2969630 secs] [Times: user=0.85 sys=0.00, real=0.29 secs]
143527.161: [CMS-concurrent-sweep-start]
143528.172: [CMS-concurrent-sweep: 1.009/1.011 secs] [Times: user=1.81 sys=0.19, real=1.01 secs]
143528.173: [CMS-concurrent-reset-start]
143528.177: [CMS-concurrent-reset: 0.004/0.004 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
晋升失败的日志:
143514.439: [GC (Allocation Failure) 143514.439: [ParNew (promotion failed): 1109666K->1244160K(1244160K), 2.5495020 secs]143516.988: [CMS: 2493592K->908854K(2508800K), 3.8376205 secs] 3310458K->908854K(3752960K), [Metaspace: 183919K->183589K(1226752K)], 6.3878347 secs] [Times: user=10.48 sys=0.72, real=6.39 secs]
143514.439: 代表了GC发生的时间,这个数字的含义是从JAVA虚拟机启动以来经过的秒数;
GC:表示这是一次垃圾回收;
Allocation Failure:GC原因在年轻代中没有足够的空间能够存储新的数据了;
[ParNew (promotion failed): 1109666K->1244160K(1244160K), 2.5495020 secs]:年轻代使用ParNew收集器,晋升失败,GC前young区已使用1109666K容量,GC后young区已使用1244160K容量(该区域一共有1244160K容量可使用),该区域GC使用时间是2.5495020 secs;此时GC后young区反而占用量变多了;因为晋升失败,所以会触发一次FGC;
143516.988:代表了GC发生的时间,这个数字的含义是从JAVA虚拟机启动以来经过的秒数;
[CMS: 2493592K->908854K(2508800K), 3.8376205 secs]:old区使用了CMS收集器,old区GC前2493592K,GC后908854K,总共2508800K,一共使用时间3.8376205 sec;
3310458K->908854K(3752960K):GC前堆区使用量3310458K,GC后堆区使用量908854K,总共堆大小3752960K;FGC后会将年轻代存活的对象全部转移到老年代。
[Metaspace: 183919K->183589K(1226752K)], 6.3878347 secs:Metaspace区GC前使用量183919K,GC后使用量183589K,一共可使用大小1226752K,GC时间6.3878347 secs;
[Times: user=10.48 sys=0.72, real=6.39 secs]:用户态消耗CPU的时间是10.48S,内核态消耗CPU的时间是0.72s,操作从开始到结束所经历的墙钟时间。
- promotion failed后日志打印的young区占用大小反而变多:
所以是有可能晋升失败后日志打印young区的占用量反而变多的。
- user时间大于real时间:
墙钟时间和CPU时间区别:墙钟时间包括各种非运算符的等待耗时,比如等待线程阻塞,等待磁盘I/O,而CPU时间不包含这些耗时。当系统有多CPU或者多核的话,多线程操作会叠加这些CPU时间,所以看到user或者sys时间超过real时间是完全正常的。
正常的young区 gc日志
143522.172: [GC (Allocation Failure) 143522.172: [ParNew: 1105920K->138240K(1244160K), 1.0588337 secs] 2014774K->1599284K(3752960K), 1.0592778 secs] [Times: user=3.67 sys=0.04, real=1.06 secs]
143522.172:代表了GC发生的时间,这个数字的含义是从JAVA虚拟机启动以来经过的秒数;
GC:表示这是一次垃圾回收;
Allocation Failure:GC原因是年轻代中没有足够的空间能够存储新的数据了;
ParNew: 1105920K->138240K(1244160K), 1.0588337 secs]:年轻代使用了ParNew垃圾收集器;gc前空间使用量为1105920K,gc后空间使用量为138240K,young区的总可使用大小为1244160K,GC一共耗时1.0588337 secs;
2014774K->1599284K(3752960K), 1.0592778 secs:总堆区GC前已使用2014774K,GC后还剩余1599284K,堆区一共3752960K,GC共耗时1.0592778 secs;
Times: user=3.67 sys=0.04, real=1.06 secs:用户态GC CPU占用时间3.67,内核态占用时间0.04,操作从开始到结束的墙钟时间是1.06;
本次Minor GC:young区总共减少1105920K-138240K=967680K,堆区总共减少:415490K,说明有967680K-415490K=552190K晋升到老年代。
CMS GC日志
143523.234: [GC (CMS Initial Mark) [1 CMS-initial-mark: 1461044K(2508800K)] 1602492K(3752960K), 0.0335833 secs] [Times: user=0.12 sys=0.00, real=0.03 secs]
143523.268: [CMS-concurrent-mark-start]
143524.209: [CMS-concurrent-mark: 0.942/0.942 secs] [Times: user=1.80 sys=0.20, real=0.94 secs]
143524.209: [CMS-concurrent-preclean-start]
143524.225: [CMS-concurrent-preclean: 0.015/0.015 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
143524.225: [CMS-concurrent-abortable-preclean-start]
143525.127: [GC (Allocation Failure) 143525.127: [ParNew: 1244160K->138240K(1244160K), 0.7197909 secs] 2705204K->1988877K(3752960K), 0.7202266 secs] [Times: user=2.62 sys=0.01, real=0.72 secs]
143526.861: [CMS-concurrent-abortable-preclean: 1.901/2.635 secs] [Times: user=9.40 sys=0.41, real=2.64 secs]
143526.863: [GC (CMS Final Remark) [YG occupancy: 747147 K (1244160 K)]143526.863: [Rescan (parallel) , 0.1912562 secs]143527.054: [weak refs processing, 0.0000446 secs]143527.054: [class unloading, 0.0670853 secs]143527.121: [scrub symbol table, 0.0349644 secs]143527.156: [scrub string table, 0.0033321 secs][1 CMS-remark: 1850637K(2508800K)] 2597785K(3752960K), 0.2969630 secs] [Times: user=0.85 sys=0.00, real=0.29 secs]
143527.161: [CMS-concurrent-sweep-start]
143528.172: [CMS-concurrent-sweep: 1.009/1.011 secs] [Times: user=1.81 sys=0.19, real=1.01 secs]
143528.173: [CMS-concurrent-reset-start]
143528.177: [CMS-concurrent-reset: 0.004/0.004 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
初始标记:
[GC (CMS Initial Mark) [1 CMS-initial-mark: 1461044K(2508800K)] 1602492K(3752960K), 0.0335833 secs] [Times: user=0.12 sys=0.00, real=0.03 secs]:CMS开始对老年代进行垃圾圾收集的初始标记阶段,该阶段从垃圾回收的“根对象”开始,且只扫描直接与“根对象”直接关联的对象,并做标记,需要暂停用户线程,STW。1461044K(2508800K):表示当前老年代的容量为2508800K,在使用了1461044K时开始进行CMS垃圾回收,此时CMS收集器的启动内存使用阈值=1461044K/2508800K≈58%;
1602492K(3752960K):当前堆的使用情况和堆的总大小;
[Times: user=0.12 sys=0.00, real=0.03 secs]:本次初始标记的耗时;
并发标记:
[CMS-concurrent-mark: 0.942/0.942 secs] [Times: user=1.80 sys=0.20, real=0.94 secs]:表示并发标记阶段,会遍历整个年老代并且标记活着的对象,后面的0.942/0.942 secs表示该阶段持续的时间和时钟时间,耗时0.9秒,可见耗时是比较长的。
由于该阶运行的过程中用户线程也在运行,这就可能会发生这样的情况,已经被遍历过的对象的引用被用户线程改变,如果发生了这样的情况,JVM就会标记这个区域为Dirty Card。
[CMS-concurrent-preclean: 0.015/0.015 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]:并发预清理阶段会把上一个阶段被标记为Dirty Card的对象以及可达的对象重新遍历标记,完成后清楚Dirty Card标记。另外,一些必要的清扫工作也会做,还会做一些final remark阶段需要的准备工作。
143524.225: [CMS-concurrent-abortable-preclean-start]:
143525.127: [GC (Allocation Failure) 143525.127: [ParNew: 1244160K->138240K(1244160K), 0.7197909 secs] 2705204K->1988877K(3752960K), 0.7202266 secs] [Times: user=2.62 sys=0.01, real=0.72 secs]
143526.861: [CMS-concurrent-abortable-preclean: 1.901/2.635 secs] [Times: user=9.40 sys=0.41, real=2.64 secs]
可终止的并发预清理,此阶段在Eden区使用超过2M时启动,当然2M是默认的阈值,可以通过参数修改。该阶段是为了尽量承担 STW(stop-the-world)中最终标记阶段的工作。通过日志看到在此阶段中发生了一次Minor GC,这是CMS垃圾收集器想要看到的,目的是下一个remark阶段减少扫描young区指向old区引用的时间(跨代引用)。
重新标记:
143536.262: [GC (CMS Final Remark) [YG occupancy: 341350 K (1244160 K)]143536.262: [Rescan (parallel) , 0.0717460 secs]143536.334: [weak refs processing, 0.0001182 secs]143536.334: [class unloading, 0.0700041 secs]143536.404: [scrub symbol table, 0.0309733 secs]143536.435: [scrub string table, 0.0046430 secs][1 CMS-remark: 1398706K(2508800K)] 1740056K(3752960K), 0.1778235 secs] [Times: user=0.38 sys=0.01, real=0.18 secs]
143536.262: [GC (CMS Final Remark):CMS的重新标记阶段
[YG occupancy: 341350 K (1244160 K)]:表示年轻代当前的内存占用情况,通常Final Remark阶段要尽量运行在年轻代是足够干净的时候,这样可以消除紧接着的连续的几个STW阶段。
143536.262: [Rescan (parallel) , 0.0717460 secs]:这是整个final remark阶段扫描对象的用时总计,该阶段会重新扫描CMS堆中剩余的对象,重新从“根对象”开始扫描,并且也会处理对象关联。本次扫描共耗时 0.0717460s。
143536.334: [weak refs processing, 0.0001182 secs]:第一个子阶段,表示对弱引用的处理耗时为0.0001182s。
143536.334: [class unloading, 0.0700041 secs]:第二个子阶段,表示卸载无用的类的耗时为0.0700041s。
143536.404: [scrub symbol table, 0.0309733 secs]:表示清理分别包含类级元数据和内部化字符串的符号和字符串表的耗时为0.0309733s。
[1 CMS-remark: 1398706K(2508800K)] 1740056K(3752960K), 0.1778235 secs]:表示经历后上述几个阶段后此时old区的使用情况,现在old区1398706K,总可用大小2508800K,堆区使用1740056K,总大小3752960K;
[Times: user=0.38 sys=0.01, real=0.18 secs]:重新标记阶段的耗时
并发清除:
143527.161: [CMS-concurrent-sweep-start]
143528.172: [CMS-concurrent-sweep: 1.009/1.011 secs] [Times: user=1.81 sys=0.19, real=1.01 secs]
清除那些没有标记的无用对象并回收内存。
143528.173: [CMS-concurrent-reset-start]
143528.177: [CMS-concurrent-reset: 0.004/0.004 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
重新阶段,准备下一个CMS生命周期的使用。
MetaSpace GC日志
531648.622: [Full GC (Last ditch collection) 531648.622: [CMS: 342854K->342854K(2508800K), 0.8929903 secs] 342854K->342854K(3752960K), [Metaspace: 251311K->251311K(1413120K)], 0.8935836 secs] [Times: user=0.89 sys=0.00, real=0.89 secs]
531649.518: [Full GC (Metadata GC Threshold) 531649.518: [CMS: 342854K->342854K(2508800K), 0.8738460 secs] 357775K->342854K(3752960K), [Metaspace: 251311K->251311K(1413120K)], 0.8744387 secs] [Times: user=0.87 sys=0.00, real=0.88 secs]
531650.392: [Full GC (Last ditch collection) 531650.392: [CMS: 342854K->342851K(2508800K), 0.8954263 secs] 342854K->342851K(3752960K), [Metaspace: 251311K->251311K(1413120K)], 0.8959793 secs] [Times: user=0.90 sys=0.00, real=0.89 secs]
531651.290: [Full GC (Metadata GC Threshold) 531651.290: [CMS: 342851K->342850K(2508800K), 0.8650246 secs] 342856K->342850K(3752960K), [Metaspace: 251311K->251311K(1413120K)], 0.8656931 secs] [Times: user=0.87 sys=0.00, real=0.87 secs]
531652.156: [Full GC (Last ditch collection) 531652.156: [CMS: 342850K->342850K(2508800K), 0.9005325 secs] 342850K->342850K(3752960K), [Metaspace: 251311K->251311K(1413120K)], 0.9011448 secs] [Times: user=0.90 sys=0.00, real=0.90 secs]
531653.058: [GC (CMS Initial Mark) [1 CMS-initial-mark: 342850K(2508800K)] 342850K(3752960K), 0.0145835 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
应用实际配置详解:
一个4C8G Java8的应用
/opt/java/bin/java -server -Xloggc:/home/admin/logs/gc-%p.log -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:CMSFullGCsBeforeCompaction=5 -XX:+UseCMSCompactAtFullCollection -XX:+CMSClassUnloadingEnabled -XX:+DisableExplicitGC -XX:CMSInitiatingOccupancyFraction=70 -XX:+UseCMSInitiatingOccupancyOnly -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/home/admin/logs/ -Xms3800m -Xmx3800m -Xmn1350m -Xss512k -XX:MetaspaceSize=384m -XX:MaxMetaspaceSize=384m
补充说明
1.可以作为GC Roots的对象
虚拟机栈(栈帧中的本地变量表)中引用的对象;
方法区中类静态属性引用的对象;
方法区中常量引用的对象;
本地方法栈中JNI(即一般说的Native方法)引用的对象。
学习参考:
【美团点评】 从实际案例聊聊Java应用的GC优化:
https://tech.meituan.com/2017/12/29/jvm-optimize.html
理解CMS GC日志:
https://www.jianshu.com/p/ba768d8e9fec
MetaspaceSize和MaxMetaspaceSize的理解:
https://www.jianshu.com/p/5ee71f1724cd
《深入理解Java虚拟机》 周志明
常见问题:
1.Promotion failure + Concurrent mode failure 原因
说明:Minor GC后,Survivor空间容纳不了剩余对象,将要放入老年代,老年代有碎片或者不能容纳这些对象。
参考:https://www.jianshu.com/p/ca1b0d4107c5
2.不断进行CMS GC