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

Parsing FindBugs report hangs sometimes

    Details

    • Type: Bug
    • Status: Resolved (View Workflow)
    • Priority: Minor
    • Resolution: Not A Defect
    • Component/s: findbugs-plugin
    • Labels:
      None
    • Environment:
      Jenkins ver. 1.509.1, FindBugs Plug-in 4.48.
      Server: CentOS 6.3 x64, jre 1.7.0_04.
      Slave: win2003R2 x32, jre 1.7.0_06.
    • Similar Issues:

      Description

      I've just discovered that one of our builds was hanging for 19 hours. Last line of build log is:

      [FINDBUGS] Collecting findbugs analysis files...

      Slave treads:

      "Attach Listener" daemon prio=5 RUNNABLE

      "Channel reader thread: channel" prio=5 RUNNABLE
      java.net.SocketInputStream.socketRead0(Native Method)
      java.net.SocketInputStream.read(Unknown Source)
      java.net.SocketInputStream.read(Unknown Source)
      java.io.FilterInputStream.read(Unknown Source)
      java.io.BufferedInputStream.fill(Unknown Source)
      java.io.BufferedInputStream.read(Unknown Source)
      java.io.ObjectInputStream$PeekInputStream.peek(Unknown Source)
      java.io.ObjectInputStream$BlockDataInputStream.peek(Unknown Source)
      java.io.ObjectInputStream$BlockDataInputStream.peekByte(Unknown Source)
      java.io.ObjectInputStream.readObject0(Unknown Source)
      java.io.ObjectInputStream.readObject(Unknown Source)
      hudson.remoting.Command.readFrom(Command.java:92)
      hudson.remoting.ClassicCommandTransport.read(ClassicCommandTransport.java:59)
      hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:48)

      "Finalizer" daemon prio=8 WAITING
      java.lang.Object.wait(Native Method)
      java.lang.ref.ReferenceQueue.remove(Unknown Source)
      java.lang.ref.ReferenceQueue.remove(Unknown Source)
      java.lang.ref.Finalizer$FinalizerThread.run(Unknown Source)

      "main" prio=5 WAITING
      java.lang.Object.wait(Native Method)
      java.lang.Object.wait(Object.java:503)
      hudson.remoting.Channel.join(Channel.java:800)
      hudson.remoting.Launcher.main(Launcher.java:484)
      hudson.remoting.Launcher.runOnSocket(Launcher.java:375)
      hudson.remoting.Launcher.runAsTcpServer(Launcher.java:365)
      hudson.remoting.Launcher.run(Launcher.java:218)
      hudson.remoting.Launcher.main(Launcher.java:180)

      "Ping thread for channel hudson.remoting.Channel@bebb88:channel" daemon prio=5 TIMED_WAITING
      java.lang.Thread.sleep(Native Method)
      hudson.remoting.PingThread.run(PingThread.java:86)

      "Ping thread for channel hudson.remoting.Channel@bebb88:channel" daemon prio=5 TIMED_WAITING
      java.lang.Thread.sleep(Native Method)
      hudson.remoting.PingThread.run(PingThread.java:86)

      "Pipe writer thread: channel" prio=5 WAITING
      sun.misc.Unsafe.park(Native Method)
      java.util.concurrent.locks.LockSupport.park(Unknown Source)
      java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Unknown Source)
      java.util.concurrent.LinkedBlockingQueue.take(Unknown Source)
      java.util.concurrent.ThreadPoolExecutor.getTask(Unknown Source)
      java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
      java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
      java.lang.Thread.run(Unknown Source)

      "pool-1-svnkit-thread-1" daemon prio=5 WAITING
      sun.misc.Unsafe.park(Native Method)
      java.util.concurrent.locks.LockSupport.park(Unknown Source)
      java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(Unknown Source)
      java.util.concurrent.SynchronousQueue$TransferStack.transfer(Unknown Source)
      java.util.concurrent.SynchronousQueue.take(Unknown Source)
      java.util.concurrent.ThreadPoolExecutor.getTask(Unknown Source)
      java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
      java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
      java.lang.Thread.run(Unknown Source)

      "pool-1-svnkit-thread-2" daemon prio=5 WAITING
      sun.misc.Unsafe.park(Native Method)
      java.util.concurrent.locks.LockSupport.park(Unknown Source)
      java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(Unknown Source)
      java.util.concurrent.SynchronousQueue$TransferStack.transfer(Unknown Source)
      java.util.concurrent.SynchronousQueue.take(Unknown Source)
      java.util.concurrent.ThreadPoolExecutor.getTask(Unknown Source)
      java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
      java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
      java.lang.Thread.run(Unknown Source)

      "pool-1-thread-1965" prio=5 RUNNABLE
      java.io.FileOutputStream.writeBytes(Native Method)
      java.io.FileOutputStream.write(Unknown Source)
      java.io.BufferedOutputStream.write(Unknown Source)
      java.io.PrintStream.write(Unknown Source)
      sun.nio.cs.StreamEncoder.writeBytes(Unknown Source)
      sun.nio.cs.StreamEncoder.implFlushBuffer(Unknown Source)
      sun.nio.cs.StreamEncoder.implFlush(Unknown Source)
      sun.nio.cs.StreamEncoder.flush(Unknown Source)
      java.io.OutputStreamWriter.flush(Unknown Source)
      java.util.logging.StreamHandler.flush(Unknown Source)
      java.util.logging.ConsoleHandler.publish(Unknown Source)
      java.util.logging.Logger.log(Unknown Source)
      java.util.logging.Logger.doLog(Unknown Source)
      java.util.logging.Logger.log(Unknown Source)
      java.util.logging.Logger.info(Unknown Source)
      hudson.plugins.disk_usage.DiskUsageThread$DiskUsageCallable.getFileSize(DiskUsageThread.java:195)
      hudson.plugins.disk_usage.DiskUsageThread$DiskUsageCallable.getFileSize(DiskUsageThread.java:192)
      hudson.plugins.disk_usage.DiskUsageThread$DiskUsageCallable.getFileSize(DiskUsageThread.java:192)
      hudson.plugins.disk_usage.DiskUsageThread$DiskUsageCallable.getFileSize(DiskUsageThread.java:192)
      hudson.plugins.disk_usage.DiskUsageThread$DiskUsageCallable.getFileSize(DiskUsageThread.java:192)
      hudson.plugins.disk_usage.DiskUsageThread$DiskUsageCallable.getFileSize(DiskUsageThread.java:192)
      hudson.plugins.disk_usage.DiskUsageThread$DiskUsageCallable.getFileSize(DiskUsageThread.java:192)
      hudson.plugins.disk_usage.DiskUsageThread$DiskUsageCallable.getFileSize(DiskUsageThread.java:192)
      hudson.plugins.disk_usage.DiskUsageThread$DiskUsageCallable.getFileSize(DiskUsageThread.java:192)
      hudson.plugins.disk_usage.DiskUsageThread$DiskUsageCallable.getFileSize(DiskUsageThread.java:192)
      hudson.plugins.disk_usage.DiskUsageThread$DiskUsageCallable.getFileSize(DiskUsageThread.java:192)
      hudson.plugins.disk_usage.DiskUsageThread$DiskUsageCallable.getFileSize(DiskUsageThread.java:192)
      hudson.plugins.disk_usage.DiskUsageThread$DiskUsageCallable.call(DiskUsageThread.java:182)
      hudson.plugins.disk_usage.DiskUsageThread$DiskUsageCallable.call(DiskUsageThread.java:169)
      hudson.remoting.UserRequest.perform(UserRequest.java:118)
      hudson.remoting.UserRequest.perform(UserRequest.java:48)
      hudson.remoting.Request$2.run(Request.java:326)
      hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
      java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
      java.util.concurrent.FutureTask.run(Unknown Source)
      java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
      java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
      java.lang.Thread.run(Unknown Source)

      "pool-1-thread-2080" prio=5 BLOCKED
      java.util.logging.StreamHandler.publish(Unknown Source)
      java.util.logging.ConsoleHandler.publish(Unknown Source)
      java.util.logging.Logger.log(Unknown Source)
      java.util.logging.Logger.doLog(Unknown Source)
      java.util.logging.Logger.log(Unknown Source)
      hudson.plugins.findbugs.parser.FindBugsParser.findSourceFile(FindBugsParser.java:322)
      hudson.plugins.findbugs.parser.FindBugsParser.parse(FindBugsParser.java:238)
      hudson.plugins.findbugs.parser.FindBugsParser.parse(FindBugsParser.java:145)
      hudson.plugins.findbugs.parser.FindBugsParser.parse(FindBugsParser.java:105)
      hudson.plugins.analysis.core.FilesParser.parseFile(FilesParser.java:306)
      hudson.plugins.analysis.core.FilesParser.parseFiles(FilesParser.java:264)
      hudson.plugins.analysis.core.FilesParser.parserCollectionOfFiles(FilesParser.java:215)
      hudson.plugins.analysis.core.FilesParser.invoke(FilesParser.java:184)
      hudson.plugins.analysis.core.FilesParser.invoke(FilesParser.java:31)
      hudson.FilePath$FileCallableWrapper.call(FilePath.java:2387)
      hudson.remoting.UserRequest.perform(UserRequest.java:118)
      hudson.remoting.UserRequest.perform(UserRequest.java:48)
      hudson.remoting.Request$2.run(Request.java:326)
      hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
      java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
      java.util.concurrent.FutureTask.run(Unknown Source)
      java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
      java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
      java.lang.Thread.run(Unknown Source)

      "pool-1-thread-2202" prio=5 TIMED_WAITING
      sun.misc.Unsafe.park(Native Method)
      java.util.concurrent.locks.LockSupport.parkNanos(Unknown Source)
      java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(Unknown Source)
      java.util.concurrent.SynchronousQueue$TransferStack.transfer(Unknown Source)
      java.util.concurrent.SynchronousQueue.poll(Unknown Source)
      java.util.concurrent.ThreadPoolExecutor.getTask(Unknown Source)
      java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
      java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
      java.lang.Thread.run(Unknown Source)

      "pool-1-thread-2203" prio=5 RUNNABLE
      java.lang.Thread.dumpThreads(Native Method)
      java.lang.Thread.getAllStackTraces(Unknown Source)
      net.bull.javamelody.JavaInformations.buildThreadInformationsList(JavaInformations.java:286)
      net.bull.javamelody.JavaInformations.<init>(JavaInformations.java:187)
      net.bull.javamelody.RemoteCallHelper$1.call(RemoteCallHelper.java:43)
      net.bull.javamelody.RemoteCallHelper$1.call(RemoteCallHelper.java:35)
      net.bull.javamelody.RemoteCallHelper$DelegatingTask.call(RemoteCallHelper.java:129)
      hudson.remoting.UserRequest.perform(UserRequest.java:118)
      hudson.remoting.UserRequest.perform(UserRequest.java:48)
      hudson.remoting.Request$2.run(Request.java:326)
      hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
      java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
      java.util.concurrent.FutureTask.run(Unknown Source)
      java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
      java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
      java.lang.Thread.run(Unknown Source)

      "Reference Handler" daemon prio=10 WAITING
      java.lang.Object.wait(Native Method)
      java.lang.Object.wait(Object.java:503)
      java.lang.ref.Reference$ReferenceHandler.run(Unknown Source)

        Attachments

          Issue Links

            Activity

            Hide
            pancake pancake added a comment -

            After cancelling the build this was logged:

            [FINDBUGS] null

            ...and then other post-build steps were executed.

            Show
            pancake pancake added a comment - After cancelling the build this was logged: [FINDBUGS] null ...and then other post-build steps were executed.
            Hide
            pancake pancake added a comment -

            Still reproduces after migrating server to java-1.7.0-openjdk-1.7.0.19.x86_64.

            Show
            pancake pancake added a comment - Still reproduces after migrating server to java-1.7.0-openjdk-1.7.0.19.x86_64.
            Hide
            drulli Ulli Hafner added a comment -

            Seems that the disk usage plug-in logs too much information which causes a deadlock in JDK logger. Can you please disable logging for the disk usage plug-in and retry?

            Show
            drulli Ulli Hafner added a comment - Seems that the disk usage plug-in logs too much information which causes a deadlock in JDK logger. Can you please disable logging for the disk usage plug-in and retry?
            Hide
            pancake pancake added a comment -

            Ulli, thanks for your investigation! I've applied the change, so let's hope the bug will not reproduce.

            Show
            pancake pancake added a comment - Ulli , thanks for your investigation! I've applied the change, so let's hope the bug will not reproduce.

              People

              • Assignee:
                drulli Ulli Hafner
                Reporter:
                pancake pancake
              • Votes:
                0 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: