Why does GC logging show events where the user time is greater than the real time?

Solution Verified - Updated -

Environment

  • Java

Issue

Can you explain the relationship of sys time, user time and real time in a GC log, and describe why the real time may less or more than the others summation?

[GC 111: [ParNew: 3757505K->419392K(3774912K), 7.7 secs] 4196811K->1193045K(12163520K), 7.7 secs] [Times: user=5.38 sys=1.02, real=4.2 secs]

Resolution

sys: CPU time spent in kernel-mode within the executing process i.e I/O, swapping program from/to memory.
user: CPU time spent in user-mode code outside the kernel.
real: CPU time if you were using a stopwatch/clock .

Wall time and real time are used interchangeably. sys and user time may be larger than real time because the JVM can often use multiple CPU cores to do work. For example, if three CPU cores each perform 2 seconds of user-mode work and 1 second of kernel-mode work over a period of 4 seconds, that is 6 user seconds, 3 sys seconds and 4 real seconds.

Garbage collection executes user space code, so it is expected that user time will exceed sys time.

If real time is greater than user+sys time, follow article, for more information.

This solution is part of Red Hat’s fast-track publication program, providing a huge library of solutions that Red Hat engineers have created while supporting our customers. To give you the knowledge you need the instant it becomes available, these articles may be presented in a raw and unedited form.

Comments