Why does GC logging show events where the sys time is greater than the user time?
Issue
- GC logging shows a collection where the
systime is greater than theusertime:
[GC pause (G1 Evacuation Pause) (young), 189.8414654 secs]
[Parallel Time: 189836.0 ms, GC Workers: 6]
[GC Worker Start (ms): Min: 2998769103.9, Avg: 2998769103.9, Max: 2998769104.0, Diff: 0.1]
[Ext Root Scanning (ms): Min: 3.0, Avg: 3.1, Max: 3.2, Diff: 0.2, Sum: 18.5]
[Update RS (ms): Min: 3.9, Avg: 1935.0, Max: 2321.3, Diff: 2317.3, Sum: 11610.1]
[Processed Buffers: Min: 36, Avg: 103.0, Max: 143, Diff: 107, Sum: 618]
[Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.2]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Object Copy (ms): Min: 186632.0, Avg: 187311.5, Max: 189828.7, Diff: 3196.7, Sum: 1123868.7]
[Termination (ms): Min: 0.1, Avg: 586.3, Max: 879.5, Diff: 879.5, Sum: 3517.8]
[Termination Attempts: Min: 2, Avg: 205.3, Max: 348, Diff: 346, Sum: 1232]
[GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
[GC Worker Total (ms): Min: 189835.8, Avg: 189835.9, Max: 189836.0, Diff: 0.1, Sum: 1139015.4]
[GC Worker End (ms): Min: 2998958939.8, Avg: 2998958939.8, Max: 2998958939.8, Diff: 0.0]
[Code Root Fixup: 0.1 ms]
[Code Root Purge: 0.0 ms]
[String Dedup Fixup: 1.9 ms, GC Workers: 6]
[Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Table Fixup (ms): Min: 0.0, Avg: 1.2, Max: 1.7, Diff: 1.7, Sum: 7.0]
[Clear CT: 0.5 ms]
[Other: 3.0 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.3 ms]
[Ref Enq: 0.0 ms]
[Redirty Cards: 1.3 ms]
[Humongous Register: 0.1 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 0.3 ms]
[Eden: 2544.0M(2544.0M)->0.0B(2848.0M) Survivors: 528.0M->224.0M Heap: 4763.6M(60.0G)->2228.7M(60.0G)]
[Times: user=144.21 sys=221.51, real=189.84 secs]
Environment
- OpenJDK
Subscriber exclusive content
A Red Hat subscription provides unlimited access to our knowledgebase, tools, and much more.