More verbose error message in test

[benmccann]

Expanding error message per @jroper's suggestion

Will hopefully help debug https://github.com/typesafehub/js-engine/issues/50. Shows name of offending thread is "Trireme Script Thread"

[jroper]

That's the main thread that executes JavaScript code in Trireme. Possibilities include:

• Something has broken and it's not being shut down anymore
• Some other test has been introduced that isn't cleaning up properly (this would explain the non deterministic nature of it as it would depend on test ordering)
• Tests are running in parallel (this test won't work if they are)
• The test is not waiting long enough for the thread to shut down

[benmccann]

@jroper it seems that perhaps it's the last of the options you listed. I added Thread.sleep(1000) and now the test passes. Take a look and let me know what you think

[jroper]

The main thing I'd want to understand is why it's not shutdown immediately - it's ok to not shut down immediately, but it's important to understand why, to ensure that it is actually guaranteed to shutdown, and that it's not being shutdown perchance in a way that sometimes might not shutdown.

[benmccann]

@jroper I changed the sleep from 1s to 1ms and it's still enough to fix the tests. I think it is shutting down immediately. It's just that we're checking it so fast without giving it a chance first. Does this address your concern?

[jroper]

If you have to sleep 1ms then it's not happening immediately. This test used to always pass, now it often fails. Something has changed. Inserting a sleep to fix it when we don't know why it started failing is dangerous. All I'm asking is that we work out why it was failing, rather than just inserting arbitrary code into the test to make it work.

[benmccann]

This test used to always pass, now it often fails. Something has changed

Ah, sorry, I didn't realize we were on different pages here. This test has been flaky since it was introduced. It sounds to me like you're working off the assumption that Trireme changed something to make the threads not shut down properly. But I don't think that's true. I think the real issue is that this test was written in a way where it has a race condition. I have limited time to fix that and am not really sure how we would. My main concern here is that I want to ensure we're not blocking all other progress on the project because a flaky test was added. We could also disable this test if you prefer. I just want to make sure we don't stop progress on getting other bug fixes checked in and released.

$ git reset --hard bbf25c8ada7e20b980bcba988f052b8e6bbd92b3 HEAD is now at bbf25c8 Fixed trireme resource leaks $ sbt test [info] Loading global plugins from .sbt/0.13/plugins [info] Loading project definition from src/js-engine/project [info] Set current project to jse (in build file:src/js-engine/) [info] JavaxEngineSpec [info] [info] A JavaxEngine should [error] x execute some javascript by passing in a string arg and comparing its return value [error] 'undefined' is not equal to '999' (JavaxEngineSpec.scala:36) [info] [info] + execute some javascript by passing in a string arg and comparing its return value expecting an error [info] [info] Total for specification JavaxEngineSpec [info] Finished in 1 second, 629 ms [info] 2 examples, 1 failure, 0 error [info] [info] RhinoSpec [info] [INFO] [01/23/2017 11:16:15.404] [default-akka.actor.default-dispatcher-7] [akka://default/user/engine] Message [akka.dispatch.sysmsg.Terminate] from Actor[akka://default/user/engine#-481672773] to Actor[akka://default/user/engine#-481672773] was not delivered. [1] dead letters encountered. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'. [info] The Rhino engine should [info] + execute some javascript by passing in a string arg and comparing its return value [info] + execute some javascript by passing in a string arg and comparing its return value expecting an error [info] [info] Total for specification RhinoSpec [info] Finished in 231 ms [info] 2 examples, 0 failure, 0 error [info] [info] TriremeSpec [info] [INFO] [01/23/2017 11:16:15.928] [default-akka.actor.default-dispatcher-3] [akka://default/user/trireme-spec] Message [akka.dispatch.sysmsg.Terminate] from Actor[akka://default/user/trireme-spec#-1750111361] to Actor[akka://default/user/trireme-spec#-1750111361] was not delivered. [1] dead letters encountered. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'. [info] The Trireme engine should [info] + execute some javascript by passing in a string arg and comparing its return value [INFO] [01/23/2017 11:16:16.050] [default-akka.actor.default-dispatcher-2] [akka://default/user/trireme-spec/trireme-shell] Message [akka.dispatch.sysmsg.Terminate] from Actor[akka://default/user/trireme-spec/trireme-shell#-1619064707] to Actor[akka://default/user/trireme-spec/trireme-shell#-1619064707] was not delivered. [1] dead letters encountered. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'. [info] + execute some javascript by passing in a string arg and comparing its return value expecting an error [error] x not leak threads [error] '1' is not equal to '0' (TriremeSpec.scala:77) [info] [INFO] [01/23/2017 11:16:16.256] [default-akka.actor.default-dispatcher-4] [akka://default/user/not-leak-threads-test] Message [akka.dispatch.sysmsg.Terminate] from Actor[akka://default/user/not-leak-threads-test#-46769131] to Actor[akka://default/user/not-leak-threads-test#-46769131] was not delivered. [1] dead letters encountered. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'. [info] + not leak file descriptors [info] [info] Total for specification TriremeSpec [info] Finished in 366 ms [info] 4 examples, 1 failure, 0 error [info] [error] Failed: Total 8, Failed 2, Errors 0, Passed 6 [error] Failed tests: [error] com.typesafe.jse.JavaxEngineSpec [error] com.typesafe.jse.TriremeSpec [error] (root/test:test) sbt.TestsFailedException: Tests unsuccessful [error] Total time: 4 s, completed Jan 23, 2017 11:16:16 AM

[benmccann]

@jroper any thoughts on my last comment?