raquo/Airstream

PeriodicEventStreamSpec randomly failed (just once so far)

yurique opened this issue · 8 comments

Just got this test fail randomly (just once out of many runs). Not sure if it's fine or maybe some sneaky race condition there.

[info] PeriodicEventStreamSpec:
[info] - emitInitial=true, resetOnStop=true *** FAILED ***
[info]   WrappedArray(Effect(obs1,4), Effect(obs1,1)) did not equal WrappedArray(Effect(obs1,1)) (PeriodicEventStreamSpec.scala:49)
[info]   Analysis:
[info]   WrappedArray(0: Effect(obs1,4) -> Effect(obs1,1), 1: Effect(obs1,1) -> )

...

[info] *** 1 TEST FAILED ***
[error] Failed tests:
[error] 	com.raquo.airstream.eventstream.PeriodicEventStreamSpec
[info] PeriodicEventStreamSpec:
[info] - emitInitial=true, resetOnStop=true *** FAILED ***
[info]   WrappedArray(Effect(obs1,4), Effect(obs1,1)) did not equal WrappedArray(Effect(obs1,1)) (PeriodicEventStreamSpec.scala:49)
[info]   Analysis:
[info]   WrappedArray(0: Effect(obs1,4) -> Effect(obs1,1), 1: Effect(obs1,1) -> )
[info] - emitInitial=false, resetOnStop=true *** FAILED ***
[info]   WrappedArray(Effect(obs1,4)) did not equal WrappedArray() (PeriodicEventStreamSpec.scala:97)
[info]   Analysis:
[info]   WrappedArray(0: Effect(obs1,4) -> )
[info] - emitInitial=true, resetOnStop=false *** FAILED ***
[info]   WrappedArray(Effect(obs1,4), Effect(obs1,1)) did not equal WrappedArray(Effect(obs1,1)) (PeriodicEventStreamSpec.scala:144)
[info]   Analysis:
[info]   WrappedArray(0: Effect(obs1,4) -> Effect(obs1,1), 1: Effect(obs1,1) -> )
[info] - emitInitial=false, resetOnStop=false
[info] - dynamic interval *** FAILED ***
[info]   WrappedArray(Effect(obs1,2), Effect(obs1,3)) did not equal WrappedArray(Effect(obs1,3)) (PeriodicEventStreamSpec.scala:274)
[info]   Analysis:
[info]   WrappedArray(0: Effect(obs1,2) -> Effect(obs1,3), 1: Effect(obs1,3) -> )
raquo commented

Yeah, I looked through it and the test itself looks good.
I increased the interval to 50ms (from 15ms) and it seems to be more stable now (it started failing almost every time for me with 15ms)

I take it back - it's just failed with 50ms as well. Works well so far with 100ms :).

The tests take about a minute to run for me:

Total time: 52 s

So, trading an extra half a second for a bit better stability with a 100ms interval — maybe it's worth it?

raquo commented

Does 70-80ms work well enough for you maybe? The delays are somewhat probabilistic, so I doubt you'll get a 0.0% error rate with any reasonable delay, especially if tests take 52 seconds for you (for reference, tests take 5s for me and 14s in CI) – that means that code is running slower for you, so higher chance that the single thread will be blocked for longer than the timer length, delaying the execution of the timer.

With 70-80ms it seems to be good, but it works with 50ms most of the time as well (hasn't failed in the last ~10 runs or so).

I'm wondering why the tests take that long to run on my machine (it's a 10-core i9 + 32gb of memory). I tried switching to node 12.x (from 14.x), and it might have improved a bit:

Run completed in 17 seconds, 68 milliseconds.
[success] Total time: 23 s, completed Dec 27, 2020, 10:08:38 PM

But still nowhere close to 5 sec 🤔.

raquo commented

@yurique you've increased the delay to 50ms on the next-0.12 branch, has this been working well enough for you?