Uploaded image for project: 'Jenkins'
  1. Jenkins
  2. JENKINS-55066

Docker plugin erroneously terminates containers shortly after they start

    Details

    • Similar Issues:

      Description

      We are seeing an issue where Pipeline jobs using Docker agents (with the Docker plugin, as opposed to Docker containers on regular agents using Pipeline's Docker support) intermittently fail right at the start, during the initial git checkout, with a "FATAL: java.io.IOException: Unexpected termination of the channel" exception. Having enabled debug logging for the Docker plugin, it appears that the plugin is erroneously killing the container because it thinks it is no longer needed.

      Job log:

      [First few lines redacted, this is the Jenkinsfile checkout]
      
      Checking out Revision 0b45f687992585a470e5faf003309b215e3f74f1 (refs/remotes/origin/master)
       > git config core.sparsecheckout # timeout=10
       > git checkout -f 0b45f687992585a470e5faf003309b215e3f74f1
      FATAL: java.io.IOException: Unexpected termination of the channel
      java.io.EOFException
              at java.io.ObjectInputStream$PeekInputStream.readFully(ObjectInputStream.java:2679)
              at java.io.ObjectInputStream$BlockDataInputStream.readShort(ObjectInputStream.java:3154)
              at java.io.ObjectInputStream.readStreamHeader(ObjectInputStream.java:862)
              at java.io.ObjectInputStream.<init>(ObjectInputStream.java:358)
              at hudson.remoting.ObjectInputStreamEx.<init>(ObjectInputStreamEx.java:49)
              at hudson.remoting.Command.readFrom(Command.java:140)
              at hudson.remoting.Command.readFrom(Command.java:126)
              at hudson.remoting.AbstractSynchronousByteArrayCommandTransport.read(AbstractSynchronousByteArrayCommandTransport.java:36)
              at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:63)
      Caused: java.io.IOException: Unexpected termination of the channel
              at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:77)
      Also:   hudson.remoting.Channel$CallSiteStackTrace: Remote call to docker-2ae12755b75761
                      at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1741)
                      at hudson.remoting.Request.call(Request.java:202)
                      at hudson.remoting.Channel.call(Channel.java:954)
                      at hudson.remoting.RemoteInvocationHandler.invoke(RemoteInvocationHandler.java:283)
                      at com.sun.proxy.$Proxy118.withRepository(Unknown Source)
                      at org.jenkinsci.plugins.gitclient.RemoteGitImpl.withRepository(RemoteGitImpl.java:235)
                      at hudson.plugins.git.GitSCM.printCommitMessageToLog(GitSCM.java:1271)
                      at hudson.plugins.git.GitSCM.checkout(GitSCM.java:1244)
                      at hudson.scm.SCM.checkout(SCM.java:504)
                      at hudson.model.AbstractProject.checkout(AbstractProject.java:1208)
                      at hudson.model.AbstractBuild$AbstractBuildExecution.defaultCheckout(AbstractBuild.java:574)
                      at jenkins.scm.SCMCheckoutStrategy.checkout(SCMCheckoutStrategy.java:86)
                      at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:499)
                      at hudson.model.Run.execute(Run.java:1815)
                      at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
                      at hudson.model.ResourceController.execute(ResourceController.java:97)
                      at hudson.model.Executor.run(Executor.java:429)
      Caused: hudson.remoting.RequestAbortedException
              at hudson.remoting.Request.abort(Request.java:340)
              at hudson.remoting.Channel.terminate(Channel.java:1038)
              at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:96)
      Finished: FAILURE

      Docker plugin debug log:

      2018-11-15 13:59:56.444+0000 [id=25]    FINE    c.n.j.p.d.s.DockerOnceRetentionStrategy#done: terminating docker-2ae12755b75761 since PlaceholderExecutable:ExecutorStepExecution.PlaceholderTask{runId=CompileTest#22494,label=docker-2ae12755b75761,context=CpsStepContext[4:node]:Owner[CompileTest/22494:CompileTest #22494],cookie=561ba1da-fd51-4ee6-9bc3-5d4bb75a9fd0,auth=null} seems to be finished
      2018-11-15 13:59:56.446+0000 [id=2063156]       INFO    i.j.docker.DockerTransientNode$1#println: Disconnected computer for slave 'docker-2ae12755b75761'.
      2018-11-15 13:59:56.448+0000 [id=2063156]       INFO    i.j.docker.DockerTransientNode$1#println: Removed Node for slave 'docker-2ae12755b75761'. 

      Jenkins log:

      2018-11-15 13:59:56.445+0000 [id=2063144]       SEVERE  h.r.SynchronousCommandTransport$ReaderThread#run: I/O error in channel docker-2ae12755b75761
      java.net.SocketException: Socket closed
              at java.net.SocketInputStream.socketRead0(Native Method)
              at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
              at java.net.SocketInputStream.read(SocketInputStream.java:171)
              at java.net.SocketInputStream.read(SocketInputStream.java:141)
              at java.net.SocketInputStream.read(SocketInputStream.java:127)
              at io.jenkins.docker.client.DockerMultiplexedInputStream.readInternal(DockerMultiplexedInputStream.java:41)
              at io.jenkins.docker.client.DockerMultiplexedInputStream.read(DockerMultiplexedInputStream.java:25)
              at hudson.remoting.FlightRecorderInputStream.read(FlightRecorderInputStream.java:91)
              at hudson.remoting.ChunkedInputStream.readHeader(ChunkedInputStream.java:72)
              at hudson.remoting.ChunkedInputStream.readUntilBreak(ChunkedInputStream.java:103)
              at hudson.remoting.ChunkedCommandTransport.readBlock(ChunkedCommandTransport.java:39)
              at hudson.remoting.AbstractSynchronousByteArrayCommandTransport.read(AbstractSynchronousByteArrayCommandTransport.java:35)
              at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:63)
      2018-11-15 13:59:56.446+0000 [id=2063156]       INFO    i.j.docker.DockerTransientNode$1#println: Disconnected computer for slave 'docker-2ae12755b75761'.
      2018-11-15 13:59:56.448+0000 [id=2063156]       INFO    i.j.docker.DockerTransientNode$1#println: Removed Node for slave 'docker-2ae12755b75761'.
      

       

      The timestamps of the logs seem to indicate that the Docker plugin erroneously thinks that the job, or at least a step in the job, has completed and so the container should be terminated. This happens a couple of times a day on the same job, but most builds do not fail.

        Attachments

          Activity

          owenmehegan Owen Mehegan created issue -
          owenmehegan Owen Mehegan made changes -
          Field Original Value New Value
          Description We are seeing an issue where Pipeline jobs using Docker agents (with the Docker plugin, as opposed to Docker containers on regular agents using Pipeline's Docker support) intermittently fail right at the start, during the initial git checkout, with a "FATAL: java.io.IOException: Unexpected termination of the channel" exception. Having enabled debug logging for the Docker plugin, it appears that the plugin is erroneously killing the container because it thinks it is no longer needed.

          Job log:
          {noformat}
          [First few lines redacted, this is the Jenkinsfile checkout]

          Checking out Revision 0b45f687992585a470e5faf003309b215e3f74f1 (refs/remotes/origin/master)
           > git config core.sparsecheckout # timeout=10
           > git checkout -f 0b45f687992585a470e5faf003309b215e3f74f1
          FATAL: java.io.IOException: Unexpected termination of the channel
          java.io.EOFException
                  at java.io.ObjectInputStream$PeekInputStream.readFully(ObjectInputStream.java:2679)
                  at java.io.ObjectInputStream$BlockDataInputStream.readShort(ObjectInputStream.java:3154)
                  at java.io.ObjectInputStream.readStreamHeader(ObjectInputStream.java:862)
                  at java.io.ObjectInputStream.<init>(ObjectInputStream.java:358)
                  at hudson.remoting.ObjectInputStreamEx.<init>(ObjectInputStreamEx.java:49)
                  at hudson.remoting.Command.readFrom(Command.java:140)
                  at hudson.remoting.Command.readFrom(Command.java:126)
                  at hudson.remoting.AbstractSynchronousByteArrayCommandTransport.read(AbstractSynchronousByteArrayCommandTransport.java:36)
                  at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:63)
          Caused: java.io.IOException: Unexpected termination of the channel
                  at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:77)
          Also: hudson.remoting.Channel$CallSiteStackTrace: Remote call to docker-2ae12755b75761
                          at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1741)
                          at hudson.remoting.Request.call(Request.java:202)
                          at hudson.remoting.Channel.call(Channel.java:954)
                          at hudson.remoting.RemoteInvocationHandler.invoke(RemoteInvocationHandler.java:283)
                          at com.sun.proxy.$Proxy118.withRepository(Unknown Source)
                          at org.jenkinsci.plugins.gitclient.RemoteGitImpl.withRepository(RemoteGitImpl.java:235)
                          at hudson.plugins.git.GitSCM.printCommitMessageToLog(GitSCM.java:1271)
                          at hudson.plugins.git.GitSCM.checkout(GitSCM.java:1244)
                          at hudson.scm.SCM.checkout(SCM.java:504)
                          at hudson.model.AbstractProject.checkout(AbstractProject.java:1208)
                          at hudson.model.AbstractBuild$AbstractBuildExecution.defaultCheckout(AbstractBuild.java:574)
                          at jenkins.scm.SCMCheckoutStrategy.checkout(SCMCheckoutStrategy.java:86)
                          at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:499)
                          at hudson.model.Run.execute(Run.java:1815)
                          at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
                          at hudson.model.ResourceController.execute(ResourceController.java:97)
                          at hudson.model.Executor.run(Executor.java:429)
          Caused: hudson.remoting.RequestAbortedException
                  at hudson.remoting.Request.abort(Request.java:340)
                  at hudson.remoting.Channel.terminate(Channel.java:1038)
                  at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:96)
          Finished: FAILURE{noformat}
          Docker plugin debug log:
          {noformat}
          2018-11-15 13:59:56.444+0000 [id=25] FINE c.n.j.p.d.s.DockerOnceRetentionStrategy#done: terminating docker-2ae12755b75761 since PlaceholderExecutable:ExecutorStepExecution.PlaceholderTask{runId=CompileTest#22494,label=docker-2ae12755b75761,context=CpsStepContext[4:node]:Owner[CompileTest/22494:CompileTest #22494],cookie=561ba1da-fd51-4ee6-9bc3-5d4bb75a9fd0,auth=null} seems to be finished 2018-11-15 13:59:56.446+0000 [id=2063156] INFO i.j.docker.DockerTransientNode$1#println: Disconnected computer for slave 'docker-2ae12755b75761'. 2018-11-15 13:59:56.448+0000 [id=2063156] INFO i.j.docker.DockerTransientNode$1#println: Removed Node for slave 'docker-2ae12755b75761'.
          {noformat}
           

          Jenkins log:
          {noformat}
          2018-11-15 13:59:56.445+0000 [id=2063144] SEVERE h.r.SynchronousCommandTransport$ReaderThread#run: I/O error in channel docker-2ae12755b75761 java.net.SocketException: Socket closed at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) at java.net.SocketInputStream.read(SocketInputStream.java:171) at java.net.SocketInputStream.read(SocketInputStream.java:141) at java.net.SocketInputStream.read(SocketInputStream.java:127) at io.jenkins.docker.client.DockerMultiplexedInputStream.readInternal(DockerMultiplexedInputStream.java:41) at io.jenkins.docker.client.DockerMultiplexedInputStream.read(DockerMultiplexedInputStream.java:25) at hudson.remoting.FlightRecorderInputStream.read(FlightRecorderInputStream.java:91) at hudson.remoting.ChunkedInputStream.readHeader(ChunkedInputStream.java:72) at hudson.remoting.ChunkedInputStream.readUntilBreak(ChunkedInputStream.java:103) at hudson.remoting.ChunkedCommandTransport.readBlock(ChunkedCommandTransport.java:39) at hudson.remoting.AbstractSynchronousByteArrayCommandTransport.read(AbstractSynchronousByteArrayCommandTransport.java:35) at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:63) 2018-11-15 13:59:56.446+0000 [id=2063156] INFO i.j.docker.DockerTransientNode$1#println: Disconnected computer for slave 'docker-2ae12755b75761'. 2018-11-15 13:59:56.448+0000 [id=2063156] INFO i.j.docker.DockerTransientNode$1#println: Removed Node for slave 'docker-2ae12755b75761'.
          {noformat}
           

          The timestamps of the logs seem to indicate that the Docker plugin erroneously thinks that the job, or at least a step in the job, has completed and so the container should be terminated. This happens a couple of times a day on the same job, but most builds do not fail.
          We are seeing an issue where Pipeline jobs using Docker agents (with the Docker plugin, as opposed to Docker containers on regular agents using Pipeline's Docker support) intermittently fail right at the start, during the initial git checkout, with a "FATAL: java.io.IOException: Unexpected termination of the channel" exception. Having enabled debug logging for the Docker plugin, it appears that the plugin is erroneously killing the container because it thinks it is no longer needed.

          Job log:
          {noformat}
          [First few lines redacted, this is the Jenkinsfile checkout]

          Checking out Revision 0b45f687992585a470e5faf003309b215e3f74f1 (refs/remotes/origin/master)
           > git config core.sparsecheckout # timeout=10
           > git checkout -f 0b45f687992585a470e5faf003309b215e3f74f1
          FATAL: java.io.IOException: Unexpected termination of the channel
          java.io.EOFException
                  at java.io.ObjectInputStream$PeekInputStream.readFully(ObjectInputStream.java:2679)
                  at java.io.ObjectInputStream$BlockDataInputStream.readShort(ObjectInputStream.java:3154)
                  at java.io.ObjectInputStream.readStreamHeader(ObjectInputStream.java:862)
                  at java.io.ObjectInputStream.<init>(ObjectInputStream.java:358)
                  at hudson.remoting.ObjectInputStreamEx.<init>(ObjectInputStreamEx.java:49)
                  at hudson.remoting.Command.readFrom(Command.java:140)
                  at hudson.remoting.Command.readFrom(Command.java:126)
                  at hudson.remoting.AbstractSynchronousByteArrayCommandTransport.read(AbstractSynchronousByteArrayCommandTransport.java:36)
                  at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:63)
          Caused: java.io.IOException: Unexpected termination of the channel
                  at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:77)
          Also: hudson.remoting.Channel$CallSiteStackTrace: Remote call to docker-2ae12755b75761
                          at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1741)
                          at hudson.remoting.Request.call(Request.java:202)
                          at hudson.remoting.Channel.call(Channel.java:954)
                          at hudson.remoting.RemoteInvocationHandler.invoke(RemoteInvocationHandler.java:283)
                          at com.sun.proxy.$Proxy118.withRepository(Unknown Source)
                          at org.jenkinsci.plugins.gitclient.RemoteGitImpl.withRepository(RemoteGitImpl.java:235)
                          at hudson.plugins.git.GitSCM.printCommitMessageToLog(GitSCM.java:1271)
                          at hudson.plugins.git.GitSCM.checkout(GitSCM.java:1244)
                          at hudson.scm.SCM.checkout(SCM.java:504)
                          at hudson.model.AbstractProject.checkout(AbstractProject.java:1208)
                          at hudson.model.AbstractBuild$AbstractBuildExecution.defaultCheckout(AbstractBuild.java:574)
                          at jenkins.scm.SCMCheckoutStrategy.checkout(SCMCheckoutStrategy.java:86)
                          at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:499)
                          at hudson.model.Run.execute(Run.java:1815)
                          at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
                          at hudson.model.ResourceController.execute(ResourceController.java:97)
                          at hudson.model.Executor.run(Executor.java:429)
          Caused: hudson.remoting.RequestAbortedException
                  at hudson.remoting.Request.abort(Request.java:340)
                  at hudson.remoting.Channel.terminate(Channel.java:1038)
                  at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:96)
          Finished: FAILURE{noformat}
          Docker plugin debug log:
          {noformat}
          2018-11-15 13:59:56.444+0000 [id=25] FINE c.n.j.p.d.s.DockerOnceRetentionStrategy#done: terminating docker-2ae12755b75761 since PlaceholderExecutable:ExecutorStepExecution.PlaceholderTask{runId=CompileTest#22494,label=docker-2ae12755b75761,context=CpsStepContext[4:node]:Owner[CompileTest/22494:CompileTest #22494],cookie=561ba1da-fd51-4ee6-9bc3-5d4bb75a9fd0,auth=null} seems to be finished 2018-11-15 13:59:56.446+0000 [id=2063156] INFO i.j.docker.DockerTransientNode$1#println: Disconnected computer for slave 'docker-2ae12755b75761'. 2018-11-15 13:59:56.448+0000 [id=2063156] INFO i.j.docker.DockerTransientNode$1#println: Removed Node for slave 'docker-2ae12755b75761'.
          {noformat}
           

          Jenkins log:
          {noformat}
          2018-11-15 13:59:56.445+0000 [id=2063144] SEVERE h.r.SynchronousCommandTransport$ReaderThread#run: I/O error in channel docker-2ae12755b75761
          java.net.SocketException: Socket closed
                  at java.net.SocketInputStream.socketRead0(Native Method)
                  at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
                  at java.net.SocketInputStream.read(SocketInputStream.java:171)
                  at java.net.SocketInputStream.read(SocketInputStream.java:141)
                  at java.net.SocketInputStream.read(SocketInputStream.java:127)
                  at io.jenkins.docker.client.DockerMultiplexedInputStream.readInternal(DockerMultiplexedInputStream.java:41)
                  at io.jenkins.docker.client.DockerMultiplexedInputStream.read(DockerMultiplexedInputStream.java:25)
                  at hudson.remoting.FlightRecorderInputStream.read(FlightRecorderInputStream.java:91)
                  at hudson.remoting.ChunkedInputStream.readHeader(ChunkedInputStream.java:72)
                  at hudson.remoting.ChunkedInputStream.readUntilBreak(ChunkedInputStream.java:103)
                  at hudson.remoting.ChunkedCommandTransport.readBlock(ChunkedCommandTransport.java:39)
                  at hudson.remoting.AbstractSynchronousByteArrayCommandTransport.read(AbstractSynchronousByteArrayCommandTransport.java:35)
                  at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:63)
          2018-11-15 13:59:56.446+0000 [id=2063156] INFO i.j.docker.DockerTransientNode$1#println: Disconnected computer for slave 'docker-2ae12755b75761'.
          2018-11-15 13:59:56.448+0000 [id=2063156] INFO i.j.docker.DockerTransientNode$1#println: Removed Node for slave 'docker-2ae12755b75761'.
          {noformat}
           

          The timestamps of the logs seem to indicate that the Docker plugin erroneously thinks that the job, or at least a step in the job, has completed and so the container should be terminated. This happens a couple of times a day on the same job, but most builds do not fail.
          owenmehegan Owen Mehegan made changes -
          Description We are seeing an issue where Pipeline jobs using Docker agents (with the Docker plugin, as opposed to Docker containers on regular agents using Pipeline's Docker support) intermittently fail right at the start, during the initial git checkout, with a "FATAL: java.io.IOException: Unexpected termination of the channel" exception. Having enabled debug logging for the Docker plugin, it appears that the plugin is erroneously killing the container because it thinks it is no longer needed.

          Job log:
          {noformat}
          [First few lines redacted, this is the Jenkinsfile checkout]

          Checking out Revision 0b45f687992585a470e5faf003309b215e3f74f1 (refs/remotes/origin/master)
           > git config core.sparsecheckout # timeout=10
           > git checkout -f 0b45f687992585a470e5faf003309b215e3f74f1
          FATAL: java.io.IOException: Unexpected termination of the channel
          java.io.EOFException
                  at java.io.ObjectInputStream$PeekInputStream.readFully(ObjectInputStream.java:2679)
                  at java.io.ObjectInputStream$BlockDataInputStream.readShort(ObjectInputStream.java:3154)
                  at java.io.ObjectInputStream.readStreamHeader(ObjectInputStream.java:862)
                  at java.io.ObjectInputStream.<init>(ObjectInputStream.java:358)
                  at hudson.remoting.ObjectInputStreamEx.<init>(ObjectInputStreamEx.java:49)
                  at hudson.remoting.Command.readFrom(Command.java:140)
                  at hudson.remoting.Command.readFrom(Command.java:126)
                  at hudson.remoting.AbstractSynchronousByteArrayCommandTransport.read(AbstractSynchronousByteArrayCommandTransport.java:36)
                  at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:63)
          Caused: java.io.IOException: Unexpected termination of the channel
                  at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:77)
          Also: hudson.remoting.Channel$CallSiteStackTrace: Remote call to docker-2ae12755b75761
                          at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1741)
                          at hudson.remoting.Request.call(Request.java:202)
                          at hudson.remoting.Channel.call(Channel.java:954)
                          at hudson.remoting.RemoteInvocationHandler.invoke(RemoteInvocationHandler.java:283)
                          at com.sun.proxy.$Proxy118.withRepository(Unknown Source)
                          at org.jenkinsci.plugins.gitclient.RemoteGitImpl.withRepository(RemoteGitImpl.java:235)
                          at hudson.plugins.git.GitSCM.printCommitMessageToLog(GitSCM.java:1271)
                          at hudson.plugins.git.GitSCM.checkout(GitSCM.java:1244)
                          at hudson.scm.SCM.checkout(SCM.java:504)
                          at hudson.model.AbstractProject.checkout(AbstractProject.java:1208)
                          at hudson.model.AbstractBuild$AbstractBuildExecution.defaultCheckout(AbstractBuild.java:574)
                          at jenkins.scm.SCMCheckoutStrategy.checkout(SCMCheckoutStrategy.java:86)
                          at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:499)
                          at hudson.model.Run.execute(Run.java:1815)
                          at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
                          at hudson.model.ResourceController.execute(ResourceController.java:97)
                          at hudson.model.Executor.run(Executor.java:429)
          Caused: hudson.remoting.RequestAbortedException
                  at hudson.remoting.Request.abort(Request.java:340)
                  at hudson.remoting.Channel.terminate(Channel.java:1038)
                  at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:96)
          Finished: FAILURE{noformat}
          Docker plugin debug log:
          {noformat}
          2018-11-15 13:59:56.444+0000 [id=25] FINE c.n.j.p.d.s.DockerOnceRetentionStrategy#done: terminating docker-2ae12755b75761 since PlaceholderExecutable:ExecutorStepExecution.PlaceholderTask{runId=CompileTest#22494,label=docker-2ae12755b75761,context=CpsStepContext[4:node]:Owner[CompileTest/22494:CompileTest #22494],cookie=561ba1da-fd51-4ee6-9bc3-5d4bb75a9fd0,auth=null} seems to be finished 2018-11-15 13:59:56.446+0000 [id=2063156] INFO i.j.docker.DockerTransientNode$1#println: Disconnected computer for slave 'docker-2ae12755b75761'. 2018-11-15 13:59:56.448+0000 [id=2063156] INFO i.j.docker.DockerTransientNode$1#println: Removed Node for slave 'docker-2ae12755b75761'.
          {noformat}
           

          Jenkins log:
          {noformat}
          2018-11-15 13:59:56.445+0000 [id=2063144] SEVERE h.r.SynchronousCommandTransport$ReaderThread#run: I/O error in channel docker-2ae12755b75761
          java.net.SocketException: Socket closed
                  at java.net.SocketInputStream.socketRead0(Native Method)
                  at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
                  at java.net.SocketInputStream.read(SocketInputStream.java:171)
                  at java.net.SocketInputStream.read(SocketInputStream.java:141)
                  at java.net.SocketInputStream.read(SocketInputStream.java:127)
                  at io.jenkins.docker.client.DockerMultiplexedInputStream.readInternal(DockerMultiplexedInputStream.java:41)
                  at io.jenkins.docker.client.DockerMultiplexedInputStream.read(DockerMultiplexedInputStream.java:25)
                  at hudson.remoting.FlightRecorderInputStream.read(FlightRecorderInputStream.java:91)
                  at hudson.remoting.ChunkedInputStream.readHeader(ChunkedInputStream.java:72)
                  at hudson.remoting.ChunkedInputStream.readUntilBreak(ChunkedInputStream.java:103)
                  at hudson.remoting.ChunkedCommandTransport.readBlock(ChunkedCommandTransport.java:39)
                  at hudson.remoting.AbstractSynchronousByteArrayCommandTransport.read(AbstractSynchronousByteArrayCommandTransport.java:35)
                  at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:63)
          2018-11-15 13:59:56.446+0000 [id=2063156] INFO i.j.docker.DockerTransientNode$1#println: Disconnected computer for slave 'docker-2ae12755b75761'.
          2018-11-15 13:59:56.448+0000 [id=2063156] INFO i.j.docker.DockerTransientNode$1#println: Removed Node for slave 'docker-2ae12755b75761'.
          {noformat}
           

          The timestamps of the logs seem to indicate that the Docker plugin erroneously thinks that the job, or at least a step in the job, has completed and so the container should be terminated. This happens a couple of times a day on the same job, but most builds do not fail.
          We are seeing an issue where Pipeline jobs using Docker agents (with the Docker plugin, as opposed to Docker containers on regular agents using Pipeline's Docker support) intermittently fail right at the start, during the initial git checkout, with a "FATAL: java.io.IOException: Unexpected termination of the channel" exception. Having enabled debug logging for the Docker plugin, it appears that the plugin is erroneously killing the container because it thinks it is no longer needed.

          Job log:
          {noformat}
          [First few lines redacted, this is the Jenkinsfile checkout]

          Checking out Revision 0b45f687992585a470e5faf003309b215e3f74f1 (refs/remotes/origin/master)
           > git config core.sparsecheckout # timeout=10
           > git checkout -f 0b45f687992585a470e5faf003309b215e3f74f1
          FATAL: java.io.IOException: Unexpected termination of the channel
          java.io.EOFException
                  at java.io.ObjectInputStream$PeekInputStream.readFully(ObjectInputStream.java:2679)
                  at java.io.ObjectInputStream$BlockDataInputStream.readShort(ObjectInputStream.java:3154)
                  at java.io.ObjectInputStream.readStreamHeader(ObjectInputStream.java:862)
                  at java.io.ObjectInputStream.<init>(ObjectInputStream.java:358)
                  at hudson.remoting.ObjectInputStreamEx.<init>(ObjectInputStreamEx.java:49)
                  at hudson.remoting.Command.readFrom(Command.java:140)
                  at hudson.remoting.Command.readFrom(Command.java:126)
                  at hudson.remoting.AbstractSynchronousByteArrayCommandTransport.read(AbstractSynchronousByteArrayCommandTransport.java:36)
                  at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:63)
          Caused: java.io.IOException: Unexpected termination of the channel
                  at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:77)
          Also: hudson.remoting.Channel$CallSiteStackTrace: Remote call to docker-2ae12755b75761
                          at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1741)
                          at hudson.remoting.Request.call(Request.java:202)
                          at hudson.remoting.Channel.call(Channel.java:954)
                          at hudson.remoting.RemoteInvocationHandler.invoke(RemoteInvocationHandler.java:283)
                          at com.sun.proxy.$Proxy118.withRepository(Unknown Source)
                          at org.jenkinsci.plugins.gitclient.RemoteGitImpl.withRepository(RemoteGitImpl.java:235)
                          at hudson.plugins.git.GitSCM.printCommitMessageToLog(GitSCM.java:1271)
                          at hudson.plugins.git.GitSCM.checkout(GitSCM.java:1244)
                          at hudson.scm.SCM.checkout(SCM.java:504)
                          at hudson.model.AbstractProject.checkout(AbstractProject.java:1208)
                          at hudson.model.AbstractBuild$AbstractBuildExecution.defaultCheckout(AbstractBuild.java:574)
                          at jenkins.scm.SCMCheckoutStrategy.checkout(SCMCheckoutStrategy.java:86)
                          at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:499)
                          at hudson.model.Run.execute(Run.java:1815)
                          at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
                          at hudson.model.ResourceController.execute(ResourceController.java:97)
                          at hudson.model.Executor.run(Executor.java:429)
          Caused: hudson.remoting.RequestAbortedException
                  at hudson.remoting.Request.abort(Request.java:340)
                  at hudson.remoting.Channel.terminate(Channel.java:1038)
                  at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:96)
          Finished: FAILURE{noformat}
          Docker plugin debug log:
          {noformat}
          2018-11-15 13:59:56.444+0000 [id=25] FINE c.n.j.p.d.s.DockerOnceRetentionStrategy#done: terminating docker-2ae12755b75761 since PlaceholderExecutable:ExecutorStepExecution.PlaceholderTask{runId=CompileTest#22494,label=docker-2ae12755b75761,context=CpsStepContext[4:node]:Owner[CompileTest/22494:CompileTest #22494],cookie=561ba1da-fd51-4ee6-9bc3-5d4bb75a9fd0,auth=null} seems to be finished
          2018-11-15 13:59:56.446+0000 [id=2063156] INFO i.j.docker.DockerTransientNode$1#println: Disconnected computer for slave 'docker-2ae12755b75761'.
          2018-11-15 13:59:56.448+0000 [id=2063156] INFO i.j.docker.DockerTransientNode$1#println: Removed Node for slave 'docker-2ae12755b75761'. {noformat}
          Jenkins log:
          {noformat}
          2018-11-15 13:59:56.445+0000 [id=2063144] SEVERE h.r.SynchronousCommandTransport$ReaderThread#run: I/O error in channel docker-2ae12755b75761
          java.net.SocketException: Socket closed
                  at java.net.SocketInputStream.socketRead0(Native Method)
                  at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
                  at java.net.SocketInputStream.read(SocketInputStream.java:171)
                  at java.net.SocketInputStream.read(SocketInputStream.java:141)
                  at java.net.SocketInputStream.read(SocketInputStream.java:127)
                  at io.jenkins.docker.client.DockerMultiplexedInputStream.readInternal(DockerMultiplexedInputStream.java:41)
                  at io.jenkins.docker.client.DockerMultiplexedInputStream.read(DockerMultiplexedInputStream.java:25)
                  at hudson.remoting.FlightRecorderInputStream.read(FlightRecorderInputStream.java:91)
                  at hudson.remoting.ChunkedInputStream.readHeader(ChunkedInputStream.java:72)
                  at hudson.remoting.ChunkedInputStream.readUntilBreak(ChunkedInputStream.java:103)
                  at hudson.remoting.ChunkedCommandTransport.readBlock(ChunkedCommandTransport.java:39)
                  at hudson.remoting.AbstractSynchronousByteArrayCommandTransport.read(AbstractSynchronousByteArrayCommandTransport.java:35)
                  at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:63)
          2018-11-15 13:59:56.446+0000 [id=2063156] INFO i.j.docker.DockerTransientNode$1#println: Disconnected computer for slave 'docker-2ae12755b75761'.
          2018-11-15 13:59:56.448+0000 [id=2063156] INFO i.j.docker.DockerTransientNode$1#println: Removed Node for slave 'docker-2ae12755b75761'.
          {noformat}
           

          The timestamps of the logs seem to indicate that the Docker plugin erroneously thinks that the job, or at least a step in the job, has completed and so the container should be terminated. This happens a couple of times a day on the same job, but most builds do not fail.
          ndeloof Nicolas De Loof made changes -
          Assignee Nicolas De Loof [ ndeloof ]
          Hide
          narenji Ali Narenji added a comment -

          Is there any workaround on the issue?

          Show
          narenji Ali Narenji added a comment - Is there any workaround on the issue?
          Hide
          jsimas Joao Simas added a comment -

          I'm having exactly the same behavior. Did you found any solution?

          Show
          jsimas Joao Simas added a comment - I'm having exactly the same behavior. Did you found any solution?

            People

            • Assignee:
              Unassigned
              Reporter:
              owenmehegan Owen Mehegan
            • Votes:
              2 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated: