understanding GC logs

Ramki Ramakrishna y.s.ramakrishna at oracle.com
Wed Aug 3 11:36:17 PDT 2011



On 8/3/2011 11:18 AM, Darji, Kinnari wrote:
>
> Thanks Ramki
>
> So If I look at logs starting [GC and real times, that should be 
> almost application STW time. Am I correct?
>

yes. Except that the real time in that display has a resolution of 10 ms 
only.
(Thus the 9.2 ms looked like 0.01 s below, i think.)

But yes, that's the STW time.

One caveat though -- this only lists STW ops attributed to GC.
More generally, you would want to use +PrintSafepointStatistics to
see all STW operations (and details thereof), including of course the
GC ops (which are usually the most common type of STW op, but by
no means the only type).

-- ramki

> Thank you
>
> Kinnari
>
> *From:*Ramki Ramakrishna [mailto:y.s.ramakrishna at oracle.com]
> *Sent:* Wednesday, August 03, 2011 2:08 PM
> *To:* Darji, Kinnari [ICG-IT]
> *Cc:* hotspot-gc-use at openjdk.java.net
> *Subject:* Re: understanding GC logs
>
>
>
> On 8/3/2011 10:45 AM, Darji, Kinnari wrote:
>
> Hello GC team,
>
> What does this all different time mean? Can someone please clarify?
>
> What is the time application when application stops?
>
> [GC 9768.668: [ParNew
>
>            ^^^^^^ JVM timestamp (seconds since start of JVM) at start 
> of GC operation)
>
>    3746 Desired survivor size 10878976 bytes, new threshold 4 (max 4)
>
>    3747 - age   1:     594288 bytes,     594288 total
>
>    3748 - age   2:    2369912 bytes,    2964200 total
>
>    3749 - age   3:    2877584 bytes,    5841784 total
>
>    3750 - age   4:    3075264 bytes,    8917048 total
>
>    3751 : 182066K->12384K(191744K), 0.0089120 secs] 
> 2755986K->2586303K(10710272K), 0.0092180 secs]
>
>                                                            ^^^^^^^^ 
>                                                            ^^^^^^^
>                                                           Duration of 
> Scavenge                                        Duration of whole GC 
> operation
>                                                                                                                                       
> (includes scavenge)
>
> [Times: user=0.09 sys=0.00, real=0.01 secs]
>
>      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Process virtual user and system 
> times, and real (elapsed) time during GC operation.
>
> The time for which the application threads were stopped is about 9.2 ms.
>
> -- ramki
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://mail.openjdk.java.net/pipermail/hotspot-gc-dev/attachments/20110803/3046b7ca/attachment.html 
-------------- next part --------------
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use at openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use


More information about the hotspot-gc-dev mailing list