Re: What could cause surefire to stop reporting test status?

[Jason Dillon]

I'm starting to think that surefire-booter needs a  
ForkingStreamConsumerPair, which has getOut(), getErr() that can  
return StreamConsumer for the proper stream, sharing that foundTest  
flag, and PrintWriter ref and prefixing the output based on if its  
out or err output.

--jason

On Apr 1, 2007, at 5:08 PM, Jason Dillon wrote:

I've figured out what is broken... the problem is that  
ForkingStreamConsumer.consumeLine(String) is calling  
"outputConsumer.consumeOutputLine( line );" before  
outputConsumer.testSetStarting() can be invoked, which causes the  
FileOutputConsumerProxy.consumeOutputLine() to throw an ISE (which  
unfortunately gets eatten by something, so you never see that  
exception).

Not sure exactly what the best fix is for this... but I'm thinking  
that adding a 'boolean foundTest' in ForkingStreamConsumer and  
setting that flag to true after it invokes testSetStarting(), and  
then to false after it invokes testSetCompleted(), and then only  
invoke consumeOutputLine() when fountTest == true.

<snip>
Index: surefire-booter/src/main/java/org/apache/maven/surefire/ 
booter/output/ForkingStreamConsumer.java
===================================================================
--- surefire-booter/src/main/java/org/apache/maven/surefire/booter/ 
output/ForkingStreamConsumer.java    (revision 524698)
+++ surefire-booter/src/main/java/org/apache/maven/surefire/booter/ 
output/ForkingStreamConsumer.java    (working copy)
@@ -40,7 +40,9 @@
     private static int FOOTER_PREFIX_LENGTH =  
ForkingConsoleReporter.FORKING_PREFIX_FOOTER.length();
     private OutputConsumer outputConsumer;
-
+
+    private static boolean foundTest = false;
+
     public ForkingStreamConsumer( OutputConsumer outputConsumer )
     {
         this.outputConsumer = outputConsumer;
@@ -58,10 +60,12 @@
             if ( ForkingConsoleReporter.isTestSetStartingMessage 
( message ) )
             {
                 outputConsumer.testSetStarting 
( ForkingConsoleReporter.parseTestSetStartingMessage( message ) );
+                foundTest = true;
             }
             else if  
( ForkingConsoleReporter.isTestSetCompletedMessage( message ) )
             {
                 outputConsumer.testSetCompleted();
+                foundTest = false;
             }
             outputConsumer.consumeMessageLine( message );
         }
@@ -71,7 +75,12 @@
         }
         else
         {
-            outputConsumer.consumeOutputLine( line );
+            if (foundTest) {
+                outputConsumer.consumeOutputLine( line );
+            }
+            else {
+                System.out.println("UNEXPECTED: " + line);
+            }
         }
     }
}
</snip>

This does fix the problem (though it causes some test to fail), but  
there is other issue of what exactly to do with that output.  I  
just spat it out on the console, but really this information should  
be captured into some other file, which collects any other output  
that happens before the test starts up.  The flag is static at the  
moment since there are 2 consumers created, and they run on  
different threads.  With out the static, then more "UNEXPECTED:"  
output will occur because only one of the consumers knows that the  
tests have begun/ended.

Can one consumer be shared to handle the out and err streams?

Will the 2 streams clobber themselves if a test spits out to STDOUT  
and STDERR?  I only seem them trying to make a "-output.txt", so  
I'm thinking that one might get corrupted output.  If one consumer  
was used, then how should the output be marked as coming from  
STDOUT or STDERR?  Or is the output from the process muxed together?

--jason


On Apr 1, 2007, at 12:37 AM, Jason Dillon wrote:

I've been playing around with trying to get the groovy-core and  
all of its tests build using Maven2... but I keep running into  
problems with surefire, where it sometimes does not show "Running  
<testcase>" for anything.

I've see something like this too, where it dosen't show anything  
at all:

<snip>
[INFO] [surefire:test]
[INFO] Surefire report directory: /Users/jason/ws/groovy/groovy- 
core-reorg/groovy-core/target/surefire-reports
[INFO]  
--------------------------------------------------------------------- 
---
[ERROR] BUILD FAILURE
[INFO]  
--------------------------------------------------------------------- 
---
[INFO] There are test failures.
[INFO]  
--------------------------------------------------------------------- 
---
</snip>

As well as partial output:

<snip>
[INFO] [surefire:test]
[INFO] Surefire report directory: /Users/jason/ws/groovy/groovy- 
core-reorg/groovy-core/target/surefire-reports

-------------------------------------------------------
T E S T S
-------------------------------------------------------
Running groovy.lang.ScriptTest
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed:  
0.675 sec
Running org.codehaus.groovy.classgen.VerifierCodeVisitorTest
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed:  
0.011 sec
Running groovy.xml.dom.DOMCategoryTest
Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed:  
2.487 sec
Running org.codehaus.groovy.control.CompilationUnitTest
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed:  
0.005 sec
Running groovy.bugs.NestedClosure2Bug
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed:  
1.227 sec
Running groovy.MethodParameterAccessWithinClosureTest
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed:  
0.414 sec
Running groovy.BooleanOperationTest
Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed:  
0.36 sec
Running groovy.sql.SqlCompleteWithoutDataSourceTest
Tests run: 11, Failures: 0, Errors: 1, Skipped: 0, Time elapsed:  
1.053 sec <<< FAILURE!
Running groovy.tree.VerboseTreeTest
[INFO]  
--------------------------------------------------------------------- 
---
[ERROR] BUILD FAILURE
[INFO]  
--------------------------------------------------------------------- 
---
</snip>

It doesn't even show what happened to VerboseTreeTest... just  
output ends.

I can get output when forkMode is never, but that doesn't help  
since I need to force, and would like to forkOnce.

It seems like some of these tests are spitting out some extra  
output before the tests even run too, which may be confusing  
surefire?  For example a few test cases have constructor methods  
that System.out.println() via the println keyword in Groovy.  This  
seems to throw off the output I see when running mvn.

For example 2 classes have constructors that have:

    println "Hey"

And when run with forkMode never, I get output like:

<snip>
[INFO] [surefire:test]
[INFO] Surefire report directory: /Users/jason/ws/groovy/groovy- 
core-reorg/groovy-core/target/surefire-reports
Hey
Hey

-------------------------------------------------------
T E S T S
-------------------------------------------------------
Running groovy.lang.ScriptTest
succeeded
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed:  
0.232 sec
Running org.codehaus.groovy.classgen.VerifierCodeVisitorTest
Caught invalid exception:  
org.codehaus.groovy.syntax.RuntimeParserException: Invalid  
variable name. Must start with a letter but was: 1.
Node: org.codehaus.groovy.ast.ASTNode. At [-1:-1]
Caught invalid exception:  
org.codehaus.groovy.syntax.RuntimeParserException: Invalid  
variable name. Must start with a letter but was: 100.
Node: org.codehaus.groovy.ast.ASTNode. At [-1:-1]
Caught invalid exception:  
org.codehaus.groovy.syntax.RuntimeParserException: Invalid  
variable name. Must start with a letter but was: 1a.
Node: org.codehaus.groovy.ast.ASTNode. At [-1:-1]
Caught invalid exception:  
org.codehaus.groovy.syntax.RuntimeParserException: Invalid  
variable name. Invalid character at position: 2 of value:  ! in  
name: a!.
Node: org.codehaus.groovy.ast.ASTNode. At [-1:-1]
Caught invalid exception:  
org.codehaus.groovy.syntax.RuntimeParserException: Invalid  
variable name. Invalid character at position: 2 of value:  . in  
name: a..
Node: org.codehaus.groovy.ast.ASTNode. At [-1:-1]
Caught invalid exception:  
org.codehaus.groovy.syntax.RuntimeParserException: Invalid  
variable name. Must start with a letter but was: $.
Node: org.codehaus.groovy.ast.ASTNode. At [-1:-1]
Caught invalid exception:  
org.codehaus.groovy.syntax.RuntimeParserException: Invalid  
variable name. Must start with a letter but was: $foo.
Node: org.codehaus.groovy.ast.ASTNode. At [-1:-1]
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed:  
0.001 sec
Running groovy.xml.dom.DOMCategoryTest
</snip>

If I change the forkMode to once, then I don't see any output past  
where the report directory is.  If I go and comment out those  
println "Hey" lines, then output gets further, but still stops  
(see the partial output that ends with "Running  
groovy.tree.VerboseTreeTest" above.

This is *very* bizarre that the output of a testcase has such an  
effect on the output of the surefire plugin.

This seems to happen with surefire 2.3 when  
redirectTestOutputToFile is true.

It would really be nice to get redirectTestOutputToFile working  
with forkMode once... and have it reliably capture the tests output.

Anyone run into this problem before?

--jason



---------------------------------------------------------------------
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]