Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 2 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -297,6 +297,8 @@ await dq.stream_length("orders") # entries retained in the log (XLEN
await dq.pending("orders", "order-service") # delivered-but-not-acked (PEL) — in flight right now
await dq.lag("orders", "order-service") # published-but-not-yet-delivered (Redis ≥ 7)
await dq.peek("orders", count=10) # read without consuming
await dq.registered() # every (stream, group) registered against this Redis
await dq.health() # itemised liveness; healthy() is this, as a bool

await dq.dlq_messages("orders", "order-service") # triage the DLQ
await dq.redrive_dlq("orders", "order-service") # put a batch back
Expand Down
262 changes: 262 additions & 0 deletions loadtest/README.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,262 @@
# xstreamq load test — Python consumers, Kotlin producer

A load and chaos harness for the Python [xstreamq](../README.md): a JVM producer
publishing straight to Redis while the real Python library consumes — and, in chaos
mode, while its consumer processes are being SIGKILLed underneath it.

This is a port of the [TypeScript twin's harness][ts-harness]. The supervisor and
worker take the **same flags**, the ledger uses the **same Redis keys**, and the
producer is literally the same JVM program, so a Python run and a TypeScript run
are directly comparable.

| | what it is | what it proves |
|---|---|---|
| **producer** (Kotlin) | N virtual threads doing blocking `XADD` | how fast xstreamq's stream can be fed, and where the latency actually goes |
| **supervisor** (Python) | spawns consumer processes, optionally kills them, owns the tally | no loss under hard kills, and what at-least-once actually costs |
| **worker** (Python) | one real `XStreamQ` subscriber process | the system under test |

## The producer lives in the TypeScript repo

There is only one producer and it is **shared**, at
`../../01-node/xstreamq-ts/loadtest/`. It is a JVM process that imports neither
library — it reimplements xstreamq's envelope and key naming from the outside
(`Wire.kt`) and writes entries directly.

That is the point, and it is why one copy serves both twins. xstreamq documents
its stream envelope as an **open contract**: a foreign producer may write a bare
`{b: <json>}` entry and either consumer will decode it, defaulting `rc` to 0. A
load test that drove xstreamq's own `publish()` would be measuring the library
against itself; this one measures it against an independent implementation of its
own published contract.

`Wire.kt` mirrors `envelope.py` / `keys.py` and their TypeScript equivalents. **If
any of the three drift, this stops testing xstreamq and starts testing a fiction.**

## Running

Redis first:

```sh
make redis-up # port 6399
```

Then the consumer fleet, which stays up until every message is accounted for:

```sh
uv run python loadtest/harness/supervisor.py --messages=100000 --failure-rate=0.25
```

And the producer, in another shell — note the absolute path into the other repo:

```sh
gradle -p ../../01-node/xstreamq-ts/loadtest run \
--args="--messages=100000 --concurrency=1024 --connections=64"
```

`--help` on either lists every knob. The two `--messages` values should match: the
producer uses it as how many to send, the supervisor as when to stop waiting.

### The knobs that matter

| producer | |
|---|---|
| `--rate=<n>` | target msgs/sec; `0` (default) means unbounded — find the ceiling |
| `--concurrency=<n>` | virtual threads. Cheap. Raise it until `pool wait` dominates |
| `--connections=<n>` | pooled sockets. The actually-scarce resource |

| supervisor | |
|---|---|
| `--workers=<n>` | consumer **processes** |
| `--kill-interval=<ms>` | SIGKILL a random worker this often. `0` (default) disables chaos |
| `--respawn-delay=<ms>` | how long a killed worker stays down |
| `--failure-rate=<0..1>` | chance each *delivery* throws — so a message that fails once can still succeed on retry |
| `--max-retries=<n>` | attempts before the DLQ |
| `--retry-on-idle=<ms>` | the visibility timeout. **Without it there are no retries at all** |
| `--dedupe=<ms>` | turn on idempotency markers and watch the duplicate count |

Every flag is denominated in **milliseconds**, matching the TypeScript harness.
The Python API takes seconds for two of them, and `worker.py` does that conversion
at the boundary so the two harnesses stay invocation-compatible:

```
--reclaim-interval=<ms> -> retry_reclaim_interval_s
--dedupe=<ms> -> dedupe_ttl_s
```

## Chaos mode

`--kill-interval=<ms>` SIGKILLs a random worker on a timer and respawns it under
the same consumer name, the way a restarted pod would come back. SIGKILL
specifically — no handler, no drain, no chance to ack — because that is the failure
the pending-entries list exists for.

Three outcomes are worth separating, because they are not the same thing:

- **loss** — `resolved` must reach the published count. A message orphaned by a
kill and never reclaimed shows up here and nowhere else.
- **duplicates** — a worker killed *between* a successful handler and its ack gets
that message redelivered. That is at-least-once working as documented, not a bug.
- **retry budget** — a reclaim bumps `rc` whether the handler failed or the worker
died. Enough kills and a message is dead-lettered having never once failed.

### The accounting has to live in Redis

Chaos mode kills processes, so anything a worker held in local variables dies with
it — and dies *in proportion to how much chaos happened*, which is the worst
possible bias. [`ledger.py`](harness/ledger.py) therefore keeps everything in
Redis: bitmaps indexed by sequence number for `seen` / `dead` / `failed` / `dup`,
plus counter and latency hashes.

Bitmaps because the interesting questions are all set operations, and Redis does
those server-side. `|seen ∪ dead|` is how many messages reached a terminal state.
`dead ∖ failed` is the one that matters most here: messages dead-lettered *without
the handler ever failing*.

Where the TypeScript ledger leans on ioredis auto-pipelining to collapse a
delivery's writes into one round trip, redis-py has no equivalent, so each
recording method builds an explicit `pipeline(transaction=False)` and executes it
once. Same round-trip count, stated outright rather than inferred from a client
setting. That round trip is a real cost and it is the price of accounting that
survives a kill.

The `on_dlq` callback fires in whichever worker's reclaimer did the move, and that
worker can be killed a moment later. So the final reconciliation reads the DLQ
**stream** and sets the `dead` bit from there — the stream is the authoritative
record, the callbacks are just the live signal.

## Runs

All on the repo's Redis container, 12-core box, 128-byte payloads, `--work-ms=0`.

> **Comparing against the TypeScript numbers:** the runs below use **100,000**
> messages where [the TS README][ts-runs] used 200,000, because the point here was
> to validate the port, not to re-derive throughput. Rates and *ratios* compare
> directly; absolute counts do not.

### 1. Baseline — no chaos, 25% failure rate

100,000 messages, unbounded producer, `max_retries=3`, 4 consumers.

```
PRODUCER (Kotlin, 1024 virtual threads)
published 100,000 in 2.9s → 34,495 msg/s
redis rtt p50 1.65ms p90 2.45ms p99 4.11ms
pool wait p50 0.01ms p90 95ms p99 300ms

CONSUMER succeeded 99,618 dead-lettered 382 duplicates 0
✓ every published message accounted for (100,000/100,000)
```

**382 dead letters against a theoretical 391.** With `max_retries=3` a message must
lose the coin flip four times, so the expected count is `0.25⁴ × 100,000 = 391`.
Observed 382, about 0.4σ off — the same agreement the TypeScript run showed, which
is the useful signal: both twins spend their retry budget identically.

**Zero duplicates without chaos**, as it should be.

Producer-side numbers are within noise of the TypeScript run (34.5k vs 36.8k
msg/s), which is expected — the producer is the same program and never touches
either library.

### 2. Chaos — 85 workers SIGKILLed mid-flight

100,000 messages, 6 consumer processes, a kill every 400ms, 2% failure rate,
`max_retries=3`.

```
workers killed 85
delivered 102,080 succeeded 100,000
failed attempts 2,056 duplicates 24 dead-lettered 0
✓ every published message accounted for (100,000/100,000)
```

**Zero loss across 85 hard kills.** The visibility timeout did its job every time.

The retry stream held **3,268** reclaims against only **2,056** injected failures —
so **1,212 messages were orphaned by kills** and brought back by the reclaimer. Of
those, **24 had already been handled**: killed in the window between the handler
returning and `XACK` landing, redelivered, and handled again.

The accounting closes exactly: `100,000 + 2,056 + 24 = 102,080` deliveries.

That is **~2.0% of kill-orphaned messages processed twice**, against the
TypeScript twin's 1.44% on the same knobs. Both are the same phenomenon at the
same order of magnitude; the gap is not a meaningful difference between the twins
at n=24 duplicates (Poisson noise alone is ±20% here), and the two runs also
differ in message count and therefore in how long each message sat in flight.

### 3. Retry budget — kills alone can dead-letter a healthy message

50,000 messages, 6 consumers, a kill every 250ms, **`--failure-rate=0`**,
**`--max-retries=1`**. With no injected failures at all, anything reaching the DLQ
got there purely by being orphaned.

```
workers killed 116
failed attempts 0
dead-lettered 3
duplicates 21
dlq, never failed 3 ← retry budget spent on kills, not on failures
✓ no loss: 50,000/50,000 accounted for
```

All three dead letters carry `rc=2` — orphaned exactly twice, `max_retries=1`
exhausted, handler never once completed for them:

```
1786177189387-0 rc=2 oid=1786177183257-13 {"seq":1258,...}
1786177197423-0 rc=2 oid=1786177184040-9 {"seq":25505,...}
1786177198181-0 rc=2 oid=1786177184190-20 {"seq":22139,...}
```

**This reproduces the TypeScript finding exactly**, down to the `rc=2`. xstreamq
cannot distinguish "the handler failed" from "the worker died" — both are just an
un-acked entry going idle, and both cost one retry. A flappy deployment with a low
`max_retries` will therefore dead-letter perfectly healthy messages. Nothing is
lost (they're in the DLQ, and redrive puts them back), but restart churn and
handler failures draw on the same budget.

Note `succeeded (49,998) + dead-lettered (3) = 50,001`, one more than published.
That is not an accounting error: one message was handled, killed before its ack,
redelivered, orphaned again, and dead-lettered — so it is in *both* sets.
`resolved` is `|seen ∪ dead|`, which is exactly 50,000.

## What this does not cover

- **Consumer throughput as a headline number.** The Redis ledger adds a round trip
per delivery specifically to survive kills. Consume rate here is not xstreamq's
ceiling.
- **The drain/sustained-rate ceilings** measured for the TypeScript twin. Those
runs have not been repeated here, so there are no Python numbers to quote and
none should be assumed from the TS ones — the consumer is the half that differs.
- **Dedupe under chaos.** `--dedupe` is wired through and works, but the
duplicate-halving run has not been repeated on this side.
- **Correlated failure.** Kills are uniform-random and independent. A real bad
deploy takes every worker down at once, which is a different shape.
- **Redis itself failing.** No failover, no partition, no `appendfsync` stall.
- **Redis under memory pressure.** Nothing trims the main stream, so a long run
grows it without bound. Realistic for a burst test, wrong for a soak test.
- **Realistic handlers.** Every run above uses a no-op handler. That is the right
choice for finding the queue's ceiling and the wrong one for predicting yours.
- **Bigger payloads.** Everything is 128 bytes; `--payload` is right there.

## Layout

```
loadtest/
harness/
supervisor.py spawns workers, runs chaos, owns the tally
worker.py one real xstreamq consumer process — the system under test
ledger.py kill-safe run accounting in Redis bitmaps

(producer: ../../01-node/xstreamq-ts/loadtest/, shared, JVM, library-agnostic)
```

The producer and the supervisor talk through one Redis key
(`xstreamq:loadtest:progress`), rewritten about once a second, so the producer's
console can show both sides at once. That key's schema is shared with the
TypeScript harness, which is why the producer can report on either twin without
knowing which one is running.

[ts-harness]: ../../01-node/xstreamq-ts/loadtest/README.md
[ts-runs]: ../../01-node/xstreamq-ts/loadtest/README.md#runs
Loading
Loading