From da33b81939bb2ef1882b3d297d0d0a8a051dce00 Mon Sep 17 00:00:00 2001 From: zzstoatzz Date: Fri, 17 Apr 2026 00:08:49 -0500 Subject: [PATCH] notes? --- docs/operator-note-2026-04-09-threaded.md | 67 +++ docs/zlay-canary-plan-2026-04-09.md | 401 ++++++++++++++++++ docs/zlay-situation-2026-04-09-reviewer.md | 451 +++++++++++++++++++++ 3 files changed, 919 insertions(+) create mode 100644 docs/operator-note-2026-04-09-threaded.md create mode 100644 docs/zlay-canary-plan-2026-04-09.md create mode 100644 docs/zlay-situation-2026-04-09-reviewer.md diff --git a/docs/operator-note-2026-04-09-threaded.md b/docs/operator-note-2026-04-09-threaded.md new file mode 100644 index 0000000..9a03788 --- /dev/null +++ b/docs/operator-note-2026-04-09-threaded.md @@ -0,0 +1,67 @@ +# operator note: switch to Io.Threaded — 2026-04-09 + +## what changed + +`e6cdf84` switches zlay from `Io.Evented` (io_uring fibers, ~35 threads) +to `Io.Threaded` (OS thread per PDS subscriber, ~2,800 threads). this is +the same execution model as the 0.15 baseline that ran at 99%+ coverage. + +one-line change in `src/main.zig:61`. everything else is the same. + +## why + +the Evented backend was the root of every major issue since the 0.16 +migration: 8 crash classes, a ReleaseSafe GPF, and a persistent 10-15% +coverage gap that nobody could explain. the zig team marks Evented as +experimental. rather than continuing to debug an unstable runtime, we're +reverting to the proven thread-per-PDS model and keeping all other 0.16 +improvements. + +## how to deploy + +**build with ReleaseSafe** (not ReleaseFast). the fiber GPF that forced +ReleaseFast was an Evented-only bug. ReleaseSafe gives better error +messages and safety checks. + +``` +just zlay publish-remote ReleaseSafe +``` + +this is a change from previous deploys which used ReleaseFast. + +## what to expect + +- thread count: ~2,800-2,900 (same as 0.15 baseline, up from ~35-47) +- VmSize: ~22-25 GiB (same as 0.15 baseline) +- RSS: should be comparable to 0.15 (~1.4 GiB) +- coverage: targeting 99%+ (matching 0.15 and the b91382b rollback) +- the cross-Io crash class is eliminated entirely + +## what to watch + +1. external health: `curl https://zlay.waow.tech/_health` — should respond + in < 1s immediately, no 10-minute degradation cycle +2. delivery: 15s websocket consumer should show ~395 fps once host table + ramps (~20 min) +3. host_authority reject rate: should be ~1-2% steady state (same as + b91382b), not the 88-99% seen on Evented builds +4. thread count: `ps -eLf | grep zlay | wc -l` — expect ~2,800-2,900 +5. no restarts through a full 4h reconnect-cron cycle +6. ReleaseSafe specific: if any safety check fires, you'll get a clear + error message + stack trace instead of silent corruption + +## rollback + +if anything goes wrong, roll back to the known-good b91382b image: + +``` +kubectl --kubeconfig=zlay/kubeconfig.yaml -n zlay set image deployment/zlay main=atcr.io/zzstoatzz.io/zlay:ReleaseFast-zat21-b91382b +``` + +## what this is NOT + +this is not a feature change, a dependency bump, or a new fix for the +april 8-9 outage. it's a backend selection change that eliminates the +runtime layer that was causing all the problems. the UAF fix (1eec324), +dep bumps, gcLoop fix, and host_authority work are all still in the tree +and unaffected. diff --git a/docs/zlay-canary-plan-2026-04-09.md b/docs/zlay-canary-plan-2026-04-09.md new file mode 100644 index 0000000..e677cf1 --- /dev/null +++ b/docs/zlay-canary-plan-2026-04-09.md @@ -0,0 +1,401 @@ +# zlay canary plan — 2026-04-09 + +**Goal**: isolate which commit in the `b91382b..31825b2` window regressed +external HTTP responsiveness + downstream delivery. Current production is +`ReleaseFast-zat21-b91382b` (known good — 99.4% delivery, responsive HTTP). +We ship three canaries, each adding exactly one behavioral commit on top +of `b91382b`, in the order the reviewer recommended. Each canary answers +one diagnostic question. No canary attempts to "fix everything." + +**Reading guide for operator**: each canary section below is self-contained. +You should only need the "deploy" / "watch for" / "on failure" / "rollback" +blocks. The narrative between them is for the engineer if something +weird happens. + +## a note on the `zat21-` prefix in the production image tag + +Production is running `atcr.io/zzstoatzz.io/zlay:ReleaseFast-zat21-b91382b`. +The `zat21-` prefix looks like it means "built with zat v0.3.0-alpha.21", +but that's a misleading label. The committed `b91382b` pins zat +**v0.3.0-alpha.17**, and no commit in this repo (across any branch or tag) +ever pinned alpha.21. The image is built from committed b91382b, so its +actual zat is alpha.17. The only zat bump after b91382b is `168d9f1`, +which goes directly to alpha.22. + +Consequence: **canary 1 (zat alpha.17) matches production exactly.** No +drift, no hidden variable. Canary 2 is where zat actually changes +(alpha.17 → alpha.22, via 168d9f1). + +| canary | zat version | +|---|---| +| production `ReleaseFast-zat21-b91382b` | alpha.17 | +| canary 1 | alpha.17 (same) | +| canary 2 | alpha.22 | +| canary 3 | alpha.22 (same as canary 2) | + +## branches ready to build + +All three branches exist locally and build clean against +`-Dtarget=x86_64-linux-gnu -Doptimize=ReleaseFast`. `zig build test` +passes on each. + +``` +canary/1-uaf-only d71379c b91382b + 1eec324 +canary/2-uaf-plus-deps fa7b5c4 canary/1 + 168d9f1 +canary/3-uaf-deps-gc e9802df canary/2 + 3dc21b9 +``` + +None are pushed to any remote yet. Tell me if you want them pushed as +`origin/canary/N-...` before the operator builds. + +Build command per canary (run on Hetzner server per the normal flow, +but validated locally first): + +``` +just zlay publish-remote ReleaseFast +# — or whatever flag the publish script takes to target a specific SHA +``` + +Image tag expectation: +- canary 1 → `atcr.io/zzstoatzz.io/zlay:ReleaseFast-d71379c` +- canary 2 → `atcr.io/zzstoatzz.io/zlay:ReleaseFast-fa7b5c4` +- canary 3 → `atcr.io/zzstoatzz.io/zlay:ReleaseFast-e9802df` + +(The exact naming depends on `just zlay publish-remote`. Adjust if needed.) + +--- + +## Canary 1 — `b91382b + 1eec324` (UAF fix only) + +### what's in it + +Exactly one cherry-pick on top of b91382b: `1eec324 fix UAF: dupe +FrameWork.hostname per submit instead of borrowing`. Touches +`src/frame_worker.zig` (+2 -1) and `src/subscriber.zig` (+10 -1). No +dependency bumps. No gcLoop. No other changes. + +### diagnostic question + +**Does adding the FrameWork UAF fix alone reintroduce the HTTP / +delivery failure?** + +### hoped-for outcome + +Canary 1 runs indistinguishably from current production: +- external `/health` responsive in < 1 s +- 15 s websocket consumer receives ~395 fps (99%+ of ingest) +- `frames_broadcast_total` advances with an attached consumer +- zero readiness flaps through 60 min +- zero container restarts through a 4-hour reconnect-cron cycle +- the corrupted-hostname log pattern from the 2026-04-07 incident is + ABSENT under reconnect-storm load + +If canary 1 is clean, the UAF fix is not the regressor and we roll +forward to canary 2. Canary 1 stays as the new production baseline +because it strictly improves on b91382b by closing the UAF. + +### what to check + +Run the operator's measurement recipe from +`../relay/docs/zlay-handoff-2026-04-09-rollback.md#reproducing-the-measurements`. +Specifically: + +1. **External health** (every 5 min for first hour): + ``` + curl --connect-timeout 3 -m 5 https://zlay.waow.tech/_health + curl --connect-timeout 3 -m 5 https://zlay.waow.tech/xrpc/_health + ``` + expected: `200 in < 1 s` every time. + +2. **15 s websocket consumer** (every 15 min): + ``` + uvx --from 'websockets==13.*' python -c ' + import asyncio, websockets, time + async def main(): + async with websockets.connect("wss://zlay.waow.tech/xrpc/com.atproto.sync.subscribeRepos", max_size=None) as ws: + n = 0; t = time.time() + while time.time() - t < 15: + await ws.recv(); n += 1 + print(f"{n} frames in 15s = {n/15:.1f} fps") + asyncio.run(main()) + ' + ``` + expected: `~5,000+ frames, ~330+ fps` by 20 min uptime, climbing + toward 395 fps as the host table ramps. + +3. **15 s metrics delta** (with a consumer attached, port-forward to :3001): + ``` + # t0: snapshot frames_received_total and frames_broadcast_total + # wait 15 s + # t1: snapshot again + # compute delta. ratio should be >= 99%. + ``` + +4. **Readiness state**: + ``` + kubectl --kubeconfig=zlay/kubeconfig.yaml -n zlay get pod -l app.kubernetes.io/instance=zlay -o custom-columns=NAME:.metadata.name,READY:.status.conditions[?(@.type==\"Ready\")].status,RESTARTS:.status.containerStatuses[*].restartCount + ``` + expected: `True`, `0` restarts. + +5. **Reconnect-cron survival**: the cron fires every 4h at 00/04/08/... + UTC. Canary 1 should survive at least one fire cycle without + restart or corrupted-hostname log lines. That's the UAF test. + +### success criteria (all must hold for 60 min from deploy) + +- external `/health` responds `200` in < 1 s on every check +- 15 s consumer snapshot shows delivery at or above 90% of + `frames_received_total` delta +- `kubectl get pod` shows `Ready=True` throughout +- `restartCount=0` +- no corrupted-hostname patterns in `kubectl logs` (no DIDs in + hostname-shaped log fields, no stack-pointer-shaped bytes) + +### failure signals + +ANY of these means canary 1 is bad, roll back: + +- external `/health` hangs or returns 503 on any probe +- 15 s consumer delivers < 100 fps or disconnects +- `Ready=False` at any point +- `restartCount > 0` +- metrics port-forward hangs where a single probe + 15 s wait + + second probe doesn't complete + +### on failure: capture evidence IMMEDIATELY then roll back + +Before rolling back, capture (needs to happen BEFORE the pod is +recycled — evidence is gone after rollback): + +``` +# 1. socket state on the HTTP ports (are accepts queueing up?) +kubectl --kubeconfig=zlay/kubeconfig.yaml -n zlay exec $POD -- sh -c 'ss -ltn 2>&1 | grep -E "(3000|3001)"' > /tmp/zlay-canary1-ss.txt 2>&1 + +# 2. thread state (anyone stuck in R/D?) +kubectl --kubeconfig=zlay/kubeconfig.yaml -n zlay exec $POD -- sh -c 'ps -eLo pid,tid,stat,wchan,comm 2>&1' > /tmp/zlay-canary1-ps.txt 2>&1 + +# 3. final metrics snapshot (might hang, that's also a data point) +timeout 15 kubectl --kubeconfig=zlay/kubeconfig.yaml -n zlay exec $POD -- sh -c 'wget -qO- http://localhost:3001/metrics' > /tmp/zlay-canary1-metrics.txt 2>&1 + +# 4. recent logs +kubectl --kubeconfig=zlay/kubeconfig.yaml -n zlay logs --tail=2000 $POD > /tmp/zlay-canary1-logs.txt 2>&1 +``` + +Then roll back: + +``` +kubectl --kubeconfig=zlay/kubeconfig.yaml -n zlay set image deployment/zlay main=atcr.io/zzstoatzz.io/zlay:ReleaseFast-zat21-b91382b +kubectl --kubeconfig=zlay/kubeconfig.yaml -n zlay rollout status deployment/zlay --timeout=300s +``` + +Interpretation if canary 1 fails: +- 1eec324's frame-queueing change (heap-duping hostname, freeing in + `processFrame`) is implicated directly. The engineer's next move + would be to study the allocation lifetime carefully. +- Alternatively: zat 17 has a subtle issue that zat 21 (production) + fixes. Easy to distinguish — build canary 1 with zat 21 manually + pinned (same as production) and retest. + +--- + +## Canary 2 — `b91382b + 1eec324 + 168d9f1` (add dep bump) + +**Only run this after canary 1 is clean for ≥ 60 min AND has survived at +least one 4h reconnect-cron fire.** + +### what's in it + +Canary 1 plus `168d9f1 bump websocket.zig + zat`. Only change is +`build.zig.zon` (4 lines): zat v0.3.0-alpha.17 → v0.3.0-alpha.22 and +websocket.zig 9ac64da → 3c6794a. The functional change in 168d9f1 is +"fix requestCrawl POST hang in websocket.zig Handshake.parse" — but +the reviewer points out this commit changes runtime dependency behavior +more than any other in the window, which makes it a plausible regression +carrier for reasons other than its stated fix. + +### diagnostic question + +**Does bumping websocket.zig + zat (alpha.17 → alpha.22) on top of +canary 1 reintroduce the HTTP / delivery failure?** + +### hoped-for outcome + +Same clean run as canary 1, with one additional expected improvement: +the zlay-reconnect cronjob (fires at 00/04/08/... UTC) should now +correctly re-announce PDS hosts (that's what 168d9f1 specifically +fixes). The cron log from the runner side should show a successful +POST response where it previously hung. + +If canary 2 is clean, dep bump is not the regressor. Roll forward to +canary 3. Canary 2 becomes the new production baseline. + +### what to check + +Same 5 checks as canary 1. PLUS: + +6. **Reconnect cron success**: the next fire after canary 2 deploys + should complete normally — the requestCrawl POST hang fix is in + 168d9f1. If this cron was failing before with canary 1, it should + succeed now. If it was already succeeding on canary 1 (because + b91382b's websocket lib was handling this path through a different + code path), no change expected. + +### success criteria + +Same as canary 1: health, delivery, readiness, restarts, no corrupted +hostnames. Plus successful reconnect cron. + +### failure signals + +Same as canary 1. + +### on failure + +Capture (same 4 commands as canary 1, retitled `canary2`), then roll +back: + +``` +kubectl --kubeconfig=zlay/kubeconfig.yaml -n zlay set image deployment/zlay main=atcr.io/zzstoatzz.io/zlay:ReleaseFast-d71379c # canary 1 +kubectl --kubeconfig=zlay/kubeconfig.yaml -n zlay rollout status deployment/zlay --timeout=300s +``` + +Interpretation: the dep bump is implicated. Either websocket.zig +3c6794a's Handshake.parse behavior has a regression we haven't seen +yet, or zat alpha.22's transport layer does. Both are cheap to further +bisect: websocket.zig and zat are both small repos with narrow change +windows between 9ac64da→3c6794a and alpha.17→alpha.22. + +--- + +## Canary 3 — `b91382b + 1eec324 + 168d9f1 + 3dc21b9` (add gcLoop re-enable) + +**Only run this after canary 2 is clean for ≥ 60 min.** + +### what's in it + +Canary 2 plus `3dc21b9 fix gcLoop: silently exited after one tick`. +Touches only `src/main.zig` (+15 -9). The behavioral change: prior to +3dc21b9, `gcLoop` used `io.sleep` on pool_io from a plain std.Thread, +which failed on the second tick and silently exited via `catch return`. +So `gcLoop` actually ran ONE tick (+ malloc_trim) at ~10 min into each +pod's life, then was dead for the rest of the pod. 3dc21b9 replaced +`io.sleep` with `std.c.nanosleep` so gcLoop runs every 10 min for the +entire pod lifetime. + +The gcLoop stabilization I shipped in 4f3d1d4 (disable malloc_trim, +bump interval to 1 hour) is intentionally NOT included in canary 3. +We want to isolate the effect of 3dc21b9 first. If 3dc21b9 is the +regressor, the 4f3d1d4-style mitigation becomes the next canary. + +### diagnostic question + +**Does re-enabling gcLoop at its original 10-minute cadence (with +`malloc_trim(0)` intact) reintroduce the HTTP / delivery failure?** + +### hoped-for outcome + +Same clean run as canary 2 for the first 10 minutes, then NO +degradation at the 10-minute mark when `gcLoop` first fires with +`dp.gc()` and `malloc_trim(0)`. If the 10-min mark is clean, +continue watching to ~60 min (by which point gcLoop has fired 5×). + +If canary 3 is clean, 3dc21b9 is not the regressor and we've narrowed +the window further. Remaining suspects in the window are `fbdffbe` +(did_cache health-mark) and `31825b2` (subscriber prepareFrameWork +extraction + test). Both are lower-priority per the reviewer; we'd +run them as canary 4 and 5 or let them ride if canary 3 is fully +stable with all other changes layered. + +### what to check + +Same 5 checks as canary 1. PLUS special attention to the 10-minute mark: + +7. **10-minute gc fire**: canary 3's gcLoop fires at pod uptime ~10 + min. Run: + - external `/health` probe at 9:50, 10:00, 10:10, 10:30 + - websocket consumer at 10:00, 10:30 + - check `kubectl logs $POD | grep gc` for log evidence of the + gc body running and malloc_trim completing + - if any probe fails in the 10:00 ± 30s window, gcLoop is the + smoking gun + +### success criteria + +Same as canary 1. PLUS clean behavior across the 10-min mark (and +the 20, 30, 40, 50, 60 min marks — each a gcLoop fire). + +### failure signals + +Same as canary 1, with heightened attention at ~10-min intervals. + +### on failure + +Capture (same as above), then roll back: + +``` +kubectl --kubeconfig=zlay/kubeconfig.yaml -n zlay set image deployment/zlay main=atcr.io/zzstoatzz.io/zlay:ReleaseFast-fa7b5c4 # canary 2 +kubectl --kubeconfig=zlay/kubeconfig.yaml -n zlay rollout status deployment/zlay --timeout=300s +``` + +Interpretation: gcLoop is the regressor. This would partially +rehabilitate the gcLoop-stall hypothesis from +`docs/zlay-gcloop-stall-2026-04-09.md`, but only "partially" because +4f3d1d4 (which disabled malloc_trim and bumped gc to 1 hour) still +exhibited the HTTP hang at ~35 min uptime. So if canary 3 fails at +the 10-min mark, the next diagnostic step is: +- canary 3b = canary 3 with just `malloc_trim(0)` disabled (gc still + runs every 10 min). Isolates allocator stall from mutex-hold stall. +- canary 3c = canary 3b with gc interval bumped to 1 hour. Matches + the 4f3d1d4 state exactly. + +If canary 3c fails, we've exactly reproduced 4f3d1d4 from first +principles and learned that neither the allocator stall nor the +mutex-hold can be the sole cause — something else on top of 3dc21b9 +is also in play. That's a bisection lead, not a conclusion. + +--- + +## summary table + +| canary | base | + cherry-pick | zat ver | diagnostic question | rollback to | +|---|---|---|---|---|---| +| 1 | b91382b | `1eec324` | alpha.17 | Is the UAF fix alone enough to regress? | `ReleaseFast-zat21-b91382b` | +| 2 | canary 1 | `168d9f1` | **alpha.22** | Does the dep bump regress on top of 1? | canary 1 image | +| 3 | canary 2 | `3dc21b9` | alpha.22 | Does gcLoop re-enable regress on top of 2? | canary 2 image | + +## what's explicitly out of scope for these canaries + +- **No host_authority work** (`bbba92c` keep_alive=false, `795cc41` + slot recovery + observability). These add diagnostic noise and we + don't need them to test delivery/HTTP. Reviewer was explicit. +- **No broadcaster writeLoop fix.** Real bug, but not the cause of + the HTTP hang, and unrelated to what we're isolating. +- **No host_mismatch investigation in code.** Reviewer asked for a + DB audit first — check for duplicate hostnames in the `host` + table and stale `account.host_id` references before any + `getHostIdForHostname` patch. +- **No additional "fix bundles."** Every canary is exactly one + cherry-pick on top of the previous canary. + +## what the engineer needs from the operator + +1. **Confirmation of the zat version running in the current + `ReleaseFast-zat21-b91382b` image.** If you can inspect the + image or recall how you built it, knowing whether it's literally + alpha.21 vs alpha.17 vs alpha.22 matters for interpreting canary 1 + vs canary 2 results. +2. **Push the canary branches to origin?** All three branches exist + locally only. If your build pipeline pulls from remote, I need + to push them. Let me know and I will. +3. **Evidence from the 4f3d1d4 dying window, if any was captured.** + Specifically `ss -ltn` on ports 3000/3001 and `ps -eLo + pid,tid,stat,wchan,comm` during the active hang. If none was + captured, that's fine — we'll capture it on the first canary + failure instead. +4. **DB audit results (independent of the canary sequence)**: + ``` + SELECT hostname, count(*) FROM host GROUP BY hostname HAVING count(*) > 1; + SELECT count(*) FROM account WHERE host_id NOT IN (SELECT id FROM host); + ``` + If either is non-empty, that's data we need before touching any + host_authority code. diff --git a/docs/zlay-situation-2026-04-09-reviewer.md b/docs/zlay-situation-2026-04-09-reviewer.md new file mode 100644 index 0000000..7e94363 --- /dev/null +++ b/docs/zlay-situation-2026-04-09-reviewer.md @@ -0,0 +1,451 @@ +# zlay situation report for reviewer — 2026-04-09 evening + +This doc is a frank account of where zlay stands at end-of-day 2026-04-09 +after a long debug session. It supersedes, as primary-cause narratives, both +`zlay-broadcaster-starvation-2026-04-09.md` and +`zlay-gcloop-stall-2026-04-09.md` — those were hypotheses we shipped fixes +for, and both turned out to be wrong about root cause (they may still be +real secondary issues). + +Purpose: help us stop ship-and-guess. We want the reviewer to sanity-check +the failure model, call out observations we're over-fitting to, and help +the next deploy be the one that works. + +## update: rollback to b91382b succeeded — regression window confirmed + +After this doc was first drafted, the operator completed the rollback to +`ReleaseFast-zat21-b91382b` (the 2026-04-06 build). Full write-up in +`../relay/docs/zlay-handoff-2026-04-09-rollback.md`. The load-bearing +measurements: + +- external `https://zlay.waow.tech/_health` returns 200 in ~0.29 s +- a raw 15 s `subscribeRepos` websocket consumer receives **5,896 frames + at ~395 fps**, vs 6 frames in 170 s (0.035 fps) on `4f3d1d4` +- with an attached consumer: `frames_broadcast` advances at **99.4% of + `frames_received`** over a 15 s window (6801 / 6843) +- `host_authority` reject rate is **~1.3% steady state** (no workaround + in place) — the 99.54% catastrophic rejection that motivated the + `keep_alive=false` work is **not present** on b91382b + +Conclusion: **both bugs** (external HTTP unreachability + delivery +collapse, *and* the 99.5% host_authority reject rate) were introduced in +the commit window `b91382b..31825b2`. The five commits in that window: + +``` +3dc21b9 fix gcLoop: silently exited after one tick +fbdffbe mark DB success on did_cache hits +168d9f1 bump websocket.zig + zat: fix requestCrawl POST hang +1eec324 fix UAF: dupe FrameWork.hostname per submit instead of borrowing +31825b2 subscriber: extract prepareFrameWork + add UAF regression test +``` + +The operator's rollback doc flagged `1eec324` as the prime suspect on the +theory that it was the most invasive frame-path change. The reviewer has +pushed back on that framing: `1eec324` is a narrow UAF ownership fix and +`31825b2` is mostly test/extraction scaffolding; neither obviously +explains the outage by itself. The commits that most clearly change +runtime behavior are: + +1. `168d9f1` — bumps `websocket.zig` and `zat` (runtime dependencies) +2. `3dc21b9` — re-enables `gcLoop` (it had been silently dead after one + tick prior to this fix, so the gc body has effectively never run in + production on b91382b either) + +Any of the three (`1eec324`, `168d9f1`, `3dc21b9`) could plausibly be the +cause. The reviewer's recommended path is a controlled additive canary +sequence from `b91382b`, one commit at a time, so we isolate which one +introduces the regression — rather than another multi-change branch. +The operator plan for those canaries is in +`docs/zlay-canary-plan-2026-04-09.md`. The rest of this doc stands as +background for the reviewer on *what* we're isolating and *why* the +per-commit attribution matters. + +**Current production state**: `ReleaseFast-zat21-b91382b`, 1/1 Running, +delivering ~400 fps. Note: b91382b does NOT have the FrameWork.hostname +UAF fix (`1eec324` is 04-07), so a reconnect storm could trip the UAF +and restart the pod. The operator is accepting that risk to keep +evaluators served. + +## high-level headline + +**Every pod we've shipped after 31825b2 (2026-04-07) has exhibited a symptom +where zlay's external HTTP surface — `/health`, `describeServer`, +`/_readyz`, `/metrics` on port 3000 / 3001 — stops responding past a +threshold of a few minutes to half an hour of uptime. Internal metrics +continue to be collected by the process (frames_in climbs, workers count is +stable, CPU usage is low), but external consumers cannot complete a +handshake, prometheus scrapes time out at 10s, and relay-eval reports 0% +coverage for zlay while indigo shows 99%+.** + +We have been wrong three times in a row about what causes this: +1. "zig 0.16 `std.http.Client` stale keep-alive handling" (falsified by + engineer's standalone repro). +2. "broadcaster writeLoop scheduler starvation, fix by moving to pool_io" + (falsified by recognizing the cross-Io crash class documented in 6674812). +3. "gcLoop + malloc_trim every 10 min" (falsified by the 4f3d1d4 deploy + today — symptom returned at ~35 min uptime despite gc bumped to 1 hour + and `malloc_trim` fully removed). + +We need help getting to a correct fourth hypothesis rather than shipping a +fourth wrong one. + +## what we know the symptom looks like from the outside + +- External curl to `https://zlay.waow.tech/health` and + `com.atproto.sync.describeServer` hangs through a 3 s timeout, or returns + 503 from the ingress. +- prometheus `/metrics` scrapes fail with `context deadline exceeded` at + the 10 s scrape timeout. this is continuous, not intermittent, once the + symptom starts. +- internal port-forwarded `/metrics` hit can succeed for a single probe + then hang >10 s on the next one 15 s later — i.e. the HTTP handler isn't + dead, it's responding on a fraction of probes and timing out on the rest. +- `/_healthz` comes back in ~11 s in the same window. `/_readyz` in ~17 s + (above the relaxed 15 s probe timeout — pod only survives because + kubelet's 20-failure threshold happens to hit faster windows sometimes). +- k8s eventually marks the pod `Ready=False` with + `ContainersNotReady`. On 4f3d1d4 that happened at 20:59:34, ~35 min after + pod start (vs ~10-14 min on the unmodified 795cc41 and bbba92c pods). +- service `endpoints/zlay` has no endpoints because Ready=False kicked the + pod out of the service. ingress returns 503. +- pod process itself: ~0.26 CPU cores of usage, all ~47 threads in + S-state (sleeping). nothing is hot-spinning. load average on the node is + high (67/8) but **zlay is not the one consuming CPU**. + +## what we know the symptom looks like from the inside + +Representative snapshot from the live 4f3d1d4 pod at ~28m uptime just +before rollback: + +| metric | value | +|---|---:| +| `frames_received_total` | 742,988 | +| `frames_broadcast_total` | 478 (lifetime, barely moved) | +| `broadcast_no_consumers_total` | 37,956 | +| `consumers_active` | 0 | +| `workers_count` | 2,761 (spawn complete) | +| `host_authority_checks_total` | 17,236 | +| `host_authority_reject{branch="host_mismatch"}` | 15,257 (88%) | +| `host_resolver_in_use` | 0 (pool idle at the moment of probe) | + +Gap analysis: +- `frames_received = 742,988` vs `frames_broadcast + no_cons ≈ 38,434`. + That's ~5% of received frames reaching `broadcast()`. The rest is either + still in-flight in the frame_worker pool, dropped on the validation + branches (host_authority, sig, chain, etc), or lost to something we're + not tracking. We did not capture the full validation counter delta in + the incident — recovering that is one of the first things we need. +- `broadcast_no_consumers = 37,956` vs `frames_broadcast = 478`: ~99% + of the frames that did reach `broadcast()` hit the "zero consumers" fast + path (broadcaster.zig:611). Lifetime `frames_broadcast_total = 478` + means ~all of a consumer's ever-delivered frames were from a brief + window long ago — consistent with "consumers couldn't attach for most + of the pod's life" rather than "consumers attached but were kicked." +- `host_authority_reject{host_mismatch} = 88%` is a second independent + bad signal on this pod (see "additional observation" below). + +## what commits are in play + +Between the last reliably-observable pod (`31825b2`, 2026-04-07) and now: + +| commit | date | what | risk flagged | +|---|---|---|---| +| `3dc21b9` | 04-06 | fix gcLoop silent-exit after one tick | gc actually ran again after this; masked previously | +| `fbdffbe` | 04-06 | mark DB success on did_cache hits | low | +| `168d9f1` | 04-06 | bump websocket.zig + zat (requestCrawl POST hang fix) | low but touches websocket lib | +| `ee4e368` | 04-08 | buffer 8192→65536 + per-branch counters | low | +| `bbba92c` | 04-08 | **`keep_alive=false` on host_authority pool** | **high — workaround, not root-caused** | +| `795cc41` | 04-09 | host_authority slot recovery + pool metrics + preload account count | medium — changes cold-start path | +| `4f3d1d4` | 04-09 | disable malloc_trim, bump gc to 1h, timing log | low, but didn't fix the issue | + +The single most significant behavioral change in that set is `bbba92c`'s +`keep_alive=false`. Every `is_new`/`host_changed` event now does a fresh +DNS + TCP + TLS + HTTPS round-trip to plc.directory (~350-900 ms/call), +and the resolver pool is only 4 slots acquired by 16 frame_worker threads +via atomic spinlock. This is a known aggravating factor for cold-start +load, but ops-changelog claims it was also present on 795cc41 without +persistent HTTP death — which weakens the "keep_alive=false is the whole +story" claim. + +## what we know is NOT the cause + +1. **scheduler contention on writeLoop.** I wrote this hypothesis up + (`docs/zlay-broadcaster-starvation-2026-04-09.md`), proposed moving + writeLoop to `pool_io`. Zlay engineer correctly pointed out this + re-enters the `Thread.current() NULL deref on plain threads calling + Evented Io.Mutex` crash class fixed in `6674812`. **Do not do this.** + See the cross-Io rule in NOTES/stdlib-patches.md. +2. **gcLoop mutex hold + malloc_trim.** I wrote this hypothesis up + (`docs/zlay-gcloop-stall-2026-04-09.md`), shipped 4f3d1d4 with gc + interval 10min → 1h and malloc_trim removed. **Pod still flapped**, + this time at ~35 min uptime instead of ~10 min. So those changes + delayed the symptom but did not prevent it. Longer uptime might + mean we moved some pressure off the critical path, or it might just + be process-state timing noise — we did not collect enough data to + distinguish. +3. **broadcaster writeLoop `io.sleep(100ms)` polling** (broadcaster.zig: + 447-453). This is a real bug — `cond.signal` on line 413 is a no-op + and per-consumer drain is capped at 10 frames/sec in the best case. + But it is NOT the cause of the HTTP server being unreachable. It + affects throughput _to attached consumers_, and the problem we have + is that consumers cannot attach at all. + +## additional observation: host_mismatch burst + +On both 795cc41 and 4f3d1d4 cold-starts, we see a large burst of +`host_authority_reject{branch="host_mismatch"}`: 15k-17k rejects in the +first ~15 min, then the rate drops to ~0/sec. This is qualitatively +different from the 2026-04-08 `resolve`-branch 99% reject bug. It means: +the DID resolver succeeded, returned a valid DID doc, and +`pds_host_id != incoming_host_id` at the comparison step +(`validator.zig checkPdsHost`). + +Plausible causes not yet investigated: +- Stale `account.host_id` values persisted from a previous pod + triggering `host_changed=true` on events where the current DID doc + still resolves to the current subscriber's hostname. +- Duplicate rows in the `host` table with the same hostname and + different ids (`getHostIdForHostname` has no ORDER BY — lookup is + non-deterministic). +- Something in how 795cc41's `preload_account_count` change interacts + with host_id assignment at spawn time. + +None of these candidates are new in 4f3d1d4. The burst exists independent +of the HTTP-hang symptom, but it's the same window, so we can't say for +sure whether it's a contributor or an unrelated mess. + +**We have not captured sampled warn logs for any of these host_mismatch +rejects.** The log buffer has rotated out by the time we look. Any +isolation experiment here needs to pull logs _during_ the burst, not +after. + +## rollback completed — see "update" at top of doc + +Rollback is done. b91382b is responsive, delivery is healthy, host_authority +reject rate is ~1.3% not 99.54%. See the "update" section at the top of this +doc for the full measurements. The diagnostic path going forward is the +canary sequence from b91382b, documented in `zlay-canary-plan-2026-04-09.md`. + +## things that are REAL bugs regardless of which hypothesis wins + +Independent of the HTTP-hang root cause, these are defects we want to +fix eventually. Enumerated so the reviewer can weigh in on priority and +shape: + +1. **`Consumer.writeLoop` polling** (broadcaster.zig:439-477). Replace + the `io.sleep(100ms)` with proper `cond.wait(mutex, io)`. Schedule + pings via separate timer fiber or opportunistic-on-wake. Do NOT move + writeLoop off Evented. Cap on per-consumer drain is otherwise + 10 frames/sec even in perfect conditions. +2. **`DiskPersist.gc()` holds the persist hot-path mutex for its + entire body** (event_log.zig:977-1033). The mutex is there to + protect `evtbuf`/`outbuf`/`cur_seq`/`current_file_path`/`flushLocked`. + Nothing gc actually does (DB iteration, per-file unlink) needs that + lock. Proposed fix: discover candidate files without the lock, + re-acquire briefly per-file only to re-check `current_file_path` + before unlinking. Same treatment for `gcBySize()` and + `takeDownUser()`. +3. **Missing pool slot recovery** (validator.zig resolver pool). The + slot-recovery fix in 795cc41 exists but is dormant under + `keep_alive=false`. We haven't actually proven the recovery path + works because it hasn't been exercised in production. The planned + canary ("1 of 4 slots `keep_alive=true`") was never run. +4. **`zig build test` is not sufficient CI.** Lazy analysis skips + functions not referenced from tests. Engineer added a rule: run + `zig build` (exe) in addition to `zig build test` for + validator/subscriber/frame_worker changes. The `584571a` build + break is the precedent. +5. **Two different error types get swallowed in zat's transport path** + (zat/src/internal/xrpc/transport.zig, did_resolver.zig). Partially + fixed by zat 0.3.0-alpha.23 which propagates the underlying + `std.http.Client.fetch` error. Upgrade is shipped in 795cc41 but we + never saw a failure after it shipped because `keep_alive=false` was + still in place. +6. **`getHostIdForHostname` has no `ORDER BY`** — if there are ever + duplicate rows for the same hostname, lookup is non-deterministic. + We ran the reviewer's DB audit on 2026-04-09: 0 duplicate hostnames + in production, so this is not currently a live bug — but the query + should still be deterministic as a hardening matter. +7. **Dual host_authority call sites with asymmetric metrics.** + `resolveHostAuthority` is invoked from both `frame_worker.zig:107` + and `subscriber.zig:555`. Only the frame_worker path emits the + `relay_host_authority_trigger{reason=...}` and + `relay_host_authority_checks_total` counters; both paths increment + `relay_validation_failed{reason="host_authority"}` on reject. This + makes the ratio `trigger:reject` structurally misleading — trigger + is a lower bound on true authority-check count, while rejects + include both paths. Discovered during the 2026-04-09 canary 1 + investigation when we tried to correlate the `host_id=0` sentinel + finding against the reject counter. Long-term fix is one of: + (a) consolidate authority checking to a single path, or + (b) have both paths emit the same counters. Not a blocker for any + current canary — flagged so it doesn't get forgotten. +8. **`account.host_id = 0` is a sentinel ("host not set yet") by + design**, documented in `event_log.zig:513`. As of the 2026-04-09 + DB audit, 239,422 out of 5,817,756 accounts (4.11%) are still at + the sentinel. Reviewer's semantic correction (2026-04-09): orphan + accounts produce `is_new=true` in `uidForDidFromHost`, which + triggers a host_authority CHECK — not automatically a reject. The + reject only happens if `resolveHostAuthority` returns `.reject`, + which depends on the DID doc's PDS vs the incoming host. So the + sentinel explains an `is_new` burst during cold-start ramp but + does NOT by itself explain the `host_mismatch` reject burst we + observed on 795cc41/4f3d1d4. Real fix is probably: `is_new` + accept-and-update path should not go through the full + host_authority resolution pipeline (too slow for first-seen + events), but that's an optimization, not an outage fix. +9. **Relaxed k8s probes are a band-aid over "HTTP fibers can get + stuck for 10+ s under load."** With probes at + `initialDelay=300s, timeout=15s, failureThreshold=20`, the pod + effectively has ~5 minutes to get its act together at startup and + can be in a degraded state for up to 300 s at runtime before + kubelet notices. If we ever genuinely hang at startup, we now get + no feedback for 5 minutes. These should be tightened once the + underlying cause is fixed. + +## what I'd want the reviewer to help us with + +### 1. the core question — why external HTTP stops responding + +The HTTP server fibers (`runWsServer`, `MetricsServer.run`) live on main +`Io.Evented` io alongside ~2,800 per-subscriber fibers, the broadcaster +loop fiber, and the slurper spawn fiber. On the 4f3d1d4 pod at the time +of death, the pod is using ~0.26 cores, nothing is spinning, all +threads are in S-state. Yet HTTP accepts aren't completing and probes +time out. + +Possible shapes of the failure we can't distinguish with the evidence we +have: + +a. **Accept-queue exhaustion**: listener fiber is running but the + kernel's SYN/accept backlog is full so new connections don't reach + the fiber. Check with `netstat -an | grep :3000` for SYN_RECV, + `ss -ltn` for Recv-Q on the listening socket. + +b. **Single Evented runtime thread wedged**: if Evented is a work-stealing + scheduler across ~47 threads, one stuck fiber on one thread should + not freeze the whole thing. If it's a single-loop-per-thread design + and accepts are pinned to one loop, a stuck loop could freeze + accept specifically. Which of these does zig 0.16 `Io.Evented` + actually implement? + +c. **malloc contention**: the pod runs with `MALLOC_ARENA_MAX=4`, and + 16 frame_worker threads (plus ~47 Evented runtime threads) are all + contending for 4 glibc arenas. Under sustained allocator pressure + (keep_alive=false resolves every allocating a TLS session), any + thread that calls malloc at the wrong time may block on arena + locks. The HTTP handler allocates for response bodies. Is this + plausible as a sustained-state cause rather than just a burst? + +d. **Some fiber consistently monopolizes a CPU slice and the HTTP + accept fiber doesn't get scheduled often enough**: spawnWorkers + finished at 96 s but maybe something else has replaced it. Possible + candidates: Consumer.writeLoop fibers with their 100 ms polling, + the broadcaster loop fiber under push-lock contention (persist_order + spinlock). + +We cannot distinguish these today. We have no fiber-level trace, no +evented scheduler diagnostics, no per-fiber wake-latency metric. **This +is the single biggest gap in our ability to debug this.** + +### 2. the falsifiable hypotheses we'd try next + +In priority order, these are experiments where a positive result would +strengthen one of (a)-(d) and a null result would rule it out. None of +these are "ship a fix" — they're all "get diagnostic signal": + +- **(a) accept-queue check**: on a live flapping pod, run + `ss -ltn | grep 3000`, `netstat -an | awk '$NF=="LISTEN"'`, and + `cat /proc/net/tcp` to look at socket state and queue depth. If + accept backlog is full, that's a scheduler-not-running-accept + problem. If it's empty, handshakes are reaching the fiber and + something inside the fiber is slow. + +- **(b) Evented runtime design**: read zig 0.16 `std.Io.Uring` / + `Io.Evented` source to confirm whether it's single-loop or work- + stealing. If single-loop, accept-pinned-to-one-thread is a known + class of failure. If work-stealing, a single stuck fiber shouldn't + freeze the accept fiber — which would point away from + scheduler-starvation and toward something else. + +- **(c) malloc contention experiment**: temporarily set + `MALLOC_ARENA_MAX=16` (or unset it entirely) on the Deployment and + see if the HTTP-hang cadence changes. Not a fix, just a signal. + Does not require a code change. Fully reversible. + +- **(d) fiber occupancy metric**: add a counter for Evented main-io + fiber wake-to-wake time for the HTTP accept fiber. On a healthy + pod it should be < 1ms at idle. On a wedged pod it should be + seconds. This is the one new instrumentation we most need. + +### 3. questions on the host_mismatch burst + +- Is there a known migration / spawn pattern that would cause + `host_changed=true` on events that, when the DID doc is re-resolved, + actually point back at the host the event came from? Is there a + race between `requestCrawl` assigning a host_id and a frame arriving + from a subscriber that already has a different host_id? +- Could `preload_account_count` (new in 795cc41) have changed the + cold-start order such that subscribers start firing events before + `host.id` is stable? + +### 4. zat 0.3.0-alpha.21 risk + +This is a theory I don't have time to fully develop but want on the +table: the CBOR/CAR/MST hardening that landed in b91382b could in +principle slow down frame decode enough to cause frame workers to +back up, which cascades into broadcast_queue pressure, which cascades +into persist_order spinlock contention, which cascades into the +Evented broadcaster fiber holding main io for longer chunks, which +cascades into HTTP fibers getting less scheduler share. + +We haven't measured decode latency. The ops-changelog says "expected +throughput drop: ~290k → ~202k fps decode+verify. still 13x faster +than Go." which, on 300 fps ingest, is nowhere near a bottleneck. So +this is probably not it. But it's the one behavior change in b91382b +that we haven't ruled out, and b91382b is what we're rolling back to. + +## open operator questions + +Things I'd like data on as the canary sequence runs: + +1. On each canary, if the HTTP-hang symptom returns: capture `ss -ltn` + on ports 3000/3001 (accept-queue depth), and + `ps -eLo pid,tid,stat,comm` on the main PID (thread state + distribution). We've never captured either during an active hang. +2. Is there any preserved log output from the host_mismatch burst on + 795cc41 or 4f3d1d4 showing the actual rejected DIDs and the + `resolved_host` vs `incoming_host` that mismatched? None captured + yet — the log buffer rotates by the time we look. +3. For the host_mismatch question specifically: the reviewer has asked + for a DB audit **before** any code change. Check for duplicate + hostnames in the `host` table and stale `account.host_id` + references. Do not speculatively patch `getHostIdForHostname` with + an `ORDER BY` before knowing whether duplicate rows exist. + +## what we are NOT asking for + +- Another hypothesis with a fix attached. We've shipped three of those + today. +- A code review of the broadcaster polling or gcLoop mutex. Both are + real bugs, both are known, both should be fixed later. They are not + the cause of the outage. +- Strong opinions on architecture. The Evented + Threaded hybrid is + load-bearing in ways we don't fully understand yet and this doc is + not the time to decide whether it should be replaced. + +## what we ARE asking for + +- A sanity check on "the HTTP-hang is the primary symptom worth + debugging, and everything else we've been chasing is secondary". +- Help designing the next *measurement* (not fix), specifically + something that would distinguish between the four failure shapes + listed in section 1. +- Fresh eyes on whether the commits between 31825b2 and 4f3d1d4 + contain anything we've missed that could plausibly cause HTTP + fibers to stop getting scheduled. +- Whether "roll forward to bbba92c without 795cc41's preload_account_count + and without 4f3d1d4's gc changes" is a safer diagnostic step than + "roll all the way back to b91382b", given that bbba92c is the last + image we saw responsive HTTP on (ops-changelog says so at the 14-min + mark, and we never collected data past that). -- 2.51.2