JDK-8076626 : stream StreamSpliteratorTest.java timeout
  • Type: Bug
  • Component: core-libs
  • Sub-Component: java.util.stream
  • Affected Version: 9
  • Priority: P2
  • Status: Resolved
  • Resolution: Duplicate
  • Submitted: 2015-04-03
  • Updated: 2015-04-23
  • Resolved: 2015-04-23
Related Reports
Duplicate :  
JDK-8077392 - Stream fork/join tasks occasionally fail to complete
Relates :  
JDK-8076458 - java/util/stream/test/org/openjdk/tests/java/util/stream/FlatMapOpTest.java timeout
Description
java/util/stream/test/org/openjdk/tests/java/util/stream/StreamSpliteratorTest.java

Test fail due to time out in different runs, at different machine.

Here's one failure example, run on a powerful Linux (8 cores 32 processors, 256G mem) with jtreg options:
-agentvm -a -ea -esa -timeoutFactor:8 -J-Xmx512m -vmoption:-Xmx512m -conc:8

#section:build
----------messages:(3/3266)----------
... ...
elapsed time (seconds): 0.005
... ...
#section:testng
----------messages:(204/11088)----------
command: testng org.openjdk.tests.java.util.stream.StreamSpliteratorTest
reason: Assumed action based on file name: run testng org.openjdk.tests.java.util.stream.StreamSpliteratorTest 
Timeout information:
Running jstack on process 9570
2015-04-03 01:19:16
Full thread dump OpenJDK 64-Bit Server VM (1.9.0-... mixed mode):

"Attach Listener" #55 daemon prio=9 os_prio=0 tid=0x00007f5928001000 nid=0x295e waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"ForkJoinPool.commonPool-worker-6" #45 daemon prio=5 os_prio=0 tid=0x00007f58a0001000 nid=0x25ad waiting on condition [0x00007f5987dfc000]
   java.lang.Thread.State: TIMED_WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000000e0010530> (a java.util.concurrent.ForkJoinPool)
	at java.util.concurrent.ForkJoinPool.awaitWork(ForkJoinPool.java:1826)
	at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1695)
	at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157)

"MainThread" #23 prio=5 os_prio=0 tid=0x00007f59d4151000 nid=0x2595 in Object.wait() [0x00007f598d64c000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at java.lang.Object.wait(Native Method)
	at java.util.concurrent.ForkJoinTask.externalAwaitDone(ForkJoinTask.java:334)
	- locked <0x00000000f680be28> (a java.util.stream.Nodes$CollectorTask$OfRef)
	at java.util.concurrent.ForkJoinTask.doInvoke(ForkJoinTask.java:405)
	at java.util.concurrent.ForkJoinTask.invoke(ForkJoinTask.java:734)
	at java.util.stream.Nodes.collect(Nodes.java:328)
	at java.util.stream.ReferencePipeline.evaluateToNode(ReferencePipeline.java:109)
	at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:564)
	at java.util.stream.SortedOps$OfRef.opEvaluateParallel(SortedOps.java:157)
	at java.util.stream.AbstractPipeline.opEvaluateParallelLazy(AbstractPipeline.java:728)
	at java.util.stream.AbstractPipeline.sourceSpliterator(AbstractPipeline.java:455)
	at java.util.stream.AbstractPipeline.lambda$spliterator$0(AbstractPipeline.java:360)
	at java.util.stream.AbstractPipeline$$Lambda$71/140072543.get(Unknown Source)
	at java.util.stream.StreamSpliterators$AbstractWrappingSpliterator.init(StreamSpliterators.java:142)
	at java.util.stream.StreamSpliterators$AbstractWrappingSpliterator.characteristics(StreamSpliterators.java:237)
	at java.util.Spliterator.hasCharacteristics(Spliterator.java:447)
	at java.util.stream.SpliteratorTestHelper.assertSpliterator(SpliteratorTestHelper.java:580)
	at java.util.stream.SpliteratorTestHelper.testSplitSixDeep(SpliteratorTestHelper.java:395)
	at java.util.stream.SpliteratorTestHelper.testSpliterator(SpliteratorTestHelper.java:166)
	at java.util.stream.SpliteratorTestHelper.testSpliterator(SpliteratorTestHelper.java:65)
	at java.util.stream.SpliteratorTestHelper.testSpliterator(SpliteratorTestHelper.java:60)
	at org.openjdk.tests.java.util.stream.StreamSpliteratorTest.testParSpliterators(StreamSpliteratorTest.java:316)
	at sun.reflect.GeneratedMethodAccessor16.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:502)
	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:84)
	at org.testng.internal.Invoker.invokeMethod(Invoker.java:714)
	at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:901)
	at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1231)
	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:127)
	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:111)
	at org.testng.TestRunner.privateRun(TestRunner.java:767)
	at org.testng.TestRunner.run(TestRunner.java:617)
	at org.testng.SuiteRunner.runTest(SuiteRunner.java:334)
	at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:329)
	at org.testng.SuiteRunner.privateRun(SuiteRunner.java:291)
	at org.testng.SuiteRunner.run(SuiteRunner.java:240)
	at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
	at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:86)
	at org.testng.TestNG.runSuitesSequentially(TestNG.java:1224)
	at org.testng.TestNG.runSuitesLocally(TestNG.java:1149)
	at org.testng.TestNG.run(TestNG.java:1057)
	at com.sun.javatest.regtest.TestNGAction$TestNGRunner.main(TestNGAction.java:163)
	at com.sun.javatest.regtest.TestNGAction$TestNGRunner.main(TestNGAction.java:147)
	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:502)
	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:92)
	at java.lang.Thread.run(Thread.java:745)

"Service Thread" #21 daemon prio=9 os_prio=0 tid=0x00007f59d40ff000 nid=0x2593 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Sweeper thread" #20 daemon prio=9 os_prio=0 tid=0x00007f59d40f2800 nid=0x2592 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C1 CompilerThread14" #19 daemon prio=9 os_prio=0 tid=0x00007f59d40f0800 nid=0x2591 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C1 CompilerThread13" #18 daemon prio=9 os_prio=0 tid=0x00007f59d40ee800 nid=0x258f waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C1 CompilerThread12" #17 daemon prio=9 os_prio=0 tid=0x00007f59d40ec800 nid=0x258e waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C1 CompilerThread11" #16 daemon prio=9 os_prio=0 tid=0x00007f59d40ea800 nid=0x258d waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C1 CompilerThread10" #15 daemon prio=9 os_prio=0 tid=0x00007f59d40e8800 nid=0x258c waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread9" #14 daemon prio=9 os_prio=0 tid=0x00007f59d40e6000 nid=0x258b waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread8" #13 daemon prio=9 os_prio=0 tid=0x00007f59d40e4000 nid=0x258a waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread7" #12 daemon prio=9 os_prio=0 tid=0x00007f59d40e2000 nid=0x2589 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread6" #11 daemon prio=9 os_prio=0 tid=0x00007f59d40e0000 nid=0x2588 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread5" #10 daemon prio=9 os_prio=0 tid=0x00007f59d40de000 nid=0x2587 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread4" #9 daemon prio=9 os_prio=0 tid=0x00007f59d40d4000 nid=0x2586 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread3" #8 daemon prio=9 os_prio=0 tid=0x00007f59d40d1800 nid=0x2585 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread2" #7 daemon prio=9 os_prio=0 tid=0x00007f59d40d0000 nid=0x2584 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" #6 daemon prio=9 os_prio=0 tid=0x00007f59d40cd000 nid=0x2583 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #5 daemon prio=9 os_prio=0 tid=0x00007f59d40c7000 nid=0x2582 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" #4 daemon prio=9 os_prio=0 tid=0x00007f59d40b5000 nid=0x2581 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007f59d409b000 nid=0x2580 in Object.wait() [0x00007f598eeed000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
	- locked <0x00000000e0040c10> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
	at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:212)

"Reference Handler" #2 daemon prio=10 os_prio=0 tid=0x00007f59d4097000 nid=0x257f in Object.wait() [0x00007f598efee000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	at java.lang.Object.wait(Object.java:508)
	at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
	- locked <0x00000000e0048788> (a java.lang.ref.Reference$Lock)
	at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)

"main" #1 prio=5 os_prio=0 tid=0x00007f59d4009000 nid=0x2565 in Object.wait() [0x00007f59daa03000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00000000e00290d0> (a java.lang.Thread)
	at java.lang.Thread.join(Thread.java:1249)
	- locked <0x00000000e00290d0> (a java.lang.Thread)
	at java.lang.Thread.join(Thread.java:1323)
	at com.sun.javatest.regtest.agent.MainWrapper.main(MainWrapper.java:69)

"VM Thread" os_prio=0 tid=0x00007f59d4090800 nid=0x257e runnable 

"ParGC Thread#0" os_prio=0 tid=0x00007f59d401e000 nid=0x2567 runnable 

"ParGC Thread#1" os_prio=0 tid=0x00007f59d4020000 nid=0x2568 runnable 

"ParGC Thread#2" os_prio=0 tid=0x00007f59d4021800 nid=0x2569 runnable 

"ParGC Thread#3" os_prio=0 tid=0x00007f59d4023800 nid=0x256a runnable 

"ParGC Thread#4" os_prio=0 tid=0x00007f59d4025000 nid=0x256b runnable 

"ParGC Thread#5" os_prio=0 tid=0x00007f59d4027000 nid=0x256c runnable 

"ParGC Thread#6" os_prio=0 tid=0x00007f59d4028800 nid=0x256d runnable 

"ParGC Thread#7" os_prio=0 tid=0x00007f59d402a800 nid=0x256e runnable 

"ParGC Thread#8" os_prio=0 tid=0x00007f59d402c000 nid=0x256f runnable 

"ParGC Thread#9" os_prio=0 tid=0x00007f59d402e000 nid=0x2570 runnable 

"ParGC Thread#10" os_prio=0 tid=0x00007f59d402f800 nid=0x2571 runnable 

"ParGC Thread#11" os_prio=0 tid=0x00007f59d4031800 nid=0x2572 runnable 

"ParGC Thread#12" os_prio=0 tid=0x00007f59d4033000 nid=0x2573 runnable 

"ParGC Thread#13" os_prio=0 tid=0x00007f59d4035000 nid=0x2574 runnable 

"ParGC Thread#14" os_prio=0 tid=0x00007f59d4036800 nid=0x2575 runnable 

"ParGC Thread#15" os_prio=0 tid=0x00007f59d4038800 nid=0x2576 runnable 

"ParGC Thread#16" os_prio=0 tid=0x00007f59d403a000 nid=0x2577 runnable 

"ParGC Thread#17" os_prio=0 tid=0x00007f59d403c000 nid=0x2578 runnable 

"ParGC Thread#18" os_prio=0 tid=0x00007f59d403d800 nid=0x2579 runnable 

"ParGC Thread#19" os_prio=0 tid=0x00007f59d403f800 nid=0x257a runnable 

"ParGC Thread#20" os_prio=0 tid=0x00007f59d4041000 nid=0x257b runnable 

"ParGC Thread#21" os_prio=0 tid=0x00007f59d4043000 nid=0x257c runnable 

"ParGC Thread#22" os_prio=0 tid=0x00007f59d4044800 nid=0x257d runnable 

"VM Periodic Task Thread" os_prio=0 tid=0x00007f59d4104800 nid=0x2594 waiting on condition 

JNI global references: 657

--- Timeout information end.
elapsed time (seconds): 1005.775
Comments
This test is timing out for the same reason as JDK-8077392
23-04-2015
I've attached the JTR file from the Mach 5 mac build #841. Oddly, this is dated 2015-03-30 -- two weeks old -- and there are several references to aurora in it. This seems suspicious; not sure what it means. But I'm attaching it before it's expired from Mach 5.
15-04-2015
I've attached the JTR file from the Mach 5 failure.
03-04-2015