PrintSafepointStatistics (was Re: understanding GC logs)

Ramki Ramakrishna y.s.ramakrishna at oracle.com
Wed Aug 3 14:47:51 PDT 2011


Hi Kinnari -- hs14, which you are on, is rather old (current dev is 
hs22;  latest public is hs21).
Is it possible that you could switch to a more recent JDK? If that's not 
possible,
send me  an hs_err file and I can get a ticket opened for you via the 
usual support
channels. If the problem occurs with a recent hs21 or hs22, we can certainly
take a look here. In either case, I have modified the subject line for 
relevance
to the issue at hand, and also cross-posted to hsotspot-runtime-dev at o.j.n
where PrintSafepointStatistics expertise resides.

-- ramki

On 8/3/2011 2:40 PM, Darji, Kinnari wrote:
>
> Hi Ramki,
>
> Not sure what's the problem. The process dies with following when I 
> have +PrintSafepointStatistics
>
> java version "1.6.0_16"
>
> Java(TM) SE Runtime Environment (build 1.6.0_16-b01)
>
> Java HotSpot(TM) 64-Bit Server VM (build 14.2-b01, mixed mode)
>
>      vmop_name               [threads: total initially_running 
> wait_to_block] [time: spin block sync] [vmop_time  time_elapsed] 
> page_trap_count
>
> no vm operation                    [       7          1              
> 1]          [     0     0     0]     [     0        0]          0
>
> Polling page always armed
>
>     0 VM operations coalesced during safepoint
>
> Maximum sync time      0 ms
>
> ~
>
> Can you please help?
>
> Thank you
>
> Kinnari
>
> *From:*Ramki Ramakrishna [mailto:y.s.ramakrishna at oracle.com]
> *Sent:* Wednesday, August 03, 2011 2:36 PM
> *To:* Darji, Kinnari [ICG-IT]
> *Cc:* hotspot-gc-use at openjdk.java.net
> *Subject:* Re: understanding GC logs
>
>
>
> 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 
> <mailto: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/0ab25d9b/attachment-0001.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