[SUREFIRE-1410] Add FAQ and improve Warning message when native strea…

…m in forked JVM is corrupted

maven-surefire-common/src/main/java/org/apache/maven/plugin/surefire/booterclient/ForkStarter.java

@@ -69,6 +69,7 @@
 import java.util.concurrent.ScheduledFuture;
 import java.util.concurrent.ThreadFactory;
 import java.util.concurrent.ThreadPoolExecutor;
+import java.util.concurrent.atomic.AtomicBoolean;
 import java.util.concurrent.atomic.AtomicInteger;
 
 import static java.lang.StrictMath.min;
@@ -269,7 +270,8 @@ private RunResult run( SurefireProperties effectiveSystemProperties, Map<String,
         TestLessInputStreamBuilder builder = new TestLessInputStreamBuilder();
         PropertiesWrapper props = new PropertiesWrapper( providerProperties );
         TestLessInputStream stream = builder.build();
-        ForkClient forkClient = new ForkClient( forkedReporterFactory, stream, log );
+        ForkClient forkClient = new ForkClient( forkedReporterFactory, stream, log, forkConfiguration.isDebug(),
+                new AtomicBoolean() );
         Thread shutdown = createImmediateShutdownHookThread( builder, providerConfiguration.getShutdown() );
         ScheduledFuture<?> ping = triggerPingTimerForShutdown( builder );
         try
@@ -334,7 +336,8 @@ private RunResult runSuitesForkOnceMultiple( final SurefireProperties effectiveS
             addShutDownHook( shutdown );
             int failFastCount = providerConfiguration.getSkipAfterFailureCount();
             final AtomicInteger notifyStreamsToSkipTestsJustNow = new AtomicInteger( failFastCount );
-            Collection<Future<RunResult>> results = new ArrayList<Future<RunResult>>( forkCount );
+            final Collection<Future<RunResult>> results = new ArrayList<Future<RunResult>>( forkCount );
+            final AtomicBoolean printedErrorStream = new AtomicBoolean();
             for ( final TestProvidingInputStream testProvidingInputStream : testStreams )
             {
                 Callable<RunResult> pf = new Callable<RunResult>()
@@ -345,7 +348,8 @@ public RunResult call()
                     {
                         DefaultReporterFactory reporter = new DefaultReporterFactory( startupReportConfiguration, log );
                         defaultReporterFactories.add( reporter );
-                        ForkClient forkClient = new ForkClient( reporter, testProvidingInputStream, log )
+                        ForkClient forkClient = new ForkClient( reporter, testProvidingInputStream, log,
+                                forkConfiguration.isDebug(), printedErrorStream )
                         {
                             @Override
                             protected void stopOnNextTest()
@@ -397,6 +401,7 @@ private RunResult runSuitesForkPerTestSet( final SurefireProperties effectiveSys
             addShutDownHook( shutdown );
             int failFastCount = providerConfiguration.getSkipAfterFailureCount();
             final AtomicInteger notifyStreamsToSkipTestsJustNow = new AtomicInteger( failFastCount );
+            final AtomicBoolean printedErrorStream = new AtomicBoolean();
             for ( final Object testSet : getSuitesIterator() )
             {
                 Callable<RunResult> pf = new Callable<RunResult>()
@@ -408,8 +413,8 @@ public RunResult call()
                         DefaultReporterFactory forkedReporterFactory =
                             new DefaultReporterFactory( startupReportConfiguration, log );
                         defaultReporterFactories.add( forkedReporterFactory );
-                        ForkClient forkClient =
-                                new ForkClient( forkedReporterFactory, builder.getImmediateCommands(), log )
+                        ForkClient forkClient = new ForkClient( forkedReporterFactory, builder.getImmediateCommands(),
+                                log, forkConfiguration.isDebug(), printedErrorStream )
                         {
                             @Override
                             protected void stopOnNextTest()

maven-surefire-common/src/main/java/org/apache/maven/plugin/surefire/booterclient/output/ForkClient.java

@@ -42,6 +42,7 @@
 import java.util.TreeSet;
 import java.util.concurrent.ConcurrentHashMap;
 import java.util.concurrent.ConcurrentLinkedQueue;
+import java.util.concurrent.atomic.AtomicBoolean;
 import java.util.concurrent.atomic.AtomicLong;
 
 import static java.lang.Integer.decode;
@@ -101,23 +102,35 @@ public class ForkClient
 
     private final ConsoleLogger log;
 
+    private final boolean debug;
+
+    /**
+     * prevents from printing same warning
+     */
+    private final AtomicBoolean printedErrorStream;
+
+    /**
+     * Used by single Thread started by {@link ThreadedStreamConsumer} and therefore does not need to be volatile.
+     */
     private RunListener testSetReporter;
 
+    /**
+     * Written by one Thread and read by another: Main Thread and ForkStarter's Thread.
+     */
     private volatile boolean saidGoodBye;
 
     private volatile StackTraceWriter errorInFork;
 
     private volatile int forkNumber;
 
-    // prevents from printing same warning
-    private boolean printedErrorStream;
-
-    public ForkClient( DefaultReporterFactory defaultReporterFactory,
-                       NotifiableTestStream notifiableTestStream, ConsoleLogger log )
+    public ForkClient( DefaultReporterFactory defaultReporterFactory, NotifiableTestStream notifiableTestStream,
+                       ConsoleLogger log, boolean debug, AtomicBoolean printedErrorStream )
     {
         this.defaultReporterFactory = defaultReporterFactory;
         this.notifiableTestStream = notifiableTestStream;
         this.log = log;
+        this.debug = debug;
+        this.printedErrorStream = printedErrorStream;
     }
 
     protected void stopOnNextTest()
@@ -304,18 +317,27 @@ private void logStreamWarning( Throwable e, String event )
     {
         if ( event == null || !event.contains( PRINTABLE_JVM_NATIVE_STREAM ) )
         {
-            final String msg = "Corrupted stdin stream in forked JVM " + forkNumber + ".";
-            final InPluginProcessDumpSingleton util = InPluginProcessDumpSingleton.getSingleton();
-            final File dump =
+            String msg = "Corrupted STDOUT by directly writing to native stream in forked JVM " + forkNumber + ".";
+
+            InPluginProcessDumpSingleton util = InPluginProcessDumpSingleton.getSingleton();
+            File dump =
                     e == null
                     ? util.dumpText( msg + " Stream '" + event + "'.", defaultReporterFactory, forkNumber )
                     : util.dumpException( e, msg + " Stream '" + event + "'.", defaultReporterFactory, forkNumber );
 
-            if ( !printedErrorStream )
+            if ( printedErrorStream.compareAndSet( false, true ) )
             {
-                printedErrorStream = true;
-                log.warning( msg + " See the dump file " + dump.getAbsolutePath() );
+                log.warning( msg + " See FAQ web page and the dump file " + dump.getAbsolutePath() );
             }
+
+            if ( debug && event != null )
+            {
+                log.debug( event );
+            }
+        }
+        else if ( debug )
+        {
+            log.debug( event );
         }
         else
         {

maven-surefire-common/src/test/java/org/apache/maven/plugin/surefire/booterclient/ForkingRunListenerTest.java

@@ -222,7 +222,8 @@ public void testSystemProperties()
 
         TestSetMockReporterFactory providerReporterFactory = new TestSetMockReporterFactory();
         NullConsoleLogger log = new NullConsoleLogger();
-        ForkClient forkStreamClient = new ForkClient( providerReporterFactory, new MockNotifiableTestStream(), log );
+        ForkClient forkStreamClient =
+                new ForkClient( providerReporterFactory, new MockNotifiableTestStream(), log, false, null );
 
         forkStreamClient.consumeMultiLineContent( content.toString( "UTF-8" ) );
 
@@ -246,7 +247,8 @@ public void testMultipleEntries()
 
         TestSetMockReporterFactory providerReporterFactory = new TestSetMockReporterFactory();
         NullConsoleLogger log = new NullConsoleLogger();
-        ForkClient forkStreamClient = new ForkClient( providerReporterFactory, new MockNotifiableTestStream(), log );
+        ForkClient forkStreamClient =
+                new ForkClient( providerReporterFactory, new MockNotifiableTestStream(), log, false, null );
 
         forkStreamClient.consumeMultiLineContent( content.toString( "UTF-8" ) );
 
@@ -275,15 +277,15 @@ public void test2DifferentChannels()
         NotifiableTestStream notifiableTestStream = new MockNotifiableTestStream();
         NullConsoleLogger log = new NullConsoleLogger();
 
-        ForkClient forkStreamClient = new ForkClient( providerReporterFactory, notifiableTestStream, log );
+        ForkClient forkStreamClient = new ForkClient( providerReporterFactory, notifiableTestStream, log, false, null );
         forkStreamClient.consumeMultiLineContent( content.toString( "UTF-8" ) );
 
         MockReporter reporter = (MockReporter) forkStreamClient.getReporter();
         Assert.assertEquals( MockReporter.TEST_STARTING, reporter.getFirstEvent() );
         Assert.assertEquals( expected, reporter.getFirstData() );
         Assert.assertEquals( 1, reporter.getEvents().size() );
 
-        forkStreamClient = new ForkClient( providerReporterFactory, notifiableTestStream, log );
+        forkStreamClient = new ForkClient( providerReporterFactory, notifiableTestStream, log, false, null );
         forkStreamClient.consumeMultiLineContent( anotherContent.toString( "UTF-8" ) );
         MockReporter reporter2 = (MockReporter) forkStreamClient.getReporter();
         Assert.assertEquals( MockReporter.TEST_SKIPPED, reporter2.getFirstEvent() );
@@ -352,8 +354,8 @@ public void clientReceiveContent()
         {
             TestSetMockReporterFactory providerReporterFactory = new TestSetMockReporterFactory();
             NullConsoleLogger log = new NullConsoleLogger();
-            final ForkClient forkStreamClient = new ForkClient( providerReporterFactory,
-                                                                new MockNotifiableTestStream(), log );
+            final ForkClient forkStreamClient =
+                    new ForkClient( providerReporterFactory, new MockNotifiableTestStream(), log, false, null );
             forkStreamClient.consumeMultiLineContent( content.toString( ) );
             reporter = (MockReporter) forkStreamClient.getReporter();
         }

maven-surefire-plugin/src/site/fml/faq.fml

@@ -137,5 +137,24 @@ under the License.
         </p>
       </answer>
     </faq>
+    <faq id="corruptedstream">
+      <question>Corrupted STDOUT by directly writing to native stream in forked JVM</question>
+      <answer>
+        <p>
+        If your tests use native library which prints to STDOUT this warning message appears because the library
+        corrupted the channel used by the plugin in order to transmit events with test status back to Maven process.
+        It would be even worse if you override the Java stream by <em>System.setOut</em> because the stream is also
+        supposed to be corrupted but the Maven will never see the tests finished and build may hang.
+        <br/>
+        This warning message appears if you use <em>FileDescriptor.out</em> or JVM prints GC summary.
+        <br/>
+        In that case the warning is printed
+        <em>"Corrupted STDOUT by directly writing to native stream in forked JVM"</em>, and a dump file can be found
+        in Reports directory.
+        <br/>
+        If debug level is enabled then messages of corrupted stream appear in the console.
+        </p>
+      </answer>
+    </faq>
   </part>
 </faqs>