Bug 397352 - doxygen plugin hangs on Hudson 3.0.0
Summary: doxygen plugin hangs on Hudson 3.0.0
Status: ASSIGNED
Alias: None
Product: Hudson
Classification: Technology
Component: Plugins (show other bugs)
Version: 3.0.0   Edit
Hardware: PC Linux
: P3 normal (vote)
Target Milestone: ---   Edit
Assignee: Steve Christou CLA
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2013-01-03 05:09 EST by nicholas randon CLA
Modified: 2013-08-13 06:09 EDT (History)
2 users (show)

See Also:


Attachments
threadDump Lock hudson job (99.51 KB, text/plain)
2013-01-10 09:55 EST, nicholas randon CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description nicholas randon CLA 2013-01-03 05:09:30 EST
Using a matrix based project with 2 nodes (only one producing Doxygen files) when the builder job try to copy the Doxygen files the build hangs or you get the following Java exception:

FATAL: error
hudson.util.IOException2: Failed to extract /mnt/JOBNAME/label/BOB/docs/html/**/*
	at hudson.FilePath.readFromTar(FilePath.java:1687)
	at hudson.FilePath.copyRecursiveTo(FilePath.java:1601)
	at hudson.FilePath.copyRecursiveTo(FilePath.java:1500)
	at hudson.FilePath.copyRecursiveTo(FilePath.java:1489)
	at hudson.plugins.doxygen.DoxygenArchiver._perform(DoxygenArchiver.java:231)
	at hudson.plugins.doxygen.DoxygenArchiver.access$200(DoxygenArchiver.java:50)
	at hudson.plugins.doxygen.DoxygenArchiver$1.endBuild(DoxygenArchiver.java:364)
	at hudson.matrix.MatrixBuild$RunnerImpl.post2(MatrixBuild.java:356)
	at hudson.model.AbstractBuild$AbstractRunner.post(AbstractBuild.java:566)
	at hudson.model.Run.run(Run.java:1414)
	at hudson.matrix.MatrixBuild.run(MatrixBuild.java:164)
	at hudson.model.ResourceController.execute(ResourceController.java:81)
	at hudson.model.Executor.run(Executor.java:137)
	at hudson.model.OneOffExecutor.run(OneOffExecutor.java:60)
Caused by: java.io.IOException
	at hudson.remoting.FastPipedInputStream.read(FastPipedInputStream.java:190)
	at hudson.util.HeadBufferingStream.read(HeadBufferingStream.java:56)
	at java.util.zip.InflaterInputStream.fill(InflaterInputStream.java:221)
	at java.util.zip.InflaterInputStream.read(InflaterInputStream.java:141)
	at java.util.zip.GZIPInputStream.read(GZIPInputStream.java:92)
	at org.apache.tools.tar.TarBuffer.readBlock(TarBuffer.java:257)
	at org.apache.tools.tar.TarBuffer.readRecord(TarBuffer.java:223)
	at hudson.org.apache.tools.tar.TarInputStream.read(TarInputStream.java:345)
	at java.io.FilterInputStream.read(FilterInputStream.java:90)
	at org.apache.commons.io.IOUtils.copyLarge(IOUtils.java:1262)
	at org.apache.commons.io.IOUtils.copy(IOUtils.java:1236)
	at hudson.util.IOUtils.copy(IOUtils.java:48)
	at hudson.FilePath.readFromTar(FilePath.java:1677)
	... 13 more
Comment 1 Steve Christou CLA 2013-01-09 08:40:40 EST
I'm sorry for the late response on this. I have been trying multiple ways to replicate this issue, however I can't. I got an issue similar where the output folder (OUTPUT_DIRECTORY in the DoxyFile) was either an empty folder or a folder that did not exist. Next time this hangs, could you get a threadDump for me by going to http://localhost:8080/threadDump, and attach it to this bug.

Thanks,
Steve.
Comment 2 nicholas randon CLA 2013-01-10 09:55:19 EST
Created attachment 225443 [details]
threadDump Lock hudson job

Here is a threadDump during a hang/lock of the Doxygen plug in.
Comment 3 nicholas randon CLA 2013-01-10 09:59:03 EST
It has also be notice that we get a warning in the Hudson log As follows that may be related ( This happens about once a second ).

WARNING: Native function chmod failed. Using Ant''s chmod task instead.
Jan 10, 2013 2:55:56 PM hudson.Util chmod
WARNING: Native function chmod failed. Using Ant''s chmod task instead.

Think this relate to Executor #11 for BOB from the threadDump:

"Executor #11 for BOB : executing BUILD_JOB2/label=BOB #1470" Id=97 Group=main TIMED_WAITING on org.apache.tools.ant.taskdefs.PumpStreamHandler$ThreadWithPumper@3d6c767a
	at java.lang.Object.wait(Native Method)
	-  waiting on org.apache.tools.ant.taskdefs.PumpStreamHandler$ThreadWithPumper@3d6c767a
	at java.lang.Thread.join(Thread.java:1151)
	at org.apache.tools.ant.taskdefs.PumpStreamHandler.finish(PumpStreamHandler.java:188)
	at org.apache.tools.ant.taskdefs.PumpStreamHandler.stop(PumpStreamHandler.java:158)
	at org.apache.tools.ant.taskdefs.Execute.execute(Execute.java:521)
	at org.apache.tools.ant.taskdefs.ExecTask.runExecute(ExecTask.java:631)
	at org.apache.tools.ant.taskdefs.ExecuteOn.runParallel(ExecuteOn.java:716)
	at org.apache.tools.ant.taskdefs.ExecuteOn.runExec(ExecuteOn.java:479)
	at org.apache.tools.ant.taskdefs.ExecTask.execute(ExecTask.java:498)
	at org.apache.tools.ant.taskdefs.Chmod.execute(Chmod.java:181)
	at hudson.Util._chmodAnt(Util.java:1108)
	at hudson.Util.chmod(Util.java:1092)
	at hudson.Util.chmod(Util.java:1100)
	at hudson.FilePath.readFromTar(FilePath.java:1682)
	at hudson.FilePath.copyRecursiveTo(FilePath.java:1601)
	at hudson.FilePath.copyRecursiveTo(FilePath.java:1500)
	at hudson.FilePath.copyRecursiveTo(FilePath.java:1489)
	at hudson.tasks.JavadocArchiver.perform(JavadocArchiver.java:101)
	at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:34)
	at hudson.model.AbstractBuild$AbstractRunner.perform(AbstractBuild.java:646)
	at hudson.model.AbstractBuild$AbstractRunner.performAllBuildSteps(AbstractBuild.java:624)
	at hudson.model.AbstractBuild$AbstractRunner.performAllBuildSteps(AbstractBuild.java:600)
	at hudson.model.Build$RunnerImpl.post2(Build.java:163)
	at hudson.model.AbstractBuild$AbstractRunner.post(AbstractBuild.java:566)
	at hudson.model.Run.run(Run.java:1414)
	at hudson.matrix.MatrixRun.run(MatrixRun.java:142)
	at hudson.model.ResourceController.execute(ResourceController.java:81)
	at hudson.model.Executor.run(Executor.java:137)
Comment 4 Steve Christou CLA 2013-01-10 10:02:09 EST
What version of the JNA Native Support Plugin is currently installed?
Comment 5 nicholas randon CLA 2013-01-10 10:12:34 EST
JNA Native Support Plugin 3.0.2

This is disabled in the install at as otherwise we get the following intermittently at the end of the matrix jobs:

FATAL: Remote call on FRED failed
java.io.IOException: Remote call on FRED failed
	at hudson.remoting.Channel.call(Channel.java:652)
	at hudson.Launcher$RemoteLauncher.kill(Launcher.java:771)
	at hudson.model.AbstractBuild$AbstractRunner.run(AbstractBuild.java:459)
	at hudson.model.Run.run(Run.java:1390)
	at hudson.matrix.MatrixRun.run(MatrixRun.java:142)
	at hudson.model.ResourceController.execute(ResourceController.java:81)
	at hudson.model.Executor.run(Executor.java:137)
Caused by: java.lang.NoClassDefFoundError: Could not initialize class com.sun.jna.Native
	at org.hudsonci.plugins.jna.JnaNativeMacSupport.<clinit>(JnaNativeMacSupport.java:74)
	at java.io.ObjectStreamClass.hasStaticInitializer(Native Method)
	at java.io.ObjectStreamClass.computeDefaultSUID(Unknown Source)
	at java.io.ObjectStreamClass.access$100(Unknown Source)
	at java.io.ObjectStreamClass$1.run(Unknown Source)
	at java.security.AccessController.doPrivileged(Native Method)
	at java.io.ObjectStreamClass.getSerialVersionUID(Unknown Source)
	at java.io.ObjectStreamClass.initNonProxy(Unknown Source)
	at java.io.ObjectInputStream.readNonProxyDesc(Unknown Source)
	at java.io.ObjectInputStream.readClassDesc(Unknown Source)
	at java.io.ObjectInputStream.readOrdinaryObject(Unknown Source)
	at java.io.ObjectInputStream.readObject0(Unknown Source)
	at java.io.ObjectInputStream.defaultReadFields(Unknown Source)
	at java.io.ObjectInputStream.readSerialData(Unknown Source)
	at java.io.ObjectInputStream.readOrdinaryObject(Unknown Source)
	at java.io.ObjectInputStream.readObject0(Unknown Source)
	at java.io.ObjectInputStream.defaultReadFields(Unknown Source)
	at java.io.ObjectInputStream.readSerialData(Unknown Source)
	at java.io.ObjectInputStream.readOrdinaryObject(Unknown Source)
	at java.io.ObjectInputStream.readObject0(Unknown Source)
	at java.io.ObjectInputStream.readObject(Unknown Source)
	at hudson.remoting.UserRequest.deserialize(UserRequest.java:171)
	at hudson.remoting.UserRequest.perform(UserRequest.java:91)
	at hudson.remoting.UserRequest.perform(UserRequest.java:41)
	at hudson.remoting.Request$2.run(Request.java:276)
	at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
	at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
	at java.util.concurrent.FutureTask.run(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)
Comment 6 nicholas randon CLA 2013-01-10 11:25:26 EST
Don't think this is strictly a Doxygen problem or a hang is would seem that is related to the chmod problem. If you also try using JavaDocs and copy the files back to Hudson you get a similar looking problem. The main think to note is that job that used to take 1.3 minutes now increase in time to about 20 minutes. The common factor here is the build are run at normal speed it is the copy back of the documentation form the slave to the Hudson that is slowing the process down.

Still not sure how to reproduce the Java expositions we sore when we first upgraded.
Comment 7 Steve Christou CLA 2013-01-10 11:28:39 EST
Is this a linux distro? The bug description says Linux, however when looking at the stack trace it refers to MAC.
Comment 8 nicholas randon CLA 2013-01-10 11:32:01 EST
We are running Hudson on SUSE Enterprise Linux 10 and we notice the MAC comment ??  not sure what is going no there! This is just an update form Hudson 2.2.1
Comment 9 Steve Christou CLA 2013-01-10 11:40:51 EST
Would you mind testing a fresh install? Something might have happened when doing the upgrade. You can copy all the jobs and config.xml file, just the root install needs to be fresh, along with fresh install of plugins.
Comment 10 nicholas randon CLA 2013-01-10 11:44:55 EST
Yep we can do a fresh install as you have suggested and see what happens. I will repost back when it been done.
Comment 11 nicholas randon CLA 2013-01-11 06:01:33 EST
Ok the same problem was found form a clean install. However the problem with the the JNA was only shown on initiator of the build running older versions of SLES (9 and 10). On newer version of Linux RHEL and SUSE 11 all works fine so I guess it the way the JNA selects the os.
Comment 12 Steve Christou CLA 2013-01-11 16:40:18 EST
I will log a bug with the JNA plugin to verify and fix the OS issue.

Are you still getting the doxygen issue?
Comment 13 nicholas randon CLA 2013-01-14 04:50:48 EST
I think it is fine to close this issue as the JNA seem to be causing the problem. However, it hard to test this with the JNA broken. Can this bug be linked to the JNA issue so it can be tracked ?
Comment 14 Steve Christou CLA 2013-01-14 13:25:44 EST
I currently am trying to get my hands on a copy of OpenSUSE 10 or 9 for testing, however I'm finding it a little difficult.

Are you still getting the NoClassDefFoundError. This is a compilation error that should not exist in 3.0.2 of the JNA native support plugin.
Comment 15 nicholas randon CLA 2013-01-15 04:18:20 EST
Hi we were using JNA 3.0.2 as installed by the Hudson installer and were still seeing the error. We also mad sure the war directory was removed before the upgrade and removed all the jar files installed on the slave by Hudson to make sure they were upgrade also on re-start. We have now had to revert back to Hudson 2.2.1.
Comment 16 nicholas randon CLA 2013-01-15 04:21:01 EST
FYI we are running Java runtime 1.6.0_21-b06 on all slaves and the master
Comment 17 nicholas randon CLA 2013-01-16 07:16:08 EST
We have set-up a dev system for testing using a sles9 slave (septate to the production system) and this issue is fully reproducible. We have minimised plugins to only a few (mostly default) and still see the JNA issue. 

Hudson Subversion Plug-in       2.3.6-h-1
Hudson BIRT Charts Plugin       3.0.3
JFreeChart Plugin               1.4
Hudson SSH Slaves plugin        3.0.2
Robot Framework plugin          1.2.4-h-1
XPath Provider Plugin           1.0.1
JNA Native Support Plugin       3.0.2
Comment 18 nicholas randon CLA 2013-01-16 08:34:30 EST
Found this in the Hudson log looks as if it all starts to go wrong when it tries to get status information back from the sles 9 slave

Jan 16, 2013 1:31:49 PM hudson.node_monitors.AbstractNodeMonitorDescriptor$Record run
WARNING: Failed to monitor Bock for Free Swap Space
java.io.IOException: Remote call on BOB failed
	at hudson.remoting.Channel.call(Channel.java:652)
	at hudson.node_monitors.SwapSpaceMonitor$1.monitor(SwapSpaceMonitor.java:80)
	at hudson.node_monitors.SwapSpaceMonitor$1.monitor(SwapSpaceMonitor.java:78)
	at hudson.node_monitors.AbstractNodeMonitorDescriptor$Record.run(AbstractNodeMonitorDescriptor.java:197)
Caused by: java.lang.NoClassDefFoundError: Could not initialize class org.hudsonci.plugins.jna.JnaNativeMacSupport
	at java.io.ObjectStreamClass.hasStaticInitializer(Native Method)
	at java.io.ObjectStreamClass.computeDefaultSUID(Unknown Source)
	at java.io.ObjectStreamClass.access$100(Unknown Source)
	at java.io.ObjectStreamClass$1.run(Unknown Source)
	at java.security.AccessController.doPrivileged(Native Method)
	at java.io.ObjectStreamClass.getSerialVersionUID(Unknown Source)
	at java.io.ObjectStreamClass.initNonProxy(Unknown Source)
	at java.io.ObjectInputStream.readNonProxyDesc(Unknown Source)
	at java.io.ObjectInputStream.readClassDesc(Unknown Source)
	at java.io.ObjectInputStream.readOrdinaryObject(Unknown Source)
	at java.io.ObjectInputStream.readObject0(Unknown Source)
	at java.io.ObjectInputStream.defaultReadFields(Unknown Source)
	at java.io.ObjectInputStream.readSerialData(Unknown Source)
	at java.io.ObjectInputStream.readOrdinaryObject(Unknown Source)
	at java.io.ObjectInputStream.readObject0(Unknown Source)
	at java.io.ObjectInputStream.defaultReadFields(Unknown Source)
	at java.io.ObjectInputStream.readSerialData(Unknown Source)
	at java.io.ObjectInputStream.readOrdinaryObject(Unknown Source)
	at java.io.ObjectInputStream.readObject0(Unknown Source)
	at java.io.ObjectInputStream.readObject(Unknown Source)
	at hudson.remoting.UserRequest.deserialize(UserRequest.java:171)
	at hudson.remoting.UserRequest.perform(UserRequest.java:91)
	at hudson.remoting.UserRequest.perform(UserRequest.java:41)
	at hudson.remoting.Request$2.run(Request.java:276)
	at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
	at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
	at java.util.concurrent.FutureTask.run(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)
Comment 19 Tom Fredian CLA 2013-02-25 15:14:22 EST
I also had similar problems with running builds on a RHEL5 slave node after upgrading to hudson 3.0.0. With the rhel5 slave I had two issues. First I received an error trying to use the libjnidispatch.so library which is being created in a /tmp/hudson.... directory tree. There is a problem with this library because it is linked to an incompatible libc.so.6. If I replace the libjnidispatch.so library with one provided by a jna package from epel it fixes this problem at least temporarily. This then exposes the:

Caused by: java.lang.NoClassDefFoundError: Could not initialize class org.hudsonci.plugins.jna.JnaNativeMacSupport

problem. The build on the slave completes before this problem occurs but unfortunately this problem causes hudson to report that the build failed.

If you need additional information about my installation or error messages let me know. I would also be willing to do some testing if a fix is found.
Comment 20 Tomas Buxton CLA 2013-08-13 06:07:41 EDT
I have recently revisited this issue again (with 3.0.1). I was working with the original poster when we noticed the issue. 

It does seem to be an issue with the libjnidispatch.so library that is linked to an incompatible libc.so.6.

I ran the following:.

for JAR in `find $HUDSON_HOME -name *.jar`
do
  MATCH=`unzip -l $JAR | grep libjnidispatch.so`; 
  if [ $? -eq 0 ] 
  then 
    echo $JAR; 
    unzip -o $i com/sun/jna/linux-amd64/libjnidispatch.so && nm com/sun/jna/linux-amd64/libjnidispatch.so | grep -o 'GLIBC.*' | sort | uniq -c;
    echo; 
  fi;
done

$HUDSON_HOME/plugins/jna-native-support-plugin/WEB-INF/lib/jna-3.2.4.jar
Archive:  /data/hudson-dev/plugins/jna-native-support-plugin/WEB-INF/lib/jna-3.2.4.jar
  inflating: com/sun/jna/linux-amd64/libjnidispatch.so  
     38 GLIBC_2.2.5

$HUDSON_HOME/plugins/subversion/WEB-INF/lib/jna-3.4.0.jar
Archive:  /data/hudson-dev/plugins/subversion/WEB-INF/lib/jna-3.4.0.jar
  inflating: com/sun/jna/linux-amd64/libjnidispatch.so  
      1 GLIBC_2.11
     36 GLIBC_2.2.5
      3 GLIBC_2.3.4
      1 GLIBC_2.4

$HUDSON_HOME/war/WEB-INF/lib/jna-3.3.0.jar
Archive:  /data/hudson-dev/war/WEB-INF/lib/jna-3.3.0.jar
  inflating: com/sun/jna/linux-amd64/libjnidispatch.so  
     38 GLIBC_2.2.5


As you can see the libjnidispatch.so library in the JNA release (3.4.0) included with the subversion plugin has 1 reference to GLIBC_2.11. We don't have this on are older build slaves and can't easily update them. 

To resolve the issue I copied the jna-3.3.0.jar from the core to jna-3.4.0.jar in the subversion plugin directory. This seems to fix all of the errors. I don't know why the version of the library in the subversion plugin is being used for non subversion operations I can only assume it is the last version of the library to be loaded.
Comment 21 Tomas Buxton CLA 2013-08-13 06:09:53 EDT
Update to comment #20. I restarted hudson after replacing the jar in the subversion plugin directory.