Time stopped is much longer than corresponding Full GC
Alex Aisinzon
aaisinzon at guidewire.com
Fri Mar 27 15:57:15 PDT 2009
Hi Ramki
I thank you for the feedback and help.
I have a few more questions/points before I go execute this plan:
You listed trying the latest 5uXX and OpenJDK 7. You did not list 6uXX,
any reason why? Futhermore, is OpenJDK 7 stable enough that it will
likely go through the 8 hours high load that I run when I reproduce
these issues.
The application should not include any JNI/native code.
The load is very repeatable. Aside from the different JVM tunings (64
bit used 6GB of heap while 32 bit used 2.5GB), there is really not much
of a difference between the runs. Furthermore, I have run several 32 bit
and 64 bit runs. The issue never occurred on 32 bit and did several
times through the runs on 64 bit.
Regards
Alex A
-----Original Message-----
From: Y.S.Ramakrishna at Sun.COM [mailto:Y.S.Ramakrishna at Sun.COM]
Sent: Friday, March 27, 2009 9:53 AM
To: Alex Aisinzon
Cc: hotspot-gc-use at openjdk.java.net;
hotspot-runtime-dev at openjdk.java.net
Subject: Re: Time stopped is much longer than corresponding Full GC
Hi Alex --
The bug tracking system informs me that 6546278 was fixed in 5u14
which you appear to be using here. This could be a different
problem or an aspect of the original problem that was somehow
not addressed by the fix in 6546278. I am cc'ing you over to the
hotspot-runtime-dev alias where the necessary expertise exists
to address this issue. I suggest of course checking if you can
reproduce this problem with the latest 5uXX, as well as, if possible,
the latest OpenJDK 7 JVM. In either event (i.e. if you can
reproduce the problem with either of the latest jvm's listed)
please file a bug with Sun, preferably through your official support
channels for quickest resolution especially when older JDK versions
are involved.
The following additional information may be useful:
(1) the additional JVM option -XX:+PrintSafepointStatistics
for more visibility into the issue
(2) whether you have lots of native/JNI code in your application.
(3) It is interesting (and puzzling) that you see the issue only
with the 64-bit JVM. Are all other factors equivalent between your
32 and 64-bit tests?
thanks.
-- ramki
On 03/27/09 09:32, Alex Aisinzon wrote:
> Hi all
>
>
>
> I am running tests with Sun JDK 1.5_14 32 and 64 bits. I am using
> ParallelGC with 2 threads on a Dual Core Opteron 280.
>
> On the 64 bit one, I see instances whereby the pause times, as
reported
> by the "Total time for which application threads were stopped:" is
much
> longer than the time reported for the full GC.
>
>
>
> Here is an example of this:
>
>
>
> /{Heap before gc invocations=3693:/
>
> / PSYoungGen total 2021952K, used 55892K [0x00002aabbf130000,
> 0x00002aac3f130000, 0x00002aac3f130000)/
>
> / eden space 1949248K, 0% used
> [0x00002aabbf130000,0x00002aabbf130000,0x00002aac360c0000)/
>
> / from space 72704K, 76% used
> [0x00002aac3a7a0000,0x00002aac3de353b0,0x00002aac3eea0000)/
>
> / to space 72576K, 0% used
> [0x00002aac360c0000,0x00002aac360c0000,0x00002aac3a7a0000)/
>
> / PSOldGen total 4194304K, used 4144351K [0x00002aaabf130000,
> 0x00002aabbf130000, 0x00002aabbf130000)/
>
> / object space 4194304K, 98% used
> [0x00002aaabf130000,0x00002aabbc067c20,0x00002aabbf130000)/
>
> / PSPermGen total 204800K, used 122025K [0x00002aaab2930000,
> 0x00002aaabf130000, 0x00002aaabf130000)/
>
> / object space 204800K, 59% used
> [0x00002aaab2930000,0x00002aaaba05a578,0x00002aaabf130000)/
>
> /29132.202: [Full GC [PSYoungGen: 55892K->0K(2021952K)] [PSOldGen:
> 4144351K->2185260K(4194304K)] 4200243K->2185260K(6216256K) [PSPermGen:
> 122025K->122025K(204800K)], 7.8002190 secs]/
>
> /Heap after gc invocations=3693:/
>
> / PSYoungGen total 2021952K, used 0K [0x00002aabbf130000,
> 0x00002aac3f130000, 0x00002aac3f130000)/
>
> / eden space 1949248K, 0% used
> [0x00002aabbf130000,0x00002aabbf130000,0x00002aac360c0000)/
>
> / from space 72704K, 0% used
> [0x00002aac3a7a0000,0x00002aac3a7a0000,0x00002aac3eea0000)/
>
> / to space 72576K, 0% used
> [0x00002aac360c0000,0x00002aac360c0000,0x00002aac3a7a0000)/
>
> / PSOldGen total 4194304K, used 2185260K [0x00002aaabf130000,
> 0x00002aabbf130000, 0x00002aabbf130000)/
>
> / object space 4194304K, 52% used
> [0x00002aaabf130000,0x00002aab4473b2a8,0x00002aabbf130000)/
>
> / PSPermGen total 204800K, used 122025K [0x00002aaab2930000,
> 0x00002aaabf130000, 0x00002aaabf130000)/
>
> / object space 204800K, 59% used
> [0x00002aaab2930000,0x00002aaaba05a578,0x00002aaabf130000)/
>
> /}/
>
> /Total time for which application threads were stopped: 15.2489360
seconds/
>
> /Application time: 7.2144290 seconds/
>
>
>
>
>
> I checked on the web and see descriptions of very similar behaviors:
>
> * http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6477891
> * http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6546278
>
>
>
> It remains unclear whether this is fixed in a later release of Sun JDK
1.5.
>
> If it is indeed the "
>
<http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6546278>Synchronizat
ion
> problem in the pseudo memory barrier code". It may be fixed on JDK
1.7:
> http://download.java.net/jdk7/changes/jdk7-b15.html
>
>
>
> Our application is currently supported on Sun JDK 1.5 so Sun JDK 1.6
and
> 1.7, when available, do not constitute good options.
>
> Should I try to upgrade to the latest of Sun JDK 1.5 or are there
> "switches" that could make this go away, without sacrificing
performance.
>
> The thing that surprises me most is that is, so far, it occurs only on
> the 64 bit JVM version.
>
>
>
> Thanks for letting me know
>
>
>
> Alex Aisinzon
>
>
>
>
>
------------------------------------------------------------------------
>
> _______________________________________________
> 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-use
mailing list