Clover reports wildly varying coverage percentages on two runs of the same test

I am trying to obtain a Clover 3.1.11 coverage report on a Java program that is built with mvn (multi-project), but then run outside of Maven.

Every time the program is run in the same way the coverage report shows entirely different coverage percentages. Some classes that were reported as 0% during the previous run are then reported to have 60% coverage. Other classes have it exactly the opposite.

I have tried all three flush policies and a sub-second flush interval to no avail. strace reports that the coverage data file is indeed written to periodically.

My maven configuration is as follows:

<plugin>
                                <groupId>com.atlassian.maven.plugins</groupId>
                                <artifactId>maven-clover2-plugin</artifactId>
                                <version>3.1.11</version>
                                <configuration>
                                        <singleCloverDatabase>true</singleCloverDatabase>
                                        <baseDir>target/clover</baseDir>
                                        <flushpolicy>interval</flushpolicy>
                                        <flushinterval>500</flushinterval>
                                </configuration>
                        </plugin>

                                <dependency>
                                        <groupId>com.cenqua.clover</groupId>
                                        <artifactId>clover</artifactId>
                                        <version>3.1.11</version>
                                </dependency>

The sequence of steps that I use is as follows:

$ mvn clean clover2:clean compile clover2:setup install -DskipTests=true
... call produced .jar file outside of maven
$ mvn clover2:clover -DskipTests=true

Any help would be much appreciated. Thank you.

9 answers

1 accepted

Hi Philip,

I can see that you run:

mvn clean clover2:clean compile clover2:setup install

Please move clover2:setup before compile and try once again:

mvn clean clover2:clean clover2:setup compile install

Let us know the outcome.

Cheers,
Jacek

Yes, switching the phases as you describe resulted in repeatable coverage reports. Thank you very much for your help.

java version "1.6.0_33"

Java(TM) SE Runtime Environment (build 1.6.0_33-b03)

Java HotSpot(TM) 64-Bit Server VM (build 20.8-b03, mixed mode)

0 vote

Every time the program is run in the same way

Could you elaborate, please? Do you run automated tests or manual ones? Do you deploy a jar to some application server? Do you see the same amount of global (clover.dbsome_hash) and per-test (clover.dbsome_longer_hash.s) coverage files?

Hello,

The test is automated -- it is a script that performs exactly the same actions each time. No application server is used.

The application is a Java TCP server. It is started (java -jar ...) so that it can perform initialization and start to listen on its TCP port, and then killed via kill after 2 seconds. It does not accept any actual connections or process any actual requests, and yet the reported coverage is vastly different each time. The differences are so big that I do not think they can be explained by timing issues in the code being coverage-d.

For example:

From run #1:

com.nuodb.agent (15.9%)

com.nuodb.agent.auth (5.3%)

com.nuodb.agent.db (0%)

com.nuodb.agent.event (15.7%)

com.nuodb.agent.net (0%)

com.nuodb.agent.plugin (15.6%)

com.nuodb.agent.service (5.3%)

-rw-rw-r--. 1 philips philips 3673401 May 21 14:32 clover.db

-rw-rw-r--. 1 philips philips 415 May 21 14:32 clover.dba5yz54_hgz06hzz

-rw-rw-r--. 1 philips philips 381 May 21 14:32 clover.dba5yz54_hgz06hzz.1

---
And then run #2:
com.nuodb.agent (16%)
com.nuodb.agent.auth (0.8%) <- this was 5.3% above
com.nuodb.agent.db (0%)
com.nuodb.agent.event (15.7%)
com.nuodb.agent.plugin (0%) <- this was 15.6%
com.nuodb.agent.service (1.4%)
com.nuodb.agent.util (11.7%)
com.nuodb.compliance (0%)
-rw-rw-r--. 1 philips philips 3673401 May 21 14:35 clover.db
-rw-rw-r--. 1 philips philips 386 May 21 14:35 clover.dbe1a4se_hgz0bbjp
-rw-rw-r--. 1 philips philips 386 May 21 14:35 clover.dbe1a4se_hgz0bbjp.1
-rw-rw-r--. 1 philips philips 301 May 21 14:35 clover.dbsk4k9u_hgz0bbgb
-rw-rw-r--. 1 philips philips 284 May 21 14:35 clover.dbsk4k9u_hgz0bbgb.1
Thank you.

0 vote

PS: what OS version do you have? is there any chance that coverage files are being written on a network drive?

0 vote

1) Did you perform project rebuild between run#1 and run#2? In other words, does subsequent executions of exactly the same code produce different coverage results?

2) Does your server code has some kind of lazy initialization of it's classes, i.e. sth that might take longer than 2 seconds? Have you tried to send kill signal later than 2 seconds?

3) Please run the Java TCP server with -Dclover.logging.level=debug - do you see any error messages like: class not found exceptions, problems with writing coverage files etc?

4) Please run clover2:clover task with -Dclover.logging.level=debug - are there any message like ""Ignoring coverage recording XXXX because no FileInfo supports its coverage range" or "Failed to load coverage recording XXXX"

In case tips above won't help, do not hesitate to raise a support ticket at http://support.atlassian.com (in the "Clover Support" project) and attach build logs, pom, clover.db and coverage files. I'll be happy to investigate it.

#3. The output from runing the jar file with -Dclover.logging.level=debug is:

Clover.getRecorder(/home/philips/git/nuodb/target/clover/clover.db, 1369142326765, 8589935092, 42590, [InstrumentationProperties={clover.distributed.coverage=null}, cloverSystemProperties={clover.logging.level=debug}]) resulting in new recorder called from (first 10 stack elements):
com_cenqua_clover.Clover$InitialisedRuntime$1.run(Clover.java:489)
com_cenqua_clover.Clover$InitialisedRuntime$1.run(Clover.java:477)
java.security.AccessController.doPrivileged(Native Method)
com_cenqua_clover.Clover$InitialisedRuntime.getRecorder(Clover.java:476)
com_cenqua_clover.Clover.getRecorder(Clover.java:106)
com.nuodb.agent.NuoAgent$__CLR3_1_11wrewrehgz3zojs.&lt;clinit&gt;(NuoAgent.java:57)
com.nuodb.agent.NuoAgent$1.&lt;init&gt;(NuoAgent.java:78)
com.nuodb.agent.NuoAgent.&lt;clinit&gt;(NuoAgent.java:75)

[creating new recorder for /home/philips/git/nuodb/target/clover/clover.db_1369142326765_8589935092]
CLOVER: No profiles defined in instrumented classes. Using standard settings.
Failed to newly create the recording-is-live flag file at /home/philips/git/nuodb/target/clover/clover.db.liverec because the file already exists
Started active flush thread for registry at /home/philips/git/nuodb/target/clover/clover.db, interval= 500
Added shutdown hook for registry at /home/philips/git/nuodb/target/clover/clover.db
Started recorder for registry at "/home/philips/git/nuodb/target/clover/clover.db": FixedSizeCoverageRecorder[elements.length=54394]
CLOVER: No profiles defined in instrumented classes. Using standard settings.
Distributed coverage is disabled.'
[found existing recorder for /home/philips/git/nuodb/target/clover/clover.db_1369142326765_8589935092]


#4. Setting the debug flag during clover2:clover produces no additional log output or errors

#5. I tried this on two different flavors of Linux, two different OpenJDK versions. All filesystems used are local.

Hello,

To answer your questions:

#1. Yes a project rebuild is done before each attempt. I believe exactly the same code is used. The size of the clover.db file is exactly the same after each rebuild, though the size of the clover.db{hash} files is different after each rebuild even if exactly the same test is run. If multiple tests are made after the rebuild, they will all result in same-sized files.

For example, I rebuild the project and then I exercise just the --help function of my .jar file. This produces hash files of say 100 bytes every time I run the jar file. However, if I rebuild, future executions will now produce coverage files of 200 bytes until the next rebuild.

#2. I have changed my test to exit cleanly without having to kill the JVM, that is, I run a command-line option to the binary that causes it to exit immediately. And still, code coverage varies between runs. I have also performed experiments where the server is left to run for prolonged periods of time, the code coverage still fluctuated. To the best of my knowledge, no lazy initialization is used.

Suggest an answer

Log in or Sign up to answer
How to earn badges on the Atlassian Community

How to earn badges on the Atlassian Community

Badges are a great way to show off community activity, whether you’re a newbie or a Champion.

Learn more
Community showcase
Published yesterday in Hipchat

Moving from Hipchat to Stride? Here’s what you’ll love

Heya, Hipchat friends! We’re so happy you’re checking out   Stride. Whether you know it or not, you have been instrumental in making Stride come to life. Every feature, design, and functionality...

59 views 2 6
Read article

Atlassian User Groups

Connect with like-minded Atlassian users at free events near you!

Find a group

Connect with like-minded Atlassian users at free events near you!

Find my local user group

Unfortunately there are no AUG chapters near you at the moment.

Start an AUG

You're one step closer to meeting fellow Atlassian users at your local meet up. Learn more about AUGs

Groups near you