maven-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Jason Dillon <ja...@planet57.com>
Subject Re: What could cause surefire to stop reporting test status?
Date Mon, 02 Apr 2007 01:05:31 GMT
I've whipped up a patch that implements this pair and muxing here:

     http://jira.codehaus.org/browse/SUREFIRE-315

Can someone please have a look at this?

Thanks,

--jason


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

> 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: dev-unsubscribe@maven.apache.org
For additional commands, e-mail: dev-help@maven.apache.org


Mime
View raw message