[SUREFIRE-1157] Surefire fork communication fails when a native library writes to stdout

• Type: Bug
• Status: Open
• Priority: Major
• Resolution: Unresolved
• Affects Version/s: 2.17
• Component/s: process forking
• Assignee: Unassigned
• Reporter: Dan Berindei
• Created: 16/May/15 07:31
• Updated: 20/Dec/19 11:42

Description

We are seeing this exception in some of our CI builds:

[11:17:10]W:	 [Step 2/4] [ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.17:test (default-test) on project infinispan-cachestore-leveldb: Execution default-test of goal org.apache.maven.plugins:maven-surefire-plugin:2.17:test failed: java.lang.RuntimeException: 1,org.infinispan.persistence.leveldb.LevelDBStoreTest,testStoreAndRemove(org.infinispan.persistence.leveldb.LevelDBStoreTest),unit,null,null: NoSuchElementException -> [Help 1]
[11:17:10] :	 [Step 2/4] org.apache.maven.lifecycle.LifecycleExecutionException: Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.17:test (default-test) on project infinispan-cachestore-leveldb: Execution default-test of goal org.apache.maven.plugins:maven-surefire-plugin:2.17:test failed: java.lang.RuntimeException: 1,org.infinispan.persistence.leveldb.LevelDBStoreTest,testStoreAndRemove(org.infinispan.persistence.leveldb.LevelDBStoreTest),unit,null,null
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:224)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:153)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:145)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:116)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:80)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build(SingleThreadedBuilder.java:51)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.lifecycle.internal.LifecycleStarter.execute(LifecycleStarter.java:120)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:347)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.DefaultMaven.execute(DefaultMaven.java:154)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.cli.MavenCli.execute(MavenCli.java:582)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.cli.MavenCli.doMain(MavenCli.java:214)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.cli.MavenCli.main(MavenCli.java:158)
[11:17:10] :	 [Step 2/4] 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[11:17:10] :	 [Step 2/4] 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[11:17:10] :	 [Step 2/4] 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[11:17:10] :	 [Step 2/4] 	at java.lang.reflect.Method.invoke(Method.java:483)
[11:17:10] :	 [Step 2/4] 	at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced(Launcher.java:289)
[11:17:10] :	 [Step 2/4] 	at org.codehaus.plexus.classworlds.launcher.Launcher.launch(Launcher.java:229)
[11:17:10] :	 [Step 2/4] 	at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode(Launcher.java:415)
[11:17:10] :	 [Step 2/4] 	at org.codehaus.plexus.classworlds.launcher.Launcher.main(Launcher.java:356)
[11:17:10] :	 [Step 2/4] Caused by: org.apache.maven.plugin.PluginExecutionException: Execution default-test of goal org.apache.maven.plugins:maven-surefire-plugin:2.17:test failed: java.lang.RuntimeException: 1,org.infinispan.persistence.leveldb.LevelDBStoreTest,testStoreAndRemove(org.infinispan.persistence.leveldb.LevelDBStoreTest),unit,null,null
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:143)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:208)
[11:17:10] :	 [Step 2/4] 	... 19 more
[11:17:10] :	 [Step 2/4] Caused by: java.lang.RuntimeException: java.lang.RuntimeException: 1,org.infinispan.persistence.leveldb.LevelDBStoreTest,testStoreAndRemove(org.infinispan.persistence.leveldb.LevelDBStoreTest),unit,null,null
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.plugin.surefire.booterclient.output.ThreadedStreamConsumer.close(ThreadedStreamConsumer.java:123)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.fork(ForkStarter.java:463)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.fork(ForkStarter.java:352)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:158)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeProvider(AbstractSurefireMojo.java:967)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeAfterPreconditionsChecked(AbstractSurefireMojo.java:831)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.plugin.surefire.AbstractSurefireMojo.execute(AbstractSurefireMojo.java:729)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:132)
[11:17:10] :	 [Step 2/4] 	... 20 more
[11:17:10] :	 [Step 2/4] Caused by: java.lang.RuntimeException: 1,org.infinispan.persistence.leveldb.LevelDBStoreTest,testStoreAndRemove(org.infinispan.persistence.leveldb.LevelDBStoreTest),unit,null,null
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.plugin.surefire.booterclient.output.ForkClient.createReportEntry(ForkClient.java:209)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.plugin.surefire.booterclient.output.ForkClient.consumeLine(ForkClient.java:110)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.plugin.surefire.booterclient.output.ThreadedStreamConsumer$Pumper.run(ThreadedStreamConsumer.java:67)
[11:17:10] :	 [Step 2/4] 	at java.lang.Thread.run(Thread.java:745)
[11:17:10] :	 [Step 2/4] Caused by: java.util.NoSuchElementException
[11:17:10] :	 [Step 2/4] 	at java.util.StringTokenizer.nextToken(StringTokenizer.java:349)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.plugin.surefire.booterclient.output.ForkClient.deserializeStackStraceWriter(ForkClient.java:217)
[11:17:10] :	 [Step 2/4] 	at org.apache.maven.plugin.surefire.booterclient.output.ForkClient.createReportEntry(ForkClient.java:202)
[11:17:10] :	 [Step 2/4] 	... 3 more

I believe this is caused by the native LevelDB library writing to stdout and breaking the communication between ForkingRunListener and ForkClient. It would be better if the communication between the main process and the fork happened over a socket.