Detecting failures of unit tests

[Christopher Schultz <ch...@christopherschultz.net>]

All,

I was testing 7.0.25 and "ant test" reports BUILD SUCCESSFUL but I
started looking at the TEST-*.txt files that are emitted and I was
wondering about a few things.

First, I should probably be look at the bottom of the file for the junit
summary that looks like this:

Testsuite: org.apache.tomcat.util.threads.TestLimitLatch
Tests run: 5, Failures: 0, Errors: 0, Time elapsed: 2.545 sec

Observing the "Failures: 0, Errors: 0" indicates that the tests have all
passed correctly, right?

I'm asking because I can also see things like this:

TEST-org.apache.catalina.connector.TestMaxConnections.APR.txt:INFO:
There were [4] passed requests and [2] connection failures

Obviously, that's an INFO line, but it does indicate a "failure" of some
kind.

There are also some log lines like this:

TEST-org.apache.catalina.startup.TestListener.NIO.txt:SEVERE: Context
[/] startup failed due to previous errors

Does that merely indicate that the test itself caused a failure, and
that the failure-to-startup was intentional?

Similarly:

TEST-org.apache.catalina.tribes.group.interceptors.TestNonBlockingCoordinator.APR.txt:org.apache.catalina.tribes.ChannelException:
Send failed, and sender is disconnected. Not retrying.; Faulty
members:tcp://{127, 0, 0, 1}:4005;

Again, all test files say "Failures: 0, Errors: 0" so I guess everything
is okay. It's just tough to see those log lines without asking.

Thanks,
-chris

Re: Detecting failures of unit tests

[Konstantin Kolinko <kn...@gmail.com>]

2012/1/19 Christopher Schultz <ch...@christopherschultz.net>:
> All,
>
> I was testing 7.0.25 and "ant test" reports BUILD SUCCESSFUL but I
> started looking at the TEST-*.txt files that are emitted and I was
> wondering about a few things.
>
> First, I should probably be look at the bottom of the file for the junit
> summary that looks like this:
>
> Testsuite: org.apache.tomcat.util.threads.TestLimitLatch
> Tests run: 5, Failures: 0, Errors: 0, Time elapsed: 2.545 sec
>
> Observing the "Failures: 0, Errors: 0" indicates that the tests have all
> passed correctly, right?
>
> I'm asking because I can also see things like this:
>
> TEST-org.apache.catalina.connector.TestMaxConnections.APR.txt:INFO:
> There were [4] passed requests and [2] connection failures

1. I was also puzzled.

I tried to comment some similar cases, but the work is far from being
complete. Especially I am puzzled by SEVERE messages.

This is one case where I wrote a comment. If you look closely [1]:

INFO: This test tries to create 10 connections to connector that has
maxConnections='4'. Expect half of them to fail.

[1] http://vmgump.apache.org/gump/public/tomcat-trunk/tomcat-trunk-test/gump_file/TEST-org.apache.catalina.connector.TestMaxConnections.BIO.txt.html

Well, I see maybe I shall move that log statement. This test limits
the count of simultaneous connections. Some of connections are
rejected right away, but some will be caught in a OS' accept queue and
time out.
Both results are OK. That is in the sense of handling the limit, but
user's experience will be different.


In general to suppress certain SEVERE messages triggered by tests and
printed by ErrorReportValve I think a custom ErrorReportValve might be
needed.

>
> Obviously, that's an INFO line, but it does indicate a "failure" of some
> kind.
>
> There are also some log lines like this:
>
> TEST-org.apache.catalina.startup.TestListener.NIO.txt:SEVERE: Context
> [/] startup failed due to previous errors
>
> Does that merely indicate that the test itself caused a failure, and
> that the failure-to-startup was intentional?

2. That is likely a standard message, intentionally triggered by the test.

> Similarly:
>
> TEST-org.apache.catalina.tribes.group.interceptors.TestNonBlockingCoordinator.APR.txt:org.apache.catalina.tribes.ChannelException:
> Send failed, and sender is disconnected. Not retrying.; Faulty
> members:tcp://{127, 0, 0, 1}:4005;
>
> Again, all test files say "Failures: 0, Errors: 0" so I guess everything
> is okay. It's just tough to see those log lines without asking.
>

3. That is standard message. It is expected and triggered by the test.
But personally I lack complete understanding of tribes tests. Some of
them fail occasionally (triggering Gump or Buildbot e-mails) and I do
not know what to do.

4. I have seen several cases where Tomcat shutdown was failing
(generating messages), but JUnit tests were not failing. Maybe that is
because of different threads.

I do not know how improve that.

I personally always review results and stdout for
"NullPointerException". NPEs are unexpected.

Best regards,
Konstantin Kolinko

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org

Re: Detecting failures of unit tests

[Brian Burch <br...@pingtoo.com>]

On 19/01/12 07:12, Christopher Schultz wrote:
> All,
>
> I was testing 7.0.25 and "ant test" reports BUILD SUCCESSFUL but I
> started looking at the TEST-*.txt files that are emitted and I was
> wondering about a few things.
>
> First, I should probably be look at the bottom of the file for the junit
> summary that looks like this:
>
> Testsuite: org.apache.tomcat.util.threads.TestLimitLatch
> Tests run: 5, Failures: 0, Errors: 0, Time elapsed: 2.545 sec
>
> Observing the "Failures: 0, Errors: 0" indicates that the tests have all
> passed correctly, right?
>
> I'm asking because I can also see things like this:
>
> TEST-org.apache.catalina.connector.TestMaxConnections.APR.txt:INFO:
> There were [4] passed requests and [2] connection failures
>
> Obviously, that's an INFO line, but it does indicate a "failure" of some
> kind.
>
> There are also some log lines like this:
>
> TEST-org.apache.catalina.startup.TestListener.NIO.txt:SEVERE: Context
> [/] startup failed due to previous errors
>
> Does that merely indicate that the test itself caused a failure, and
> that the failure-to-startup was intentional?
>
> Similarly:
>
> TEST-org.apache.catalina.tribes.group.interceptors.TestNonBlockingCoordinator.APR.txt:org.apache.catalina.tribes.ChannelException:
> Send failed, and sender is disconnected. Not retrying.; Faulty
> members:tcp://{127, 0, 0, 1}:4005;
>
> Again, all test files say "Failures: 0, Errors: 0" so I guess everything
> is okay. It's just tough to see those log lines without asking.
>
> Thanks,
> -chris

1. I noticed this kind of message when I was looking for problems in my 
own new tomcat tests. Because they didn't originate from my own tests, I 
didn't follow it up. Sorry...

2. I've seen similar situations in other projects, but I don't know if 
my explanation is relevant to the tomcat tests... in all previous cases, 
my tests have been complex enough to require starting another thread so 
I could have both a client and server active during each individual test 
method of the class.

3. The tomcat tests (at least the ones I have worked on) subclass 
TomcatBaseTest, which starts Tomcat in a new thread, which puts them 
into the category I am talking about.

4. As far as I remember, it is possible for these sub-threads to "fail", 
or even interfere with each-other (clashes for port numbers or other 
shared resources), or even interfere with other completely different 
test classes doing the same kind of thing, while the main thread happily 
passes all its junit assertions and reports "success".

5. Forgive me if this is too vague, or too simplistic to be helpful. 
Your comment reminded me of myself (about 10 years ago) when everyone 
else was happily reading successful junit summaries and I started 
looking at the log files generated by the tests. I found the messages 
(like yours) difficult to understand, and even more difficult to 
diagnose - set a debugger break point in the sub-thread and you will 
screw up the timing of the tests, thus never even arriving at the 
troublesome code. I often had to catch the exception when it was thrown, 
then analyse the call stack - just like the old days of reading core dumps!

6. If you are still reading this, then I'll cheer you up by saying about 
5 in 6 of these "problems" came down to artefacts of the test design, 
rather than bugs in the logic actually under test. Unfortunately, I had 
to debug and fix all of them before I could stop worrying!

I hope this war story has been helpful.

Brian



---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org