This is kinda interesting. Seems we have a logic error somewhere that results in a busy daemon receiving a command.
Actually, now that I think about it this is not that unusual. What I think is happening that in between a daemon client finding an idle daemon and sending it a command some other client has sent it some work to do. We actually handle this gracefully and then just try again with a different daemon. What's probably going wrong here is just that the log message that is output when a busy daemon receives a command needs to be bumped down from warn level to info. Begin forwarded message: > From: [email protected] > Subject: [TeamCity, FAILED] Build Gradle on Linux::Master on java 1.5: > daemonIntegTest #194 > Date: 5 October 2011 3:34:49 PM GMT+01:00 > To: [email protected] > > Build Gradle on Linux::Master on java 1.5: daemonIntegTest #194 failed (tests > failed: 1 (1 new), passed: 649, ignored: 11) > Agent: agent3 > > Changes included (3 changes). > Change 6c39702c224b1a797a0c7449232a1a640572be10 by ld (5 files): changed the > daemon process semantics so that an exit code of 0 means an idle timeout, and > 1 means it error'd or was asked to stop. > Change 979ac5cc3882dfe4d2d1eb140f7ccac4cd36569f by ld (2 files): made > DaemonMain an entry point, which removes some lifecycle differences between > background and foreground daemon mode. This give us a bit more accuracy in > our tests. > Change 23dd3570903879d44c93975c2d49843ddd42a402 by ld (7 files): added some > modelling of our tight completion semantics as EntryPoint (and friends). > Packaging this into a reusable structure makes things a bit more explicit, > and allows us to use the same logic for the daemon (and maybe other gradle > processes) without duplication. This will also help to minimise the > differences between a background and foreground daemon which will improve the > accuracy of our tests. > > Failed Tests Summary: 1 (1 new) > (new) org.gradle.integtests.UserGuideSamplesIntegrationTest.custom_logging_ui > details ยป > > Stacktraces : > (new) org.gradle.integtests.UserGuideSamplesIntegrationTest.custom_logging_ui > java.lang.AssertionError: Integration test for sample 'custom_logging_ui' in > dir 'userguide/initScripts/customLogger' with args [-I, init.gradle, build] > failed: > Unexpected value at line 1. > Expected: [compile] > Actual: onStartCommand(DaemonCommandExecution[command = Build[id=1465127168], > connection = socket connection at /0:0:0:0:0:0:0:1:36314 with > /0:0:0:0:0:0:0:1:35021]) called while currentCommandExecution = > DaemonCommandExecution[command = Build[id=1344816074], connection = socket > connection at /0:0:0:0:0:0:0:1:36314 with /0:0:0:0:0:0:0:1:35019] > --- > Actual output: > onStartCommand(DaemonCommandExecution[command = Build[id=1465127168], > connection = socket connection at /0:0:0:0:0:0:0:1:36314 with > /0:0:0:0:0:0:0:1:35021]) called while currentCommandExecution = > DaemonCommandExecution[command = Build[id=1344816074], connection = socket > connection at /0:0:0:0:0:0:0:1:36314 with /0:0:0:0:0:0:0:1:35019] > [compile] > compiling source > > [testCompile] > compiling test source > > [test] > running unit tests > > [build] > > build completed > > --- > at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) > at > sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39) > at > sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27) > at java.lang.reflect.Constructor.newInstance(Constructor.java:501) > at > org.codehaus.groovy.reflection.CachedConstructor.invoke(CachedConstructor.java:77) > at > org.codehaus.groovy.reflection.CachedConstructor.doConstructorInvoke(CachedConstructor.java:71) > at > org.codehaus.groovy.runtime.callsite.ConstructorSite$ConstructorSiteNoUnwrap.callConstructor(ConstructorSite.java:81) > at > org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCallConstructor(CallSiteArray.java:52) > at > org.codehaus.groovy.runtime.callsite.AbstractCallSite.callConstructor(AbstractCallSite.java:190) > at > org.codehaus.groovy.runtime.callsite.AbstractCallSite.callConstructor(AbstractCallSite.java:198) > at > org.gradle.integtests.UserGuideSamplesRunner.runSample(UserGuideSamplesRunner.groovy:123) > at > org.gradle.integtests.UserGuideSamplesRunner.this$3$runSample(UserGuideSamplesRunner.groovy) > at > org.gradle.integtests.UserGuideSamplesRunner$this$3$runSample.callCurrent(Unknown > Source) > at > org.gradle.integtests.UserGuideSamplesRunner.run(UserGuideSamplesRunner.groovy:68) > at > org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:51) > at > org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:63) > at > org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:49) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) > at java.lang.reflect.Method.invoke(Method.java:592) > at > org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35) > at > org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24) > at > org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32) > at > org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:75) > at $Proxy3.processTestClass(Unknown Source) > at > org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:86) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) > at java.lang.reflect.Method.invoke(Method.java:592) > at > org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35) > at > org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24) > at > org.gradle.messaging.remote.internal.TypeCastDispatch.dispatch(TypeCastDispatch.java:30) > at > org.gradle.messaging.remote.internal.WorkerProtocol.handleIncoming(WorkerProtocol.java:53) > at > org.gradle.messaging.remote.internal.WorkerProtocol.handleIncoming(WorkerProtocol.java:31) > at > org.gradle.messaging.remote.internal.ProtocolStack$ProtocolStage.handleIncoming(ProtocolStack.java:167) > at > org.gradle.messaging.remote.internal.ProtocolStack$BottomStage.handleIncoming(ProtocolStack.java:277) > at > org.gradle.messaging.remote.internal.ProtocolStack$BottomConnection$1.run(ProtocolStack.java:299) > at > org.gradle.messaging.remote.internal.ProtocolStack$ExecuteRunnable.dispatch(ProtocolStack.java:120) > at > org.gradle.messaging.remote.internal.ProtocolStack$ExecuteRunnable.dispatch(ProtocolStack.java:116) > at > org.gradle.messaging.dispatch.AsyncDispatch.dispatchMessages(AsyncDispatch.java:132) > at > org.gradle.messaging.dispatch.AsyncDispatch.access$000(AsyncDispatch.java:33) > at > org.gradle.messaging.dispatch.AsyncDispatch$1.run(AsyncDispatch.java:72) > at > org.gradle.messaging.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64) > at > java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:651) > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:676) > at java.lang.Thread.run(Thread.java:595) > Caused by: java.lang.AssertionError: Unexpected value at line 1. > Expected: [compile] > Actual: onStartCommand(DaemonCommandExecution[command = Build[id=1465127168], > connection = socket connection at /0:0:0:0:0:0:0:1:36314 with > /0:0:0:0:0:0:0:1:35021]) called while currentCommandExecution = > DaemonCommandExecution[command = Build[id=1344816074], connection = socket > connection at /0:0:0:0:0:0:0:1:36314 with /0:0:0:0:0:0:0:1:35019] > --- > Actual output: > onStartCommand(DaemonCommandExecution[command = Build[id=1465127168], > connection = socket connection at /0:0:0:0:0:0:0:1:36314 with > /0:0:0:0:0:0:0:1:35021]) called while currentCommandExecution = > DaemonCommandExecution[command = Build[id=1344816074], connection = socket > connection at /0:0:0:0:0:0:0:1:36314 with /0:0:0:0:0:0:0:1:35019] > [compile] > compiling source > > [testCompile] > compiling test source > > [test] > running unit tests > > [build] > > build completed > > --- > at org.junit.Assert.fail(Assert.java:91) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) > at java.lang.reflect.Method.invoke(Method.java:592) > at > org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:90) > at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:233) > at > org.codehaus.groovy.runtime.callsite.StaticMetaMethodSite$StaticMetaMethodSiteNoUnwrap.invoke(StaticMetaMethodSite.java:130) > at > org.codehaus.groovy.runtime.callsite.StaticMetaMethodSite.call(StaticMetaMethodSite.java:88) > at > org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:40) > at > org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:116) > at > org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:124) > at > org.gradle.integtests.UserGuideSamplesRunner.compareStrings(UserGuideSamplesRunner.groovy:142) > at > org.gradle.integtests.UserGuideSamplesRunner.this$3$compareStrings(UserGuideSamplesRunner.groovy) > at > org.gradle.integtests.UserGuideSamplesRunner$this$3$compareStrings.callCurrent(Unknown > Source) > at > org.gradle.integtests.UserGuideSamplesRunner.runSample(UserGuideSamplesRunner.groovy:99) > ... 37 more > > > Configure your email notifications on your settings page. -- Luke Daley Principal Engineer, Gradleware http://gradleware.com
