Java HotSpot(TM) 64-Bit Server VM (25.20-b23) for linux-amd64 JRE (1.8.0_20-b26), built on Jul 30 2014 13:13:52 by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8)
Memory: 4k page, physical 131744980k(12588928k free), swap 16777212k(15710540k free)
CommandLine flags: -XX:CMSInitiatingOccupancyFraction=75 -XX:+CMSScavengeBeforeRemark -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/data/logs/heap_dump_%p.log -XX:InitialHeapSize=6442450944 -XX:MaxHeapSize=6442450944 -XX:MaxTenuringThreshold=15 -XX:MetaspaceSize=838860800 -XX:NewRatio=5 -XX:OldPLABSize=16 -XX:PretenureSizeThreshold=3145728 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintTenuringDistribution -XX:SurvivorRatio=8 -XX:TargetSurvivorRatio=50 -XX:ThreadStackSize=512 -XX:+UseCMSInitiatingOccupancyOnly -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+UseParNewGC
2020-03-07T23:07:52.027+0800: 2.432: [GC (Allocation Failure) 2.432: [ParNew
Desired survivor size 53673984 bytes, new threshold 15 (max 15)
- age 1: 9181576 bytes, 9181576 total
: 838912K->9114K(943744K), 0.2039989 secs] 838912K->9114K(6186624K), 0.2041040 secs] [Times: user=0.93 sys=0.09, real=0.21 secs]
2020-03-07T23:07:55.099+0800: 5.504: [GC (Allocation Failure) 5.504: [ParNew
Desired survivor size 53673984 bytes, new threshold 15 (max 15)
- age 1: 9562632 bytes, 9562632 total
- age 2: 7526624 bytes, 17089256 total
: 848026K->20127K(943744K), 0.0282517 secs] 848026K->20127K(6186624K), 0.0283281 secs] [Times: user=0.23 sys=0.02, real=0.03 secs]
-
2020-03-07T23:07:52.027+0800:– GC事件(GC event)开始的时间点. -
5.504– GC事件的开始时间,相对于JVM的启动时间,单位是秒(Measured in seconds). -
GC (Allocation Failure)– 用来区分(distinguish)是 Minor GC 还是 Full GC 的标志(Flag). 这里的 GC 表明本次发生的是 Minor GC. -
Allocation Failure– 引起垃圾回收的原因. 本次GC是因为年轻代中没有任何合适的区域能够存放需要分配的数据结构而触发的. -
ParNew– 使用的垃圾收集器的名字 -
848026K->20127K– 在本次垃圾收集之前和之后的年轻代内存使用情况(Usage). -
(943744K)– 年轻代的总的大小(Total size). -
848026K->20127K– 在本次垃圾收集之前和之后整个堆内存的使用情况(Total used heap). -
(943744K)– 总的可用的堆内存(Total available heap). -
0.0282517 secs– GC事件的持续时间(Duration),单位是秒.
11.[Times: user=0.06 sys=0.00, real=0.06 secs]– GC事件的持续时间,通过- - 多种分类来进行衡量:
- user – 此次垃圾回收, 垃圾收集线程消耗的所有CPU时间(Total CPU time).
- sys – 操作系统调用(OS call) 以及等待系统事件的时间(waiting for system event)
- real – 应用程序暂停的时间(Clock time). 由于串行垃圾收集器(Serial Garbage Collector)只会使用单个线程, 所以 real time 等于 user 以及 system time 的总和.
通过上面的分析, 我们可以计算出在垃圾收集期间, JVM 中的内存使用情况。在垃圾收集之前, 堆内存总的使用了 6G (6,186,624K)。其中, 年轻代使用了 921M(943,744K)。可以算出老年代使用的内存为: 5.2G(5,242,880K)。
838912K->9114K(943744K), 0.2039989 secs] 838912K->9114K(6186624K)
第一次GC后，堆的总内存与年轻代内存一致，说明没有晋升至老年人数据
经过4次后，仍没有数据晋升至老年代
Desired survivor size 53673984 bytes, new threshold 15 (max 15)
- age 1: 9562632 bytes, 9562632 total
- age 2: 7526624 bytes, 17089256 total
: 848026K->20127K(943744K), 0.0282517 secs] 848026K->20127K(6186624K), 0.0283281 secs] [Times: user=0.23 sys=0.02, real=0.03 secs]
2020-03-07T23:08:00.972+0800: 11.376: [GC (Allocation Failure) 11.376: [ParNew
Desired survivor size 53673984 bytes, new threshold 15 (max 15)
- age 1: 7842976 bytes, 7842976 total
- age 2: 8626392 bytes, 16469368 total
- age 3: 7438800 bytes, 23908168 total
: 859039K->31753K(943744K), 0.1507788 secs] 859039K->31753K(6186624K), 0.1508560 secs] [Times: user=0.46 sys=0.08, real=0.15 secs]
2020-03-07T23:08:04.482+0800: 14.886: [GC (Allocation Failure) 14.886: [ParNew
Desired survivor size 53673984 bytes, new threshold 15 (max 15)
- age 1: 16845240 bytes, 16845240 total
- age 2: 6867320 bytes, 23712560 total
- age 3: 8490720 bytes, 32203280 total
- age 4: 7394248 bytes, 39597528 total
: 870665K->48366K(943744K), 0.0479012 secs] 870665K->48366K(6186624K), 0.0480065 secs] [Times: user=0.38 sys=0.17, real=0.05 secs]
第五次后,数据仍没有晋升，但new threshold 变为5
因为第五次的总内存为57848048 >53673984(Desired survivor size)
Desired survivor size默认为Survivor 区的一半,注意本次只修改new threshold，但数据仍未晋升 74216K=74216K
2020-03-07T23:08:08.315+0800: 18.720: [GC (Allocation Failure) 18.720: [ParNew
Desired survivor size 53673984 bytes, new threshold 5 (max 15)
- age 1: 19832944 bytes, 19832944 total
- age 2: 15796752 bytes, 35629696 total
- age 3: 6557216 bytes, 42186912 total
- age 4: 8315088 bytes, 50502000 total
- age 5: 7346048 bytes, 57848048 total
: 887278K->74216K(943744K), 0.1175669 secs] 887278K->74216K(6186624K), 0.1177161 secs] [Times: user=0.58 sys=0.09, real=0.12 secs]
第六次
将age>=5的晋升至老年代，重新计算threshold=3(因为60028544>53673984)
推理:
截止上次老年人为0
本次老年人103843K-96815K=7028K -0=（本次晋升内存大小）
与上次age为5的内存大小7346048 bytes相当,即age >=5的数据被晋升
2020-03-07T23:08:21.334+0800: 31.738: [GC (Allocation Failure) 31.738: [ParNew
Desired survivor size 53673984 bytes, new threshold 3 (max 15)
- age 1: 26683624 bytes, 26683624 total
- age 2: 18038792 bytes, 44722416 total
- age 3: 15306128 bytes, 60028544 total
- age 4: 5780752 bytes, 65809296 total
- age 5: 6735136 bytes, 72544432 total
: 913128K->96815K(943744K), 0.1941987 secs] 913128K->103843K(6186624K), 0.1944608 secs] [Times: user=0.57 sys=0.21, real=0.20 secs]
第7次后 未满足Desired survivor size 53673984 threshold 恢复原来的15
2020-03-07T23:08:56.345+0800: 66.749: [GC (Allocation Failure) 66.750: [ParNew
Desired survivor size 53673984 bytes, new threshold 15 (max 15)
- age 1: 4787440 bytes, 4787440 total
- age 2: 25897264 bytes, 30684704 total
- age 3: 18015256 bytes, 48699960 total
: 935723K->88447K(943744K), 0.1182821 secs] 942752K->124417K(6186624K), 0.1185731 secs] [Times: user=0.48 sys=0.18, real=0.12 secs]
参考原文
https://plumbr.io/blog/garbage-collection/understanding-garbage-collection-logs
网友评论