ecb21bd218
CI / changes (pull_request) Successful in 3s
CI / unit (pull_request) Successful in 11s
CI / integration (pull_request) Successful in 17s
CI / ui (pull_request) Has been skipped
CI / gate (pull_request) Successful in 0s
CI / deploy (pull_request) Successful in 2m18s
EvaluatePlay (the hottest gameplay call, fired on every tile placement) now uses the warm live-game cache directly: an active game stays cached (mutated in place across moves, evicted only on finish), so the cached engine game and its immutable seat list answer the membership check and the score with no DB read. The cold path (eviction / first load) still loads and validates via the store. The seat list is cached alongside the engine game for the membership fast path. GetGame also folds its two round-trips (game, then seats) into one LEFT JOIN, preserving the contract (same Game, a seatless game still returns empty seats, seat order kept) — one round-trip for every remaining caller. Measured at 500 players: evaluate p99 halves (200 -> 100 ms) and the per-op query count drops. It does NOT cut postgres CPU — that is write-bound (per-move CommitMove plus draft upserts and journal replays), the cheap indexed GetGame reads were never its bottleneck, and postgres runs with headroom (~1.5 of 2 cores). So this is a latency / query-volume optimization, not a DB-CPU one. Regression cover: a non-player evaluate against a warm game asserts the cached-seat membership path; the integration suite exercises GetGame's join across every game op.
195 lines
11 KiB
Markdown
195 lines
11 KiB
Markdown
# loadtest — stress trip report
|
||
|
||
The pre-release stress write-up for [`PRERELEASE.md`](../PRERELEASE.md). It drives the
|
||
`scrabble/loadtest` harness against a freshly redeployed test contour to confirm the
|
||
system holds at scale and to settle resource sizing before the prod cutover. The harness
|
||
stays in the repo for repeats; see [`README.md`](README.md) for how to run it.
|
||
|
||
This report supersedes the earlier per-phase notes. The harness has been through three
|
||
passes: an early diagnostic, a tuning pass that sized container limits / `GOMAXPROCS`, and
|
||
this final pass — which **added the per-tile `game.evaluate` preview to the model** (the
|
||
hottest real gameplay call, previously unmodelled) and, with it, surfaced and fixed the
|
||
**gateway→backend connection-pool bottleneck** described below. The numbers here are from
|
||
that final pass.
|
||
|
||
## What it models
|
||
|
||
The harness seeds a large account population with pre-created sessions directly in
|
||
Postgres, then drives virtual players through the **gateway edge protocol** (h2c) in real
|
||
games assembled via the invitation flow. Each player owns its own `edge.Client` (its own
|
||
h2c connection, like a real client), holds a live `Subscribe` stream, and per tick polls
|
||
`game.state`, replays `game.history`, generates a legal **mid-ranked** move with the
|
||
embedded `scrabble-solver`, and submits it (or passes/exchanges). A fraction of ticks
|
||
exercise nudge / chat / check-word / draft / profile / stats. A separate **gateway-hammer**
|
||
floods `games.list` to verify the rate limiter.
|
||
|
||
### The evaluate hot path (this pass)
|
||
|
||
A real client previews every tentative play as the user arranges tiles: the UI fires a
|
||
debounced `game.evaluate` (legality + score) on each placement change while it is the
|
||
player's turn. Over a single composed word that is **several evaluate calls per turn** —
|
||
far more than the one `submit_play` — so `game.evaluate` is the single hottest gameplay
|
||
request at scale. The earlier passes did not model it at all (they submitted directly),
|
||
which understated the real load.
|
||
|
||
This pass models it: when a player composes a play of *K* newly-placed tiles, it fires one
|
||
`evaluate` per landed tile (a growing prefix of the tiles), plus a small number of
|
||
full-composition re-previews for reconsideration, spaced by a human-paced gap (the client's
|
||
250 ms debounce), then one `draft.save`, then `submit_play`. `--eval=false` reproduces the
|
||
pre-evaluate harness for an A/B baseline; `--eval-recon` tunes the reconsideration count.
|
||
|
||
`game.check_word` is a *different*, manual "look this word up" panel (throttled, on demand)
|
||
— not the per-tile call — and is exercised separately as a secondary op.
|
||
|
||
## Final run (eval-on, after the connection-pool fix)
|
||
|
||
Contour: backend / postgres capped at 2 cores / 512 MiB (`GOMAXPROCS=2`), gateway at
|
||
3 cores / 512 MiB (`GOMAXPROCS=3`), per the tuned `deploy/docker-compose.yml`. Gradual ramp
|
||
**50 → 200 → 500** concurrent players, 4 min/step, `--tick 800ms`, gateway-hammer on. The
|
||
harness ran as a one-shot container on `scrabble-internal`, capped at `--cpus 3`. The DB was
|
||
wiped before the run (`DROP SCHEMA backend CASCADE`); the seeded population was removed by
|
||
`--cleanup` afterwards.
|
||
|
||
Per-operation results at the 500-player peak (740 s, gameplay rows; the hammer row is the
|
||
limiter probe):
|
||
|
||
| operation | count | req/s | p50 | p99 | max | notes |
|
||
|-----------|------:|------:|----:|----:|----:|-------|
|
||
| game.evaluate | 85 721 | 115.9 | 1 ms | 200 ms | 193 ms | **the hot path** — all ok |
|
||
| game.state | 115 926 | 156.7 | 100 ms | 200 ms | 260 ms | transport_error 86 (0.07 %) |
|
||
| game.history | 22 258 | 30.1 | 5 ms | 100 ms | 195 ms | all ok |
|
||
| draft.save | 23 031 | 31.1 | 2 ms | 200 ms | 194 ms | all ok |
|
||
| game.submit_play | 21 704 | 29.3 | 1 ms | 200 ms | 274 ms | ok 3 902; not_your_turn / illegal_play are concurrent-play races (see caveat) |
|
||
| hammer:games.list | 522 756 | 706.7 | 1 ms | 2 ms | 53 ms | **99.97 % rate_limited** — limiter holds |
|
||
|
||
- **Volume:** 802 200 total edge calls (1 084 req/s incl. the hammer; ~377 req/s of real
|
||
gameplay). `stream errors: 0`. Live events: 11 199 `opponent_moved`, 4 153 `your_turn`.
|
||
- **`game.evaluate` is the dominant gameplay write-path call** at ~116 req/s — second only
|
||
to the `game.state` poll — and it is cheap: p50 1 ms, effectively zero errors. The backend
|
||
serves it straight from the in-memory live-game cache; on a warm hit it skips the database
|
||
entirely (see *Postgres read path* below, which halved its p99 to 100 ms).
|
||
- **Latency stayed healthy** under the heavier evaluate load: every gameplay op p99 ≤ 200 ms.
|
||
- **The limiter holds** unchanged: 99.97 % of the hammer rejected at p99 2 ms.
|
||
|
||
### Peak CPU (500 players)
|
||
|
||
| container | CPU peak | cap |
|
||
|-----------|---------:|----:|
|
||
| scrabble-postgres | **165 %** (~1.65 cores) | 200 % |
|
||
| scrabble-backend | 77 % (~0.77 core) | 200 % |
|
||
| scrabble-gateway | **26 %** (~0.26 core) | 300 % |
|
||
| scrabble-loadtest (harness) | 42 % | 300 % |
|
||
|
||
Memory stayed modest everywhere (Go services ≤ ~90 MiB). **Postgres is now the busiest
|
||
service** — it has headroom (1.65 of 2 cores) but is the scaling axis. The gateway, after
|
||
the fix below, is near-idle.
|
||
|
||
## The headline finding: gateway→backend connection churn
|
||
|
||
The gateway proxies every synchronous client call to the single backend host over REST.
|
||
Its backend HTTP client used the default transport, whose **`MaxIdleConnsPerHost` is 2**
|
||
(`http.DefaultMaxIdleConnsPerHost`). So the gateway kept only **2** keep-alive connections
|
||
to the backend and opened — then closed — a fresh TCP connection for almost every other
|
||
call. Measured at the gateway's network namespace:
|
||
|
||
| | gateway→backend sockets |
|
||
|---|---|
|
||
| before (eval-on, 500 players) | **TIME_WAIT ≈ 26 500**, ESTABLISHED 2 |
|
||
| after (eval-on, 500 players) | TIME_WAIT ≈ 0 (steady state), **ESTABLISHED ≈ 225 (reused)** |
|
||
|
||
26 500 TIME_WAIT sockets is the connection **churn**: ~440 new connections per second,
|
||
each a full TCP handshake + teardown, the socket then lingering 60 s. That count sits right
|
||
under the ~28 000 ephemeral-port ceiling — the latent cliff that produced the residual
|
||
`transport_error` the earlier passes chased on the *client* side (h2c streams) but never
|
||
eliminated, because the real cause was here, on the *backend* side.
|
||
|
||
The fix is one custom `http.Transport` with a wide idle pool
|
||
(`gateway/internal/backendclient/client.go`, `backendMaxIdleConns`). Before / after, same
|
||
eval-on workload at 500 players:
|
||
|
||
| metric | before fix | after fix |
|
||
|--------|-----------:|----------:|
|
||
| gateway→backend TIME_WAIT | ~26 500 | **~0** |
|
||
| gateway CPU peak | **175 %** (~1.75 cores) | **26 %** (~0.26 core) |
|
||
| game.state p99 | 500 ms | 200 ms |
|
||
|
||
**The churn was burning ~1.5 gateway cores of pure connection setup/teardown.** Removing it
|
||
cut peak gateway CPU ~7× and erased the port-exhaustion cliff. The backend and postgres CPU
|
||
are unchanged — they do the real work; only the gateway's wasted overhead disappeared. The
|
||
pool settles at ~225 live connections at 500 players; the constant is set to 512 for ~2×
|
||
headroom.
|
||
|
||
## Sizing — why the old "≈150 concurrent / 2-core" figure was a bug, not a floor
|
||
|
||
The earlier tuning pass concluded the gateway was the binding constraint — "size it for
|
||
≥ 3 cores per 500 players, scale it horizontally" — and the single-host "minimum" tier
|
||
topped out near ~150 concurrent. **That was sizing around the connection-churn bug.** The
|
||
gateway drew ~1.75–3 cores not from proxying work but from churning backend connections;
|
||
the backend behind it sat near-idle the whole time.
|
||
|
||
With the churn fixed, at **500 concurrent players** the app draws roughly:
|
||
|
||
- **gateway ≈ 0.26 core** (was ~3) — no longer the constraint,
|
||
- **backend ≈ 0.77 core**,
|
||
- **postgres ≈ 1.65 cores** — now the busiest, with headroom,
|
||
|
||
≈ **2.7 app cores total** (down from the ~5.5-core contour peak the tuning pass recorded,
|
||
*and* under a heavier, more realistic workload that now includes `game.evaluate`). Postgres,
|
||
not the gateway, is the scaling axis.
|
||
|
||
Revised single-host guidance (app + co-resident observability stack on one box):
|
||
|
||
| tier | CPU | RAM | handles |
|
||
|------|-----|-----|---------|
|
||
| **Minimum** | 2 cores | 2 GiB | comfortably the low hundreds of concurrent — the gateway no longer eats cores; postgres + the observability stack set the limit |
|
||
| **Average** | 4 cores | 4 GiB | 500 concurrent with headroom |
|
||
| **Maximum** | 8 cores | 8 GiB | 500+ with full burst headroom and room to grow |
|
||
|
||
The gateway's compose limit can drop well below its old 3 cores; it is now connection-pool
|
||
bound, not connection-CPU bound. Memory was never the constraint. Disk is still dominated
|
||
by observability retention (Tempo, Prometheus) + DB growth — unchanged from before.
|
||
|
||
## Postgres read path (warm-cache optimization)
|
||
|
||
Following this pass, `game.evaluate` no longer reads the database on the hot path. An
|
||
active game is already resident in the in-memory live-game cache (mutated in place across
|
||
moves, evicted only on finish), so the preview answers its seat-membership check from the
|
||
cached immutable seat list and scores against the cached engine game — **no `GetGame` on a
|
||
warm hit**. `GetGame` itself was also folded from two round-trips (game, then seats) into a
|
||
single `LEFT JOIN`. Measured at 500 players, **`game.evaluate` p99 halved (200 → 100 ms)**
|
||
and the per-operation query count dropped.
|
||
|
||
It did **not** cut postgres CPU, and the measurement says why: postgres is **write-bound**,
|
||
not read-bound. `pg_stat_user_tables` puts the cost in the per-move `CommitMove`
|
||
transaction (a `game_moves` insert plus `games` / `game_players` updates), the debounced
|
||
`game_drafts` upserts (~60 k in one run), and the journal replays — not the cheap, indexed,
|
||
fully-cached `GetGame` lookups this change removed (one re-run even committed 28 % more
|
||
plays, whose extra writes masked the saved reads). Postgres also runs with headroom
|
||
(~1.5 of 2 cores), and the gateway fix freed ~3 cores on the box, so the lever if postgres
|
||
ever caps is **more cores** (it is CPU-bound, not I/O), not riskier write-path surgery. So
|
||
this change is a latency / query-volume win, deliberately not a DB-CPU one.
|
||
|
||
## Caveat — harness fidelity
|
||
|
||
The harness's `not_your_turn` and `illegal_play` on `submit_play` are concurrent-play
|
||
artifacts, not system errors: it generates a move from a locally replayed board, and a
|
||
fast opponent (or a transport hiccup) can move between the state fetch and the submit,
|
||
leaving the move out of turn or illegal on the now-changed board. A real client previews
|
||
with `evaluate` and only submits a legal, in-turn play. These rejections are cheap domain
|
||
outcomes (HTTP-ok with a stable code) and do not change the request *load*, which is what
|
||
the run measures. The harness also shares the host CPU with the contour (capped with
|
||
`--cpus`); a fully isolated ceiling on separate hardware remains future work.
|
||
|
||
## Re-running
|
||
|
||
From the repo root:
|
||
|
||
```sh
|
||
docker build -f loadtest/Dockerfile -t scrabble-loadtest .
|
||
docker run --rm --cpus=3 --name scrabble-loadtest --network scrabble-internal \
|
||
-e POSTGRES_PASSWORD="$TEST_POSTGRES_PASSWORD" scrabble-loadtest run --reset --cleanup
|
||
```
|
||
|
||
`--eval=false` reproduces the pre-evaluate baseline for comparison. The authoritative hard
|
||
reset of the contour DB remains `DROP SCHEMA backend CASCADE` + a backend restart.
|