TestNG, and and intermittent 0 byte jacoco.exec

1,025 views
Skip to first unread message

adam...@gmail.com

unread,
Apr 11, 2016, 5:51:02 PM4/11/16
to JaCoCo and EclEmma Users
Hi All,

I love the coverage metrics that I get out of TestNG/jacoco when I get them, but I'm having a problem that's been unsolvable so far.

We're using ant as our build platform, TestNG in "mixed" mode to run mostly JUnit, but also some TestNG tests, with Jenkins for CI. With EXACTLY THE SAME CONFIGURATION sometimes a build will generate a 1.3M jacoco.exec (~500k lines of code in the project) and other times it generates an empty file (0 bytes).

I *suspect* that something is causing the jvm to exit with a non-zero return code since the documentation for jacoco says stats are only generated if the jvm exits normally. Here's my setup...

java version "1.7.0_76"
Apache Ant(TM) version 1.9.3
junit 4.11
testng 6.8

A trigger kicks off the jenkins build. The trigger is the throttle (only 1 job can run at a time) and the build runs by calling other jobs sequentially and blocking until all steps complete.

Step 1 is the trigger, it deletes artifacts using a shell script...

if [ -f ./sonar/reports/jacoc.exec ] ; then echo "Removing ./sonar/report/jacoco.exec" ; rm -rf ./sonar/report/jacoco.exec ; else echo "No ./sonar/report/jacoco.exec." ; fi ;
if [ -d ./sonar/report/debug ] ; then echo "Removing ./sonar/report/debug" ; rm -rf ./sonar/report/debug ; else echo "No ./sonar/report/debug" ; fi ;
if [ -d ./sonar/report/junit ] ; then echo "Removing ./sonar/report/junit" ; rm -rf ./sonar/report/junit ; else echo "No ./sonar/report/junit" ; fi ;

Step 2 is a compile job that compiles the source and test code into a working directory.

(script not included)

Step 3 is calling a shell script to eliminate any possibility of the jvm being shared with anything else, even though testng theoretically always forks, just to be really, really, really sure...

#!/bin/bash
echo invoking ant build...
cd sonar
/opt/local/ant/bin/ant -file build.xml run-tests
cd ..

The code has already been compiled into a working directory, there's a throttle on the upstream job that prevents other jobs from running - this is the only thing happening in the working directory at this time, I swear! The build step looks like...

<property name="build.dir" value="${basedir}/build" />
<property name="app.name" value="XXXXXXXXXXXX" />
<property name="build.app.dir" value="${build.dir}/${app.name}" />
<property name="build.outputDir" value="${build.app.dir}/WEB-INF/classes"/>
<property name="test.src.dir" value="test"/>
<property name="test.resource.dir" value="test/resources"/>
<property name="jacoco.exec" value="../sonar/report/jacoco.exec"/>
<property name="report.dir" value="../sonar/report/"/>
<property name="junit.report" value="../sonar/report/junit/junitreports/"/>

<taskdef uri="antlib:org.jacoco.ant" resource="org/jacoco/ant/antlib.xml" classpath="../sonar/lib/jacocoant.jar">
</taskdef>

<taskdef name="testng" classname="org.testng.TestNGAntTask">
<classpath>
<pathelement location="../sonar/lib/testng-6.8.jar" />
</classpath>
</taskdef>

<target name="run-tests" description="Run unit tests to get code coverage metrics">

<jacoco:coverage
destfile="${jacoco.exec}"
append="true"
classdumpdir="../sonar/report/debug/"
enabled="true"
includes="com/XXXXXXX/**.*:com/XXXXXXXXX/**.*"
sessionId="1"
output="file"
dumpOnExit="true">
<testng
mode="mixed"
workingDir="${basedir}"
classfilesetref="unit.tests.fileset"
outputdir="../sonar/report/junit"
suitename="junitreports"
verbose="2"
haltonfailure="false">
<classpath>
<path refid="test.classpath" />
<pathelement location="${build.dir}/test/classes" />
<pathelement location="${build.outputDir}" />
<pathelement location="${test.resource.dir}" />
</classpath>
<jvmarg line="-Xmx4096m -XX:PermSize=512m -XX:MaxPermSize=2048m -Duser.timezone=UTC -XX:-UseGCOverheadLimit"/>
<jvmarg value="-Dfips.provider=SunRsaSign" />
</testng>
</jacoco:coverage>

</target>

The next step to try to get this to work, I guess, is to run the whole thing from the command line as a direct invocation of TestNG outside of ant with the jacoco command line args passed. That seems a very, very brute force way to go, but there doesn't seem to be any practical way to debug the exit code from testNG and I'm getting these empty files...

Verifying jacoco.exec...
/var/lib/jenkins/workspace/XXXXXXXXX-sonar-bugfix
Found ./sonar/report/jacoco.exec
-rw-r--r-- 1 jenkins jenkins 0 Apr 11 21:12 ./sonar/report/jacoco.exec

...so that's where I'm headed now, but I'm not full of hope and enthusiasm for this solution. If I do find I'm getting a non-zero return code I'm going to have to go diving through the TestNG code. If I don't then I'm going to be really stuck. Surely this must be some kind of race condition...???

If anyone has any insights about where I may have stumbled or knows what the problem is it would surely make me smile!

Adam Gresh

unread,
Apr 12, 2016, 12:29:25 PM4/12/16
to jac...@googlegroups.com
Sorry, I should have posted the stack that's generated by the sonar analysis...

ERROR: Error during Sonar runner execution
org.sonar.runner.impl.RunnerException: Unable to execute Sonar
	at org.sonar.runner.impl.BatchLauncher$1.delegateExecution(BatchLauncher.java:91)
	at org.sonar.runner.impl.BatchLauncher$1.run(BatchLauncher.java:75)
	at java.security.AccessController.doPrivileged(Native Method)
	at org.sonar.runner.impl.BatchLauncher.doExecute(BatchLauncher.java:69)
	at org.sonar.runner.impl.BatchLauncher.execute(BatchLauncher.java:50)
	at org.sonar.runner.api.EmbeddedRunner.doExecute(EmbeddedRunner.java:102)
	at org.sonar.runner.api.Runner.execute(Runner.java:100)
	at org.sonar.runner.Main.executeTask(Main.java:70)
	at org.sonar.runner.Main.execute(Main.java:59)
	at org.sonar.runner.Main.main(Main.java:53)
Caused by: org.sonar.api.utils.SonarException: Unable to read /var/lib/jenkins/workspace/XXXXXXXXX-sonar-bugfix/sonar/report/jacoco.exec to determine JaCoCo binary format.
	at org.sonar.plugins.jacoco.JacocoReportReader.isCurrentReportFormat(JacocoReportReader.java:99)
	at org.sonar.plugins.jacoco.JacocoReportReader.<init>(JacocoReportReader.java:50)
	at org.sonar.plugins.jacoco.JaCoCoReportMerger.loadSourceFiles(JaCoCoReportMerger.java:73)
	at org.sonar.plugins.jacoco.JaCoCoReportMerger.mergeReports(JaCoCoReportMerger.java:53)
	at org.sonar.plugins.jacoco.JaCoCoOverallSensor.analyse(JaCoCoOverallSensor.java:78)
	at org.sonar.batch.phases.SensorsExecutor.executeSensor(SensorsExecutor.java:59)
	at org.sonar.batch.phases.SensorsExecutor.execute(SensorsExecutor.java:51)
	at org.sonar.batch.phases.DatabaseModePhaseExecutor.execute(DatabaseModePhaseExecutor.java:120)
	at org.sonar.batch.scan.ModuleScanContainer.doAfterStart(ModuleScanContainer.java:264)
	at org.sonar.api.platform.ComponentContainer.startComponents(ComponentContainer.java:92)
	at org.sonar.api.platform.ComponentContainer.execute(ComponentContainer.java:77)
	at org.sonar.batch.scan.ProjectScanContainer.scan(ProjectScanContainer.java:235)
	at org.sonar.batch.scan.ProjectScanContainer.scanRecursively(ProjectScanContainer.java:230)
	at org.sonar.batch.scan.ProjectScanContainer.doAfterStart(ProjectScanContainer.java:220)
	at org.sonar.api.platform.ComponentContainer.startComponents(ComponentContainer.java:92)
	at org.sonar.api.platform.ComponentContainer.execute(ComponentContainer.java:77)
	at org.sonar.batch.scan.ScanTask.scan(ScanTask.java:57)
	at org.sonar.batch.scan.ScanTask.execute(ScanTask.java:45)
	at org.sonar.batch.bootstrap.TaskContainer.doAfterStart(TaskContainer.java:135)
	at org.sonar.api.platform.ComponentContainer.startComponents(ComponentContainer.java:92)
	at org.sonar.api.platform.ComponentContainer.execute(ComponentContainer.java:77)
	at org.sonar.batch.bootstrap.GlobalContainer.executeTask(GlobalContainer.java:158)
	at org.sonar.batch.bootstrapper.Batch.executeTask(Batch.java:95)
	at org.sonar.batch.bootstrapper.Batch.execute(Batch.java:67)
	at org.sonar.runner.batch.IsolatedLauncher.execute(IsolatedLauncher.java:48)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.sonar.runner.impl.BatchLauncher$1.delegateExecution(BatchLauncher.java:87)
	... 9 more
Caused by: java.io.EOFException
	at java.io.DataInputStream.readByte(DataInputStream.java:267)
	at org.sonar.plugins.jacoco.JacocoReportReader.isCurrentReportFormat(JacocoReportReader.java:89)
	... 38 more


--
You received this message because you are subscribed to a topic in the Google Groups "JaCoCo and EclEmma Users" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/jacoco/ErZL3TJsDqc/unsubscribe.
To unsubscribe from this group and all its topics, send an email to jacoco+un...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/jacoco/e3d66467-9713-44fc-b96c-61108e18722b%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.



--

Marc Hoffmann

unread,
Apr 13, 2016, 2:23:27 PM4/13/16
to jac...@googlegroups.com
Hi,

if exec files are not generated at all, or clipped somewhere in the
middle (as you stack trace suggests) this is typically due to a
non-graceful shutdown of the JVM running the tests.

Just this week we identified a JVM bug which causes corrupted exec files
under a specific condition, see:
https://github.com/jacoco/jacoco/issues/394

You might check whether the main thread or the thread finally calling
System.exit() is in the interrupted state.

Regards,
-marc

Adam Gresh

unread,
Apr 14, 2016, 10:35:38 AM4/14/16
to jac...@googlegroups.com
That thread does indeed sound familiar and certainly could account for the behavior I'm seeing.  Since I'm running through ant it's tough to get the exit code for the JVM.  If I want to verify this as the cause it seems like I will have to kick off TestNG from the command line, which is not trivial in my case due to a complex classpath and the arguments i'm using right now for TestNG.  I'm not sure they are all supported.

Thank you for the information, very helpful.

--
You received this message because you are subscribed to a topic in the Google Groups "JaCoCo and EclEmma Users" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/jacoco/ErZL3TJsDqc/unsubscribe.
To unsubscribe from this group and all its topics, send an email to jacoco+un...@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

Marc R. Hoffmann

unread,
Apr 14, 2016, 2:56:00 PM4/14/16
to jac...@googlegroups.com
I don't think the exit code matters: You can properly shut down the JVM with e.g. System.exit(-1) and still get an proper exec dump.

Regards,
-marc
You received this message because you are subscribed to the Google Groups "JaCoCo and EclEmma Users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to jacoco+un...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/jacoco/CALERUf1SKThrF%3DOtiz-5_GZjg59yHuvgMvO_Q08DGx2JF2s-RA%40mail.gmail.com.

adam...@gmail.com

unread,
Apr 18, 2016, 9:31:42 AM4/18/16
to JaCoCo and EclEmma Users
I get it now. A "normal exit" just means the JVM didn't crash. The bug that's preventing me from getting a populated sonar.exec is that under the right race conditions the shutdown hook doesn't run so it isn't anything to do with the exit code of the running process.

Thank you so much for the help!
Reply all
Reply to author
Forward
This conversation is locked
You cannot reply and perform actions on locked conversations.
0 new messages