The stream load-test scenario measures its own backlog, and reports zero by default

[HectorIFC]

Context

mix malachi.loadtest --scenario=stream reports zero records and one dropped connection per connection, on its defaults, against a healthy server. Six scenarios are documented and this is one of them, so the tool answers a question it was asked with a number that is always zero and a warning that blames the server.

The streaming path itself is fine. A probe that connects, authenticates and sends the same subscribe frame the generator sends gets the backlog pushed back immediately, tagged with the subscribe's correlation id, and test/log_streaming_test.exs covers the same wiring end to end over the real TCP server and passes. Instrumenting stream_recv/4 shows frames arriving continuously, so nothing is failing to be delivered.

What is wrong is what the scenario measures.

It has no producer. Every connection subscribes; none produces. The only records that can ever be pushed are the ones setup/1 wrote before the workers started, :prepopulate, which defaults to 10_000 for the backlog scenarios (lib/malachi/loadtest.ex:93, :106). The server pushes those as fast as the window allows, which takes milliseconds, and after that nothing more can arrive because nothing is writing.

So the warmup window swallows the whole measurement. handle_push/5 records only once mono_ms() >= m.warmup_end (:389), and warmup defaults to 2 seconds. The backlog is long gone by then. Set warmup to 0 and the numbers appear, and they are exactly the backlog:

--warmup=0                      -> records: 10000    ops: 100
--warmup=0 --prepopulate=200000 -> records: 200000   ops: 2000

Which is the second problem: even at warmup 0 the figure is not a rate. It is prepopulate divided by whatever --duration was passed, so raising the duration lowers the reported records per second on identical work.

And the end of the window is reported as a dropped connection. When the backlog is exhausted, stream_recv/4 blocks in Conn.recv_frame(conn, remaining) until the measurement window closes, gets {:error, :timeout}, and hands it to after_drop/1, which increments the dropped counter (:493). Every run therefore ends with one drop per connection and the report's warning says the server likely timed out the produce call. Nothing was dropped and no produce was involved.

Reproduction

Against a local dev server, single connection:

mix malachi.loadtest --scenario=stream --connections=1 --duration=5 --warmup=1
  -> 0 rec/s, records 0, dropped 1

mix malachi.loadtest --scenario=stream --connections=1 --duration=4 --warmup=0
  -> records 10000, ops 100, dropped 1

Also reproduced on the three-node Docker cluster at 16 connections (0 records, 16 dropped), and confirmed pre-existing: identical before and after the subscriber change on the current branch, built and run as an interleaved A/B.

Plan

A. Give the scenario a producer. Split the connections the way :mixed already splits them in scenario_for/2: some produce, the rest subscribe. The measured window then contains a sustained stream and the number becomes a rate that means what the column says. This is the option that makes the scenario measure streaming rather than draining, and it is the shape the tool already uses elsewhere.

B. Keep it a drain, and report it as one. Measure from the subscribe rather than after a warmup, stop at the end of the backlog rather than the end of a duration, and report time-to-drain instead of records per second. Honest and smaller, but it answers a different question than the other scenarios, and a column labelled rec/s would still mislead unless the report distinguishes it.

C. Stop counting the end of the window as a drop. Needed under either of the above, and separable from both: stream_recv/4 knows the window has closed, so a timeout there is normal termination and not a lost connection. As it stands the backpressure counters and the published pages carry a fabricated drop per connection.

D. Do nothing, and document that stream does not measure throughput. The cheapest, and it leaves a documented scenario whose default output is zero.

Risks and open questions

• Option A changes what the scenario's numbers mean, so any recorded result from it is not comparable across the change. Nothing is published from it today, which makes now the cheap moment.
• The prepopulate default of 10_000 was chosen for :fetch, where a finite backlog is the point. Whatever is chosen here should decide whether :stream still wants one at all.
• The misreported drop (C) is the part most worth fixing first regardless: it is the one that points a reader at the server for something the client did deliberately.

Verification

• A test that the scenario reports a non-zero rate on default options, which is what nobody was asserting.
• A test that a clean end of window does not increment the dropped counter.
• Whatever is chosen, run --scenario=stream at the defaults and confirm the report no longer contains the produce-timeout warning.

Found while benchmarking the reconcile-tick change on PR #48: the produce scenarios could not exercise the subscriber path, and reaching for the one that does turned this up.

PR

fix/stream-loadtest-measures-live-traffic

One PR: give the stream scenario a producer so there is something to measure after the prepopulated backlog drains, and stop the default warmup from swallowing the whole run. A scenario that can only report zero is the bug; the streaming path itself is covered and passes.