JDK-8139237 : java/util/concurrent/ThreadPoolExecutor/ConfigChanges.java fails intermittently
  • Type: Bug
  • Component: core-libs
  • Sub-Component: java.util.concurrent
  • Affected Version: 9
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2015-10-09
  • Updated: 2017-03-21
  • Resolved: 2016-09-12
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 9
9 b136Fixed
Related Reports
Relates :  
JDK-8144880 - Instrument intermittently failing test ConfigChanges.java
Relates :  
JDK-8177313 - Move FJExceptionTableLeak.java and ConfigChanges.java back to tier1
Relates :  
JDK-8169243 - java/util/concurrent/ThreadPoolExecutor/ConfigChanges.java still fails intermittently
Description
java/util/concurrent/ThreadPoolExecutor/ConfigChanges.java fails intermittently

#section:main
----------messages:(3/121)----------
command: main ConfigChanges
reason: User specified action: run main/othervm ConfigChanges 
elapsed time (seconds): 0.605
----------System.out:(4/45)----------
22 not equal to 21

Passed = 32, failed = 1

----------System.err:(26/1446)----------
java.lang.Exception: Stack trace
	at java.lang.Thread.dumpStack(Thread.java:1335)
	at ConfigChanges.fail(ConfigChanges.java:233)
	at ConfigChanges.fail(ConfigChanges.java:234)
	at ConfigChanges.equal(ConfigChanges.java:239)
	at ConfigChanges.realMain(ConfigChanges.java:202)
	at ConfigChanges.main(ConfigChanges.java:241)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:519)
	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:92)
	at java.lang.Thread.run(Thread.java:746)
java.lang.AssertionError: Some tests failed
	at ConfigChanges.main(ConfigChanges.java:243)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:519)
	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:92)
	at java.lang.Thread.run(Thread.java:746)

JavaTest Message: Test threw exception: java.lang.AssertionError: Some tests failed
JavaTest Message: shutting down test

STATUS:Failed.`main' threw exception: java.lang.AssertionError: Some tests failed
Comments
Observed failure (one time) on linux, new bug filed: JDK-8169243
04-11-2016
Thanks for taking a look Martin. Let's see if we get another failure - and on which platform... For the record that was the first time I saw this test failing (in recent months) - so I suspect it's quite infrequent.
18-10-2016
I investigated the most recent failure on windows, and can't find a root cause, so am falling back to "blaming windows time", like maybe System.nanoTime is not monotonic.
18-10-2016
I never see this test fail, but I made changes to make it more robust. The test failure seen by Daniel seems new. Might be a "windows time" problem, or an actual bug. Go ahead and file another bug.
17-10-2016
I saw this test fail again today on a windows x64 machine (jdk9/dev/jdk tip 15833:8d752af5f61d): ACTION: main -- Failed. Execution failed: `main' threw exception: java.lang.AssertionError: Some tests failed REASON: User specified action: run main/othervm ConfigChanges TIME: 0.314 seconds messages: command: main ConfigChanges reason: User specified action: run main/othervm ConfigChanges Mode: othervm [/othervm specified] elapsed time (seconds): 0.314 configuration: STDOUT: Seed from RandomFactory = -5132845571049384108L Passed = 44, failed = 1 STDERR: java.lang.Exception: Stack trace at java.lang.Thread.dumpStack(java.base@9-internal/Thread.java:1434) at ConfigChanges.fail(ConfigChanges.java:263) at ConfigChanges.check(ConfigChanges.java:266) at ConfigChanges.realMain(ConfigChanges.java:250) at ConfigChanges.main(ConfigChanges.java:271) at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@9-internal/Native Method) at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@9-internal/NativeMethodAccessorImpl.java:62) at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@9-internal/DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(java.base@9-internal/Method.java:535) at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:110) at java.lang.Thread.run(java.base@9-internal/Thread.java:843) java.lang.AssertionError: Some tests failed at ConfigChanges.main(ConfigChanges.java:273) at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@9-internal/Native Method) at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@9-internal/NativeMethodAccessorImpl.java:62) at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@9-internal/DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(java.base@9-internal/Method.java:535) at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:110) at java.lang.Thread.run(java.base@9-internal/Thread.java:843) JavaTest Message: Test threw exception: java.lang.AssertionError: Some tests failed JavaTest Message: shutting down test STATUS:Failed.`main' threw exception: java.lang.AssertionError: Some tests failed Is it worth logging a new issue?
17-10-2016
Not sure why I never see this in practice, but with the last bit of info from Amy I can explain the problem - before a worker gives up the lock (becomes "idle") it increments the completed task count non-atomically, in which case it may get counted twice by getCompletedTaskCount. There doesn't seem to be a completely reliable way to wait for a thread pool to become quiescent, but we can compensate.
31-08-2016
All recent failures are from same line: at ConfigChanges.realMain(ConfigChanges.java:214) --> line 214: equal(tpe.getTaskCount(), 7L*n);
21-07-2016
This failed recently on Mach 5, http://java.se.oracle.com/mach5/view/9-dev-test/job/9-dev-tier1-windows-x64/1869/artifact/JTwork/jdk_test/java/util/concurrent/ThreadPoolExecutor/ConfigChanges.jtr/*view*/ It's the only failure in the past 100 runs.
09-11-2015
I don't have a plan for fixing this, but I'm the original author and probably a better choice of assignee than Chris. Take ownership back if you want.
09-10-2015
I think I've seen this test fail just once recently, out of about 100,000 runs.
09-10-2015