Bug ID: JDK-6886024 G1: assert(recent_avg_pause_time

Versions (Unresolved/Resolved/Fixed)

The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.

JDK 6	JDK 7	Other
6u18Fixed	7Fixed	hs16Fixed

Here's an example log of the failure:-

http://sqeweb.sfbay.sun.com/nfs/results/vm/gtee/JDK7/NIGHTLY/VM/2009-09-24/G1_GC_Baseline/vm/linux-amd64/server/mixed/linux-amd64_server_mixed_nsk.sysdict.testlist/ResultDir/btree010//hs_err_pid17091.log

In particular:-

VM Arguments:
jvm_args: -Xmixed -XX:-UseCompressedOops -XX:-PrintVMOptions -XX:+UnlockExperimentalVMOptions -XX:+UseG1GC -XX:-UseGCOverheadLimit 
java_command: nsk.sysdict.vm.stress.btree.btree010 5 default /export/local/common/testbase/6/vm/vm/bin/jars/nsk/sysdict/share/btree.jar -waittime=5


Failing tests are:-

nsk.sysdict.vm.stress.btree.btree010
<fill in more>

EVALUATION http://hg.openjdk.java.net/hsx/hsx16/master/rev/e3c995ac8078
13-11-2009
EVALUATION http://hg.openjdk.java.net/hsx/hsx16/baseline/rev/e3c995ac8078
12-11-2009
EVALUATION http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/fc06cd9b42c7
23-10-2009
EVALUATION As I thought, it turns out that the ratio is becoming 1.0 for this particular benchmark (on some machines, the Full GC overhead is way too high). So, the assert is actually incorrect. BTW, I can also reproduce it on Solaris.
18-10-2009
EVALUATION I ran it on a Solaris box (as this is what I have available) and I could not reproduce the crash. However, I looked at the GC log. Here's a fragment (I attached the whole log on the CR): 259.918: [Full GC 1270M->1270M(2016M), 0.6834017 secs] 260.602: [Full GC 1270M->1270M(2016M), 0.6742673 secs] 261.277: [Full GC 1270M->1270M(2016M), 0.6316673 secs] 261.909: [Full GC 1270M->1270M(2016M), 0.6753306 secs] 262.586: [Full GC 1270M->1270M(2016M), 0.6734719 secs] So, it looks to me that the execution IS full of full GCs. So, if the floating point value goes mildly over 1.0 or gettimeofday is slightly incorrect, I can see how this guarantee would fire.
08-10-2009

Relates :	JDK-6902692 - G1: g1CollectorPolicy.cpp:1533, assert(false,"Debugging data for CR 6898948 has been dumped above")
Relates :	JDK-6898948 - G1: forensic instrumentation for out-of-bounds recent_avg_pause_time_ratio()
Relates :	JDK-6902701 - G1: protect debugging code related to 6898948 with a debug flag
Relates :	JDK-6894378 - Introduce better utilities to manipulate floating point values