akka-actor-tests fails - "Coroner not cancelled after 60000ms" #21375

chris-martin · 2016-09-06T05:04:04Z

When I run akka-actor-tests/test in SBT on the master branch, after a while I get the following output and then execution hangs indefinitely.

Am I doing something wrong? Are the tests just not working right now? Is there a CI server with the build status somewhere?

[info] - must support useResumeWriting==false (queue flushed) (1 second, 71 milliseconds)
[WARN] [09/06/2016 00:52:37.991] [TcpConnectionSpec-akka.actor.default-dispatcher-2] [akka://TcpConnectionSpec/deadLetters] received dead letter from Actor[akka://TcpConnectionSpec/s[198/590]
TCP/selectors/$a/1#-1570381649]: CommandFailed(Connect(0.0.0.0/0.0.0.0:23402,None,List(),None,false))
Coroner not cancelled after 60000ms. Looking for signs of foul play...
Coroner's Report: akka.io.TcpConnectionSpec
OS Architecture: amd64
Available processors: 4
System load (last minute): 1.04
VM start time: Tue Sep 06 00:30:40 EDT 2016
VM uptime: 1360065ms
Heap usage: init = 1073741824(1048576K) used = 663250784(647705K) committed = 1043857408(1019392K) max = 1043857408(1019392K)
Non-heap usage: init = 2555904(2496K) used = 139543680(136273K) committed = 144834560(141440K) max = 1476395008(1441792K)
All threads:
"Coroner" Id=675 RUNNABLE
        at sun.management.ThreadImpl.dumpThreads0(Native Method)
        at sun.management.ThreadImpl.dumpAllThreads(ThreadImpl.java:454)
        at akka.testkit.Coroner$.dumpAllThreads$1(Coroner.scala:139)
        at akka.testkit.Coroner$.printReport(Coroner.scala:230)
        at akka.testkit.Coroner$.akka$testkit$Coroner$$triggerReportIfOverdue$1(Coroner.scala:97)
        at akka.testkit.Coroner$$anon$1.run(Coroner.scala:113)
        at java.lang.Thread.run(Thread.java:745)


"Finalizer" Id=3 WAITING on java.lang.ref.ReferenceQueue$Lock@d86c33f
        at java.lang.Object.wait(Native Method)
        -  waiting on java.lang.ref.ReferenceQueue$Lock@d86c33f
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)


"Reference Handler" Id=2 WAITING on java.lang.ref.Reference$Lock@c6c73bb
        at java.lang.Object.wait(Native Method)
        -  waiting on java.lang.ref.Reference$Lock@c6c73bb
        at java.lang.Object.wait(Object.java:502)
        at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)


"ScalaTest-dispatcher" Id=223 WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@45746f49
        at sun.misc.Unsafe.park(Native Method)
        -  waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@45746f49
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
        at org.scalatest.LinkedBlockingQueue.take(JavaClassesWrappers.scala:43)
        at org.scalatest.DispatchReporter$Propagator.run(DispatchReporter.scala:160)
        at java.lang.Thread.run(Thread.java:745)

"Signal Dispatcher" Id=4 RUNNABLE


"TcpConnectionSpec-akka.actor.default-dispatcher-3" Id=670 WAITING on akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinPool@58c42833
        at sun.misc.Unsafe.park(Native Method)
        -  waiting on akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinPool@58c42833
        at scala.concurrent.forkjoin.ForkJoinPool.scan(ForkJoinPool.java:2075)
        at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)
        at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)


"TcpConnectionSpec-akka.actor.default-dispatcher-9" Id=685 TIMED_WAITING on akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinPool@58c42833
        at sun.misc.Unsafe.park(Native Method)
        -  waiting on akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinPool@58c42833
        at scala.concurrent.forkjoin.ForkJoinPool.idleAwaitWork(ForkJoinPool.java:2135)
        at scala.concurrent.forkjoin.ForkJoinPool.scan(ForkJoinPool.java:2067)
        at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)
        at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)


"TcpConnectionSpec-akka.io.pinned-dispatcher-8" Id=676 RUNNABLE (in native)
        at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
        at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
        -  locked sun.nio.ch.Util$2@5e70c388
        -  locked java.util.Collections$UnmodifiableSet@9c83e56
        -  locked sun.nio.ch.EPollSelectorImpl@643caaee
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:101)
        at akka.io.SelectionHandler$ChannelRegistryImpl$$anon$3.tryRun(SelectionHandler.scala:115)
        at akka.io.SelectionHandler$ChannelRegistryImpl$Task.run(SelectionHandler.scala:219)
        at akka.io.SelectionHandler$ChannelRegistryImpl$$anon$3.run(SelectionHandler.scala:148)
        at akka.util.SerializedSuspendableExecutionContext.run$1(SerializedSuspendableExecutionContext.scala:67)
        at akka.util.SerializedSuspendableExecutionContext.run(SerializedSuspendableExecutionContext.scala:71)
        at akka.dispatch.TaskInvocation.run(AbstractDispatcher.scala:39)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)

        Number of locked synchronizers = 1
        - java.util.concurrent.ThreadPoolExecutor$Worker@69bf2072

"TcpConnectionSpec-scheduler-1" Id=668 TIMED_WAITING
        at java.lang.Thread.sleep(Native Method)
        at akka.actor.LightArrayRevolverScheduler.waitNanos(LightArrayRevolverScheduler.scala:87)
        at akka.actor.LightArrayRevolverScheduler$$anon$4.nextTick(LightArrayRevolverScheduler.scala:268)
        at akka.actor.LightArrayRevolverScheduler$$anon$4.run(LightArrayRevolverScheduler.scala:238)
        at java.lang.Thread.run(Thread.java:745)


"Timer-0" Id=224 WAITING on java.util.TaskQueue@1d4093ea
        at java.lang.Object.wait(Native Method)
        -  waiting on java.util.TaskQueue@1d4093ea
        at java.lang.Object.wait(Object.java:502)
        at java.util.TimerThread.mainLoop(Timer.java:526)
        at java.util.TimerThread.run(Timer.java:505)

"main" Id=1 WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@152a7e1f                                                                                  [89/590]
        at sun.misc.Unsafe.park(Native Method)
        -  waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@152a7e1f
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
        at java.util.concurrent.ExecutorCompletionService.take(ExecutorCompletionService.java:193)
        at sbt.ConcurrentRestrictions$$anon$4.take(ConcurrentRestrictions.scala:188)
        at sbt.Execute.next$1(Execute.scala:85)
        at sbt.Execute.processAll(Execute.scala:88)
        at sbt.Execute.runKeep(Execute.scala:68)
        at sbt.EvaluateTask$.liftedTree1$1(EvaluateTask.scala:359)
        at sbt.EvaluateTask$.run$1(EvaluateTask.scala:358)
        at sbt.EvaluateTask$.runTask(EvaluateTask.scala:378)
        at sbt.Aggregation$$anonfun$3.apply(Aggregation.scala:64)
        at sbt.Aggregation$$anonfun$3.apply(Aggregation.scala:62)
        at sbt.EvaluateTask$.withStreams(EvaluateTask.scala:314)
        at sbt.Aggregation$.timedRun(Aggregation.scala:62)
        at sbt.Aggregation$.runTasks(Aggregation.scala:71)
        at sbt.Aggregation$$anonfun$applyTasks$1.apply(Aggregation.scala:32)
        at sbt.Aggregation$$anonfun$applyTasks$1.apply(Aggregation.scala:31)
        at sbt.Command$$anonfun$applyEffect$2$$anonfun$apply$3.apply(Command.scala:61)
        at sbt.Command$$anonfun$applyEffect$2$$anonfun$apply$3.apply(Command.scala:61)
        at sbt.Aggregation$$anonfun$evaluatingParser$4$$anonfun$apply$5.apply(Aggregation.scala:153)
        at sbt.Aggregation$$anonfun$evaluatingParser$4$$anonfun$apply$5.apply(Aggregation.scala:152)
        at sbt.Act$$anonfun$sbt$Act$$actParser0$1$$anonfun$sbt$Act$$anonfun$$evaluate$1$1$$anonfun$apply$10.apply(Act.scala:244)
        at sbt.Act$$anonfun$sbt$Act$$actParser0$1$$anonfun$sbt$Act$$anonfun$$evaluate$1$1$$anonfun$apply$10.apply(Act.scala:241)
        at sbt.Command$.process(Command.scala:93)
        at sbt.MainLoop$$anonfun$1$$anonfun$apply$1.apply(MainLoop.scala:96)
        at sbt.MainLoop$$anonfun$1$$anonfun$apply$1.apply(MainLoop.scala:96)
        at sbt.State$$anon$1.process(State.scala:184)
        at sbt.MainLoop$$anonfun$1.apply(MainLoop.scala:96)
        at sbt.MainLoop$$anonfun$1.apply(MainLoop.scala:96)
        at sbt.ErrorHandling$.wideConvert(ErrorHandling.scala:17)
        at sbt.MainLoop$.next(MainLoop.scala:96)
        at sbt.MainLoop$.run(MainLoop.scala:89)
        at sbt.MainLoop$$anonfun$runWithNewLog$1.apply(MainLoop.scala:68)
        at sbt.MainLoop$$anonfun$runWithNewLog$1.apply(MainLoop.scala:63)
        at sbt.Using.apply(Using.scala:24)
        at sbt.MainLoop$.runWithNewLog(MainLoop.scala:63)
        at sbt.MainLoop$.runAndClearLast(MainLoop.scala:46)
        at sbt.MainLoop$.runLoggedLoop(MainLoop.scala:30)
        at sbt.MainLoop$.runLogged(MainLoop.scala:22)
        at sbt.StandardMain$.runManaged(Main.scala:54)
        at sbt.xMain.run(Main.scala:29)
        at xsbt.boot.Launch$$anonfun$run$1.apply(Launch.scala:109)
        at xsbt.boot.Launch$.withContextLoader(Launch.scala:128)
        at xsbt.boot.Launch$.run(Launch.scala:109)
        at xsbt.boot.Launch$$anonfun$apply$1.apply(Launch.scala:35)
        at xsbt.boot.Launch$.launch(Launch.scala:117)
        at xsbt.boot.Launch$.apply(Launch.scala:18)
        at xsbt.boot.Boot$.runImpl(Boot.scala:41)
        at xsbt.boot.Boot$.main(Boot.scala:17)
        at xsbt.boot.Boot.main(Boot.scala)


"pool-42-thread-3-ScalaTest-running-TcpConnectionSpec" Id=221 RUNNABLE (in native)
        at java.net.PlainSocketImpl.socketAccept(Native Method)
        at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:409)
        at java.net.ServerSocket.implAccept(ServerSocket.java:545)
        at java.net.ServerSocket.accept(ServerSocket.java:513)
        at akka.io.TcpConnectionSpec$$anonfun$1$$anonfun$apply$mcV$sp$44.apply(TcpConnectionSpec.scala:837)
        at akka.io.TcpConnectionSpec$$anonfun$1$$anonfun$apply$mcV$sp$44.apply(TcpConnectionSpec.scala:826)
        at org.scalatest.OutcomeOf$class.outcomeOf(OutcomeOf.scala:85)
        at org.scalatest.OutcomeOf$.outcomeOf(OutcomeOf.scala:104)
        at org.scalatest.Transformer.apply(Transformer.scala:22)
        at org.scalatest.Transformer.apply(Transformer.scala:20)
        at org.scalatest.WordSpecLike$$anon$1.apply(WordSpecLike.scala:1078)
        at org.scalatest.TestSuite$class.withFixture(TestSuite.scala:196)
        at akka.testkit.AkkaSpec.withFixture(AkkaSpec.scala:57)
        at org.scalatest.WordSpecLike$class.invokeWithFixture$1(WordSpecLike.scala:1075)
        at org.scalatest.WordSpecLike$$anonfun$runTest$1.apply(WordSpecLike.scala:1088)
        at org.scalatest.WordSpecLike$$anonfun$runTest$1.apply(WordSpecLike.scala:1088)
        at org.scalatest.SuperEngine.runTestImpl(Engine.scala:289)
        at org.scalatest.WordSpecLike$class.runTest(WordSpecLike.scala:1088)
        at akka.testkit.AkkaSpec.runTest(AkkaSpec.scala:57)
        at org.scalatest.WordSpecLike$$anonfun$runTests$1.apply(WordSpecLike.scala:1147)
        at org.scalatest.WordSpecLike$$anonfun$runTests$1.apply(WordSpecLike.scala:1147)
        at org.scalatest.SuperEngine$$anonfun$traverseSubNodes$1$1.apply(Engine.scala:396)
        at org.scalatest.SuperEngine$$anonfun$traverseSubNodes$1$1.apply(Engine.scala:384)
        at scala.collection.immutable.List.foreach(List.scala:381)
        at org.scalatest.SuperEngine.traverseSubNodes$1(Engine.scala:384)
        at org.scalatest.SuperEngine.org$scalatest$SuperEngine$$runTestsInBranch(Engine.scala:373)
        at org.scalatest.SuperEngine$$anonfun$traverseSubNodes$1$1.apply(Engine.scala:410)
        at org.scalatest.SuperEngine$$anonfun$traverseSubNodes$1$1.apply(Engine.scala:384)
        at scala.collection.immutable.List.foreach(List.scala:381)
        at org.scalatest.SuperEngine.traverseSubNodes$1(Engine.scala:384)
        at org.scalatest.SuperEngine.org$scalatest$SuperEngine$$runTestsInBranch(Engine.scala:379)
        at org.scalatest.SuperEngine.runTestsImpl(Engine.scala:461)
        at org.scalatest.WordSpecLike$class.runTests(WordSpecLike.scala:1147)
        at akka.testkit.AkkaSpec.runTests(AkkaSpec.scala:57)
        at org.scalatest.Suite$class.run(Suite.scala:1147)
        at akka.testkit.AkkaSpec.org$scalatest$WordSpecLike$$super$run(AkkaSpec.scala:57)
        at org.scalatest.WordSpecLike$$anonfun$run$1.apply(WordSpecLike.scala:1192)
        at org.scalatest.WordSpecLike$$anonfun$run$1.apply(WordSpecLike.scala:1192)
        at org.scalatest.SuperEngine.runImpl(Engine.scala:521)
        at org.scalatest.WordSpecLike$class.run(WordSpecLike.scala:1192)
        at akka.testkit.AkkaSpec.org$scalatest$BeforeAndAfterAll$$super$run(AkkaSpec.scala:57)
        at org.scalatest.BeforeAndAfterAll$class.liftedTree1$1(BeforeAndAfterAll.scala:213)
        at org.scalatest.BeforeAndAfterAll$class.run(BeforeAndAfterAll.scala:210)
        at akka.testkit.AkkaSpec.run(AkkaSpec.scala:57)
        at org.scalatest.tools.Framework.org$scalatest$tools$Framework$$runSuite(Framework.scala:314)
        at org.scalatest.tools.Framework$ScalaTestTask.execute(Framework.scala:472)
        at sbt.TestRunner.runTest$1(TestFramework.scala:76)
        at sbt.TestRunner.run(TestFramework.scala:85)
        at sbt.TestFramework$$anon$2$$anonfun$$init$$1$$anonfun$apply$8.apply(TestFramework.scala:202)
        at sbt.TestFramework$$anon$2$$anonfun$$init$$1$$anonfun$apply$8.apply(TestFramework.scala:202)
        at sbt.TestFramework$.sbt$TestFramework$$withContextLoader(TestFramework.scala:185)
        at sbt.TestFramework$$anon$2$$anonfun$$init$$1.apply(TestFramework.scala:202)
        at sbt.TestFramework$$anon$2$$anonfun$$init$$1.apply(TestFramework.scala:202)
        at sbt.TestFunction.apply(TestFramework.scala:207)
        at sbt.Tests$.sbt$Tests$$processRunnable$1(Tests.scala:239)
        at sbt.Tests$$anonfun$makeSerial$1.apply(Tests.scala:245)
        at sbt.Tests$$anonfun$makeSerial$1.apply(Tests.scala:245)
        at sbt.std.Transform$$anon$3$$anonfun$apply$2.apply(System.scala:44)
        at sbt.std.Transform$$anon$3$$anonfun$apply$2.apply(System.scala:44)
        at sbt.std.Transform$$anon$4.work(System.scala:63)
        at sbt.Execute$$anonfun$submit$1$$anonfun$apply$1.apply(Execute.scala:228)
        at sbt.Execute$$anonfun$submit$1$$anonfun$apply$1.apply(Execute.scala:228)
        at sbt.ErrorHandling$.wideConvert(ErrorHandling.scala:17)
        at sbt.Execute.work(Execute.scala:237)
        at sbt.Execute$$anonfun$submit$1.apply(Execute.scala:228)
        at sbt.Execute$$anonfun$submit$1.apply(Execute.scala:228)
        at sbt.ConcurrentRestrictions$$anon$4$$anonfun$1.apply(ConcurrentRestrictions.scala:159)
        at sbt.CompletionService$$anon$2.call(CompletionService.scala:28)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)

        Number of locked synchronizers = 1
        - java.util.concurrent.ThreadPoolExecutor$Worker@2504861f


Deadlocks found for monitors and ownable synchronizers:
None
Coroner Thread Count started at 15, ended at 12, peaked at 24 in akka.io.TcpConnectionSpec

The text was updated successfully, but these errors were encountered:

patriknw · 2016-09-06T06:02:26Z

That is "just" a warning that the test is taking longer than expected. Does it always take that long, and do you see same in the Jenkins logs https://jenkins.akka.io:8498/job/akka-multi-node-nightly/ ?
If that is the case we should increase the expectedTestDuration. PR is welcome.

chris-martin · 2016-09-06T06:07:51Z

I do always see that output I gave above. I don't know how long it takes because I've never seen it finish.

Does the suite really take nearly two hours to run, or am I reading that Jenkins graph wrong?

chris-martin · 2016-09-06T06:16:05Z

This time I got a completion, with failures:

[info] ScalaTest
[info] Run completed in 7 minutes, 4 seconds.
[info] Total number of tests run: 1283
[info] Suites: completed 139, aborted 0
[info] Tests: succeeded 1281, failed 2, canceled 0, ignored 1, pending 16
[info] *** 2 TESTS FAILED ***
[error] Failed: Total 1283, Failed 2, Errors 0, Passed 1281, Ignored 1, Pending 16
[error] Failed tests:
[error]         akka.event.EventStreamSpec
[error]         akka.io.TcpConnectionSpec
[error] (akka-actor-tests/test:test) sbt.TestsFailedException: Tests unsuccessful
[error] Total time: 428 s, completed Sep 6, 2016 2:14:05 AM

Some excerpts from higher up in the test output:

[ERROR] [09/06/2016 02:11:46.417] [pool-42-thread-1-ScalaTest-running-ExtensionSpec] [akka.actor.ActorSystemImpl(failing)] While trying to load extension [akka.actor.MissingExtension], skippi
ng...
java.lang.ClassNotFoundException: akka.actor.MissingExtension
        at java.lang.ClassLoader.findClass(ClassLoader.java:530)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
        at sbt.classpath.ClasspathFilter.loadClass(ClassLoaders.scala:59)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        at java.lang.Class.forName0(Native Method)
        at java.lang.Class.forName(Class.java:348)
        at akka.actor.ReflectiveDynamicAccess$$anonfun$getClassFor$1.apply(ReflectiveDynamicAccess.scala:21)
        at akka.actor.ReflectiveDynamicAccess$$anonfun$getClassFor$1.apply(ReflectiveDynamicAccess.scala:20)
        at scala.util.Try$.apply(Try.scala:192)
        at akka.actor.ReflectiveDynamicAccess.getClassFor(ReflectiveDynamicAccess.scala:20)
        at akka.actor.ReflectiveDynamicAccess.createInstanceFor(ReflectiveDynamicAccess.scala:38)
        at akka.actor.ActorSystemImpl$$anonfun$loadExtensions$1$1$$anonfun$1.applyOrElse(ActorSystem.scala:769)
        at akka.actor.ActorSystemImpl$$anonfun$loadExtensions$1$1$$anonfun$1.applyOrElse(ActorSystem.scala:769)
    [...]

[info] - must stop continuous scheduling if the receiving actor has been terminated (502 milliseconds)
[ERROR] [09/06/2016 02:10:57.268] [LightArrayRevolverSchedulerSpec-akka.actor.default-dispatcher-4] [TaskInvocation] TEST (akka.actor.SchedulerSpec$$anonfun$1$$anonfun$apply$mcV$sp$4$$anonfun
$apply$mcV$sp$5$$anon$1)

chris-martin · 2016-09-06T06:35:36Z

After doing a full compile of the other modules, I'm down to only one failure.

[info] Run completed in 7 minutes, 18 seconds.
[info] Total number of tests run: 1283
[info] Suites: completed 139, aborted 0
[info] Tests: succeeded 1282, failed 1, canceled 0, ignored 1, pending 16
[info] *** 1 TEST FAILED ***
[error] Failed: Total 1283, Failed 1, Errors 0, Passed 1282, Ignored 1, Pending 16
[error] Failed tests:
[error]         akka.io.TcpConnectionSpec

This test runner doesn't print out the details for the failing tests at the end? Running it again with output piped to a file, because I think the error is too far up to scroll back to...

chris-martin · 2016-09-06T06:42:42Z

Ah, here we go.

[info] - must report abort before handler is registered (reproducer from #15033) *** FAILED *** (1 millisecond)
[info]   java.net.BindException: Address already in use
[info]   at java.net.PlainSocketImpl.socketBind(Native Method)
[info]   at java.net.AbstractPlainSocketImpl.bind(AbstractPlainSocketImpl.java:387)
[info]   at java.net.ServerSocket.bind(ServerSocket.java:375)
[info]   at java.net.ServerSocket.<init>(ServerSocket.java:237)
[info]   at akka.io.TcpConnectionSpec$$anonfun$1$$anonfun$apply$mcV$sp$44.apply(TcpConnectionSpec.scala:830)
[info]   at akka.io.TcpConnectionSpec$$anonfun$1$$anonfun$apply$mcV$sp$44.apply(TcpConnectionSpec.scala:826)
[info]   at org.scalatest.OutcomeOf$class.outcomeOf(OutcomeOf.scala:85)
[info]   at org.scalatest.OutcomeOf$.outcomeOf(OutcomeOf.scala:104)
[info]   at org.scalatest.Transformer.apply(Transformer.scala:22)
[info]   at org.scalatest.Transformer.apply(Transformer.scala:20)
[info]   at org.scalatest.WordSpecLike$$anon$1.apply(WordSpecLike.scala:1078)

Do certain ports need to be unbound for the tests to pass?

chris-martin · 2016-09-06T06:51:59Z

I guess that was port 23402 still bound by a previous instance of SBT that didn't kill all the way. Once I kill that, I'm back to the original behavior; it gets to that test and then hangs (seemingly) indefinitely.

[info] - must support useResumeWriting==false (queue flushed) (1 second, 71 milliseconds)
[WARN] [09/06/2016 02:46:08.876] [TcpConnectionSpec-akka.actor.default-dispatcher-8] [akka://TcpConnectionSpec/deadLetters] received dead letter from Actor[akka://TcpConnectionSpec/system/IO-TCP/selectors/$a/1#1210154811]: CommandFailed(Connect(0.0.0.0/0.0.0.0:23402,None,List(),None,false))

patriknw · 2016-09-06T06:59:58Z

We try to avoid fixed ports, but I see that this test is not following that recommendation. It should be possible to replace that hardcoded 23402 with SocketUtil.

chris-martin · 2016-09-06T15:36:23Z

I left this test to run overnight, and it has not yet halted.

johanandren · 2016-09-14T11:23:32Z

Was there more issues than the hardcoded port in this ticket or should I close it?

chris-martin · 2016-09-14T16:49:52Z

Yeah, the issue as I first reported it still stands. When I run the tests, they always stop at that point and never complete.

The port issue I only encountered due to a previous SBT instance that was still running as a result of the test suite never halting.

johanandren · 2016-10-17T09:50:44Z

I think this is mainly about having a machine that is vastly different (cpu speed/cores, amount of memory etc. os) from the ones we develop on and the ci-servers (which are really slow though) making the timing assumptions in the tests unstable for your env.

Did you try running it with a higher test time factor?(akka.test.timefactor)? That might help, but we have a lot of tests in the suite that uses a time constant for timeouts so in those cases it won't help.

johanandren · 2016-10-18T13:07:57Z

Two possible races in TcpSpec fixed in #21685 that may relate to this ticket.

* problem occurs when network is offline * use socket timeout * additional cleanup of socket utils

patriknw · 2016-11-09T07:38:33Z

problem occurs when network is offline, I have fixed it in #21816

* use socket timeout * additional cleanup of socket utils

patriknw added this to the 2.4.x milestone Sep 11, 2016

patriknw added 1 - triaged Tickets that are safe to pick up for contributing in terms of likeliness of being accepted failed Tickets that indicate a CI failure, likely a flakey test t:io labels Sep 11, 2016

johanandren self-assigned this Sep 13, 2016

johanandren added a commit to johanandren/akka that referenced this issue Sep 13, 2016

Remove hardcoded port number in TcpConnectionSpec akka#21375

9856062

johanandren mentioned this issue Sep 13, 2016

Remove hardcoded port number in TcpConnectionSpec #21454

Merged

johanandren added a commit that referenced this issue Sep 14, 2016

Remove hardcoded port number in TcpConnectionSpec, #21375

e493bdc

johanandren modified the milestones: 2.4.11, 2.4.x Sep 14, 2016

patriknw modified the milestones: 2.4.11, 2.4.12 Sep 30, 2016

chris-martin mentioned this issue Oct 19, 2016

Feature request: Let BackoffSupervisor reply to messages when its child is stopped #21213

Closed

ktoso modified the milestones: 2.4.12, 2.4.13 Oct 28, 2016

ktoso removed this from the 2.4.12 milestone Oct 28, 2016

patriknw assigned patriknw and unassigned johanandren Nov 9, 2016

patriknw added 3 - in progress Someone is working on this ticket and removed 1 - triaged Tickets that are safe to pick up for contributing in terms of likeliness of being accepted labels Nov 9, 2016

patriknw added a commit that referenced this issue Nov 9, 2016

avoid infinite blocking in TcpConnectionSpec, #21375

1d4d1f5

* problem occurs when network is offline * use socket timeout * additional cleanup of socket utils

patriknw mentioned this issue Nov 9, 2016

avoid infinite blocking in TcpConnectionSpec, #21375 #21816

Merged

johanandren pushed a commit that referenced this issue Nov 9, 2016

avoid infinite blocking in TcpConnectionSpec #21375

4f013a3

* use socket timeout * additional cleanup of socket utils

johanandren closed this as completed Nov 9, 2016

412b pushed a commit to 412b/akka that referenced this issue Nov 17, 2016

avoid infinite blocking in TcpConnectionSpec akka#21375

f573338

* use socket timeout * additional cleanup of socket utils

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

akka-actor-tests fails - "Coroner not cancelled after 60000ms" #21375

akka-actor-tests fails - "Coroner not cancelled after 60000ms" #21375

chris-martin commented Sep 6, 2016 •

edited by patriknw

patriknw commented Sep 6, 2016

chris-martin commented Sep 6, 2016

chris-martin commented Sep 6, 2016 •

edited

chris-martin commented Sep 6, 2016 •

edited

chris-martin commented Sep 6, 2016

chris-martin commented Sep 6, 2016 •

edited

patriknw commented Sep 6, 2016

chris-martin commented Sep 6, 2016

johanandren commented Sep 14, 2016

chris-martin commented Sep 14, 2016 •

edited

johanandren commented Oct 17, 2016

johanandren commented Oct 18, 2016

patriknw commented Nov 9, 2016

akka-actor-tests fails - "Coroner not cancelled after 60000ms" #21375

akka-actor-tests fails - "Coroner not cancelled after 60000ms" #21375

Comments

chris-martin commented Sep 6, 2016 • edited by patriknw

patriknw commented Sep 6, 2016

chris-martin commented Sep 6, 2016

chris-martin commented Sep 6, 2016 • edited

chris-martin commented Sep 6, 2016 • edited

chris-martin commented Sep 6, 2016

chris-martin commented Sep 6, 2016 • edited

patriknw commented Sep 6, 2016

chris-martin commented Sep 6, 2016

johanandren commented Sep 14, 2016

chris-martin commented Sep 14, 2016 • edited

johanandren commented Oct 17, 2016

johanandren commented Oct 18, 2016

patriknw commented Nov 9, 2016

chris-martin commented Sep 6, 2016 •

edited by patriknw

chris-martin commented Sep 6, 2016 •

edited

chris-martin commented Sep 6, 2016 •

edited

chris-martin commented Sep 6, 2016 •

edited

chris-martin commented Sep 14, 2016 •

edited