[SUREFIRE-1091] IOException when test with much output prints in @After / @AfterClass - possible haning processes

• Type: Bug
• Status: Closed
• Priority: Critical
• Resolution: Fixed
• Affects Version/s: 2.17
• Fix Version/s: 2.18
• Assignee: Andreas Gudian
• Reporter: Andreas Gudian
• Created: 26/Aug/14 14:49
• Updated: 18/Oct/14 13:49
• Resolved: 26/Aug/14 15:32

Description

If a test creates enough output for the DeferredOutputStream to switch to a buffer file, then printing to the output stream in @AfterClass results in an IOException, such as java.io.IOException: Stream Closed or:

org.apache.maven.lifecycle.LifecycleExecutionException: Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.17:test (default-test) on project salog.loadtest.online: ExecutionException
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:213)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:153)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:145)
    at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:84)
    at org.apache.maven.lifecycle.internal.LifecycleThreadedBuilder$1.call(LifecycleThreadedBuilder.java:167)
    at org.apache.maven.lifecycle.internal.LifecycleThreadedBuilder$1.call(LifecycleThreadedBuilder.java:163)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:439)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
    at java.lang.Thread.run(Thread.java:662)
Caused by: org.apache.maven.plugin.MojoFailureException: ExecutionException
    at org.apache.maven.plugin.surefire.SurefirePlugin.assertNoException(SurefirePlugin.java:203)
    at org.apache.maven.plugin.surefire.SurefirePlugin.handleSummary(SurefirePlugin.java:193)
    at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeAfterPreconditionsChecked(AbstractSurefireMojo.java:861)
    at org.apache.maven.plugin.surefire.AbstractSurefireMojo.execute(AbstractSurefireMojo.java:729)
    at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:101)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:209)
    ... 13 more
Caused by: org.apache.maven.surefire.booter.SurefireBooterForkException: ExecutionException
    at org.apache.maven.plugin.surefire.booterclient.ForkStarter.runSuitesForkOnceMultiple(ForkStarter.java:252)
    at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:165)
    at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeProvider(AbstractSurefireMojo.java:967)
    at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeAfterPreconditionsChecked(AbstractSurefireMojo.java:831)
    ... 16 more
Caused by: java.util.concurrent.ExecutionException: java.lang.RuntimeException: java.lang.RuntimeException: java.io.IOException: Bad file descriptor
    at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222)
    at java.util.concurrent.FutureTask.get(FutureTask.java:83)
    at org.apache.maven.plugin.surefire.booterclient.ForkStarter.runSuitesForkOnceMultiple(ForkStarter.java:236)
    ... 19 more
Caused by: java.lang.RuntimeException: java.lang.RuntimeException: java.io.IOException: Bad file descriptor
    at org.apache.maven.plugin.surefire.booterclient.output.ThreadedStreamConsumer.close(ThreadedStreamConsumer.java:123)
    at org.apache.maven.plugin.surefire.booterclient.ForkStarter.fork(ForkStarter.java:463)
    at org.apache.maven.plugin.surefire.booterclient.ForkStarter.fork(ForkStarter.java:352)
    at org.apache.maven.plugin.surefire.booterclient.ForkStarter.access$300(ForkStarter.java:85)
    at org.apache.maven.plugin.surefire.booterclient.ForkStarter$1.call(ForkStarter.java:224)
    at org.apache.maven.plugin.surefire.booterclient.ForkStarter$1.call(ForkStarter.java:214)
    ... 5 more
Caused by: java.lang.RuntimeException: java.io.IOException: Bad file descriptor
    at org.apache.maven.plugin.surefire.report.TestSetRunListener.writeTestOutput(TestSetRunListener.java:107)
    at org.apache.maven.plugin.surefire.booterclient.output.ForkClient.consumeLine(ForkClient.java:139)
    at org.apache.maven.plugin.surefire.booterclient.output.ThreadedStreamConsumer$Pumper.run(ThreadedStreamConsumer.java:67)
    ... 1 more
Caused by: java.io.IOException: Bad file descriptor
    at java.io.FileOutputStream.writeBytes(Native Method)
    at java.io.FileOutputStream.write(FileOutputStream.java:282)
    at org.apache.maven.surefire.shade.org.apache.commons.io.output.ThresholdingOutputStream.write(ThresholdingOutputStream.java:129)
    at org.apache.maven.plugin.surefire.report.Utf8RecodingDeferredFileOutputStream.write(Utf8RecodingDeferredFileOutputStream.java:71)
    at org.apache.maven.plugin.surefire.report.TestSetRunListener.writeTestOutput(TestSetRunListener.java:98)

In case of reuseForks=true and forkCount>1, this would even result in a hanging maven process.

The issue was pinpointed by a testcase provided in a pull-request by silencerby on GitHub: https://github.com/apache/maven-surefire/pull/42