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
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]
.
Here, the 262208K->137900K(100428K)
means Java Heap before GC
-> Java Heap after GC (Total Size of the Java Heap)
.
And, OldGen space analysis:
-
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 ?– GKPCommented May 28, 2013 at 18:49
-
1The 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
-
4Use -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
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.