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

Race condition in Proc.join during Channel.syncIO exchange

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Unresolved
    • Icon: Blocker Blocker
    • remoting
    • None
    • Jenkins 1.565.3 or 1.580.1

      Slave:

      "pool-1-thread-7 for channel / waiting for hudson.remoting.Channel@59494225:channel" #31 prio=5 os_prio=0 tid=0x00007f197c018800 nid=0xb40 in Object.wait() [0x00007f19c8f0b000]
         java.lang.Thread.State: TIMED_WAITING (on object monitor)
              at java.lang.Object.wait(Native Method)
              at hudson.remoting.Request.call(Request.java:146)
              - locked <0x00000000eb2b82b0> (a hudson.remoting.UserRequest)
              at hudson.remoting.Channel.call(Channel.java:742)
              at hudson.remoting.Channel.syncIO(Channel.java:1224)
              at hudson.Launcher$RemoteLaunchCallable$1.join(Launcher.java:1120)
              at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
              at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
              at java.lang.reflect.Method.invoke(Method.java:483)
              at hudson.remoting.RemoteInvocationHandler$RPCRequest.perform(RemoteInvocationHandler.java:310)
              at hudson.remoting.RemoteInvocationHandler$RPCRequest.call(RemoteInvocationHandler.java:290)
              at hudson.remoting.RemoteInvocationHandler$RPCRequest.call(RemoteInvocationHandler.java:249)
              at hudson.remoting.UserRequest.perform(UserRequest.java:118)
              at hudson.remoting.UserRequest.perform(UserRequest.java:48)
              at hudson.remoting.Request$2.run(Request.java:328)
              at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
              at java.util.concurrent.FutureTask.run(FutureTask.java:266)
              at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
              at java.lang.Thread.run(Thread.java:745)
      
      "Channel reader thread: channel" #14 prio=5 os_prio=0 tid=0x00007f19f4349800 nid=0xb2e runnable [0x00007f19c9506000]
         java.lang.Thread.State: RUNNABLE
              at java.io.FileInputStream.readBytes(Native Method)
              at java.io.FileInputStream.read(FileInputStream.java:246)
              at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
              at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
              - locked <0x00000000c0018040> (a java.io.BufferedInputStream)
              at hudson.remoting.FlightRecorderInputStream.read(FlightRecorderInputStream.java:82)
              at hudson.remoting.ChunkedInputStream.readHeader(ChunkedInputStream.java:72)
              at hudson.remoting.ChunkedInputStream.readUntilBreak(ChunkedInputStream.java:103)
              at hudson.remoting.ChunkedCommandTransport.readBlock(ChunkedCommandTransport.java:33)
              at hudson.remoting.AbstractSynchronousByteArrayCommandTransport.read(AbstractSynchronousByteArrayCommandTransport.java:34)
              at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:48)
      

      Master:

      "Executor #0 for Primary Koji Slave Build Machine (i-6fa7f885) : executing WildFly - WildFly Distro #39 / waiting for hudson.remoting.Channel@30bd27ca:Primary Koji Slave Build Machine (i-6fa7f885)" #9336 daemon prio=5 os_prio=0 tid=0x00002acaa84b6000 nid=0x14268 in Object.wait() [0x00002acad238f000]
         java.lang.Thread.State: TIMED_WAITING (on object monitor)
              at java.lang.Object.wait(Native Method)
              at hudson.remoting.Request.call(Request.java:146)
              - locked <0x00000007bf395350> (a hudson.remoting.UserRequest)
              at hudson.remoting.Channel.call(Channel.java:742)
              at hudson.remoting.RemoteInvocationHandler.invoke(RemoteInvocationHandler.java:168)
              at com.sun.proxy.$Proxy84.join(Unknown Source)
              at hudson.Launcher$RemoteLauncher$ProcImpl.join(Launcher.java:956)
              at hudson.Launcher$ProcStarter.join(Launcher.java:367)
              at org.jfrog.hudson.maven3.Maven3Builder.perform(Maven3Builder.java:85)
              at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
              at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:756)
              at hudson.model.Build$BuildExecution.build(Build.java:198)
              at hudson.model.Build$BuildExecution.doRun(Build.java:159)
              at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:529)
              at hudson.model.Run.execute(Run.java:1706)
              at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
              at hudson.model.ResourceController.execute(ResourceController.java:88)
              at hudson.model.Executor.run(Executor.java:232)
      
      "Channel reader thread: Primary Koji Slave Build Machine (i-6fa7f885)" #9410 daemon prio=5 os_prio=0 tid=0x00002acaab7f0800 nid=0x14205 in Object.wait() [0x00002acad2b96000]
         java.lang.Thread.State: WAITING (on object monitor)
              at java.lang.Object.wait(Native Method)
              at java.lang.Object.wait(Object.java:502)
              at com.trilead.ssh2.channel.FifoBuffer.read(FifoBuffer.java:212)
              - locked <0x00000006c4d9cc40> (a com.trilead.ssh2.channel.Channel)
              at com.trilead.ssh2.channel.Channel$Output.read(Channel.java:127)
              at com.trilead.ssh2.channel.ChannelManager.getChannelData(ChannelManager.java:946)
              - locked <0x00000006c4d9cc40> (a com.trilead.ssh2.channel.Channel)
              at com.trilead.ssh2.channel.ChannelInputStream.read(ChannelInputStream.java:58)
              at com.trilead.ssh2.channel.ChannelInputStream.read(ChannelInputStream.java:79)
              at hudson.remoting.FlightRecorderInputStream.read(FlightRecorderInputStream.java:82)
              at hudson.remoting.ChunkedInputStream.readHeader(ChunkedInputStream.java:72)
              at hudson.remoting.ChunkedInputStream.readUntilBreak(ChunkedInputStream.java:103)
              at hudson.remoting.ChunkedCommandTransport.readBlock(ChunkedCommandTransport.java:33)
              at hudson.remoting.AbstractSynchronousByteArrayCommandTransport.read(AbstractSynchronousByteArrayCommandTransport.java:34)
              at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:48)
      

      This is not localized to Maven process and seems to be very timing-sensitive and manifests most frequently in our systems during that phase of build. I was able to achieve the same race using the debugger with Git process at least once. It's unclear whether a slave is racing the master or other way around.

            vyalamarthy Venkata Vineel Yalamarthi
            arcivanov Arcadiy Ivanov
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

              Created:
              Updated: