JDK-8201603 : MonitorContendedEnter failure in nsk/jvmti/scenarios/contention/TC02/tc02t001
  • Type: Bug
  • Component: hotspot
  • Sub-Component: jvmti
  • Affected Version: 11
  • Priority: P3
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2018-04-16
  • Updated: 2019-06-20
  • Resolved: 2018-10-09
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 12
12 b15Fixed
Related Reports
Relates :  
JDK-8224555 - vmTestbase/nsk/jvmti/scenarios/contention/TC02/tc02t001/TestDescription.java failed
Relates :  
JDK-8036026 - nsk/jvmti/scenarios/capability/CM02/cm02t001 fails intermittently
Description
Test: nsk/jvmti/scenarios/contention/TC02/tc02t001 

[2018-04-13T05:59:11.09] Started recording 1. No limit specified, using maxsize=250MB as default.
[2018-04-13T05:59:11.09] 
[2018-04-13T05:59:11.09] Use JFR.dump name=1 filename=FILEPATH to copy recording data to file.
[2018-04-13T05:59:11.58] The following fake exception stacktrace is for failuire analysis. 
[2018-04-13T05:59:11.58] nsk.share.Fake_Exception_for_RULE_Creation: (tc02t001.c:112) line == lines[enterEventsCount] || line == (lines[enterEventsCount] + 1)
[2018-04-13T05:59:11.58] 	at nsk_lvcomplain(nsk_tools.c:156)
[2018-04-13T05:59:11.58] # ERROR: tc02t001.c, 112: line == lines[enterEventsCount] || line == (lines[enterEventsCount] + 1)
[2018-04-13T05:59:11.58] #   verified assertion is FALSE
[2018-04-13T05:59:11.58] # ERROR: tc02t001.c, 115: MonitorContendedEnter event: thread=0000005845DC0AD8, object=0000005845DC0AE0, line=117
[2018-04-13T05:59:11.69] # ERROR: tc02t001.c, 156: line == lines[enteredEventsCount] || line == (lines[enteredEventsCount] + 1)
[2018-04-13T05:59:11.69] #   verified assertion is FALSE
[2018-04-13T05:59:11.69] # ERROR: tc02t001.c, 159: MonitorContendedEntered event: thread=0000005845DC0AD8, object=0000005845DC0AE0, line=117
[2018-04-13T05:59:11.69] # ERROR: tc02t001.c, 112: line == lines[enterEventsCount] || line == (lines[enterEventsCount] + 1)
[2018-04-13T05:59:11.69] #   verified assertion is FALSE
[2018-04-13T05:59:11.69] # ERROR: tc02t001.c, 115: MonitorContendedEnter event: thread=0000005845DC0AD8, object=0000005845DC0AE0, line=122
[2018-04-13T05:59:11.79] # ERROR: tc02t001.c, 156: line == lines[enteredEventsCount] || line == (lines[enteredEventsCount] + 1)
[2018-04-13T05:59:11.79] #   verified assertion is FALSE
[2018-04-13T05:59:11.80] # ERROR: tc02t001.c, 159: MonitorContendedEntered event: thread=0000005845DC0AD8, object=0000005845DC0AE0, line=122
[2018-04-13T05:59:11.80] # ERROR: tc02t001.c, 295: enterEventsCount == 3
[2018-04-13T05:59:11.80] #   verified assertion is FALSE
[2018-04-13T05:59:11.80] # ERROR: tc02t001.c, 302: enteredEventsCount == 3
[2018-04-13T05:59:11.80] #   verified assertion is FALSE
[2018-04-13T05:59:12.14] # Test level exit status: 97
Comments
New theory of what is going wrong here. I think the test is properly synced up between the agent initialization and the start of Java code processing. But we are seeing a similar issue to cm02t001. The main thread uses a sleep(100) while holding the lock "synchronized(M)". If the debuggee thread is not scheduled quickly enough the main thread releases the lock when it calls "M.wait(5 mins)" Increasing the pause time "sleep(1000)" should allow the expected contended sync to be provoked as expected.
04-10-2018
Here is a failed log with nsk verbose messages enabled. The first MonitorContenedEnter should be at line 128. I suspect that the agent initialization (agentProc call to prepare()) has not completed by the time the main thread launches the test thread. The test may have executed past the first monitor contended location before the events are enabled, lines 263-273 in tc02t001.cpp. - tc02t001.cpp, 357: Timeout: 300000 msc - tc02t001.cpp, 194: Prepare: find tested thread - tc02t001.cpp, 214: thread #0 (main): 100dbb918 - tc02t001.cpp, 214: thread #1 (Reference Handler): 100dbb920 - tc02t001.cpp, 214: thread #2 (Finalizer): 100dbb928 - tc02t001.cpp, 214: thread #3 (Signal Dispatcher): 100dbb930 - tc02t001.cpp, 214: thread #4 (Common-Cleaner): 100dbb938 - tc02t001.cpp, 214: thread #5 (MainThread): 100dbb940 - tc02t001.cpp, 214: thread #6 (Debuggee Thread): 100dbb948 - tc02t001.cpp, 214: thread #7 (JVMTI agent thread): 100dbb950 - tc02t001.cpp, 122: MonitorContendedEnter event: thread=100dc9658, object=100dc9660, line=133 The following fake exception stacktrace is for failuire analysis. nsk.share.Fake_Exception_for_RULE_Creation: (tc02t001.cpp:128) line == lines[enterEventsCount] || line == (lines[enterEventsCount] + 1) at nsk_lvcomplain(nsk_tools.cpp:172) # ERROR: tc02t001.cpp, 128: line == lines[enterEventsCount] || line == (lines[enterEventsCount] + 1) # verified assertion is FALSE # ERROR: tc02t001.cpp, 131: MonitorContendedEnter event: thread=100dc9658, object=100dc9660, line=133 - tc02t001.cpp, 166: MonitorContendedEntered event: thread=100dc9658, object=100dc9660, line=133 # ERROR: tc02t001.cpp, 172: line == lines[enteredEventsCount] || line == (lines[enteredEventsCount] + 1) # verified assertion is FALSE # ERROR: tc02t001.cpp, 175: MonitorContendedEntered event: thread=100dc9658, object=100dc9660, line=133 - tc02t001.cpp, 122: MonitorContendedEnter event: thread=100dc9658, object=100dc9660, line=138 # ERROR: tc02t001.cpp, 128: line == lines[enterEventsCount] || line == (lines[enterEventsCount] + 1) # verified assertion is FALSE # ERROR: tc02t001.cpp, 131: MonitorContendedEnter event: thread=100dc9658, object=100dc9660, line=138 - tc02t001.cpp, 166: MonitorContendedEntered event: thread=100dc9658, object=100dc9660, line=138 # ERROR: tc02t001.cpp, 172: line == lines[enteredEventsCount] || line == (lines[enteredEventsCount] + 1) # verified assertion is FALSE # ERROR: tc02t001.cpp, 175: MonitorContendedEntered event: thread=100dc9658, object=100dc9660, line=138 - tc02t001.cpp, 309: Number of MonitorContendedEnter events: 2 # ERROR: tc02t001.cpp, 311: enterEventsCount == 3 # verified assertion is FALSE - tc02t001.cpp, 316: Number of MonitorContendedEntered events: 2 # ERROR: tc02t001.cpp, 318: enteredEventsCount == 3 # verified assertion is FALSE
01-10-2018
Re-targeted this issue to tbd_major.
08-06-2018
No. I'm not sure why George assigned this one to me.
08-06-2018
Hi Dan, Are you really working on this one? Does it make sense to move this to 12?
29-05-2018
Moving from hotspot/runtime -> hotspot/jvmti since this is a JVM/TI test.
17-04-2018