Flaky unit tests

[samuelgruetter]

It looks like there are some flaky unit tests:

On my machine, this test failed today (but only once):

rx.operators.OperationNext$UnitTest.testOnErrorViaHasNext

On cloudbees, these tests seem to be flaky:

Build #278: rx.concurrency.CurrentThreadScheduler$UnitTest.testSequenceOfDelayedActions
Build #276: rx.concurrency.CurrentThreadScheduler$UnitTest.testSequenceOfDelayedActions
Build #237: rx.concurrency.CurrentThreadScheduler$UnitTest.testSequenceOfDelayedActions
Build #185: rx.concurrency.CurrentThreadScheduler$UnitTest.testSequenceOfDelayedActions
Build #251: rx.concurrency.TestSchedulers.testSchedulingWithDueTime
Build #277: rx.operators.OperationConcat$UnitTest.testConcatConcurrentWithInfinity

Edit: also

Build #290: rx.operators.OperationConcat$UnitTest.testConcatConcurrentWithInfinity 

[samuelgruetter]

Output of failed rx.operators.OperationNext$UnitTest.testOnErrorViaHasNext:

java.lang.AssertionError: should not have received exception
    at org.junit.Assert.fail(Assert.java:93)
    at rx.operators.OperationNext$UnitTest.testOnErrorViaHasNext(OperationNext.java:252)
    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.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:45)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:42)
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:263)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:68)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:47)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:300)
    at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:80)
    at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:47)
    at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:69)
    at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:49)
    at sun.reflect.GeneratedMethodAccessor7.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
    at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
    at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
    at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
    at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
    at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:103)
    at sun.reflect.GeneratedMethodAccessor6.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
    at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
    at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:355)
    at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:66)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:724)

[benjchristensen]

Build 278: rx.concurrency.CurrentThreadScheduler$UnitTest.testSequenceOfDelayedActions Build 276: rx.concurrency.CurrentThreadScheduler$UnitTest.testSequenceOfDelayedActions Build 237: rx.concurrency.CurrentThreadScheduler$UnitTest.testSequenceOfDelayedActions Build 185: rx.concurrency.CurrentThreadScheduler$UnitTest.testSequenceOfDelayedActions

The CurrentThreadScheduler tests that are testing delay functionality are very non-deterministic. The assertions either need to change to allow for that, or we need to change to using artificial time (though these particular tests are purposefully testing the real implementation, so using artificial time would someone defeat the purpose).

Build 251: rx.concurrency.TestSchedulers.testSchedulingWithDueTime

This is similar, it's asserting something scheduled on a background thread. I haven't dug into what needs to change.

Build 277: rx.operators.OperationConcat$UnitTest.testConcatConcurrentWithInfinity

Not sure at a quick glance what the issue here is.

---

I don't have time this morning to fix these but will do so at some point (their intermittent failures annoy me too).

[benjchristensen]

Another here: https://netflixoss.ci.cloudbees.com/job/RxJava-pull-requests/293/

[samuelgruetter]

another local failure:

rx.operators.OperationNext$UnitTest > testOnErrorViaHasNext FAILED
    java.lang.AssertionError at OperationNext.java:252

[samuelgruetter]

and yet another (in rx.operators.SynchronizedObserver$UnitTest):

java.lang.AssertionError: expected:<1> but was:<0>
    at org.junit.Assert.fail(Assert.java:93)
    at org.junit.Assert.failNotEquals(Assert.java:647)
    at org.junit.Assert.assertEquals(Assert.java:128)
    at org.junit.Assert.assertEquals(Assert.java:472)
    at org.junit.Assert.assertEquals(Assert.java:456)
    at rx.operators.SynchronizedObserver$UnitTest.testMultiThreadedWithNPEinMiddle(SynchronizedObserver.java:250)
...

[zsxwing]

rx.concurrency.CurrentThreadScheduler$UnitTest failed several times in my machine today:

org.mockito.exceptions.verification.VerificationInOrderFailure: 
Verification in order failure
Wanted but not invoked:
action0.call();
-> at rx.concurrency.CurrentThreadScheduler$UnitTest.testSequenceOfDelayedActions(CurrentThreadScheduler.java:191)
Wanted anywhere AFTER following interaction:
action0.call();
-> at rx.Scheduler$4.call(Scheduler.java:184)
    at rx.concurrency.CurrentThreadScheduler$UnitTest.testSequenceOfDelayedActions(CurrentThreadScheduler.java:191)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:45)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:42)
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:263)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:68)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:47)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:300)
    at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:80)
    at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:47)
    at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:69)
    at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:49)
    at sun.reflect.GeneratedMethodAccessor7.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
    at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
    at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
    at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
    at $Proxy2.processTestClass(Unknown Source)
    at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:103)
    at sun.reflect.GeneratedMethodAccessor6.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
    at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
    at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:355)
    at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:66)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:662)

[samuelgruetter]

again rx.operators.OperationNext$UnitTest.testOnErrorViaHasNext

[petermd]

wrt

rx.operators.OperationNext$UnitTest.testOnErrorViaHasNext

I don't think the test is necessarily flaky. rather that the Iterable returned by next() is inconsistent. if you trigger an exception during Iterable.next() then the Iterable.hasNext() will revert to returning 'true'. This can fail the test if the

assertFalse(it.hasNext());

runs after the it.next() on the async thread.

so you can't really fix the test, you can either make the test thread delay a little longer and definitely fail, or remove the assert and accept that the behavior of hasNext() is unreliable after next() completes (either with a value or exception) since its unusual that you'd be checking the Iterable from a different thread.

also might be worth noting that the wiki suggests the Iterable should return a single 'null' value if the Observable completes without any value (https://github.com/Netflix/RxJava/wiki/Blocking-Observable-Operators#next) but I can't see any test or implementation for this case - am I misunderstanding this?

[abersnaze]

Then the hasNext should block until either the onNext or onComplete has been called.

[petermd]

not sure in which case you mean? the hasNext() in the failing test is called after the onNext/onComplete has occurred (the async thread has called next() and it has thrown an exception)

or do you mean in the case where the Observable completes without an onNext?

[zsxwing]

The following error happened in my machine today:

java.lang.AssertionError: expected:<39.0> but was:<100.0>
    at org.junit.Assert.fail(Assert.java:93)
    at org.junit.Assert.failNotEquals(Assert.java:647)
    at org.junit.Assert.assertEquals(Assert.java:443)
    at org.junit.Assert.assertEquals(Assert.java:512)
    at rx.operators.OperationGroupBy$UnitTest.testUnsubscribe(OperationGroupBy.java:546)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:45)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:42)
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:263)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:68)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:47)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:300)
    at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:80)
    at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:47)
    at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:69)
    at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:49)
    at sun.reflect.GeneratedMethodAccessor7.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
    at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
    at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
    at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
    at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
    at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:103)
    at sun.reflect.GeneratedMethodAccessor6.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
    at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
    at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:355)
    at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:66)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
    at java.lang.Thread.run(Thread.java:695)

I reviewed rx.operators.OperationGroupBy.UnitTest.testUnsubscribe() and found the following assumption was wrong:

// sentEvents will go until 'eventCounter' hits 20 and then unsubscribes
            // which means it will also send (but ignore) the 19/20 events for the other group
            // It will not however send all 100 events.
            assertEquals(39, sentEventCounter.get(), 10);
            // gave it a delta of 10 to account for the threading/unsubscription race condition which can vary depending on a machines performance, thread-scheduler, etc

Actually, since we can not control when to run a thread, sentEventCounter can be 100 in some scenario.

[abersnaze]

I fixed one flaky test by moving the decrement of the latch in to the observer.

                 .map(new Func1<String, String>() {
                     public String call(String arg0) {
+                        throw new IllegalArgumentException("any error");
-                        try {
-                            throw new IllegalArgumentException("any error");
-                        } finally {
-                            latch.countDown();
-                        }
                     }
                 });

+        // wait for the call to get to the observer before decrementing the latch
+        doAnswer(new Answer() {
+            @Override
+            public Object answer(InvocationOnMock invocation) throws Throwable {
+                latch.countDown();
+                return null;
+            }
+        }).when(stringObserver).onError(any(Throwable.class));
         m.subscribe(stringObserver);
         latch.await();

[zsxwing]

@abersnaze Thanks. I added your patch to PR #461. Is it OK? Could you take a look?

[samuelgruetter]

Just had another instance of this:

java.lang.NullPointerException
    at rx.operators.OperationConcatTest.testConcatConcurrentWithInfinity(OperationConcatTest.java:324)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    ...

[samuelgruetter]

Another test which also seems to be flaky:

rx.schedulers.NewThreadSchedulerTest.testMixOfDelayedAndNonDelayedActions

org.mockito.exceptions.verification.VerificationInOrderFailure: 
Verification in order failure
Wanted but not invoked:
action0.call();
-> at rx.schedulers.AbstractSchedulerTests.testMixOfDelayedAndNonDelayedActions(AbstractSchedulerTests.java:317)
Wanted anywhere AFTER following interaction:
action0.call();
-> at rx.Scheduler$4.call(Scheduler.java:194)

    at rx.schedulers.AbstractSchedulerTests.testMixOfDelayedAndNonDelayedActions(AbstractSchedulerTests.java:317)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    ...

This was with version 0.16.0.

[zsxwing]

For the rx.schedulers.NewThreadSchedulerTest.testMixOfDelayedAndNonDelayedActions, as AbstractSchedulerTests.testMixOfDelayedAndNonDelayedActions uses the real time to schedule the actions, it's non-deterministic. When the CPUs are busy, the test may fail. Can we enlarge the time?

                scheduler.schedule(first);
                scheduler.schedule(second, 300, TimeUnit.MILLISECONDS);
                scheduler.schedule(third, 100, TimeUnit.MILLISECONDS);
                scheduler.schedule(fourth);
                scheduler.schedule(new Action0() {

                    @Override
                    public void call() {
                        latch.countDown();
                    }
                }, 400, TimeUnit.MILLISECONDS);

[benjchristensen]

Closing as this has become an epic dumping ground ... most issues have been solved. The only one I'm still aware of is a new one, the pivot operator.