utest
utest copied to clipboard
Lagom "requirement failed" in Executor on server stop after all tests
I'm posting here since there is no failure in ScalaTest, but the details of the issue are beyond my understanding; let me know if it should be posted elsewhere (like to lagom issues).
repro: https://github.com/jibbers42/lagom-utest-stop-server-issue
When running service tests we have to start a lagom server and then are expected to stop it after that test suite completes. Upon stopping we fail a require
inside the Executor
.
-
start server:
private val server = ServiceTest.startServer( ServiceTest.defaultSetup .withCassandra() ) { ctx => new HelloApplication(ctx) with LocalServiceLocator }
https://github.com/jibbers42/lagom-utest-stop-server-issue/blob/c9ad1021fc09f6678cf43e8c371baa045aa4f7b9/hello-impl/src/test/scala/com/example/hello/impl/HelloServiceTests.scala#L10-L15
-
stop server:
override def utestAfterAll(): Unit = server.stop()
https://github.com/jibbers42/lagom-utest-stop-server-issue/blob/c9ad1021fc09f6678cf43e8c371baa045aa4f7b9/hello-impl/src/test/scala/com/example/hello/impl/HelloServiceTests.scala#L19 -
failed require:
require(_tasksLocal.get eq null)
https://github.com/scala/scala/blob/30a1428925497a7358fd386db84fd982c3108707/src/library/scala/concurrent/BatchingExecutor.scala#L51
The test (which returns a Future):
"say hello" - {
client.hello("Alice").invoke().map { answer =>
assert(answer == "Hello, Alice!")
}
Right now it's just an annoyingly long stack trace, but once I add more suites the failure to stop might become an issue.
ScalaTest session:
sbt> testQuick com.example.hello.impl.HelloServiceSpec
[info] Passed: Total 0, Failed 0, Errors 0, Passed 0
[info] No tests to run for hello/test:testQuick
[info] Passed: Total 0, Failed 0, Errors 0, Passed 0
[info] No tests to run for hello-api/test:testQuick
-------------------------------- Running Tests --------------------------------
03/16 10:31:57 ERROR[main] o.a.c.s.StartupChecks - cassandra.jmx.local.port missing from cassandra-env.sh, unable to start local JMX service.
2018-03-16 10:32:03,437 INFO com.lightbend.lagom.internal.persistence.cluster.ClusterStartupTaskActor - Executing cluster start task cassandraOffsetStorePrepare.
2018-03-16 10:32:05,282 INFO com.lightbend.lagom.internal.persistence.cluster.ClusterStartupTaskActor - Cluster start task cassandraOffsetStorePrepare done.
2018-03-16 10:32:06,184 ERROR com.lightbend.lagom.internal.broker.kafka.Producer$TaggedOffsetProducerActor - Unable to locate Kafka service named [kafka_native]
[info] HelloServiceSpec:
[info] Hello service
[info] - should say hello
-------------------------------- Running Tests --------------------------------
[info] ScalaTest
[info] Run completed in 16 seconds, 531 milliseconds.
[info] Total number of tests run: 1
[info] Suites: completed 1, aborted 0
[info] Tests: succeeded 1, failed 0, canceled 0, ignored 0, pending 0
[info] All tests passed.
[info] utest
[info] Passed: Total 1, Failed 0, Errors 0, Passed 1
[success] Total time: 17 s, completed Mar 16, 2018 10:32:12 AM
uTest session:
sbt> testQuick com.example.hello.impl.HelloServiceTests
[info] Passed: Total 0, Failed 0, Errors 0, Passed 0
[info] No tests to run for hello/test:testQuick
[info] Passed: Total 0, Failed 0, Errors 0, Passed 0
[info] No tests to run for hello-api/test:testQuick
-------------------------------- Running Tests --------------------------------
-------------------------------- Running Tests --------------------------------
03/16 10:31:18 ERROR[main] o.a.c.s.StartupChecks - cassandra.jmx.local.port missing from cassandra-env.sh, unable to start local JMX service.
2018-03-16 10:31:24,074 INFO com.lightbend.lagom.internal.persistence.cluster.ClusterStartupTaskActor - Executing cluster start task cassandraOffsetStorePrepare.
2018-03-16 10:31:27,214 INFO com.lightbend.lagom.internal.persistence.cluster.ClusterStartupTaskActor - Cluster start task cassandraOffsetStorePrepare done.
2018-03-16 10:31:27,805 ERROR com.lightbend.lagom.internal.broker.kafka.Producer$TaggedOffsetProducerActor - Unable to locate Kafka service named [kafka_native]
+ com.example.hello.impl.HelloServiceTests.say hello 698ms
2018-03-16 10:31:29,818 WARN play.api.Play - Error stopping application
java.lang.IllegalArgumentException: requirement failed
at scala.Predef$.require(Predef.scala:264)
at scala.concurrent.BatchingExecutor$Batch.run(BatchingExecutor.scala:51)
at scala.concurrent.Future$InternalCallbackExecutor$.unbatchedExecute(Future.scala:866)
at scala.concurrent.BatchingExecutor$Batch.blockOn(BatchingExecutor.scala:92)
at scala.concurrent.Await$.ready(package.scala:142)
at play.api.Play$.$anonfun$stop$1(Play.scala:145)
at play.utils.Threads$.withContextClassLoader(Threads.scala:21)
at play.api.Play$.stop(Play.scala:145)
at com.lightbend.lagom.scaladsl.testkit.ServiceTest$TestServer.$anonfun$stop$1(ServiceTest.scala:185)
at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:12)
at scala.util.Try$.apply(Try.scala:209)
at com.lightbend.lagom.scaladsl.testkit.ServiceTest$TestServer.stop(ServiceTest.scala:185)
at com.example.hello.impl.HelloServiceTests$.utestAfterAll(HelloServiceTests.scala:19)
at utest.TestRunner$.$anonfun$runAsync$11(TestRunner.scala:102)
at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:12)
at utest.framework.StackMarker$.dropOutside(StackMarker.scala:13)
at utest.TestRunner$.$anonfun$runAsync$10(TestRunner.scala:102)
at scala.util.Success.$anonfun$map$1(Try.scala:251)
at scala.util.Success.map(Try.scala:209)
at scala.concurrent.Future.$anonfun$map$1(Future.scala:289)
at scala.concurrent.impl.Promise.liftedTree1$1(Promise.scala:29)
at scala.concurrent.impl.Promise.$anonfun$transform$1(Promise.scala:29)
at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:60)
at utest.framework.ExecutionContext$RunNow$.execute(ExecutionContext.scala:16)
at scala.concurrent.impl.CallbackRunnable.executeWithValue(Promise.scala:68)
at scala.concurrent.impl.Promise$DefaultPromise.$anonfun$tryComplete$1(Promise.scala:284)
at scala.concurrent.impl.Promise$DefaultPromise.$anonfun$tryComplete$1$adapted(Promise.scala:284)
at scala.concurrent.impl.Promise$DefaultPromise.tryComplete(Promise.scala:284)
at scala.concurrent.Promise.complete(Promise.scala:49)
at scala.concurrent.Promise.complete$(Promise.scala:48)
at scala.concurrent.impl.Promise$DefaultPromise.complete(Promise.scala:183)
at scala.concurrent.impl.Promise.$anonfun$transform$1(Promise.scala:29)
at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:60)
at utest.framework.ExecutionContext$RunNow$.execute(ExecutionContext.scala:16)
at scala.concurrent.impl.CallbackRunnable.executeWithValue(Promise.scala:68)
at scala.concurrent.impl.Promise$DefaultPromise.$anonfun$tryComplete$1(Promise.scala:284)
at scala.concurrent.impl.Promise$DefaultPromise.$anonfun$tryComplete$1$adapted(Promise.scala:284)
at scala.concurrent.impl.Promise$DefaultPromise.tryComplete(Promise.scala:284)
at scala.concurrent.Promise.complete(Promise.scala:49)
at scala.concurrent.Promise.complete$(Promise.scala:48)
at scala.concurrent.impl.Promise$DefaultPromise.complete(Promise.scala:183)
at scala.concurrent.impl.Promise.$anonfun$transform$1(Promise.scala:29)
at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:60)
at scala.concurrent.BatchingExecutor$Batch.processBatch$1(BatchingExecutor.scala:63)
at scala.concurrent.BatchingExecutor$Batch.$anonfun$run$1(BatchingExecutor.scala:78)
at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:12)
at scala.concurrent.BlockContext$.withBlockContext(BlockContext.scala:81)
at scala.concurrent.BatchingExecutor$Batch.run(BatchingExecutor.scala:55)
at scala.concurrent.Future$InternalCallbackExecutor$.unbatchedExecute(Future.scala:866)
at scala.concurrent.BatchingExecutor.execute(BatchingExecutor.scala:106)
at scala.concurrent.BatchingExecutor.execute$(BatchingExecutor.scala:103)
at scala.concurrent.Future$InternalCallbackExecutor$.execute(Future.scala:864)
at scala.concurrent.impl.CallbackRunnable.executeWithValue(Promise.scala:68)
at scala.concurrent.impl.Promise$DefaultPromise.$anonfun$tryComplete$1(Promise.scala:284)
at scala.concurrent.impl.Promise$DefaultPromise.$anonfun$tryComplete$1$adapted(Promise.scala:284)
at scala.concurrent.impl.Promise$DefaultPromise.tryComplete(Promise.scala:284)
at scala.concurrent.Promise.complete(Promise.scala:49)
at scala.concurrent.Promise.complete$(Promise.scala:48)
at scala.concurrent.impl.Promise$DefaultPromise.complete(Promise.scala:183)
at scala.concurrent.impl.Promise.$anonfun$transform$1(Promise.scala:29)
at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:60)
at utest.framework.ExecutionContext$RunNow$.execute(ExecutionContext.scala:16)
at scala.concurrent.impl.CallbackRunnable.executeWithValue(Promise.scala:68)
at scala.concurrent.impl.Promise$DefaultPromise.$anonfun$tryComplete$1(Promise.scala:284)
at scala.concurrent.impl.Promise$DefaultPromise.$anonfun$tryComplete$1$adapted(Promise.scala:284)
at scala.concurrent.impl.Promise$DefaultPromise.tryComplete(Promise.scala:284)
at scala.concurrent.Promise.complete(Promise.scala:49)
at scala.concurrent.Promise.complete$(Promise.scala:48)
at scala.concurrent.impl.Promise$DefaultPromise.complete(Promise.scala:183)
at scala.concurrent.impl.Promise.$anonfun$transform$1(Promise.scala:29)
at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:60)
at utest.framework.ExecutionContext$RunNow$.execute(ExecutionContext.scala:16)
at scala.concurrent.impl.CallbackRunnable.executeWithValue(Promise.scala:68)
at scala.concurrent.impl.Promise$DefaultPromise.$anonfun$tryComplete$1(Promise.scala:284)
at scala.concurrent.impl.Promise$DefaultPromise.$anonfun$tryComplete$1$adapted(Promise.scala:284)
at scala.concurrent.impl.Promise$DefaultPromise.tryComplete(Promise.scala:284)
at scala.concurrent.Promise.complete(Promise.scala:49)
at scala.concurrent.Promise.complete$(Promise.scala:48)
at scala.concurrent.impl.Promise$DefaultPromise.complete(Promise.scala:183)
at scala.concurrent.impl.Promise.$anonfun$transform$1(Promise.scala:29)
at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:60)
at utest.framework.ExecutionContext$RunNow$.execute(ExecutionContext.scala:16)
at scala.concurrent.impl.CallbackRunnable.executeWithValue(Promise.scala:68)
at scala.concurrent.impl.Promise$DefaultPromise.$anonfun$tryComplete$1(Promise.scala:284)
at scala.concurrent.impl.Promise$DefaultPromise.$anonfun$tryComplete$1$adapted(Promise.scala:284)
at scala.concurrent.impl.Promise$DefaultPromise.tryComplete(Promise.scala:284)
at scala.concurrent.Promise.complete(Promise.scala:49)
at scala.concurrent.Promise.complete$(Promise.scala:48)
at scala.concurrent.impl.Promise$DefaultPromise.complete(Promise.scala:183)
at scala.concurrent.impl.Promise.$anonfun$transform$1(Promise.scala:29)
at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:60)
at utest.framework.ExecutionContext$RunNow$.execute(ExecutionContext.scala:16)
at scala.concurrent.impl.CallbackRunnable.executeWithValue(Promise.scala:68)
at scala.concurrent.impl.Promise$DefaultPromise.$anonfun$tryComplete$1(Promise.scala:284)
at scala.concurrent.impl.Promise$DefaultPromise.$anonfun$tryComplete$1$adapted(Promise.scala:284)
at scala.concurrent.impl.Promise$DefaultPromise.tryComplete(Promise.scala:284)
at scala.concurrent.Promise.complete(Promise.scala:49)
at scala.concurrent.Promise.complete$(Promise.scala:48)
at scala.concurrent.impl.Promise$DefaultPromise.complete(Promise.scala:183)
at scala.concurrent.impl.Promise.$anonfun$transform$1(Promise.scala:29)
at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:60)
at utest.framework.ExecutionContext$RunNow$.execute(ExecutionContext.scala:16)
at scala.concurrent.impl.CallbackRunnable.executeWithValue(Promise.scala:68)
at scala.concurrent.impl.Promise$DefaultPromise.$anonfun$tryComplete$1(Promise.scala:284)
at scala.concurrent.impl.Promise$DefaultPromise.$anonfun$tryComplete$1$adapted(Promise.scala:284)
at scala.concurrent.impl.Promise$DefaultPromise.tryComplete(Promise.scala:284)
at scala.concurrent.Promise.complete(Promise.scala:49)
at scala.concurrent.Promise.complete$(Promise.scala:48)
at scala.concurrent.impl.Promise$DefaultPromise.complete(Promise.scala:183)
at scala.concurrent.impl.Promise.$anonfun$transform$1(Promise.scala:29)
at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:60)
at akka.dispatch.BatchingExecutor$AbstractBatch.processBatch(BatchingExecutor.scala:55)
at akka.dispatch.BatchingExecutor$BlockableBatch.$anonfun$run$1(BatchingExecutor.scala:91)
at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:12)
at scala.concurrent.BlockContext$.withBlockContext(BlockContext.scala:81)
at akka.dispatch.BatchingExecutor$BlockableBatch.run(BatchingExecutor.scala:91)
at akka.dispatch.TaskInvocation.run(AbstractDispatcher.scala:40)
at akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinTask.exec(ForkJoinExecutorConfigurator.scala:43)
at akka.dispatch.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)
at akka.dispatch.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)
at akka.dispatch.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)
at akka.dispatch.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)
Tests: 1, Passed: 1, Failed: 0
[info] ScalaTest
[info] Run completed in 14 seconds, 264 milliseconds.
[info] Total number of tests run: 0
[info] Suites: completed 0, aborted 0
[info] Tests: succeeded 0, failed 0, canceled 0, ignored 0, pending 0
[info] No tests were executed.
[info] utest
[info] Passed: Total 1, Failed 0, Errors 0, Passed 1
[success] Total time: 15 s, completed Mar 16, 2018 10:31:30 AM