Somehow we start executions in wrong order - Githubissues

sbt / sbt-remote-control

Create and manage sbt process using unicorns and forks

Other

74 stars 14 forks source link

Somehow we start executions in wrong order #213

Closed havocp closed 9 years ago

havocp commented 10 years ago

From https://s3.amazonaws.com/archive.travis-ci.org/jobs/36180244/log.txt (which may get deleted), we start infiniteLoop then compile but we try to run infiniteLoop after compile, in CanCancelTasks integration test. Here is a piece of the log.

[0m[[0minfo[0m] [0mCoreLogEvent(LogMessage(info,Set current project to test (in build file:/home/travis/build/sbt/sbt-remote-control/it-runner/target/integration-test/com-typesafe-sbtrc-it-loading-CanCancelTasks/scratch/test/)))[0m
[0m[[0minfo[0m] [0mCoreLogEvent(LogMessage(debug,> iflast shell))[0m
[0m[[0minfo[0m] [0mCoreLogEvent(LogMessage(debug,> server-send-ready-for-request))[0m
[0m[[0minfo[0m] [0mBuildLoaded()[0m
[0m[[0minfo[0m] [0mCoreLogEvent(LogMessage(debug,> server-handle-next-server-request))[0m
[0m[[0minfo[0m] [0mExecutionWaiting(1,infiniteLoop,ClientInfo(3eb7e272-faa0-46eb-9baf-a4f96d392ca4,sbt-client-test,SbtClientTest unit test))[0m
[0m[[0minfo[0m] [0mExecutionWaiting(2,compile,ClientInfo(3eb7e272-faa0-46eb-9baf-a4f96d392ca4,sbt-client-test,SbtClientTest unit test))[0m
[0m[[0minfo[0m] [0mExecutionStarting(2)[0m
[0m[[0minfo[0m] [0mExecutionFailure(2)[0m
[0m[[0minfo[0m] [0mExecutionStarting(1)[0m
[0m[[0minfo[0m] [0mCoreLogEvent(LogMessage(debug,> infiniteLoop))[0m
[0m[[0minfo[0m] [0mCoreLogEvent(LogMessage(debug,Evaluating tasks: *:infiniteLoop))[0m
[0m[[0minfo[0m] [0mCoreLogEvent(LogMessage(debug,Running task... Cancel: sbt.server.ServerTaskCancellation@b2cd998, check cycles: false))[0m
[0m[[0minfo[0m] [0mCoreLogEvent(LogStdOut([0m
[0m[[0minfo[0m] [0m))[0m
[0m[[0minfo[0m] [0mCoreLogEvent(LogMessage(warn,Canceling execution...))[0m
[0m[[0minfo[0m] [0mTaskStarted(1,3,Some(AttributeKey[void]("infiniteLoop") in Scope(Build: file:/home/travis/build/sbt/sbt-remote-control/it-runner/target/integration-test/com-typesafe-sbtrc-it-loading-CanCancelTasks/scratch/test/, , Project: ProjectReference(file:/home/travis/build/sbt/sbt-remote-control/it-runner/target/integration-test/com-typesafe-sbtrc-it-loading-CanCancelTasks/scratch/test/,test))))[0m
[0m[[0minfo[0m] [0mCoreLogEvent(LogMessage(error,java.util.concurrent.RejectedExecutionException))[0m
[0m[[0minfo[0m] [0mCoreLogEvent(LogMessage(error,Use 'last' for the full log.))[0m
[0m[[0minfo[0m] [0mCoreLogEvent(LogMessage(debug,> server-post-command-error-handler))[0m
[0m[[0minfo[0m] [0mExecutionFailure(1)[0m
[0m[[0minfo[0m] [0mCoreLogEvent(LogMessage(debug,> server-post-command-cleanup))[0m
[0m[[31merror[0m] [0m-- Sequence did not match expected --[0m
[0m[[31merror[0m] [0m * CoreLogEvent(LogMessage(debug,> infiniteLoop))[0m
[0m[[31merror[0m] [0m * CoreLogEvent(LogMessage(debug,Evaluating tasks: *:infiniteLoop))[0m
[0m[[0minfo[0m] [0mlog file is /home/travis/build/sbt/sbt-remote-control/it-runner/target/integration-test/com-typesafe-sbtrc-it-loading-CanCancelTasks/scratch/test/.sbtserver/connections/sbt-client-test-3eb7e272-faa0-46eb-9baf-a4f96d392ca4.log, you can uncomment some code in SbtClientTest.scala to dump this if you need to[0m
[0m[[31merror[0m] [0m * CoreLogEvent(LogMessage(debug,Running task... Cancel: sbt.server.ServerTaskCancellation@b2cd998, check cycles: false))[0m
[0m[[31merror[0m] [0m * CoreLogEvent(LogStdOut([0m
[0m[[31merror[0m] [0m))[0m
[0m[[31merror[0m] [0m * CoreLogEvent(LogMessage(warn,Canceling execution...))[0m
[0m[[31merror[0m] [0m * TaskStarted(1,3,Some(AttributeKey[void]("infiniteLoop") in Scope(Build: file:/home/travis/build/sbt/sbt-remote-control/it-runner/target/integration-test/com-typesafe-sbtrc-it-loading-CanCancelTasks/scratch/test/, , Project: ProjectReference(file:/home/travis/build/sbt/sbt-remote-control/it-runner/target/integration-test/com-typesafe-sbtrc-it-loading-CanCancelTasks/scratch/test/,test))))[0m
[0m[[31merror[0m] [0m * CoreLogEvent(LogMessage(error,java.util.concurrent.RejectedExecutionException))[0m
[0m[[31merror[0m] [0m * CoreLogEvent(LogMessage(error,Use 'last' for the full log.))[0m
[0m[[31merror[0m] [0m * CoreLogEvent(LogMessage(debug,> server-post-command-error-handler))[0m
[0m[[31merror[0m] [0m * ExecutionFailure(1)[0m
[0m[[0minfo[0m] [0mCoreLogEvent(LogMessage(debug,> server-handle-next-server-request))[0m
[0m[[0minfo[0m] [0mWaiting for client to close[0m
[0m[[0minfo[0m] [0mClosedEvent()[0m
[0m[[0minfo[0m] [0mNot executing runnable because we only run one thing: Runnable(onError(reconnecting=true, Connection closed))[0m
[0m[[0minfo[0m] [0mWaiting for client to close[0m
[0m[[0minfo[0m] [0mlog file is /home/travis/build/sbt/sbt-remote-control/it-runner/target/integration-test/com-typesafe-sbtrc-it-loading-CanCancelTasks/scratch/test/.sbtserver/master.log, you can uncomment some code in SbtClientTest.scala to dump this if you need to[0m
[0m[[31merror[0m] [0mTest failed: java.lang.AssertionError: No items matching compileStartedSecond[0m
[0m[[31merror[0m] [0mjava.lang.AssertionError: No items matching compileStartedSecond[0m
[0m[[31merror[0m] [0m   at com.typesafe.sbtrc.it.loading.CanCancelTasks$$anonfun$1.verifyOne$1(CanCancelTasks.scala:83)[0m
[0m[[31merror[0m] [0m   at com.typesafe.sbtrc.it.loading.CanCancelTasks$$anonfun$1.verifySequence$1(CanCancelTasks.scala:88)[0m
[0m[[31merror[0m] [0m   at com.typesafe.sbtrc.it.loading.CanCancelTasks$$anonfun$1.apply(CanCancelTasks.scala:137)[0m
[0m[[31merror[0m] [0m   at com.typesafe.sbtrc.it.loading.CanCancelTasks$$anonfun$1.apply(CanCancelTasks.scala:26)[0m
[0m[[31merror[0m] [0m   at com.typesafe.sbtrc.it.SbtClientTest$$anonfun$8.apply(SbtClientTest.scala:187)[0m
[0m[[31merror[0m] [0m   at com.typesafe.sbtrc.it.SbtClientTest$$anonfun$8.apply(SbtClientTest.scala:161)[0m
[0m[[31merror[0m] [0m   at com.typesafe.sbtrc.client.SimpleConnector$OpenListener$$anon$2.run(SimpleConnector.scala:151)[0m
[0m[[31merror[0m] [0m   at com.typesafe.sbtrc.it.SbtClientTest$runOneThingExecutor$2$.runWhenReady(SbtClientTest.scala:144)[0m
[0m[[31merror[0m] [0m   at com.typesafe.sbtrc.it.SbtClientTest$class.withSbt(SbtClientTest.scala:216)[0m
[0m[[31merror[0m] [0m   at com.typesafe.sbtrc.it.loading.CanCancelTasks.withSbt(CanCancelTasks.scala:14)[0m
[0m[[31merror[0m] [0m   at com.typesafe.sbtrc.it.loading.CanCancelTasks.delayedEndpoint$com$typesafe$sbtrc$it$loading$CanCancelTasks$1(CanCancelTasks.scala:26)[0m
[0m[[31merror[0m] [0m   at com.typesafe.sbtrc.it.loading.CanCancelTasks$delayedInit$body.apply(CanCancelTasks.scala:14)[0m
[0m[[31merror[0m] [0m   at scala.Function0$class.apply$mcV$sp(Function0.scala:40)[0m
[0m[[31merror[0m] [0m   at scala.runtime.AbstractFunction0.apply$mcV$sp(AbstractFunction0.scala:12)[0m
[0m[[31merror[0m] [0m   at com.typesafe.sbtrc.it.IntegrationTest$$anonfun$run$1.apply(IntegrationTest.scala:32)[0m
[0m[[31merror[0m] [0m   at com.typesafe.sbtrc.it.IntegrationTest$$anonfun$run$1.apply(IntegrationTest.scala:29)[0m
[0m[[31merror[0m] [0m   at com.typesafe.sbtrc.it.package$.withContextClassloader(package.scala:12)[0m
[0m[[31merror[0m] [0m   at com.typesafe.sbtrc.it.IntegrationTest.run(IntegrationTest.scala:29)[0m
[0m[[31merror[0m] [0m   at xsbt.boot.Launch$$anonfun$run$1.apply(Launch.scala:109)[0m
[0m[[31merror[0m] [0m   at xsbt.boot.Launch$.withContextLoader(Launch.scala:128)[0m
[0m[[31merror[0m] [0m   at xsbt.boot.Launch$.run(Launch.scala:109)[0m
[0m[[31merror[0m] [0m   at xsbt.boot.Launch$$anonfun$apply$1.apply(Launch.scala:35)[0m
[0m[[31merror[0m] [0m   at xsbt.boot.Launch$.launch(Launch.scala:117)[0m
[0m[[31merror[0m] [0m   at xsbt.boot.Launch$.apply(Launch.scala:18)[0m
[0m[[31merror[0m] [0m   at xsbt.boot.Boot$.runImpl(Boot.scala:41)[0m
[0m[[31merror[0m] [0m   at xsbt.boot.Boot$.main(Boot.scala:17)[0m
[0m[[31merror[0m] [0m   at xsbt.boot.Boot.main(Boot.scala)[0m
[0m[[0minfo[0m] [0mError during sbt execution: java.lang.AssertionError: No items matching compileStartedSecond[0m
[0m[[31merror[0m] [0m [IT] com.typesafe.sbtrc.it.loading.CanCancelTasks result: FAILURE[0m

havocp commented 10 years ago

This was caused by a short-circuit in the cancel case; when canceling, we removed a task from the queue and synthesized start/finish events for that task. I am removing that short-circuit and just always letting executions hit the ServerEngine, even if they are already canceled. This keeps events in order and reduces special cases.