I have a process which schedules internal timed activity and notifies about specific events via pubsub. I want to write a test which asserts expected time between events/messages. I can control time values in test so they can be as large as required by VM to differentiate reliably, but preferably small (in prod it will be seconds).
Due to inconsistencies related to timer-triggering (and maybe message receiving) — the actual time between events can be slightly larger as compared to expected time, but this can be solved with assert_in_delta.
Is it a sane strategy to make a pubsub “mock” (or is it a “spy”?) which instead of broadcasting will write to event log with timestamps, then I can somehow assert on log contents?
In general, it’s a bad idea to assert on details like this.
Instead, what should be done is asserting on the side effects.
I would not mock PubSub. Instead I would make the message handler, in test, write to a log file with maybe a timestamp I could read back and compare that the difference in timestamps was sufficient
2 Likes
I thought about this and my reasoning was that since we know there is a pubsub output — then pubsub usage is not a detail but an interface instead. But thinking further seems like I was wrong — the interface is only pubsub messages, but not the specific pubsub module/function used. Though in message handler variant I’ll still need to use pubsub.subscribe, instead of mocking pubsub.broadcast, but since it is what also will be used by clients to listen messages — it seems ok
I run tests for a while using a generated message log with timestamps, and asserting differences between time passed as per timestamps and expected time — using assert_in_delta, with 50ms delta
The problem is, while this delta (and actually a delta a lot less) is fine in 99% cases, sometimes (usually during a first test run) the assertion fails, and the actual delta may be N times larger as compared to 50 ms, so it can be in hundreds ms.
It usually happens rarely and only on a first test run. Test suite runs in about 1.5 seconds. My hardware: MacBook Pro Mid 2012 with quad core Intel i7 2.7 GHz CPU, SSD and 16 GB RAM. So it’s not fast, but it is not by no means slow.
Can assert_in_delta even be used to assert actual time between messages? I don’t see any other way for this, and I wonder what is the reason for this rare but huge difference between expected and actual delta. Maybe this is due to a CPU overload somehow causing Erlang VM to throttle or something. My main concern is how this test will run in CI — the instance running this probably won’t be any faster but at least it should be “stable”, e.g. it won’t have unexpected CPU hogs and will at least keep this 50 ms delta unexceeded?
