Flaky Test: AssertionError for TestParallelMatcher#testParallelSlowLog

[Alisha-0321]

When I ran the test uk.co.flax.luwak.matchers.TestParallelMatcher#testParallelSlowLog using the command mvn test -pl luwak –Dtest=uk.co.flax.luwak.matchers.TestParallelMatcher#testParallelSlowLog, I observed a test failure like the following:

Running uk.co.flax.luwak.matchers.TestParallelMatcher
Tests run: 1, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 1.007 sec <<< FAILURE!
testParallelSlowLog(uk.co.flax.luwak.matchers.TestParallelMatcher)  Time elapsed: 0.951 sec  <<< FAILURE!
java.lang.AssertionError:
Expecting:
 <"Limit: 0
        1 [253931520ns]
        2 [2503096ns]
        3 [253931253ns]
">
not to contain:
 <"2 [">
        at uk.co.flax.luwak.matchers.ConcurrentMatcherTestBase.testParallelSlowLog(ConcurrentMatcherTestBase.java:118)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
        at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
        at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44)
        at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
        at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271)
        at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70)
        at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
        at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238)
        at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63)
        at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236)
        at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53)
        at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229)
        at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
        at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:242)
        at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:137)
        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:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        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)

Results :
Failed tests:   testParallelSlowLog(uk.co.flax.luwak.matchers.TestParallelMatcher): (..)

Tests run: 1, Failures: 1, Errors: 0, Skipped: 0

I noticed this test failure is flaky, because this test failed 3 times out of 5000 times I ran that same command. I ran the test on an Ubuntu 18.04.4 LTS machine using OpenJDK 1.8.0_312.

Also, I found that if I were to insert a 100ms delay right before Line 476 in the file luwak/src/main/java/uk/co/flax/luwak/Monitor.java (through adding a Thread.sleep(100);), I could reproduce the same failure more reliably, almost every time I ran the test.