Test task is very slow


(Richard Cole) #1

I’m currently noticing that my test task is very slow. I have enabled profile and I can see that the total execution time of the tests is around 1 second, however the test task itself takes closer to 1 minute. Turning on --debug I can see the point where it takes the time is:

Starting process ‘Gradle Worker 1’. Working directory: /Users/richard/Documents/work Command: /Library/Java/JavaVirtualMachines/jdk1.7.0_25.jdk/Contents/Home/bin/java -Djava.security.manager=jarjar.org.gradle.process.internal.child.BootstrapSecurityManager -javaagent:target/tmp/expandedArchives/org.jacoco.agent-0.6.2.201302030002.jar_nr6ps8atth435ev82f650urfk/jacocoagent.jar=destfile=target/jacoco/test.exec,append=true,dumponexit=true,output=file,jmx=false -Dfile.encoding=UTF-8 -ea -cp /Users/richard/.gradle/caches/1.11/workerMain/gradle-worker.jar jarjar.org.gradle.process.internal.launcher.GradleWorkerMain Successfully started process ‘Gradle Worker 1’

At this point there is nothing until the task returns a minute or so later. Any ideas?


(Richard Cole) #2

Before I post on SO, anyone have any ideas on this please?


(Peter Niederwieser) #3

Oftentimes it’s a low memory issue. Try to give the ‘Test’ task more memory and play around with the ‘forkEvery’ setting. For details, check ‘Test’ in the Gradle Build Language Reference.


(Richard Cole) #4

Hi Peter, I’ve tried various settings for minHeapSize and maxHeapSize all the way up to 2048m and it doesn’t make any difference. Also worth noting that these tests are incredibly simple. Running the same tests directly from idea takes < 1 second.


(Peter Niederwieser) #5

Hard to say then. Perhaps try without JaCoCo in the mix.


(Richard Cole) #6

Any other debug information that I can throw in to help? This is becoming a blocker to me using gradle at the moment.


(Peter Niederwieser) #7

If you can provide a self-contained example that reproduces the problem on your machine, I’ll have a look. You could also try on a different machine, or investigate with a profiler.


(Richard Cole) #8

Pushed a very simple example to github:

https://github.com/imrichardcole/test-example/tree/master

I’ve included some stats in the readme but basically the test phase takes about 30 seconds, the test itself took about 3ms.


(Peter Niederwieser) #9

‘gradle test’ takes 1.3 seconds on my machine (with Gradle daemon enabled), and of course you don’t need to configure memory settings for such a small build. The ‘test’ task starts a second JVM, which communicates with the Gradle JVM over a socket. Perhaps something is going wrong on your machine there, although I’ve never heard of such a case before. (Typically, such a problem would cause the build to fail.) It’s hard to say what the problem is, but first thing I’d do is to try with a newer JDK and go over the debug log once more.


(Richard Cole) #10

What OS are you running on your machine? And which JDK?

Adding a bit more information with --debug, I can see the test runs very quickly, it seems to take a long time for the worker process to finish, before continuing. Perhaps it’s timing out before returning to the main process?

Is there anyway to turn off running tests in a separate JVM?


(Peter Niederwieser) #11

I happened to try it on Mac with Java 8.

Tests always run in a separate JVM, and there is no way to turn this off. Perhaps you could attach a debugger to the worker JVM and see what’s going on. You could also create a thread dump using the JDK’s ‘jstack’ tool.


(Richard Cole) #12

Ok - after a fair amount of debugging I found the issue. It stems down to Binary2JUnitXmlReportGenerator.getHostname(). This relies on:

InetAddress.getLocalHost().getHostName()

which there is a known issue for on Mac OSX with Java. After a fair while (20-30 seconds) it throws a UnknownHostException which means getHostName() just returns “localhost”.

I believe this is fixed in Java 8 (probably why you didn’t see it) but I suspect there are many people out there experiencing it and just assuming their tests are slow.

Quite an expensive operation just to have the hostname in the test reports! :slight_smile:


(Peter Niederwieser) #13

Thanks for the digging. I still use JDK7 most of the time, and have never hit this issue. If I remember correctly, some Gradle users experienced problems due to JDK7 bugs somewhere around 7u20, but updating to a newer minor version solved their problems. 7u25 is quite old, and I recommend that you update to a recent minor version. Let us know if this solves your problem.


(Richard Cole) #14

No problem, even with the latest version:

richards-imac:gradle richard$ java -version
java version "1.7.0_55"
Java(TM) SE Runtime Environment (build 1.7.0_55-b13)
Java HotSpot(TM) 64-Bit Server VM (build 24.55-b03, mixed mode)

I still get it.

There is a workaround by adding your machine name into /etc/hosts. Making this change alone meant it went from:

BUILD SUCCESSFUL
  Total time: 34.586 secs

to

BUILD SUCCESSFUL
  Total time: 9.556 secs

N.B this is the bug report http://bugs.java.com/bugdatabase/view_bug.do?bug_id=7180557

Just to finish, if I make the hostname a no-op and just return “localhost” it takes less than 4.5 seconds overall.

Richard