性能问答>如何打印出CMS GC详细日志?>
1回复
2月前

如何打印出CMS GC详细日志?



jdk版本:

version "1.8.0_231"
Java(TM) SE Runtime Environment (build 1.8.0_231-b11)
Java HotSpot(TM) 64-Bit Server VM (build 25.231-b11, mixed mode)

启动命令行添加参数-XX:+PrintGCDetails 和 -XX:+PrintGCTimeStamps后,未正常打印出 GC (CMS Initial Mark、GC (CMS Final Remark )详细日志。

541 阅读
请先登录,再评论

当前打印的日志格式有两种日志没有打印出来,1是: CMS-initial-mark、CMS-remark 类似的信息;2是晋级信息:- age 1: 10532656 bytes, 10532656 total- age 2: 14082976 bytes, 24615632 total 。
而原因其实很简单,jdk8默认的老年代垃圾回收并不是CMS而是ParallelGC,如何确认呢?
终端命令行执行: java -XX:+PrintFlagsFinal 可打印出全量扩展参数列表,截取垃圾回收器部分如下:

        bool UseConcMarkSweepGC   = false                                {product}
        bool UseParallelGC                   := true                                {product}
 确实默认启用的是ParallelGC,而若需要使用CMS则在启动参加中添加 -XX:+UseConcMarkSweepGC 即可,再结合其他参数,GC日志中即可正常打印相关日志。JVM参数示例:-Xmx180M -Xms180M -Xmn45M -XX:+PrintGCDetails -XX:+PrintTenuringDistribution -XX:+PrintGCTimeStamps  -XX:+UseConcMarkSweepGC -Xloggc:d:/logs/gc20220222.log
 日志示例片段:
    61.011: [GC (CMS Initial Mark) [1 CMS-initial-mark: 132238K(138240K)] 139160K(179712K), 0.0014212 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
61.012: [CMS-concurrent-mark-start]
61.085: [CMS-concurrent-mark: 0.073/0.073 secs] [Times: user=0.23 sys=0.00, real=0.07 secs] 
61.085: [CMS-concurrent-preclean-start]
61.089: [CMS-concurrent-preclean: 0.003/0.004 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
61.089: [CMS-concurrent-abortable-preclean-start]
62.658: [CMS-concurrent-abortable-preclean: 0.154/1.569 secs] [Times: user=0.23 sys=0.01, real=1.57 secs] 
62.658: [GC (CMS Final Remark) [YG occupancy: 24224 K (41472 K)]62.658: [Rescan (parallel) , 0.0034494 secs]62.662: [weak refs processing, 0.0003129 secs]62.662: [class unloading, 0.0108166 secs]62.673: [scrub symbol table, 0.0144841 secs]62.687: [scrub string table, 0.0009962 secs][1 CMS-remark: 132238K(138240K)] 156462K(179712K), 0.0302161 secs] [Times: user=0.17 sys=0.00, real=0.03 secs] 
62.689: [CMS-concurrent-sweep-start]
62.726: [CMS-concurrent-sweep: 0.038/0.038 secs] [Times: user=0.20 sys=0.00, real=0.04 secs] 
62.726: [CMS-concurrent-reset-start]
62.726: [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
62.764: [GC (Allocation Failure) 62.764: [ParNew
Desired survivor size 2359296 bytes, new threshold 2 (max 6)
- age   1:    1810832 bytes,    1810832 total
- age   2:    1537976 bytes,    3348808 total
: 40647K->3962K(41472K), 0.0025315 secs] 172849K->136164K(179712K), 0.0025762 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
12月前