[GRADLE-1158] Exception when writing messages after successfully running tests. Created: 28/Sep/10  Updated: 04/Jan/13  Resolved: 24/Feb/11

Status: Resolved
Project: Gradle
Affects Version/s: 0.9.1
Fix Version/s: 1.0-milestone-1

Type: Bug
Reporter: Julian Kelsey Assignee: Adam Murdoch
Resolution: Fixed Votes: 1


 Description   

After successfully running about 4000+ tests in about 900+ test classes before the build completes gradle crashes with warnings as below. The specific file that causes the failure varies from run to run.

FAILURE: Build failed with an exception.

  • Where:
    Build file '/home/jbk/workspace-gradle/TIM/build.gradle'
  • What went wrong:
    Execution failed for task ':TIM:test'.
    Cause: Errors while applying transformations: javax.xml.transform.TransformerException: com.sun.org.apache.xalan.internal.xsltc.TransletException: java.io.FileNotFoundException: /home/jbk/workspace-gradle/TIM/build/reports/tests/com/youdevise/tradeideas/ideagroup/rules/evaluation/732_TotalNumberOfIdeasTest.html (Too many open files)
  • Exception is:
    org.gradle.api.tasks.LocationAwareTaskExecutionException: Build file '/home/jbk/workspace-gradle/TIM/build.gradle'
    Execution failed for task ':TIM:test'.
    at org.gradle.api.internal.tasks.DefaultTaskExecuter.executeActions(DefaultTaskExecuter.java:63)
    at org.gradle.api.internal.tasks.DefaultTaskExecuter.execute(DefaultTaskExecuter.java:41)
    at org.gradle.api.internal.project.taskfactory.PostExecutionAnalysisTaskExecuter.execute(PostExecutionAnalysisTaskExecuter.java:32)
    at org.gradle.api.internal.project.taskfactory.ExecutionShortCircuitTaskExecuter.execute(ExecutionShortCircuitTaskExecuter.java:50)
    at org.gradle.api.internal.tasks.SkipTaskExecuter.doExecute(SkipTaskExecuter.java:57)
    at org.gradle.api.internal.tasks.SkipTaskExecuter.execute(SkipTaskExecuter.java:35)
    at org.gradle.api.internal.tasks.ExecuteAtMostOnceTaskExecuter.execute(ExecuteAtMostOnceTaskExecuter.java:32)
    at org.gradle.api.internal.AbstractTask.execute(AbstractTask.java:231)
    at org.gradle.execution.DefaultTaskGraphExecuter.executeTask(DefaultTaskGraphExecuter.java:167)
    at org.gradle.execution.DefaultTaskGraphExecuter.doExecute(DefaultTaskGraphExecuter.java:160)
    at org.gradle.execution.DefaultTaskGraphExecuter.execute(DefaultTaskGraphExecuter.java:78)
    at org.gradle.execution.TaskNameResolvingBuildExecuter.execute(TaskNameResolvingBuildExecuter.java:161)
    at org.gradle.execution.DelegatingBuildExecuter.execute(DelegatingBuildExecuter.java:54)
    at org.gradle.initialization.DefaultGradleLauncher.doBuildStages(DefaultGradleLauncher.java:153)
    at org.gradle.initialization.DefaultGradleLauncher.doBuild(DefaultGradleLauncher.java:107)
    at org.gradle.initialization.DefaultGradleLauncher.run(DefaultGradleLauncher.java:75)
    at org.gradle.launcher.Main.execute(Main.java:93)
    at org.gradle.launcher.Main.main(Main.java:42)
    at org.gradle.launcher.GradleMain.main(GradleMain.java:49)
    Caused by: org.apache.tools.ant.BuildException: Errors while applying transformations: javax.xml.transform.TransformerException: com.sun.org.apache.xalan.internal.xsltc.TransletException: java.io.FileNotFoundException: /home/jbk/workspace-gradle/TIM/build/reports/tests/com/youdevise/tradeideas/servlet/manageideas/render/979_UpdateRenderablesFactoryTest.html (Too many open files)
    at org.apache.tools.ant.taskdefs.optional.junit.AggregateTransformer.transform(AggregateTransformer.java:266)
    at org.apache.tools.ant.taskdefs.optional.junit.XMLResultAggregator.execute(XMLResultAggregator.java:158)
    at org.apache.tools.ant.UnknownElement.execute(UnknownElement.java:291)
    at org.apache.tools.ant.dispatch.DispatchUtils.execute(DispatchUtils.java:106)
    at org.gradle.api.internal.project.ant.BasicAntBuilder.doInvokeMethod(BasicAntBuilder.java:74)
    at org.gradle.api.internal.project.DefaultAntBuilder.super$3$invokeMethod(DefaultAntBuilder.groovy)
    at org.gradle.api.internal.project.DefaultAntBuilder.invokeMethod(DefaultAntBuilder.groovy:37)
    at org.gradle.api.internal.tasks.testing.junit.AntJUnitReport.execute(AntJUnitReport.groovy:29)
    at org.gradle.api.internal.tasks.testing.junit.JUnitTestFramework.report(JUnitTestFramework.java:67)
    at org.gradle.api.tasks.testing.Test.executeTests(Test.java:328)
    at org.gradle.api.internal.BeanDynamicObject.invokeMethod(BeanDynamicObject.java:158)
    at org.gradle.api.internal.CompositeDynamicObject.invokeMethod(CompositeDynamicObject.java:93)
    at org.gradle.api.tasks.testing.Test_Decorated.invokeMethod(Unknown Source)
    at org.gradle.util.ReflectionUtil.invoke(ReflectionUtil.groovy:23)
    at org.gradle.api.internal.project.taskfactory.AnnotationProcessingTaskFactory$2.execute(AnnotationProcessingTaskFactory.java:131)
    at org.gradle.api.internal.project.taskfactory.AnnotationProcessingTaskFactory$2.execute(AnnotationProcessingTaskFactory.java:129)
    at org.gradle.api.internal.tasks.DefaultTaskExecuter.executeActions(DefaultTaskExecuter.java:55)
    ... 18 common frames omitted
    Caused by: org.apache.tools.ant.BuildException: javax.xml.transform.TransformerException: com.sun.org.apache.xalan.internal.xsltc.TransletException: java.io.FileNotFoundException: /home/jbk/workspace-gradle/TIM/build/reports/tests/com/youdevise/tradeideas/servlet/manageideas/render/979_UpdateRenderablesFactoryTest.html (Too many open files)
    at org.apache.tools.ant.taskdefs.XSLTProcess.handleTransformationError(XSLTProcess.java:1259)
    at org.apache.tools.ant.taskdefs.XSLTProcess.process(XSLTProcess.java:849)
    at org.apache.tools.ant.taskdefs.XSLTProcess.execute(XSLTProcess.java:386)
    at org.apache.tools.ant.taskdefs.optional.junit.AggregateTransformer.transform(AggregateTransformer.java:264)
    ... 34 common frames omitted
    Caused by: javax.xml.transform.TransformerException: com.sun.org.apache.xalan.internal.xsltc.TransletException: java.io.FileNotFoundException: /home/jbk/workspace-gradle/TIM/build/reports/tests/com/youdevise/tradeideas/servlet/manageideas/render/979_UpdateRenderablesFactoryTest.html (Too many open files)
    at com.sun.org.apache.xalan.internal.xsltc.trax.TransformerImpl.transform(TransformerImpl.java:714)
    at com.sun.org.apache.xalan.internal.xsltc.trax.TransformerImpl.transform(TransformerImpl.java:313)
    at org.apache.tools.ant.taskdefs.optional.TraXLiaison.transform(TraXLiaison.java:194)
    at org.apache.tools.ant.taskdefs.XSLTProcess.process(XSLTProcess.java:839)
    ... 36 common frames omitted
    Caused by: com.sun.org.apache.xalan.internal.xsltc.TransletException: java.io.FileNotFoundException: /home/jbk/workspace-gradle/TIM/build/reports/tests/com/youdevise/tradeideas/servlet/manageideas/render/979_UpdateRenderablesFactoryTest.html (Too many open files)
    at com.sun.org.apache.xalan.internal.xsltc.runtime.AbstractTranslet.openOutputHandler(AbstractTranslet.java:565)
    at junit_frames.package()
    at junit_frames.template$dot$0()
    at junit_frames.applyTemplates()
    at junit_frames.applyTemplates()
    at junit_frames.transform()
    at com.sun.org.apache.xalan.internal.xsltc.runtime.AbstractTranslet.transform(AbstractTranslet.java:602)
    at com.sun.org.apache.xalan.internal.xsltc.trax.TransformerImpl.transform(TransformerImpl.java:710)
    ... 39 common frames omitted

BUILD FAILED



 Comments   
Comment by Julian Kelsey [ 30/Sep/10 ]

Setting the ulimit "* hard nofile 10000" works around this problem. Was it really trying to use 1000+ files in parallel, or was it leaking file handles?

Comment by Adam Murdoch [ 09/Oct/10 ]

Another workaround is to disable the junit report:

test.testReport = false

Comment by Steve Ebersole [ 10/Oct/10 ]

Any idea with regard to the root of this problem yet? Is it platform specific? I too run Linux: Fedora 13, 64-bit (KDE 4.4.5). I am also running Sun JVM 1.6 (1.6.0_21 - 64-bit). I am using Gradle 0.9-rc-1.

Could y'all verify Julian's question? Is Gradle really opening that many files at the same time? Or is this just a timing thing where the underlying file handles just are not released timely enough? If Gradle is explicitly opening that many files at the same time, I think it should be controllable as users to limit how many files we want it opening simultaneously; bumping ulimit file handle limits indefinitely is not really reasonable imo; those limits exist for a reason.

Comment by Adam Murdoch [ 10/Oct/10 ]

The junit report generation certainly seems to be leaking file handles. We use the Ant junit report task to do this. There seems to be a leak in the xml transformer which it uses. I've checked a fix to work around this into head. Could you try this out with your build?

Comment by Steve Ebersole [ 12/Oct/10 ]

I built locally from:

commit 83754a2083d943bdb57c106fb2276ad5d2b1fe76
...
Date:   Mon Oct 11 11:16:56 2010 +1100

    GRADLE-1158 - Ensure test report output files are closed once they have been generat

It fixed the issue I was seeing here.

Comment by Julian Kelsey [ 13/Oct/10 ]

The problem is mostly effecting my CI nodes (managed via Hudson) where it's really awkward for me to bundle up and distribute a distinct version of Gradle.

I hope to go live with my Gradle build system in the next few weeks, turning off our Ant based system, but the intermittent failures I get now will be a show stopper.

I'll have to give this patch a go when I can. Where would I find out what format the Hudson Gradle plugin expects for the Gradle package it deploys?

Comment by Steve Ebersole [ 13/Oct/10 ]

What does using the Gradle plugin in Hudson actually delivery to you beyond just using, say, gradlew? And if you use gradlew you can in fact easily bundle up the patched version until 0.9 (or whichever version is released next) is pushed.

Comment by Steve Ebersole [ 11/Feb/11 ]

Not sure this issue is actually fixed, or perhaps it has been regressed. Using 0.9.2 I am seeing this failure again after re-enabling test report generation

Comment by Brett Cave [ 11/Feb/11 ]

Two things to check in the environment:

1. ulimit -n is more than number of open files. adjust in /etc/security/limits.conf (soft nofile 10240, hard nofile 10240)

2. cat /proc/sys/fs/file-max to check kernel-level configuration. adjust to a suitable value (e.g. fs.file-max = 65536 in /etc/sysctl.conf)

Comment by Adam Murdoch [ 17/Feb/11 ]

The problem is still present in 0.9.2

Comment by Adam Murdoch [ 24/Feb/11 ]

Test reporting has been reimplemented, and so should fix this problem.

Comment by Steve Ebersole [ 02/Mar/11 ]

Just tried 1.0-milestone-1 and it too is failing, although now it is a much different stack trace:

org.gradle.api.GradleException: Could not stop connection.
        at org.gradle.messaging.remote.internal.DefaultMultiChannelConnection.stop(DefaultMultiChannelConnection.java:111)
        at org.gradle.messaging.remote.internal.DefaultObjectConnection.stop(DefaultObjectConnection.java:65)
        at org.gradle.messaging.remote.internal.DefaultMessagingClient.stop(DefaultMessagingClient.java:38)
        at org.gradle.messaging.concurrent.CompositeStoppable.stop(CompositeStoppable.java:91)
        at org.gradle.messaging.remote.internal.TcpMessagingClient.stop(TcpMessagingClient.java:47)
        at org.gradle.process.internal.child.ActionExecutionWorker.execute(ActionExecutionWorker.java:82)
        at org.gradle.process.internal.child.ActionExecutionWorker.execute(ActionExecutionWorker.java:35)
        at org.gradle.process.internal.child.ImplementationClassLoaderWorker.execute(ImplementationClassLoaderWorker.java:79)
        at org.gradle.process.internal.child.ImplementationClassLoaderWorker.execute(ImplementationClassLoaderWorker.java:35)
        at org.gradle.process.internal.child.SystemApplicationClassLoaderWorker.call(SystemApplicationClassLoaderWorker.java:56)
        at org.gradle.process.internal.child.SystemApplicationClassLoaderWorker.call(SystemApplicationClassLoaderWorker.java:38)
        at org.gradle.process.internal.launcher.BootstrapClassLoaderWorker.call(BootstrapClassLoaderWorker.java:52)
        at org.gradle.process.internal.launcher.BootstrapClassLoaderWorker.call(BootstrapClassLoaderWorker.java:33)
        at org.gradle.process.internal.launcher.GradleWorkerMain.run(GradleWorkerMain.java:30)
        at org.gradle.process.internal.launcher.GradleWorkerMain.main(GradleWorkerMain.java:35)
Caused by: java.lang.IllegalStateException: Timeout waiting for concurrent jobs to complete.
        at org.gradle.messaging.concurrent.DefaultExecutorFactory$StoppableExecutorImpl.stop(DefaultExecutorFactory.java:90)
        at org.gradle.messaging.remote.internal.DefaultMultiChannelConnection.stop(DefaultMultiChannelConnection.java:109)
        ... 14 more
null
java.lang.NullPointerException
        at org.gradle.messaging.remote.internal.SocketConnection.isEndOfStream(SocketConnection.java:76)
        at org.gradle.messaging.remote.internal.SocketConnection.receive(SocketConnection.java:65)
        at org.gradle.messaging.remote.internal.EndOfStreamReceive.receive(EndOfStreamReceive.java:33)
        at org.gradle.messaging.dispatch.AsyncReceive.receiveMessages(AsyncReceive.java:85)
        at org.gradle.messaging.dispatch.AsyncReceive.access$000(AsyncReceive.java:31)
        at org.gradle.messaging.dispatch.AsyncReceive$1.run(AsyncReceive.java:53)
        at org.gradle.messaging.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:63)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:619)
java.lang.InterruptedException
org.gradle.util.UncheckedException: java.lang.InterruptedException
        at org.gradle.messaging.dispatch.AsyncDispatch.dispatchMessages(AsyncDispatch.java:113)
        at org.gradle.messaging.dispatch.AsyncDispatch.access$000(AsyncDispatch.java:33)
        at org.gradle.messaging.dispatch.AsyncDispatch$1.run(AsyncDispatch.java:69)
        at org.gradle.messaging.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:63)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:619)
Caused by: java.lang.InterruptedException
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:1961)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1996)
        at org.gradle.messaging.dispatch.AsyncDispatch.dispatchMessages(AsyncDispatch.java:111)
        ... 6 more
3252 tests completed, 80 failures

FAILURE: Build failed with an exception.

* Where:
Build file '/home/steve/projects/hibernate/github/hibernate-core/hibernate-core/hibernate-core.gradle'

* What went wrong:
Execution failed for task ':hibernate-core:test'.
Cause: Gradle Worker 1 finished with (non-zero) exit value 1.
Comment by Steve Ebersole [ 02/Mar/11 ]

Hm, after this initial failure it seems to be fine now..

Comment by Niclas Hedhman [ 05/Dec/11 ]

This issue has re-emerged when running on a CI box;

  • What went wrong:
    Execution failed for task ':test'.
    Cause: Errors while applying transformations: javax.xml.transform.TransformerException: com.sun.org.apache.xalan.internal.xsltc.TransletException: java.io.FileNotFoundException: /home/hudson/hudson_work/jobs/Qi4j SDK/workspace/build/reports/junit/org/qi4j/envisage/sample/232_EnvisageSample.html (Too many open files)

We are on Hudson with

Gradle milestone-6

java version "1.6.0_26"
Java(TM) SE Runtime Environment (build 1.6.0_26-b03)
Java HotSpot(TM) Server VM (build 20.1-b02, mixed mode)

Comment by Adam Murdoch [ 05/Dec/11 ]

Are you using the ant junit/junitreport tasks?

Comment by Niclas Hedhman [ 25/Jun/12 ]

Yes, since we have not figured out how to do test report aggregation, i.e. there are almost 100 subprojects and we don't want a report in each project directory, but an aggregated report at the top.

Suggestions are appreciated.

Comment by Niclas Hedhman [ 25/Jun/12 ]

I will answer myself... Effectively this;

allprojects {

   test {
      testReport = false
      testResultDir = "$rootProject.testResultDir"
   }
}

test {
    testReport = true
}
Generated at Wed Jun 30 11:48:26 CDT 2021 using Jira 8.4.2#804003-sha1:d21414fc212e3af190e92c2d2ac41299b89402cf.