JDK-8020692 : G1: TestGCEventMixed.java failed because of timestamp in event after end event
  • Type: Bug
  • Component: hotspot
  • Sub-Component: gc
  • Affected Version: hs25
  • Priority: P3
  • Status: Resolved
  • Resolution: Fixed
  • OS: windows
  • CPU: x86
  • Submitted: 2013-07-17
  • Updated: 2013-09-18
  • Resolved: 2013-09-04
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 8 Other
8Fixed hs25Fixed
Description
The test failed in Promotion testing for JDK8-b99 (2013-07-13), this failure mode has not been seen before.

java.lang.AssertionError: Assertion failed: 4444392 <= 4444390 : Timestamp in event after end event
	at jrockit.Asserts.assertion(Asserts.java:33)
	at jrockit.Asserts.assertLessOrEqualThan(Asserts.java:66)
	at GCEventAll.verifySingleGcBatch(GCEventAll.java:348)
	at GCEventAll.verify(GCEventAll.java:155)
	at GCEventAll.doSingleTest(GCEventAll.java:106)
	at TestGCEventMixed.main(TestGCEventMixed.java:37)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:491)
	at com.sun.javatest.regtest.MainWrapper$MainThread.run(MainWrapper.java:94)
	at java.lang.Thread.run(Thread.java:724)
Collector(G1Old) ignores error: Assertion failed: 6 = 5 : Wrong number of collections for collector G1Old
EventCounts:
CollectionSummary: young.collections=9, young.time=72742, old.collections=6, old.time=347702, collectors=(SerialOld, G1Old, G1New)
BeanCounts:
CollectionSummary: young.collections=9, young.time=24000, old.collections=5, old.time=116000, collectors=(G1 Young Generation, G1 Old Generation)
java.lang.AssertionError: Assertion failed: 4444392 <= 4444390 : Timestamp in event after end event
	at jrockit.Asserts.assertion(Asserts.java:33)
	at jrockit.Asserts.assertLessOrEqualThan(Asserts.java:66)
	at GCEventAll.verifySingleGcBatch(GCEventAll.java:348)
	at GCEventAll.verify(GCEventAll.java:155)
	at GCEventAll.doSingleTest(GCEventAll.java:106)
	at TestGCEventMixed.main(TestGCEventMixed.java:37)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:491)
	at com.sun.javatest.regtest.MainWrapper$MainThread.run(MainWrapper.java:94)
	at java.lang.Thread.run(Thread.java:724)

JavaTest Message: Test threw exception: java.lang.AssertionError: Assertion failed: 4444392 <= 4444390 : Timestamp in event after end event
JavaTest Message: shutting down test

There is a flight recording in the results dir.

Priority justification: 
ILW = MMH => P3

Link to failure: http://vmsqe-app.russia.sun.com/surl/0V

Link to test history: http://vmsqe-app.russia.sun.com/surl/0W

Matching rule:
RULE closed/com/oracle/jfr/gc/TestGCEventMixed.java Exception java.lang.AssertionError: Assertion failed: ... <= ... : Timestamp in event after end event

Comments
Attached xml version of recording
21-08-2013

Attached the original recording
21-08-2013

Not a fasttime issue, but the ConcurrentModeFailure event looks fishy. For some reason, it is only partially printed: Concurrent Mode Failure@4444392 = 6 I have attached the recording as recording.txt
09-08-2013