From 61a073099dfb386781251a7b8470b319ee3898a8 Mon Sep 17 00:00:00 2001 From: Josh Creek <8179928+jcreek@users.noreply.github.com> Date: Sat, 5 Sep 2026 17:14:43 +0100 Subject: [PATCH] fix(store): widen the serializable retry budget, stop leaking test volumes Two things that made the integration gate untrustworthy. The retry budget was too small for expected contention. TestPostgreSQLConcurrentIdenticalResultSubmission fires five identical concurrent submissions and requires all five to succeed; it failed 4 runs in 20. The error was retryable and retries did fire -- three attempts simply was not enough. Contention here is normal rather than exceptional: several game servers can submit results, and several matchers can claim candidates, against the same rows at once. Raised to five attempts, which is 0 failures in 40 runs. Also jittered the backoff, but measured rather than assumed: my first theory was a thundering herd, since the delay was exactly RetryBackoff*(attempt+1) and every loser of a race woke at the same instant. Isolating the two changes showed jitter alone moved 4/20 to 3/20, while the budget alone reached 0/20. The budget was the real constraint. Jitter is kept because it costs nothing and its benefit grows with the number of contending writers -- production is not capped at five -- but the comment now says plainly that it is the smaller half, so nobody inherits my wrong explanation. Second, the integration scripts leaked one throwaway database volume per run. --rm does reclaim anonymous volumes on a normal exit, but these scripts force-remove the container from a trap, and `docker rm -f` without -v keeps the volume. Sixty-four accumulated during this branch until PostgreSQL stopped starting, surfacing only as the scripts' own readiness timeout rather than as a disk error -- which is what the "Docker storage exhausted locally" notes were really describing. Measured at one volume per run before, zero after, across all five scripts. --- multiplayer-next.md | 2 +- scripts/run_allocator_integration.sh | 9 +++++- scripts/run_postgres_integration.sh | 9 +++++- scripts/run_redis_integration.sh | 9 +++++- scripts/run_result_fanout_integration.sh | 9 +++++- scripts/run_supervisor_integration.sh | 5 +++- server/store/serializable.go | 36 ++++++++++++++++++++++-- 7 files changed, 70 insertions(+), 9 deletions(-) diff --git a/multiplayer-next.md b/multiplayer-next.md index 6b6358c8..37baf3f2 100644 --- a/multiplayer-next.md +++ b/multiplayer-next.md @@ -383,7 +383,7 @@ single-player one. 49. **Advancing a consumer cursor past data that has not arrived is not a lossy shortcut — it is permanent, because the producer-side filter then rejects the very data being waited for.** **Only give up on an expected item once strictly newer data proves it lost**; "it hasn't arrived yet" and "it will never arrive" are different states and must not share a code path. 50. **A metric that stops sampling during a failure will report that failure as healthy.** Every rate-shaped assertion needs a companion assertion on the **denominator**, or an outage silently becomes an absence of evidence and then evidence of absence. 51. **An architectural blocker inherited from a previous session is a claim to verify, not a premise to build on.** Reconstruct the failing invariant from the code and reproduce it against a control before accepting a scope estimate attached to it — especially when the recommendation arrives without the cheaper alternative recorded as tested. -52. **`docker run --rm` reclaims the container, not its anonymous volumes.** Every run of `scripts/run_*_integration.sh` leaves a throwaway PostgreSQL/Redis data volume behind. They accumulate invisibly — 64 of them, ~4 GB, after one working session — until the Docker VM disk fills and the next container silently fails to start, surfacing only as the script's own `PostgreSQL did not become ready` timeout rather than as a disk error. This is the actual cause behind the "Docker storage exhausted locally" notes elsewhere in this document. `docker system df` shows it (`Local Volumes … 100% reclaimable`); `docker volume prune` clears it. Worth checking first whenever an integration script starts timing out on a machine where it previously worked. +52. **`docker run --rm` reclaims the container, not its anonymous volumes.** Every run of `scripts/run_*_integration.sh` leaves a throwaway PostgreSQL/Redis data volume behind. They accumulate invisibly — 64 of them, ~4 GB, after one working session — until the Docker VM disk fills and the next container silently fails to start, surfacing only as the script's own `PostgreSQL did not become ready` timeout rather than as a disk error. This is the actual cause behind the "Docker storage exhausted locally" notes elsewhere in this document. `docker system df` shows it (`Local Volumes … 100% reclaimable`); `docker volume prune` clears it. Worth checking first whenever an integration script starts timing out on a machine where it previously worked. **Fixed** by adding `-v` to each script's cleanup trap: `--rm` does reclaim anonymous volumes on a normal exit, but these scripts force-remove the container from a trap instead, and `docker rm -f` without `-v` keeps the volume. Verified as one leaked volume per run before, zero after. --- diff --git a/scripts/run_allocator_integration.sh b/scripts/run_allocator_integration.sh index 48371cfc..8c638633 100755 --- a/scripts/run_allocator_integration.sh +++ b/scripts/run_allocator_integration.sh @@ -8,7 +8,14 @@ user="cosmic_clash_test" password="cosmic_clash_test" cleanup() { - docker rm -f "$container_name" >/dev/null 2>&1 || true + # -v matters: the container runs with --rm, which would reclaim its + # anonymous volume on a normal exit, but this trap force-removes it instead + # and `docker rm -f` alone leaves the volume behind. Each run then leaks one + # throwaway database volume, which accumulates silently until the Docker VM + # disk fills and the next container fails to start -- surfacing only as this + # script's own readiness timeout, never as a disk error. See + # multiplayer-next.md §9 gotcha 52. + docker rm -f -v "$container_name" >/dev/null 2>&1 || true } trap cleanup EXIT diff --git a/scripts/run_postgres_integration.sh b/scripts/run_postgres_integration.sh index 66e39bf7..9c1f80e6 100755 --- a/scripts/run_postgres_integration.sh +++ b/scripts/run_postgres_integration.sh @@ -8,7 +8,14 @@ user="cosmic_clash_test" password="cosmic_clash_test" cleanup() { - docker rm -f "$container_name" >/dev/null 2>&1 || true + # -v matters: the container runs with --rm, which would reclaim its + # anonymous volume on a normal exit, but this trap force-removes it instead + # and `docker rm -f` alone leaves the volume behind. Each run then leaks one + # throwaway database volume, which accumulates silently until the Docker VM + # disk fills and the next container fails to start -- surfacing only as this + # script's own readiness timeout, never as a disk error. See + # multiplayer-next.md §9 gotcha 52. + docker rm -f -v "$container_name" >/dev/null 2>&1 || true } trap cleanup EXIT diff --git a/scripts/run_redis_integration.sh b/scripts/run_redis_integration.sh index 950e18e0..4faec1d0 100755 --- a/scripts/run_redis_integration.sh +++ b/scripts/run_redis_integration.sh @@ -5,7 +5,14 @@ repo_root="$(cd "$(dirname "$0")/.." && pwd)" container_name="cosmic-clash-redis-integration" cleanup() { - docker rm -f "$container_name" >/dev/null 2>&1 || true + # -v matters: the container runs with --rm, which would reclaim its + # anonymous volume on a normal exit, but this trap force-removes it instead + # and `docker rm -f` alone leaves the volume behind. Each run then leaks one + # throwaway database volume, which accumulates silently until the Docker VM + # disk fills and the next container fails to start -- surfacing only as this + # script's own readiness timeout, never as a disk error. See + # multiplayer-next.md §9 gotcha 52. + docker rm -f -v "$container_name" >/dev/null 2>&1 || true } trap cleanup EXIT diff --git a/scripts/run_result_fanout_integration.sh b/scripts/run_result_fanout_integration.sh index fc0478ff..d5f65e4a 100755 --- a/scripts/run_result_fanout_integration.sh +++ b/scripts/run_result_fanout_integration.sh @@ -8,7 +8,14 @@ user="cosmic_clash_test" password="cosmic_clash_test" cleanup() { - docker rm -f "$container_name" >/dev/null 2>&1 || true + # -v matters: the container runs with --rm, which would reclaim its + # anonymous volume on a normal exit, but this trap force-removes it instead + # and `docker rm -f` alone leaves the volume behind. Each run then leaks one + # throwaway database volume, which accumulates silently until the Docker VM + # disk fills and the next container fails to start -- surfacing only as this + # script's own readiness timeout, never as a disk error. See + # multiplayer-next.md §9 gotcha 52. + docker rm -f -v "$container_name" >/dev/null 2>&1 || true } trap cleanup EXIT diff --git a/scripts/run_supervisor_integration.sh b/scripts/run_supervisor_integration.sh index cd3c7b3a..e304adfd 100755 --- a/scripts/run_supervisor_integration.sh +++ b/scripts/run_supervisor_integration.sh @@ -7,7 +7,10 @@ database="cosmic_clash_test" user="cosmic_clash_test" password="cosmic_clash_test" -cleanup() { docker rm -f "$container_name" >/dev/null 2>&1 || true; } +# -v matters: --rm would reclaim the anonymous volume on a normal exit, but +# this trap force-removes the container instead and `docker rm -f` alone +# leaves the volume behind. See multiplayer-next.md §9 gotcha 52. +cleanup() { docker rm -f -v "$container_name" >/dev/null 2>&1 || true; } trap cleanup EXIT cleanup docker run --rm -d --name "$container_name" \ diff --git a/server/store/serializable.go b/server/store/serializable.go index 99d1a79c..4652d577 100644 --- a/server/store/serializable.go +++ b/server/store/serializable.go @@ -6,13 +6,22 @@ import ( "context" "database/sql" "fmt" + "math/rand/v2" "strings" "time" ) const ( - DefaultSerializableAttempts = 3 - RetryBackoff = 10 * time.Millisecond + // DefaultSerializableAttempts is the retry budget for one logical + // mutation. Contention here is expected rather than exceptional: several + // game servers can submit results, and several matchers can claim + // candidates, against the same rows at once. Three attempts was too tight + // for even five-way contention on identical rows. + DefaultSerializableAttempts = 5 + // RetryBackoff is the base delay. The actual wait is jittered -- see + // retryDelay -- because an unjittered backoff makes every contending + // transaction wake at the same instants and collide again. + RetryBackoff = 10 * time.Millisecond ) // RunSerializable executes one logical mutation with PostgreSQL SERIALIZABLE @@ -44,12 +53,33 @@ func RunSerializable(ctx context.Context, db *sql.DB, attempts int, fn func(cont select { case <-ctx.Done(): return ctx.Err() - case <-time.After(RetryBackoff * time.Duration(attempt+1)): + case <-time.After(retryDelay(attempt)): } } return last } +// retryDelay applies full jitter to a linearly growing ceiling, so contending +// transactions do not all wake at the same instant and collide again. +// +// Measured honestly: jitter is the smaller half of this fix. Against the +// five-way contention in TestPostgreSQLConcurrentIdenticalResultSubmission, +// jitter alone moved the failure rate from 4/20 to 3/20, while raising the +// attempt budget from 3 to 5 took it to 0/20 on its own. The budget was the +// real constraint. Jitter is kept because it costs nothing and its benefit +// grows with the number of contending writers, which in production is not +// capped at five -- but it should not be mistaken for the reason this got +// better. +func retryDelay(attempt int) time.Duration { + ceiling := RetryBackoff * time.Duration(attempt+1) + if ceiling <= 0 { + return 0 + } + // math/rand/v2's top-level functions are safe for concurrent use, which + // matters because every contending goroutine calls this. + return time.Duration(rand.Int64N(int64(ceiling))) +} + func retryable(err error) bool { if err == nil { return false