PrintSafepointStatistics (was Re: understanding GC logs)
Y. S. Ramakrishna
y.s.ramakrishna at oracle.com
Thu Aug 4 17:12:20 UTC 2011
Hi Kinnari --
On 08/04/11 08:01, Darji, Kinnari wrote:
> Hi Ramki,
>
> I am running jdk-1.6.0_16 and Java HotSpot(TM) 64-Bit Server VM (build
> 14.2-b01, mixed mode). I can’t change JDK version. Is there any other
> way to have this info printed on GC logs with this JDK version?
I'll get you in touch, off-list, with support folk so they can help open a service
ticket based on your support contract for the older JDK.
As regards having this kind of info printed without recourse to +PrintSafepointStatistics,
try -XX:+PrintGCApplicationStoppedTime and -XX:+PrintGCApplicationConcurrentTime,
which should give you the times you want, albeit with none of the finer
details that +PrintSafepointStatistics would have provided you.
Here's a description of those flags from globals.hpp:-
product(bool, PrintGCApplicationConcurrentTime, false, \
"Print the time the application has been running") \
\
product(bool, PrintGCApplicationStoppedTime, false, \
"Print the time the application has been stopped") \
\
(... basically between safepoints, or at safepoints respectively).
As regards:
>
>
>
> Attaching error file..
As I understood you were getting a JVM crash when you used
+PrintSafepointStatistics with 6u16. In that case, the JVM would
typically dump a file named hs_err_<pid>.log in the $CWD of
your invoking shell. That's what the support folks would
want (along with the core file may be in some cases).
Please send the hs_err_*.log file so I can provide
that to the support folk.
It is possible that someone on the runtime list
might already recognize this problem as one that
has since been fixed.
-- ramki
>
>
>
> Thank you
>
> Kinnari
>
>
>
> *From:* Ramki Ramakrishna [mailto:y.s.ramakrishna at oracle.com]
> *Sent:* Wednesday, August 03, 2011 5:48 PM
> *To:* Darji, Kinnari [ICG-IT]
> *Cc:* 'hotspot-gc-use at openjdk.java.net';
> hotspot-runtime-dev at openjdk.java.net
> *Subject:* PrintSafepointStatistics (was Re: understanding GC logs)
>
>
>
> 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 <mailto: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
> <mailto: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
>
_______________________________________________
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