30

70.222: [GC [PSYoungGen: 131072K->15437K(152896K)] 131072K->15509K(502464K), 0.0228420 secs] [Times: user=0.09 sys=0.01, real=0.02 secs]

2 Answers 2

37

You can find tutorials on interpreting verbose GC output eg. in:

Looking at verbosegc output tutorial - Java 7, you can see YoungGen space analysis:

UPDATE 03/27/2014: The "Collection time (secs)" is actually a Timestamp showing the when the GC occurred. The Collection times are reported as Times=user=0.45 sys=0.01, real=0.14 secs].

enter image description here

Here, the 262208K->137900K(100428K) means Java Heap before GC-> Java Heap after GC (Total Size of the Java Heap).

And, OldGen space analysis:

enter image description here

6
  • So you are saying that 131072K (young gen before)->15437K (young gen after)(152896K)] 131072K (java heap before)->15509K(502464K) (java heap after), ??? Is my understanding correct ?
    – GKP
    Commented May 28, 2013 at 18:49
  • 1
    The number on the left is not the collection time. But, it's the timestamp representing the time since java process is running. Commented Mar 27, 2014 at 11:05
  • You are correct, wow, there is a mistake. Timestamp is so essential to me that I did not check it in that picture... will put an update there.
    – Aleš
    Commented Mar 27, 2014 at 15:02
  • Thanks, I cannot upgrade the diagram so I have added an explanation.
    – Aleš
    Commented Mar 27, 2014 at 16:58
  • 4
    Use -XX:+PrintGCDateStamps, you will get the actual time when the process is running rather than the time elasped. I find it more useful. Commented May 13, 2015 at 15:45
14

In Addition to other answer , I am explaining Times section of log

[Times: user=0.09 sys=0.01, real=0.02 secs]

The “Times” section of the detailed log contains information about the CPU time used by the GC, separated into user space (“user”) and kernel space (“sys”) of the operating system.Also, it shows the real time (“real”) that passed while the GC was running.

In your case the CPU time (0.09 sec) is considerably higher than the real time passed (0.02 Sec), we can conclude that the GC was run using multiple threads.

Detailed Example

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.