JVM GC过程


发布于 2025-01-26 / 7 阅读 / 0 评论 /
记录一次JVM GC过程,包括young GC和Old GC

GC日志如下所示

[2025-01-25T22:10:25.275+0800][info][gc            ] GC(40318) Concurrent Cycle
[2025-01-25T22:10:25.275+0800][info][gc,marking    ] GC(40318) Concurrent Clear Claimed Marks
[2025-01-25T22:10:25.276+0800][info][gc,marking    ] GC(40318) Concurrent Clear Claimed Marks 0.706ms
[2025-01-25T22:10:25.276+0800][info][gc,marking    ] GC(40318) Concurrent Scan Root Regions
[2025-01-25T22:10:25.303+0800][info][gc,marking    ] GC(40318) Concurrent Scan Root Regions 26.472ms
[2025-01-25T22:10:25.303+0800][info][gc,marking    ] GC(40318) Concurrent Mark (434851.762s)
[2025-01-25T22:10:25.303+0800][info][gc,marking    ] GC(40318) Concurrent Mark From Roots
[2025-01-25T22:10:25.303+0800][info][gc,task       ] GC(40318) Using 21 workers of 21 for marking
[2025-01-25T22:10:25.434+0800][info][gc,marking    ] GC(40318) Concurrent Mark From Roots 131.568ms
[2025-01-25T22:10:25.434+0800][info][gc,marking    ] GC(40318) Concurrent Preclean
[2025-01-25T22:10:25.459+0800][info][gc,marking    ] GC(40318) Concurrent Preclean 24.161ms
[2025-01-25T22:10:25.459+0800][info][gc,marking    ] GC(40318) Concurrent Mark (434851.762s, 434851.918s) 155.871ms
[2025-01-25T22:10:25.460+0800][info][gc,start      ] GC(40318) Pause Remark
[2025-01-25T22:10:25.890+0800][info][gc,stringtable] GC(40318) Cleaned string table, strings: 134774 processed, 4691 removed
[2025-01-25T22:10:25.892+0800][info][gc,mmu        ] GC(40318) MMU target violated: 100.0ms (20.0ms/100.0ms)
[2025-01-25T22:10:25.892+0800][info][gc            ] GC(40318) Pause Remark 11803M->11787M(32768M) 432.620ms
[2025-01-25T22:10:25.893+0800][info][gc,cpu        ] GC(40318) User=15.37s Sys=16.45s Real=0.43s
[2025-01-25T22:10:25.893+0800][info][gc,marking    ] GC(40318) Concurrent Rebuild Remembered Sets
[2025-01-25T22:10:26.006+0800][info][gc,marking    ] GC(40318) Concurrent Rebuild Remembered Sets 113.672ms
[2025-01-25T22:10:26.095+0800][info][gc,start      ] GC(40318) Pause Cleanup
[2025-01-25T22:10:26.096+0800][info][gc            ] GC(40318) Pause Cleanup 11862M->11862M(32768M) 1.877ms
[2025-01-25T22:10:26.097+0800][info][gc,cpu        ] GC(40318) User=0.03s Sys=0.01s Real=0.00s
[2025-01-25T22:10:26.097+0800][info][gc,marking    ] GC(40318) Concurrent Cleanup for Next Mark
[2025-01-25T22:10:26.111+0800][info][gc,marking    ] GC(40318) Concurrent Cleanup for Next Mark 14.752ms
[2025-01-25T22:10:26.111+0800][info][gc            ] GC(40318) Concurrent Cycle 836.079ms
[2025-01-25T22:10:31.451+0800][info][gc,start      ] GC(40319) Pause Young (Prepare Mixed) (G1 Evacuation Pause)
[2025-01-25T22:10:31.451+0800][info][gc,task       ] GC(40319) Using 83 workers of 83 for evacuation
[2025-01-25T22:10:31.471+0800][info][gc,phases     ] GC(40319)   Pre Evacuate Collection Set: 0.1ms
[2025-01-25T22:10:31.471+0800][info][gc,phases     ] GC(40319)   Evacuate Collection Set: 12.8ms
[2025-01-25T22:10:31.471+0800][info][gc,phases     ] GC(40319)   Post Evacuate Collection Set: 5.6ms
[2025-01-25T22:10:31.471+0800][info][gc,phases     ] GC(40319)   Other: 1.6ms
[2025-01-25T22:10:31.471+0800][info][gc,heap       ] GC(40319) Eden regions: 1026->0(100)
[2025-01-25T22:10:31.471+0800][info][gc,heap       ] GC(40319) Survivor regions: 2->2(129)
[2025-01-25T22:10:31.471+0800][info][gc,heap       ] GC(40319) Old regions: 697->697
[2025-01-25T22:10:31.471+0800][info][gc,heap       ] GC(40319) Humongous regions: 9->9
[2025-01-25T22:10:31.471+0800][info][gc,metaspace  ] GC(40319) Metaspace: 84792K->84792K(90112K)
[2025-01-25T22:10:31.472+0800][info][gc            ] GC(40319) Pause Young (Prepare Mixed) (G1 Evacuation Pause) 27718M->11304M(32768M) 20.136ms
[2025-01-25T22:10:31.472+0800][info][gc,cpu        ] GC(40319) User=0.66s Sys=0.14s Real=0.02s
[2025-01-25T22:10:31.930+0800][info][gc,start      ] GC(40320) Pause Young (Mixed) (G1 Evacuation Pause)
[2025-01-25T22:10:31.930+0800][info][gc,task       ] GC(40320) Using 83 workers of 83 for evacuation
[2025-01-25T22:10:31.946+0800][info][gc,phases     ] GC(40320)   Pre Evacuate Collection Set: 0.2ms
[2025-01-25T22:10:31.946+0800][info][gc,phases     ] GC(40320)   Evacuate Collection Set: 10.0ms
[2025-01-25T22:10:31.946+0800][info][gc,phases     ] GC(40320)   Evacuate Optional Collection Set: 1.5ms
[2025-01-25T22:10:31.946+0800][info][gc,phases     ] GC(40320)   Post Evacuate Collection Set: 3.6ms
[2025-01-25T22:10:31.946+0800][info][gc,phases     ] GC(40320)   Other: 0.9ms
[2025-01-25T22:10:31.946+0800][info][gc,heap       ] GC(40320) Eden regions: 100->0(100)
[2025-01-25T22:10:31.946+0800][info][gc,heap       ] GC(40320) Survivor regions: 2->2(13)
[2025-01-25T22:10:31.946+0800][info][gc,heap       ] GC(40320) Old regions: 697->533
[2025-01-25T22:10:31.946+0800][info][gc,heap       ] GC(40320) Humongous regions: 9->9
[2025-01-25T22:10:31.946+0800][info][gc,metaspace  ] GC(40320) Metaspace: 84792K->84792K(90112K)
[2025-01-25T22:10:31.946+0800][info][gc            ] GC(40320) Pause Young (Mixed) (G1 Evacuation Pause) 12904M->8680M(32768M) 16.207ms
[2025-01-25T22:10:31.946+0800][info][gc,cpu        ] GC(40320) User=0.55s Sys=0.15s Real=0.02s
[2025-01-25T22:10:32.371+0800][info][gc,start      ] GC(40321) Pause Young (Mixed) (G1 Evacuation Pause)
[2025-01-25T22:10:32.372+0800][info][gc,task       ] GC(40321) Using 83 workers of 83 for evacuation
[2025-01-25T22:10:32.386+0800][info][gc,phases     ] GC(40321)   Pre Evacuate Collection Set: 0.2ms
[2025-01-25T22:10:32.386+0800][info][gc,phases     ] GC(40321)   Evacuate Collection Set: 8.9ms
[2025-01-25T22:10:32.386+0800][info][gc,phases     ] GC(40321)   Evacuate Optional Collection Set: 1.1ms
[2025-01-25T22:10:32.386+0800][info][gc,phases     ] GC(40321)   Post Evacuate Collection Set: 3.3ms
[2025-01-25T22:10:32.386+0800][info][gc,phases     ] GC(40321)   Other: 0.9ms
[2025-01-25T22:10:32.386+0800][info][gc,heap       ] GC(40321) Eden regions: 100->0(100)
[2025-01-25T22:10:32.386+0800][info][gc,heap       ] GC(40321) Survivor regions: 2->2(13)
[2025-01-25T22:10:32.386+0800][info][gc,heap       ] GC(40321) Old regions: 533->425
[2025-01-25T22:10:32.386+0800][info][gc,heap       ] GC(40321) Humongous regions: 9->9
[2025-01-25T22:10:32.386+0800][info][gc,metaspace  ] GC(40321) Metaspace: 84792K->84792K(90112K)
[2025-01-25T22:10:32.386+0800][info][gc            ] GC(40321) Pause Young (Mixed) (G1 Evacuation Pause) 10280M->6953M(32768M) 14.382ms
[2025-01-25T22:10:32.386+0800][info][gc,cpu        ] GC(40321) User=0.41s Sys=0.24s Real=0.02s
[2025-01-25T22:10:32.810+0800][info][gc,start      ] GC(40322) Pause Young (Mixed) (G1 Evacuation Pause)
[2025-01-25T22:10:32.810+0800][info][gc,task       ] GC(40322) Using 83 workers of 83 for evacuation
[2025-01-25T22:10:32.833+0800][info][gc,mmu        ] GC(40322) MMU target violated: 22.7ms (20.0ms/100.0ms)
[2025-01-25T22:10:32.833+0800][info][gc,phases     ] GC(40322)   Pre Evacuate Collection Set: 0.2ms
[2025-01-25T22:10:32.833+0800][info][gc,phases     ] GC(40322)   Evacuate Collection Set: 13.9ms
[2025-01-25T22:10:32.833+0800][info][gc,phases     ] GC(40322)   Evacuate Optional Collection Set: 5.1ms
[2025-01-25T22:10:32.833+0800][info][gc,phases     ] GC(40322)   Post Evacuate Collection Set: 3.2ms
[2025-01-25T22:10:32.833+0800][info][gc,phases     ] GC(40322)   Other: 0.9ms
[2025-01-25T22:10:32.833+0800][info][gc,heap       ] GC(40322) Eden regions: 100->0(100)
[2025-01-25T22:10:32.833+0800][info][gc,heap       ] GC(40322) Survivor regions: 2->2(13)
[2025-01-25T22:10:32.833+0800][info][gc,heap       ] GC(40322) Old regions: 425->221
[2025-01-25T22:10:32.833+0800][info][gc,heap       ] GC(40322) Humongous regions: 9->9
[2025-01-25T22:10:32.833+0800][info][gc,metaspace  ] GC(40322) Metaspace: 84792K->84792K(90112K)
[2025-01-25T22:10:32.833+0800][info][gc            ] GC(40322) Pause Young (Mixed) (G1 Evacuation Pause) 8553M->3685M(32768M) 23.194ms
[2025-01-25T22:10:32.833+0800][info][gc,cpu        ] GC(40322) User=0.60s Sys=0.18s Real=0.02s
[2025-01-25T22:10:33.270+0800][info][gc,start      ] GC(40323) Pause Young (Mixed) (G1 Evacuation Pause)
[2025-01-25T22:10:33.270+0800][info][gc,task       ] GC(40323) Using 83 workers of 83 for evacuation
[2025-01-25T22:10:33.283+0800][info][gc,phases     ] GC(40323)   Pre Evacuate Collection Set: 0.2ms
[2025-01-25T22:10:33.283+0800][info][gc,phases     ] GC(40323)   Evacuate Collection Set: 9.2ms
[2025-01-25T22:10:33.283+0800][info][gc,phases     ] GC(40323)   Post Evacuate Collection Set: 2.5ms
[2025-01-25T22:10:33.283+0800][info][gc,phases     ] GC(40323)   Other: 0.8ms
[2025-01-25T22:10:33.283+0800][info][gc,heap       ] GC(40323) Eden regions: 100->0(100)
[2025-01-25T22:10:33.283+0800][info][gc,heap       ] GC(40323) Survivor regions: 2->2(13)
[2025-01-25T22:10:33.283+0800][info][gc,heap       ] GC(40323) Old regions: 221->134
[2025-01-25T22:10:33.283+0800][info][gc,heap       ] GC(40323) Humongous regions: 9->9
[2025-01-25T22:10:33.283+0800][info][gc,metaspace  ] GC(40323) Metaspace: 84792K->84792K(90112K)
[2025-01-25T22:10:33.283+0800][info][gc            ] GC(40323) Pause Young (Mixed) (G1 Evacuation Pause) 5285M->2301M(32768M) 12.725ms
[2025-01-25T22:10:33.283+0800][info][gc,cpu        ] GC(40323) User=0.46s Sys=0.08s Real=0.01s
[2025-01-25T22:10:33.680+0800][info][gc,start      ] GC(40324) Pause Young (Mixed) (G1 Evacuation Pause)
[2025-01-25T22:10:33.680+0800][info][gc,task       ] GC(40324) Using 83 workers of 83 for evacuation
[2025-01-25T22:10:33.692+0800][info][gc,phases     ] GC(40324)   Pre Evacuate Collection Set: 0.1ms
[2025-01-25T22:10:33.692+0800][info][gc,phases     ] GC(40324)   Evacuate Collection Set: 7.9ms
[2025-01-25T22:10:33.692+0800][info][gc,phases     ] GC(40324)   Post Evacuate Collection Set: 2.3ms
[2025-01-25T22:10:33.692+0800][info][gc,phases     ] GC(40324)   Other: 1.5ms
[2025-01-25T22:10:33.692+0800][info][gc,heap       ] GC(40324) Eden regions: 100->0(1038)
[2025-01-25T22:10:33.692+0800][info][gc,heap       ] GC(40324) Survivor regions: 2->2(13)
[2025-01-25T22:10:33.692+0800][info][gc,heap       ] GC(40324) Old regions: 134->130
[2025-01-25T22:10:33.692+0800][info][gc,heap       ] GC(40324) Humongous regions: 9->9
[2025-01-25T22:10:33.692+0800][info][gc,metaspace  ] GC(40324) Metaspace: 84792K->84792K(90112K)
[2025-01-25T22:10:33.692+0800][info][gc            ] GC(40324) Pause Young (Mixed) (G1 Evacuation Pause) 3901M->2237M(32768M) 11.723ms
[2025-01-25T22:10:33.692+0800][info][gc,cpu        ] GC(40324) User=0.39s Sys=0.06s Real=0.01s
[2025-01-25T22:10:39.158+0800][info][gc,start      ] GC(40325) Pause Young (Normal) (G1 Evacuation Pause)
[2025-01-25T22:10:39.158+0800][info][gc,task       ] GC(40325) Using 83 workers of 83 for evacuation
[2025-01-25T22:10:39.174+0800][info][gc,phases     ] GC(40325)   Pre Evacuate Collection Set: 0.1ms
[2025-01-25T22:10:39.174+0800][info][gc,phases     ] GC(40325)   Evacuate Collection Set: 10.1ms
[2025-01-25T22:10:39.174+0800][info][gc,phases     ] GC(40325)   Post Evacuate Collection Set: 5.4ms
[2025-01-25T22:10:39.175+0800][info][gc,phases     ] GC(40325)   Other: 1.2ms
[2025-01-25T22:10:39.175+0800][info][gc,heap       ] GC(40325) Eden regions: 1038->0(1040)
[2025-01-25T22:10:39.175+0800][info][gc,heap       ] GC(40325) Survivor regions: 2->1(130)
[2025-01-25T22:10:39.175+0800][info][gc,heap       ] GC(40325) Old regions: 130->130
[2025-01-25T22:10:39.175+0800][info][gc,heap       ] GC(40325) Humongous regions: 9->9
[2025-01-25T22:10:39.175+0800][info][gc,metaspace  ] GC(40325) Metaspace: 84792K->84792K(90112K)
[2025-01-25T22:10:39.175+0800][info][gc            ] GC(40325) Pause Young (Normal) (G1 Evacuation Pause) 18845M->2237M(32768M) 16.706ms
[2025-01-25T22:10:39.175+0800][info][gc,cpu        ] GC(40325) User=0.49s Sys=0.11s Real=0.02s