Skip to content

Diagnostics for the stuck-room bug: party server logging, a room log watcher, and a ?debug health endpoint - #611

Merged
noahm merged 8 commits into
partykitfrom
claude/partykit-server-logging-8o0i1n
Jul 25, 2026
Merged

Diagnostics for the stuck-room bug: party server logging, a room log watcher, and a ?debug health endpoint#611
noahm merged 8 commits into
partykitfrom
claude/partykit-server-logging-8o0i1n

Conversation

@noahm

@noahm noahm commented Jul 25, 2026

Copy link
Copy Markdown
Owner

Tooling to find out where an event room's persisted snapshot stops advancing. This is diagnosis only — no fix for the underlying bug, and no change to how state is stored or served.

The bug being chased

Two clients in one event room. An edit shows up on the other machine, but after a socket cycle (flaky venue wifi) both reset to an earlier state and keep snapping back to that same checkpoint. The suspicion is that edits reach peers via broadcast but aren't durably stored, so the next reconnect's roomstate reverts everyone.

Two suspects, both addressed here:

  1. The fire-and-forget void this.room.storage.put("currentState", ...) may not flush before the room is evicted or hibernated.
  2. Supabase upserts may be failing silently — supabase returns errors in the result rather than throwing, so the existing try/catch never saw them.

Since onStart is getFromStorage() || getFromSupabase(), a stale-but-present storage value always beats a fresher Supabase row — Supabase is never even consulted. That would pin a room to one checkpoint indefinitely, which matches "keep snapping back to that same checkpoint" better than a one-off lost write (which would self-heal on the next action).

What's in here

1. Diagnostic logging (src/party/server.ts) — no behavior change

Structured, greppable lines (prefix [party-diag], one per event, room=<id> on every line) at onStart (hydration source + fingerprint + seq), onConnect (roomstate served + connection count), handleAction (type, seq, post-dispatch fingerprint), around the storage write, around the supabase upsert, and onClose/onError.

The state fingerprint is drawings=<count> stateLen=<JSON length> — cheap, and comparable across events to see whether the snapshot advanced.

Deliberately not changed: the storage put stays fire-and-forget (wrapped with .then/.catch for observability, not awaited, so timing is untouched), and the storage || supabase short-circuit is preserved. Two previously-swallowed errors now log loudly: the empty catch {} in onStart, and the supabase upsert's returned error.

2. scripts/watch-room.mjs / yarn watch:room

partykit tail accepts a server-side --search filter, and every diagnostic line carries room=<id>, so the firehose can be narrowed to one event. The room id is the :roomName from the event URL, so a reporter's link pastes in verbatim:

yarn watch:room https://ddrdraw.surge.sh/#/e/abc123

It digests the stream into a timeline and flags the two signatures that matter: a room restarting while holding unsettled storage writes, and an onStart hydrating a snapshot that doesn't match the last state an action produced.

Because the server-side search matches whole invocations and isn't anchored, it re-filters client-side on an exact room= match.

Tail sessions expire and the CLI doesn't reconnect, so the tail is supervised and restarted with backoff (giving up after 5 failures that never stay up). Tail has no backfill, so gaps are printed rather than papered over, and findings that straddle one are handled honestly: in-flight writes move to an "outcome unknown" tally instead of being reported as lost, and baseline-dependent alerts are marked uncertain until a fresh action re-establishes the baseline. --out <file> appends a colour-free copy so it can be parked for a whole event.

3. Opt-in ?debug health snapshot

Hosted PartyKit has no persistent logs — partykit tail is live-only, and the logpush/tailConsumers/analytics config keys all require your own CLOUDFLARE_ACCOUNT_ID + token, which a *.partykit.dev deploy doesn't have. So a report arriving hours later needs the room to describe its own health on demand:

GET /parties/main/<room>?debug

returns three views of the same state side by side — memory, storage (read back, with matchesMemory), and supabase (with updated_at and matchesMemory) — plus hydration source, storage/supabase write tallies (started/ok/failed/unsettled), last action, last error, and connection count. A healthy boolean and warnings array make it self-interpreting; it explicitly calls out storage and supabase disagreeing.

The default GET response is untouched — the debug branch is gated on the query param, so getPartykitState() is unaffected. Note this is the one behavior change in the PR (additive and opt-in).

Verification

tsc --noemit, oxlint, and oxfmt --check all pass.

The endpoint was exercised against a real local partykit dev, not just typechecked:

  • Plain GET still returns raw AppState, unchanged.
  • After driving two actions over a live websocket: seq=2, storage.matchesMemory: true, 2 started / 2 ok / 0 unsettled, healthy: true, with memory visibly ahead of hydration.
  • With a deliberately stalled storage write injected, it reproduced the production shape and caught it: memory=346 vs storage=291, unsettled: 1, healthy: false, with both expected warnings. The injection was reverted and the committed code re-verified healthy.

The watcher was run against synthetic tail streams covering the bug shape, a healthy room, the error/exception paths, and a mid-stream tail drop. Alerts fire only where warranted — notably the bug-shape alerts appear unqualified without a gap and qualified with one — and a healthy room produces no alerts at all.

Known limitations

  • ?debug instantiates the room if it was evicted, so the counters describe the instance you just woke, not the one that died. The storage-vs-supabase comparison is the part that survives an eviction — and that's the part that localizes this bug.
  • seq is in-memory only and resets to 0 on every onStart, so it is not a progress marker across restarts; the fingerprint is. (That reset may itself be worth a look later.)
  • Logs during a watcher reconnect gap are unrecoverable — hence the explicit gap markers.

Generated by Claude Code

@vercel

vercel Bot commented Jul 25, 2026

Copy link
Copy Markdown

The latest updates on your projects. Learn more about Vercel for GitHub.

Project Deployment Actions Updated (UTC)
ddr-tools Ready Ready Preview Jul 25, 2026 7:15am

claude added 5 commits July 24, 2026 23:41
Investigate a production bug where an event room's shared state gets
"stuck" at a checkpoint: edits reach peers via broadcast but the
persisted/served snapshot appears to stop advancing, so the next
reconnect's roomstate reverts everyone.

Adds greppable, low-noise structured logs (prefix "[party-diag]",
one line per event, room.id on every line) at the points where the
snapshot lifecycle can diverge:

- onStart: hydration source (storage/supabase/fresh), state
  fingerprint (drawings count + serialized length), and restored seq.
  The previously silent hydrate catch now logs loudly.
- onConnect: the roomstate being served (seq + fingerprint) and live
  connection count.
- onMessage/handleAction: action type, assigned seq, and post-dispatch
  fingerprint.
- currentState storage write: log start, and wrap the still
  fire-and-forget put so completion or rejection is logged.
- Supabase upsert: log success and, crucially, log the returned error
  (which the existing try/catch never saw) loudly.
- onClose/onError: correlate socket cycles and evictions with the last
  served/persisted snapshot.

No logic/behavior changes: the storage put stays fire-and-forget and
the onStart storage-then-supabase short-circuit is preserved. tsc
--noemit, oxlint, and oxfmt all pass.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01KmuaLNBXFwzHU6BUd1vGtD
`partykit tail` accepts a server-side `--search <string>` filter (it maps
to the Cloudflare tail API's `query` text match), and every diagnostic
line the server emits carries `room=<id>`. That makes it possible to
narrow the log firehose to a single event when someone reports a problem
in the field.

This wraps that up so troubleshooting is one command:

    yarn watch:room https://ddrdraw.surge.sh/#/e/abc123
    yarn watch:room abc123

The room id is the `:roomName` segment of the event URL, so a reporter's
link can be pasted verbatim. Beyond filtering, the script correlates the
lines to answer the question the logging was added for:

- prints a compact one-line-per-event timeline
- re-filters client side on an exact `room=` match, since the server-side
  search matches whole invocations and is not anchored
- alerts when a room restarts still holding unsettled storage writes
  (the "put didn't flush before eviction" suspicion)
- alerts when an onStart hydrates a snapshot that doesn't match the last
  state we saw an action apply — the snapshot-reverted signature itself
- surfaces upsert/hydrate errors, uncaught exceptions, and non-ok
  invocation outcomes
- prints a tally and a verdict on exit

A tail session expires server-side and the partykit CLI does not
reconnect, so the tail is supervised and restarted with exponential
backoff, giving up after 5 consecutive failures that never stay up (which
is what a login or project-name problem looks like). Tail has no backfill,
so gaps are printed rather than papered over, and findings that straddle
one are handled honestly: writes in flight when the tail dropped move to
an "outcome unknown" tally instead of being reported as lost, and
baseline-dependent alerts are annotated as uncertain until a freshly
observed action re-establishes the baseline.

`--out <file>` appends the same timeline without colour codes, so the
watcher can be parked for a whole event and read afterwards.

Flags: --out <file>, --no-reconnect, --verbose, --raw, --all; anything
after `--` is forwarded to `partykit tail`, e.g. `-- --preview my-preview`.

Verified against synthetic tail streams covering the bug shape, a healthy
room, the error/exception paths, and a mid-stream tail drop: alerts fire
only where warranted, the gap qualifier appears only after an actual gap,
and the --out file is written clean. oxfmt passes; scripts/ is outside the
oxlint and tsc include globs.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01KmuaLNBXFwzHU6BUd1vGtD
Hosted PartyKit gives no persistent logs: `partykit tail` is a live
websocket with no backfill, and the logpush/tailConsumers/analytics
config keys all require your own CLOUDFLARE_ACCOUNT_ID + API token, which
a *.partykit.dev deploy does not have. So troubleshooting a report that
arrives hours after the fact needs the room to be able to describe its
own health on demand.

`GET /parties/main/<room>?debug` now returns a health snapshot. The
default GET response is untouched — the debug branch is opt-in via the
query param, so clients calling getPartykitState() are unaffected.

The snapshot answers "did this room's persisted snapshot stop advancing?"
in one request by comparing three views of the state:

- memory:   the live store's fingerprint
- storage:  read back from room storage, with matchesMemory
- supabase: the persisted row plus its updated_at, with matchesMemory

plus per-instance diagnostics: how it hydrated (source/when/fingerprint),
storage write tallies (started/ok/failed/unsettled), supabase upsert
tallies, last action, last error, and connection count. A `warnings`
array and `healthy` boolean make it self-interpreting; notably it calls
out storage and supabase disagreeing, since onStart prefers storage and a
stale value there pins the room to an old checkpoint indefinitely.

Caveat documented in the code: requesting this instantiates the room if it
was evicted, so the counters describe the instance you just woke. The
storage/supabase comparison is the part that survives an eviction.

Verified against a local `partykit dev`: the plain GET still returns raw
AppState unchanged; after driving two actions over a websocket the
snapshot reports seq=2, storage matchesMemory=true, 2 started / 2 ok /
0 unsettled, healthy=true. Re-run with a deliberately stalled storage
write reproduced the production shape and reported memory=346 vs
storage=291, unsettled=1, healthy=false with both expected warnings.
tsc --noemit, oxlint, and oxfmt pass.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01KmuaLNBXFwzHU6BUd1vGtD
When an organizer hits sync trouble mid-event, we currently have no way to
find out what their client saw. Server logs cover the room's side, but the
client's view — when it dropped, what it was still holding, what got
refused — was only in a devtools console nobody has open at a venue.

Adds a diagnostics panel reachable from the app header in event mode
(hamburger → "Connection diagnostics"), gated with EventModeGated so it
doesn't appear in classic mode. It shows:

- a plain-language connection log with local timestamps, covering
  session start, connect/reconnect, disconnect, catch-up replays,
  heartbeat loss, resyncs, blocked changes, rejected actions, and
  actions abandoned after repeated attempts
- a live list of changes not yet saved to the server, with the action
  type, how long each has been waiting, and how many send attempts
- a copy button that puts a report on the clipboard: room, timestamp
  with UTC offset, user agent, pending list, then the whole log
- a prompt asking the user to post it in a thread on the Discord server

The log lives in `src/party/diagnostics.ts`, deliberately outside redux for
the same reason `connection-status.ts` is: anything in the store gets
broadcast to the room and persisted into every event's snapshot, and a
per-client debug log is neither shared state nor something to write there.
It is a 200-entry ring buffer read through useSyncExternalStore, so the
panel updates live while open.

`SyncManager` grows a `pendingActions` getter (and records when each
pending entry was first sent) so the panel can read the real pending list
rather than duplicating that state.

DISCORD_INVITE_URL in diagnostics-dialog.tsx is intentionally left empty: no
invite link exists in the repo, and the prompt renders fine without one
rather than shipping a URL that goes nowhere. Set it to make the link
appear.

Verified in a real browser against both dev servers, driving the actual
failure path with the workerd SIGSTOP recipe from the verify skill:
- while the server was frozen, the panel showed 2 pending event/addCab
  entries with live ages and attempt counts
- after recovery the log read: action-abandoned x2, heartbeat-lost ("no
  reply to 2 pings; forcing a reconnect"), disconnected, then
  reconnected (seq 3)
- the copy button produced the full report on the clipboard and flipped
  to "Copied!"
tsc --noemit, oxlint, and oxfmt pass; webpack builds clean.

New UI strings are in en and ja; the Japanese is a best effort and should
get a native-speaker pass.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01KmuaLNBXFwzHU6BUd1vGtD
The invite already existed in the about/credits dialog; it just wasn't
found earlier because a shortened discord.gg URL doesn't contain the word
"discord" in any searchable form beyond the host.

Rather than repeat the URL in a second place where the two could drift,
this extracts it to src/external-links.ts and has both the about dialog and
the diagnostics panel read from there. The diagnostics prompt now always
renders the link, so the empty-string fallback branch is gone.

Verified in a browser: the diagnostics panel renders "Open Discord" ->
https://discord.gg/QPyEATsbP7 with target=_blank, and the about dialog
still carries the same link after the refactor.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01KmuaLNBXFwzHU6BUd1vGtD
The prompt next to the copy button asks people to paste the report into a
thread on Discord, so format it for that destination:

- bold labels on the header fields, so the room/time/browser are skimmable
  rather than a wall of text
- the pending list and the connection log go in fenced code blocks, which
  keeps their column alignment in Discord's proportional font and — more
  importantly — stops markdown from eating their contents. Action types and
  room names routinely contain underscores, and a reducer's error message
  can contain anything; outside a fence `foo_bar_baz` renders as partly
  italic. Any backticks in that content are neutralised so they can't close
  the fence early.
- the event column is padded to a common width so details line up
- empty pending/log sections render as italic placeholders instead of an
  empty code block

Also fixes the UTC offset in the header, which divided minutes by 60 without
flooring: a half-hour zone came out as "UTC+5.5". It now formats as +05:30,
verified across UTC, +02, -05, +05:30, -03:30 and +14.

Verified by driving the browser with the server frozen so the report had
both pending changes and failure events, and by exercising the formatter
directly for the empty case, the common no-pending case, and a hostile case
carrying triple backticks, underscores and asterisks.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01KmuaLNBXFwzHU6BUd1vGtD
A 200-entry buffer produced a ~21k character report, well past Discord's
2000 character message limit. Discord turns an over-long paste into a
message.txt attachment, which works but throws away the markdown the last
commit added — and the user has no idea that happened.

The main copy button now trims to fit. It keeps the most recent events,
since the tail of a log is where the trouble is, and says so in the report
rather than silently dropping them:

    _171 earlier events trimmed to fit — ask for the full log if needed_

Trimming is by character budget rather than a fixed event count, because
detail lengths vary a lot; it includes as many recent events as fit under
the limit (with a little headroom). The header reflects it too: "most
recent 29 of 200 events" instead of "200 events". If even a single event
would overflow — a pathological pending list, say — it keeps that one event
rather than emitting a report with no log at all.

Adds a second "Copy full log" button for when you want everything. That one
is plain text, no markdown: it's expected to arrive as a file attachment,
where bold markers and code fences are just noise. Both formats come from
one builder so they can't drift apart.

The clipboard fallback textarea is now written imperatively via a ref, since
one hidden element has to serve both formats and a state update wouldn't
have landed before the selection.

Verified against the formatter directly: a 200-entry buffer trims to 1811
characters, keeps event 199, drops event 0, carries the trim note, and the
full report still contains every event across 20950 characters of plain
text; a 5-event log is untouched and carries no note. Then in a browser
with the server frozen: both buttons present and labelled, the trimmed one
yields markdown with fences, the full one yields plain text, and each shows
its own "Copied!" state.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01KmuaLNBXFwzHU6BUd1vGtD
@noahm
noahm merged commit 76ad095 into partykit Jul 25, 2026
2 checks passed
@noahm
noahm deleted the claude/partykit-server-logging-8o0i1n branch July 25, 2026 07:17
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants