db-derby-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Army <qoz...@sbcglobal.net>
Subject Intermittent failure with lang/errorStream.java (added w/ DERBY-205)
Date Wed, 08 Jun 2005 00:03:13 GMT
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.

 > xxxxxxFILTERED-TIMESTAMPxxxxxGMT Thread[main,5,main] 
java.lang.NoSuchFieldException: nonExistingFieldStream
< 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)...


View raw message