[QPID-3501] LogMonitor can corrupt test logs files and cause tests subclassing AbstractLoggingTests to fail.

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Fix Version/s: 0.13
• Component/s: Java Tests
• Assignee: Keith Wall
• Reporter: Keith Wall
• Created: 22/Sep/11 14:32
• Updated: 14/Mar/17 20:08
• Resolved: 23/Sep/11 10:58

Description

On an old slow CI box, occasionally we see test failures from those tests subclassing AbstractLoggingTests (ChannelLoggingTests, ExchangeLoggingTest etc).

For example: org.apache.qpid.server.logging.ExchangeLoggingTest fails on the 0-9-1 test profile with exception:

TestName: testDiscardedMessage Duration: 11.167

Incorrect message expected:<...3> but was:<...1>
                                

junit.framework.ComparisonFailure: Incorrect message expected:<...3> but was:<...1>
	at org.apache.qpid.server.logging.AbstractTestLogging.validateMessageID(AbstractTestLogging.java:119)
	at org.apache.qpid.server.logging.ExchangeLoggingTest.testDiscardedMessage(ExchangeLoggingTest.java:249)
	at org.apache.qpid.test.utils.QpidBrokerTestCase.runBare(QpidBrokerTestCase.java:238)
	at org.apache.qpid.test.utils.QpidTestCase.run(QpidTestCase.java:131)

Analysis shows that the tests' assertions are failing because the test standard out file is corrupt. When the test fails, the .out file contains a long sequence of ASCII NULs and parts of the log are duplicated. It is the duplication that causes the assertion failure, as the log files contain incorrect numbers of operation log messages (EXH- in this case).

od -a TEST-org.apache.qpid.server.logging.ExchangeLoggingTest.testDiscardedMessage.out | head
0000000 nul nul nul nul nul nul nul nul nul nul nul nul nul nul nul nul
*
0164000 nul nul nul nul nul nul nul nul nul nul nul nul m a i n
0164020 sp 2 0 1 1 - 0 9 - 2 1 sp 2 1 : 1