Intermittent unit test failure with Oracle JDK7

[rankinc]

(I'm not sure how BTM even builds with JDK7, due to MockDriver and MockXADataSource not implementing getParentLogger(). However...)

I've run this several times with my changes to JdbcPooledConnection reverted (just to be sure), and there is an intermittent error in bitronix.tm.recovery.RecovererTest when built against JDK7. I have been unable to reproduce this when building against JDK5.

Running bitronix.tm.recovery.RecovererTest
Tests run: 9, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 6.838 sec <<< FAILURE!
testBackgroundRecovererSkippingInFlightTransactions(bitronix.tm.recovery.RecovererTest) Time elapsed: 0.838 sec <<< FAILURE!
junit.framework.AssertionFailedError: TX has been committed more or less times than just once expected:<1> but was:<2>
at junit.framework.Assert.fail(Assert.java:47)
at junit.framework.Assert.failNotEquals(Assert.java:283)
at junit.framework.Assert.assertEquals(Assert.java:64)
at junit.framework.Assert.assertEquals(Assert.java:195)
at bitronix.tm.recovery.RecovererTest.testBackgroundRecovererSkippingInFlightTransactions(RecovererTest.java:360)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at junit.framework.TestCase.runTest(TestCase.java:168)
at junit.framework.TestCase.runBare(TestCase.java:134)
at junit.framework.TestResult$1.protect(TestResult.java:110)
at junit.framework.TestResult.runProtected(TestResult.java:128)
at junit.framework.TestResult.run(TestResult.java:113)
at junit.framework.TestCase.run(TestCase.java:124)
at junit.framework.TestSuite.runTest(TestSuite.java:243)
at junit.framework.TestSuite.run(TestSuite.java:238)
at org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:83)
at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:252)
at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:141)
at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:112)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.apache.maven.surefire.util.ReflectionUtils.invokeMethodWithArray(ReflectionUtils.java:189)
at org.apache.maven.surefire.booter.ProviderFactory$ProviderProxy.invoke(ProviderFactory.java:165)
at org.apache.maven.surefire.booter.ProviderFactory.invokeProvider(ProviderFactory.java:85)
at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:115)
at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:75)

[rankinc]

Having said that, I see that the Travis build has just broken again:
https://travis-ci.org/bitronix/btm/jobs/22012562

Even worse, this particular failure has been happening for a while!
https://travis-ci.org/bitronix/btm/jobs/13401645
https://travis-ci.org/bitronix/btm/jobs/11306852

This looks like a race condition - conflicts with static variables, perhaps? Am I wasting my time here?

[lorban]

I suppose this is related to #20, right? If so, I propose that you close this issue.

Thanks!

[rankinc]

#20 fixes an intermittent failure with JmsProperUsageMockTest, which only happens for me on GitHub. This issue is with RecovererTest, which sometimes happens locally but not on GitHub.

[lorban]

There may be a race in the recoverer code or test that only JDK 7 can trigger, that wouldn't be new. I'll try to see if I can reproduce that locally.

[rankinc]

NetBeans has flagged this as an issue in PoolingConnectionFactory:

public class PoolingConnectionFactory extends ResourceBean implements ConnectionFactory, XAResourceProducer, PoolingConnectionFactoryMBean {

    private volatile transient List<JmsPooledConnection> xaStatefulHolders;

    // ... etc

    public XAResourceHolder findXAResourceHolder(XAResource xaResource) {
        synchronized (xaStatefulHolders) {
            // ... etc
        }
        return null;
    }
}

It doesn't like synchronising on a "volatile" variable; and there's no good reason why xaStatefulHolders cannot be "final" anyway.

[rankinc]

Synchronising on a volatile field may be a dubious construct, but making the field final doesn't fix this.

But it occurs to me that the failing test "testBackgroundRecovererSkippingInFlightTransactions" is alphabetically the first test case in RecovererTest. Also, "EventRecorder.clear()" is called as part of the test tearDown() rather than the setUp(), which means that EventRecorder.clear() is not executed before RecovererTest's first test case.

And "yes", JUnit does execute testBackgroundRecovererSkippingInFlightTransactions() first :-).

So I'm thinking that this intermittent failure is due to EventRecorder sometimes containing a lingering event from an earlier Test. And the fix is to call EventRecorder.clear() in RecovererTest.setUp().

With this fix applied, the test is no longer failing. (Not so far, anyway...)

[rankinc]

My unit-test-jdk7 branch has now been merged.