As part of the patch for DERBY-205, a new test called "lang/errorStream.java"
was added to the Derby test package (svn revision 179584).
When I run this test against a local codeline, I seem to be seeing intermittent
failures because two lines in the output file are printed out of order.
23a24
> xxxxxxFILTERED-TIMESTAMPxxxxxGMT Thread[main,5,main]
java.lang.NoSuchFieldException: nonExistingFieldStream
25d25
< xxxxxxFILTERED-TIMESTAMPxxxxxGMT Thread[main,5,main]
java.lang.NoSuchFieldException: nonExistingFieldStream
The Derby harness takes output from System.err and System.out and prints them
both to the test output file, so usually, when diffs like this occur, it's
because the two streams (System.out and System.err) are overlapping.
With that in mind I started looking at the errorStream.java test and I noticed
that, for the negative test cases (ex. "checkWrongField"), since the target
stream/method/file doesn't exist (which is intentional), the default error
stream ends up being System.err (at least, that's what the comments at the top
of the test say). At the same time, the call to shutdown Derby in these same
test cases leads to a "shutdown ok" message being printed to System.out.
My theory, then, is that the error messages from the negative test cases (which
are going to System.err) are overlapping arbitrarily with the "shutdown ok"
message (which is going to System.out) and the result is an intermittent diff
(because the overlapping output isn't consistent). At least, that would explain
the intermittent diff that I'm seeing.
As a proof of concept, I changed the "System.out" that is in the shutdownDerby()
method to be "System.err", thus forcing both the negative test case messages and
the "shutdown ok" messages to the same stream, which in turn means that they
will always show up in the same order w.r.t each other, and thus the
intermittent diff _should_ go away.
After making this change, the intermittent diff that I was seeing did in fact go
away--but then I saw another one caused by the "Test errorStream finished
successfully" message. The same theory applies there: this message is printed
to System.out right after the final derbyShutdown() method is called, and since
I changed the "shutdown ok" message to print to System.err, that means that it
was intermittently overlapping with the "finished successfully" message. I then
fixed this problem by changing the "finished successfully" method to print to
System.err, as well.
All of that said, I think I've found the cause of the problem (System.err and
System.out are overlapping), but I'm not sure what the best solution is. It
seems like changing the "shutdown ok", "finished successfully", and "Test
errorStream starting" (just to be safe) messages to use System.err would solve
the problem, but that's not a very intuitive solution. A better fix would be to
somehow change the 'default error stream' (for cases when an error
file/method/field doesn't exist) to be System.out--but is that even possible??
If anyone has any input here, please do speak up (it's quite possible I'm
missing something). Otherwise, though it's not very intuitive, we might need to
change the above-mentioned messages to all print to System.err in order to avoid
the intermittent diff(s)...
Comments?
Army
- Intermittent failure with lang/errorStream.java (added w/ DE... Army
-
