GC: CMS垃圾回收器三(实践)

jstat -gc -t [pid] 1000 监控日志... ,抽取其中关键记录不一定连续

应用启动时间 2015-06-23 10:22:27 ,换算后,第二条记录时间是2015-06-24 22:35:16 ,转换过程中有毫秒级的误差,与GC日志一致。

Timestamp S0C S1C S0U S1U EC EU OC OU PC PU YGC YGCT FGC FGCT GCT
130368.2 209664.0 209664.0 142366.4 0.0 1677824.0 1677824.0 2097152.0 1043374.3 131072.0 15537.9 80 18.274 0 0.000 18.274
130369.2 209664.0 209664.0 0.0 137896.2 1677824.0 19949.5 2097152.0 1054947.1 131072.0 15537.9 81 18.532 1 0.039 18.571
130374.3 209664.0 209664.0 0.0 137896.2 1677824.0 33201.4 2097152.0 1054837.5 131072.0 15537.9 81 18.532 2 0.076 18.608

以下是开启-XX:+PrintGCDetails -XX:+PrintGCDateStamps 后的部分日志:

第一步:CMS-initial-mark

2015-06-24T22:35:17.084+0800: 130368.643: [GC [1 CMS-initial-mark: 1054947K(2097152K)] 1193557K(3984640K), 0.0386010 secs] [Times: user=0.03 sys=0.00, real=0.04 secs] 
  • 本例中启动参数未设置-XX:+UseCMSInitiatingOccupancyOnly ,只设置了-XX:CMSInitiatingOccupancyFraction=70 ,系统根据统计数据自行决定50%触发cms gc ,而不是在70%时候。
  • 格式: PrintGCDateStamps部分  [GC [1 CMS-initial-mark: OU(OC)] SU+EU+OU(-Xmx), 耗时] []

第二步:CMS-concurrent-mark

2015-06-24T22:35:17.125+0800: 130368.684: [CMS-concurrent-mark-start]
2015-06-24T22:35:17.152+0800: 130368.711: [CMS-concurrent-mark: 0.027/0.027 secs] [Times: user=0.16 sys=0.00, real=0.03 secs]

第三步:CMS-concurrent-preclean

2015-06-24T22:35:17.153+0800: 130368.712: [CMS-concurrent-preclean-start]
2015-06-24T22:35:17.164+0800: 130368.723: [CMS-concurrent-preclean: 0.011/0.011 secs] [Times: user=0.04 sys=0.00, real=0.01 secs]

第四步:CMS-concurrent-abortable-preclean

2015-06-24T22:35:17.164+0800: 130368.723: [CMS-concurrent-abortable-preclean-start]
 CMS: abort preclean due to time 2015-06-24T22:35:22.481+0800: 130374.041: [CMS-concurrent-abortable-preclean: 5.216/5.317 secs] [Times: user=6.14 sys=0.11, real=5.32 secs] 

第五步:CMS-remark

2015-06-24T22:35:22.486+0800: 130374.045: [GC[YG occupancy: 171097 K (1887488 K)]2015-06-24T22:35:22.486+0800: 130374.045: [Rescan (parallel) , 0.0175320 secs]2015-06-24T22:35:22.504+0800: 130374.063: [weak refs processing, 0.0005460 secs]2015-06-24T22:35:22.505+0800: 130374.064: [class unloading, 0.0074730 secs]2015-06-24T22:35:22.512+0800: 130374.071: [scrub symbol table, 0.0054870 secs]2015-06-24T22:35:22.518+0800: 130374.077: [scrub string table, 0.0013050 secs] [1 CMS-remark: 1054947K(2097152K)] 1226044K(3984640K), 0.0372980 secs] [Times: user=0.25 sys=0.00, real=0.04 secs] 

 第六步:CMS-concurrent-sweep-start

2015-06-24T22:35:22.525+0800: 130374.084: [CMS-concurrent-sweep-start]
2015-06-24T22:35:22.546+0800: 130374.105: [CMS-concurrent-sweep: 0.021/0.021 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]

 第七步:CMS-concurrent-reset

2015-06-24T22:35:22.547+0800: 130374.106: [CMS-concurrent-reset-start]
2015-06-24T22:35:22.564+0800: 130374.123: [CMS-concurrent-reset: 0.017/0.017 secs] [Times: user=0.01 sys=0.00, real=0.02 secs]
原文地址:https://www.cnblogs.com/zno2/p/4600487.html