You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@maven.apache.org by Jason Dillon <ja...@planet57.com> on 2007/04/01 09:37:47 UTC
What could cause surefire to stop reporting test status?
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
Re: What could cause surefire to stop reporting test status?
Posted by Jason Dillon <ja...@planet57.com>.
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
Re: What could cause surefire to stop reporting test status?
Posted by Jason Dillon <ja...@planet57.com>.
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
Re: What could cause surefire to stop reporting test status?
Posted by Jason Dillon <ja...@planet57.com>.
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