bug(serve): session MCP connection drops mid-session while `madtea serve` stays alive (2nd recurrence)

hexajon commented

2026-08-17 15:45:07 +00:00

Owner

Summary

For the second time in a row, the madtea MCP connection died mid-session. Every mad_t_* tool suddenly returns "No such tool available", and the client marks the server disconnected. With hook steering active (ADR 0009, no opt-outs), the session then loses every forge and commit operation until someone runs a /mcp reconnect.

1st occurrence: 2026-07-01/02, around 13:48. No panic or OOM trace found. Unresolved, and I noted to file an issue if it repeated.
2nd occurrence: 2026-07-02, around 11:26.

Timeline (2nd occurrence, 2026-07-02)

Around 11:25 - two clients are connected in parallel. Each loads the mad_t_issues and mad_t_prs schemas and issues a large batch mad_t_issues action=get numbers=[...16-24 numbers...].
The session then runs mad_t_issues action=rank, action=list limit=60, action=get numbers=[...], mad_t_pull and mad_t_status successfully in this window.
Around 11:26 - the next calls (mad_t_branches action=list, mad_t_worktrees action=list) fail with "No such tool available", and the client reports the MCP server disconnected.

Suspicious correlation both times: the death follows concurrent MCP use, with multiple clients making batch reads.

Process evidence at around 11:27

Two madtea serve processes are alive and their sockets are intact. The server process did not crash. The session-side stdio binding is what broke, or the client respawned a process it never rebound:

two `madtea serve` processes alive - one for this session, one for another concurrent session; sockets intact

Both have fd 0/1/2 bound to live sockets, and eventpoll is healthy. A later probe of mad_t_issues action=list limit=1 still returned "No such tool available".

Impact

The session loses ALL forge operations (issues, PRs, finish, commit). The CLI fallback is hook-steered back to the dead mad_t_* surface, so the session has no way to recover by itself.
Only a manual /mcp reconnect restores the session.

Asks

Diagnose why madtea serve stops answering, or why the stdio stream breaks, under concurrent multi-client batch load. Add stderr logging and a crash-trace path, so the next occurrence is diagnosable. serve currently leaves no trace.
Consider whether serve needs per-connection robustness, for example surviving a slow or large batch get, or logging and exiting nonzero instead of going silent.

Notes

Verify the concurrency hypothesis: both deaths coincided with concurrent multi-client MCP traffic. Single-client sessions have never dropped.

## Summary For the second time in a row, the madtea MCP connection died mid-session. Every `mad_t_*` tool suddenly returns "No such tool available", and the client marks the server disconnected. With hook steering active (ADR 0009, no opt-outs), the session then loses every forge and commit operation until someone runs a `/mcp` reconnect. - 1st occurrence: 2026-07-01/02, around 13:48. No panic or OOM trace found. Unresolved, and I noted to file an issue if it repeated. - 2nd occurrence: 2026-07-02, around 11:26. ## Timeline (2nd occurrence, 2026-07-02) 1. Around 11:25 - two clients are connected in parallel. Each loads the mad_t_issues and mad_t_prs schemas and issues a large batch `mad_t_issues action=get numbers=[...16-24 numbers...]`. 2. The session then runs `mad_t_issues action=rank`, `action=list limit=60`, `action=get numbers=[...]`, `mad_t_pull` and `mad_t_status` successfully in this window. 3. Around 11:26 - the next calls (`mad_t_branches action=list`, `mad_t_worktrees action=list`) fail with "No such tool available", and the client reports the MCP server disconnected. Suspicious correlation both times: the death follows concurrent MCP use, with multiple clients making batch reads. ## Process evidence at around 11:27 Two `madtea serve` processes are alive and their sockets are intact. The *server process* did not crash. The session-side stdio binding is what broke, or the client respawned a process it never rebound: ``` two `madtea serve` processes alive - one for this session, one for another concurrent session; sockets intact ``` Both have fd 0/1/2 bound to live sockets, and eventpoll is healthy. A later probe of `mad_t_issues action=list limit=1` still returned "No such tool available". ## Impact - The session loses ALL forge operations (issues, PRs, finish, commit). The CLI fallback is hook-steered back to the dead mad_t_* surface, so the session has no way to recover by itself. - Only a manual `/mcp` reconnect restores the session. ## Asks 1. Diagnose why `madtea serve` stops answering, or why the stdio stream breaks, under concurrent multi-client batch load. Add stderr logging and a crash-trace path, so the next occurrence is diagnosable. serve currently leaves no trace. 2. Consider whether serve needs per-connection robustness, for example surviving a slow or large batch get, or logging and exiting nonzero instead of going silent. ## Notes - Verify the concurrency hypothesis: both deaths coincided with concurrent multi-client MCP traffic. Single-client sessions have never dropped.

hexajon added the

bug

status/needs-info

labels

2026-08-17 15:45:07 +00:00

hexajon commented

2026-08-17 15:45:22 +00:00

Author

Owner

Built the diagnosability half of this. The root cause is still unknown. This does not attempt a fix. It only makes the next occurrence traceable. Commit 8760455f on a serve-diagnosability branch, not yet merged.

Root-cause lead worth handing to a follow-up: mcp.NewServer(...) never set ServerOptions.Logger. The go-sdk defaults a nil Logger to slog.DiscardHandler (go-sdk mcp/server.go:183-184, mcp/logging.go:93-98). That means every one of the SDK's OWN lifecycle log lines was silently thrown away: "server run start", "server connect failed", "server session connected"/"disconnected", "server session ended with error", "server run cancelled" (go-sdk mcp/server.go around lines 947-1002). That is very likely why the first occurrence left "no panic/OOM trace found": there was never anywhere for a trace to land, even if the SDK itself detected and logged the exact failure.

Also relevant: the go-sdk's own request dispatch (internal/jsonrpc2/conn.go handleAsync) spawns one goroutine per in-flight request, with no recover() anywhere between that goroutine and a registered tool handler. An unrecovered panic in any mad_t_* handler crashes the entire process, and Go's default panic trace lands on whatever stderr the client happened to attach, which is captured nowhere durable. A bug hit only under concurrent multi-client batch load matches both observations here: two live serve processes with intact sockets, and the correlation with concurrent multi-client MCP traffic.

What was added on this branch, with no protocol or behavior change:

internal/mcp/servelog.go - mcp.ServerOptions.Logger is now wired to a structured (JSON) slog.Logger. It writes to stderr AND a bounded rotating file at <user cache dir>/madtea/serve.log (1 MiB per generation, 3 generations, dependency-free rotation, via os.UserCacheDir(), so $XDG_CACHE_HOME/madtea/serve.log or ~/.cache/madtea/serve.log on Linux). It never writes to stdout, because stdout carries the MCP protocol itself. If the cache dir cannot be resolved, it degrades to stderr only with a logged warning, and never blocks serve from starting.
internal/mcp/server.go Run() - logs the process start (pid, version, resolved log file path) and the shutdown cause on exit (clean EOF or context-canceled, against an actual transport error with detail).
internal/mcp/panic_recovery.go - an outermost receiving middleware. It recovers any panic from a request handler, logs the message plus the full goroutine stack trace, then exits nonzero (os.Exit(1), indirected through serveExitFunc for tests). It converts today's silent, untraced process death into a deliberate, logged one. The end state is the same, because the process was always going to die, but now it is diagnosable.

On the next occurrence, check ~/.cache/madtea/serve.log (and .1/.2) first, together with stderr, before assuming there is no trace.

Full gate green (./scripts/gate.sh: build, gofmt, vet, gofix, modtidy, hook-tests, plus test-race, staticcheck, govulncheck, gosec, modernize, docs-verify and cross-compile all PASS). This issue stays open, because the root cause is still open.

Built the diagnosability half of this. The root cause is still unknown. This does not attempt a fix. It only makes the next occurrence traceable. Commit `8760455f` on a serve-diagnosability branch, not yet merged. **Root-cause lead worth handing to a follow-up:** `mcp.NewServer(...)` never set `ServerOptions.Logger`. The go-sdk defaults a nil `Logger` to `slog.DiscardHandler` (`go-sdk mcp/server.go:183-184`, `mcp/logging.go:93-98`). That means every one of the SDK's OWN lifecycle log lines was silently thrown away: `"server run start"`, `"server connect failed"`, `"server session connected"`/`"disconnected"`, `"server session ended with error"`, `"server run cancelled"` (`go-sdk mcp/server.go` around lines 947-1002). That is very likely why the first occurrence left "no panic/OOM trace found": there was never anywhere for a trace to land, even if the SDK itself detected and logged the exact failure. Also relevant: the go-sdk's own request dispatch (`internal/jsonrpc2/conn.go` `handleAsync`) spawns one goroutine per in-flight request, with **no `recover()`** anywhere between that goroutine and a registered tool handler. An unrecovered panic in any `mad_t_*` handler crashes the **entire process**, and Go's default panic trace lands on whatever stderr the client happened to attach, which is captured nowhere durable. A bug hit only under concurrent multi-client batch load matches both observations here: two live serve processes with intact sockets, and the correlation with concurrent multi-client MCP traffic. **What was added on this branch, with no protocol or behavior change:** - `internal/mcp/servelog.go` - `mcp.ServerOptions.Logger` is now wired to a structured (JSON) `slog.Logger`. It writes to **stderr AND** a bounded rotating file at `<user cache dir>/madtea/serve.log` (1 MiB per generation, 3 generations, dependency-free rotation, via `os.UserCacheDir()`, so `$XDG_CACHE_HOME/madtea/serve.log` or `~/.cache/madtea/serve.log` on Linux). It never writes to stdout, because stdout carries the MCP protocol itself. If the cache dir cannot be resolved, it degrades to stderr only with a logged warning, and never blocks serve from starting. - `internal/mcp/server.go` `Run()` - logs the process start (pid, version, resolved log file path) and the shutdown cause on exit (clean EOF or context-canceled, against an actual transport error with detail). - `internal/mcp/panic_recovery.go` - an outermost receiving middleware. It recovers any panic from a request handler, logs the message plus the full goroutine stack trace, then exits nonzero (`os.Exit(1)`, indirected through `serveExitFunc` for tests). It converts today's silent, untraced process death into a deliberate, logged one. The end state is the same, because the process was always going to die, but now it is diagnosable. On the next occurrence, check `~/.cache/madtea/serve.log` (and `.1`/`.2`) first, together with stderr, before assuming there is no trace. Full gate green (`./scripts/gate.sh`: build, gofmt, vet, gofix, modtidy, hook-tests, plus test-race, staticcheck, govulncheck, gosec, modernize, docs-verify and cross-compile all PASS). This issue stays open, because the root cause is still open.

hexajon commented

2026-08-17 15:45:32 +00:00

Author

Owner

The instrumentation is live. There is no diagnosable recurrence yet.

An earlier PR landed on main and is running. ~/.cache/madtea/serve.log carries lifecycle events from 2026-07-02 14:33 onward, with the current process on v0.14.14. It is a single file well under the 1 MiB rotation threshold, so there is no serve.log.1/.2. This file is the complete record since the instrumentation landed.

Since then:

Zero "serve request handler panicked" lines. The panic-recovery middleware never fired.
Zero cause:transport_error lines and zero session-ended-with-error lines.
Every recorded termination is cause=clean_shutdown (stdin EOF or context canceled).
Several processes stopped logging with no exit line before the next serve starting. Those abrupt gaps are indistinguishable from a normal client SIGKILL teardown, and no clearly-concurrent live serve processes interleave, so none can be attributed to this bug. The concurrency conditions blamed here have probably not recurred.

Blind spot found while auditing, and it undercuts the diagnosability just shipped: panic_recovery.go recovers with recover(), which does NOT catch Go runtime fatal errors. A concurrent map write or read, or a stack overflow, is exactly the "death under concurrent multi-client batch load" this issue hypothesizes. The runtime writes those fatal error: ... traces straight to fd 2 and bypasses the slog logger, so they land nowhere durable. That is the same untraced gap this issue filed. SIGKILL and OOM are likewise uncatchable. I am building the completion now under this issue: redirect or tee the process's real stderr (fd 2) into a durable crash file next to serve.log, plus GOTRACEBACK handling, so the next fatal-error death leaves a full runtime trace.

Housekeeping: the earlier comment points at another issue as the root-cause follow-up, but that issue was the unrelated mad_t_finish resumability bug. The root-cause work continues here.

Where to look on the next occurrence: ~/.cache/madtea/serve.log and its rotations, for a transport_error or panic line, plus the new fd-2 crash capture for a bare fatal error: runtime trace.

The instrumentation is live. There is no diagnosable recurrence yet. An earlier PR landed on main and is running. `~/.cache/madtea/serve.log` carries lifecycle events from 2026-07-02 14:33 onward, with the current process on v0.14.14. It is a single file well under the 1 MiB rotation threshold, so there is no `serve.log.1`/`.2`. This file is the complete record since the instrumentation landed. Since then: - Zero `"serve request handler panicked"` lines. The panic-recovery middleware never fired. - Zero `cause:transport_error` lines and zero session-ended-with-error lines. - Every recorded termination is `cause=clean_shutdown` (stdin EOF or context canceled). - Several processes stopped logging with no exit line before the next `serve starting`. Those abrupt gaps are indistinguishable from a normal client SIGKILL teardown, and no clearly-concurrent live serve processes interleave, so none can be attributed to this bug. The concurrency conditions blamed here have probably not recurred. Blind spot found while auditing, and it undercuts the diagnosability just shipped: `panic_recovery.go` recovers with `recover()`, which does NOT catch Go runtime *fatal* errors. A concurrent map write or read, or a stack overflow, is exactly the "death under concurrent multi-client batch load" this issue hypothesizes. The runtime writes those `fatal error: ...` traces straight to fd 2 and bypasses the slog logger, so they land nowhere durable. That is the same untraced gap this issue filed. SIGKILL and OOM are likewise uncatchable. **I am building the completion now under this issue:** redirect or tee the process's real stderr (fd 2) into a durable crash file next to serve.log, plus GOTRACEBACK handling, so the next fatal-error death leaves a full runtime trace. Housekeeping: the earlier comment points at another issue as the root-cause follow-up, but that issue was the unrelated `mad_t_finish` resumability bug. The root-cause work continues here. Where to look on the next occurrence: `~/.cache/madtea/serve.log` and its rotations, for a `transport_error` or panic line, plus the new fd-2 crash capture for a bare `fatal error:` runtime trace.

hexajon commented

2026-08-17 15:45:39 +00:00

Author

Owner

The instrumentation completion landed in a later PR: subprocess-proven crash capture through runtime/debug.SetCrashOutput, where a real unrecovered panic demonstrably lands in ~/.cache/madtea/serve-crash.log. It also fixes the startup prior-crash preview, which previously came up empty for runtime fatals, because their crash files carry no fatal error: header (that is stderr-only). The preview now surfaces the goroutine-dump header instead.

This issue stays open as the tracker until the underlying drop is root-caused. Next-occurrence playbook: on the first madt_* failure after a drop, check ~/.cache/madtea/serve-crash.log. The startup log also warns with crash_file, size_bytes and first_line if a prior trace exists. Attach the trace here. The instrumentation now guarantees that a runtime-level death leaves durable evidence. A drop with an EMPTY crash file is itself diagnostic: it points away from process death, toward transport or client-side causes.

The instrumentation completion landed in a later PR: subprocess-proven crash capture through `runtime/debug.SetCrashOutput`, where a real unrecovered panic demonstrably lands in `~/.cache/madtea/serve-crash.log`. It also fixes the startup prior-crash preview, which previously came up empty for runtime fatals, because their crash files carry no `fatal error:` header (that is stderr-only). The preview now surfaces the goroutine-dump header instead. This issue stays open as the tracker until the underlying drop is root-caused. Next-occurrence playbook: on the first `madt_*` failure after a drop, check `~/.cache/madtea/serve-crash.log`. The startup log also warns with `crash_file`, `size_bytes` and `first_line` if a prior trace exists. Attach the trace here. The instrumentation now guarantees that a runtime-level death leaves durable evidence. A drop with an EMPTY crash file is itself diagnostic: it points away from process death, toward transport or client-side causes.

hexajon commented

2026-08-17 15:45:42 +00:00

Author

Owner

Open question: what is the best practice for MCP servers here? A client can also run over SSH and get disconnected, hung, or orphaned. How does that affect the MCP server?

hexajon commented

2026-08-17 15:45:49 +00:00

Author

Owner

On the dual-registration finding, I removed the MCP server from the plugin. Registration stays solely with madtea mcp-config --install and madtea install.

This landed in a later PR: the mcpServers block is gone from .claude-plugin/plugin.json. The plugin keeps its load-bearing pieces, which are the five git-steering hooks plus the two workflow skills. Steering is unaffected, because it targets madt_* tool names, and the direct registration serves those. Once the next plugin release propagates through the plugin marketplace, sessions go back to exactly one madtea serve process. The mcp__plugin_madtea_madtea__* deny rule and the old-prefix leftovers in ~/.claude/settings.json then become removable, tracked as a separate follow-up. Do NOT drop the deny rule before the plugin cache updates past 0.14.6.

I also fixed the version-skew half today. madtea install upgraded /usr/local/bin/madtea to v0.14.21-dev and removed a stale duplicate copy on PATH. Until the plugin release lands, both spawns at least run the same binary.

On the dual-registration finding, I removed the MCP server from the plugin. Registration stays solely with `madtea mcp-config --install` and `madtea install`. This landed in a later PR: the `mcpServers` block is gone from `.claude-plugin/plugin.json`. The plugin keeps its load-bearing pieces, which are the five git-steering hooks plus the two workflow skills. Steering is unaffected, because it targets `madt_*` tool names, and the direct registration serves those. Once the next plugin release propagates through the plugin marketplace, sessions go back to exactly one `madtea serve` process. The `mcp__plugin_madtea_madtea__*` deny rule and the old-prefix leftovers in `~/.claude/settings.json` then become removable, tracked as a separate follow-up. Do NOT drop the deny rule before the plugin cache updates past 0.14.6. I also fixed the version-skew half today. `madtea install` upgraded `/usr/local/bin/madtea` to v0.14.21-dev and removed a stale duplicate copy on PATH. Until the plugin release lands, both spawns at least run the same binary.

hexajon commented

2026-08-17 15:46:10 +00:00

Author

Owner

Answering the open question above (best practice for MCP servers, and what an SSH-disconnected, hung or orphaned client does to the server). Researched against the go-sdk source and the MCP spec, 2026-07-15.

How stdio client death manifests server-side - three distinct signatures

Client process dies or is killed, so the server sees a clean EOF. The read goroutine's dec.Decode returns io.EOF (go-sdk mcp/transport.go:385-411), jsonrpc2 tears down, and Server.Run returns nil. This is what our instrumentation logs as clean_shutdown.
Client alive, but its binding or reader broke, pipes held open, still draining stdout, so the server blocks in Read forever. stdin never hits EOF. The process stays alive, the sockets stay intact, and there is no termination event.
Client alive, but it stopped reading stdout (backpressure), so the server blocks in Write forever. ioConn.Write and the jsonrpc2 framer check ctx.Done() only before the write, then call a blocking w.out.Write(data) with no deadline. When the roughly 64 KB pipe buffer fills, the write blocks indefinitely and holds writeMu. Again: alive, intact sockets, nothing logged. The go-sdk's own comments concede this gap (transport.go:220-225).

What go-sdk v1.6.x handles, and what it does not

Handles: stdin EOF gives a clean exit; ctx-cancel closes the session; in-flight calls retire on caller-ctx cancel.
Optional, and OFF by default: the server keepalive ping. ServerOptions.KeepAlive time.Duration pings every interval, with an interval/2 timeout, and closes the session on failure. madtea does not set it (internal/mcp/server.go NewServer options). It is spec-sanctioned: the ping utility says a sender MAY treat a missing ping response as stale and terminate, and SHOULD ping periodically.
Does NOT handle: there is no write deadline anywhere, and no detection of a live-but-silent client. Keepalive is also useless against full-pipe backpressure, because the ping's own write blocks on the same full pipe. Upstream also has a known write-poisoning bug (go-sdk #683), where a transient write error permanently poisons the connection.

Caveat: I verified the transport internals against the locally-cached v1.3.0 source. ServerSession.Ping and keepalive are confirmed present in v1.6.1 through pkg.go.dev, but the exact v1.6.1 struct field should be re-checked when building.

The SSH angle

An SSH-orphaned client does not signal the MCP child directly. The server sees either signature 2 or signature 3 above: stdin stays open but silent, or stdout stops draining. madtea's existing getppid-reparenting orphan reaper covers the parent-death case. A parent that is alive but hung is deliberately not reaped (internal/mcp/shutdown.go), and that residual gap is exactly these signatures. PDEATHSIG is NOT recommended: it is thread-bound, and Go migrates goroutines across threads, so it fires spuriously. The existing getppid polling is the correct portable choice.

Does this explain "client says disconnected, server alive, sockets intact"?

Yes, and it is internally consistent with every observation. The incident produces no termination record at all, because the server is blocked in Read or Write. It is not crashing, so no panic or SetCrashOutput trace fires, and it is not orphaned, so the reaper stays quiet. The correlation with concurrent multi-client batch traffic points hard at the backpressure signature: heavy batch output fills the stdout pipe, the client's read side stalls under load, the server's write blocks with no deadline, the client's own timeout fires and marks the server disconnected, and every tool call then answers "No such tool available", while the process lingers with intact fds.

Recommended hardening, queued to build

Enable ServerOptions.KeepAlive at about 30-60 s. It is spec-sanctioned and SDK-supported, and it closes the "client drains but stopped answering" case. It does not fix full-pipe hangs.
Add a write watchdog. This one is custom: wrap the stdout writer through IOTransport, so each protocol write runs against a generous timeout. On expiry, log the event durably to serve.log and cancel the run ctx, so the process exits nonzero instead of lingering. This is the only lever that catches the backpressure signature, which is the most likely root cause of both incidents.
Keep the getppid reaper as it is. Exit-on-stdin-EOF is already correct through Server.Run.

A lingering blocked process from a past drop would also explain the multiple live serve processes seen after an incident. Once 1 and 2 land, the next occurrence either self-terminates with a durable write_watchdog log line, which confirms the root cause, or the watchdog never fires and the client-side-binding theory takes over.

Answering the open question above (best practice for MCP servers, and what an SSH-disconnected, hung or orphaned client does to the server). Researched against the go-sdk source and the MCP spec, 2026-07-15. ## How stdio client death manifests server-side - three distinct signatures - **Client process dies or is killed, so the server sees a clean EOF.** The read goroutine's `dec.Decode` returns `io.EOF` (go-sdk `mcp/transport.go:385-411`), jsonrpc2 tears down, and `Server.Run` returns nil. This is what our instrumentation logs as `clean_shutdown`. - **Client alive, but its binding or reader broke, pipes held open, still draining stdout, so the server blocks in `Read` forever.** stdin never hits EOF. The process stays alive, the sockets stay intact, and there is **no termination event**. - **Client alive, but it stopped reading stdout (backpressure), so the server blocks in `Write` forever.** `ioConn.Write` and the jsonrpc2 framer check `ctx.Done()` **only before** the write, then call a blocking `w.out.Write(data)` with **no deadline**. When the roughly 64 KB pipe buffer fills, the write blocks indefinitely and holds `writeMu`. Again: alive, intact sockets, nothing logged. The go-sdk's own comments concede this gap (`transport.go:220-225`). ## What go-sdk v1.6.x handles, and what it does not - Handles: stdin EOF gives a clean exit; ctx-cancel closes the session; in-flight calls retire on caller-ctx cancel. - Optional, and OFF by default: the **server keepalive ping**. `ServerOptions.KeepAlive time.Duration` pings every interval, with an `interval/2` timeout, and closes the session on failure. **madtea does not set it** (`internal/mcp/server.go` NewServer options). It is spec-sanctioned: the ping utility says a sender MAY treat a missing ping response as stale and terminate, and SHOULD ping periodically. - Does NOT handle: there is no write deadline anywhere, and no detection of a live-but-silent client. Keepalive is also **useless against full-pipe backpressure**, because the ping's own write blocks on the same full pipe. Upstream also has a known write-poisoning bug (go-sdk #683), where a transient write error permanently poisons the connection. Caveat: I verified the transport internals against the locally-cached v1.3.0 source. `ServerSession.Ping` and keepalive are confirmed present in v1.6.1 through pkg.go.dev, but the exact v1.6.1 struct field should be re-checked when building. ## The SSH angle An SSH-orphaned client does not signal the MCP child directly. The server sees either signature 2 or signature 3 above: stdin stays open but silent, or stdout stops draining. madtea's existing `getppid`-reparenting orphan reaper covers the parent-*death* case. A parent that is alive but hung is deliberately not reaped (`internal/mcp/shutdown.go`), and that residual gap is exactly these signatures. PDEATHSIG is NOT recommended: it is thread-bound, and Go migrates goroutines across threads, so it fires spuriously. The existing getppid polling is the correct portable choice. ## Does this explain "client says disconnected, server alive, sockets intact"? **Yes, and it is internally consistent with every observation.** The incident produces *no termination record at all*, because the server is blocked in Read or Write. It is not crashing, so no panic or SetCrashOutput trace fires, and it is not orphaned, so the reaper stays quiet. The **correlation with concurrent multi-client batch traffic points hard at the backpressure signature**: heavy batch output fills the stdout pipe, the client's read side stalls under load, the server's write blocks with no deadline, the client's own timeout fires and marks the server disconnected, and every tool call then answers "No such tool available", while the process lingers with intact fds. ## Recommended hardening, queued to build 1. **Enable `ServerOptions.KeepAlive` at about 30-60 s.** It is spec-sanctioned and SDK-supported, and it closes the "client drains but stopped answering" case. It does not fix full-pipe hangs. 2. **Add a write watchdog.** This one is custom: wrap the stdout writer through `IOTransport`, so each protocol write runs against a generous timeout. On expiry, log the event durably to serve.log and cancel the run ctx, so the process exits nonzero instead of lingering. This is the only lever that catches the backpressure signature, which is the most likely root cause of both incidents. 3. Keep the getppid reaper as it is. Exit-on-stdin-EOF is already correct through `Server.Run`. A lingering blocked process from a past drop would also explain the multiple live `serve` processes seen after an incident. Once 1 and 2 land, the next occurrence either self-terminates with a durable `write_watchdog` log line, which confirms the root cause, or the watchdog never fires and the client-side-binding theory takes over.

hexajon commented

2026-08-17 15:46:15 +00:00

Author

Owner

The hardening landed (PR #143): KeepAlive at 45s, plus the 120s stdout write watchdog with durable write_watchdog logging and a loud exit. This issue now waits on a live occurrence. If the next drop self-terminates with a write_watchdog line in serve.log, the backpressure theory is confirmed and this closes with that evidence. If a drop happens with no watchdog fire, the investigation moves to the client-side binding theory. Labeled for the waiting state.

hexajon commented

2026-08-17 15:46:24 +00:00

Author

Owner

An active reproduction attempt, plus a client-behavior fact-check. Three results:

(1) The write watchdog is now reproduction-verified. Deterministic test: one serve, and a client that floods batches and never drains stdout. The roughly 64KB pipe filled, the protocol write wedged, and at exactly 120.0s the watchdog fired with a durable line (serve.log ERROR cause=write_watchdog timeout=2m0s pending_bytes=172783, exit 1). A genuine full-stall drop WILL self-terminate with recorded evidence when it next occurs.

(2) A healthy server does not drop under brutal concurrent load: 8 concurrent serve processes, 4 minutes, healthy draining clients at about 5760 req/s aggregate. All 8 stayed alive and answered to shutdown, with zero watchdog, transport, panic or keepalive lines. That leans the production root cause toward the client side of the binding, not a server-side crash under batch traffic.

(3) The suspected watchdog-versus-client-timeout gap does NOT exist, and no tuning is warranted. Checked against Claude Code's documented behavior: for stdio servers the idle abort is 30 minutes (the 60s per-request timer applies to HTTP/SSE, not stdio), and on giving up the client closes stdin, then escalates SIGTERM and SIGKILL. Our watchdog fires at 120s, which is 15x sooner than the client would abandon the server, and serve exits promptly on stdin EOF (verified: exit 0 immediately with stdin closed). The multiple-lingering-processes symptom matches a documented client limitation instead: stdio children are orphaned when the client exits uncleanly (crash or force-kill). No server-side timer prevents that, and it fits the incident timeline here.

Net: the instrumentation is proven, no code change is needed, and this still waits on a live occurrence to settle backpressure versus client binding. The watchdog now guarantees that the occurrence documents itself.

An active reproduction attempt, plus a client-behavior fact-check. Three results: (1) The write watchdog is now reproduction-verified. Deterministic test: one serve, and a client that floods batches and never drains stdout. The roughly 64KB pipe filled, the protocol write wedged, and at exactly 120.0s the watchdog fired with a durable line (serve.log ERROR cause=write_watchdog timeout=2m0s pending_bytes=172783, exit 1). A genuine full-stall drop WILL self-terminate with recorded evidence when it next occurs. (2) A healthy server does not drop under brutal concurrent load: 8 concurrent serve processes, 4 minutes, healthy draining clients at about 5760 req/s aggregate. All 8 stayed alive and answered to shutdown, with zero watchdog, transport, panic or keepalive lines. That leans the production root cause toward the client side of the binding, not a server-side crash under batch traffic. (3) The suspected watchdog-versus-client-timeout gap does NOT exist, and no tuning is warranted. Checked against Claude Code's documented behavior: for stdio servers the idle abort is 30 minutes (the 60s per-request timer applies to HTTP/SSE, not stdio), and on giving up the client closes stdin, then escalates SIGTERM and SIGKILL. Our watchdog fires at 120s, which is 15x sooner than the client would abandon the server, and serve exits promptly on stdin EOF (verified: exit 0 immediately with stdin closed). The multiple-lingering-processes symptom matches a documented client limitation instead: stdio children are orphaned when the client exits uncleanly (crash or force-kill). No server-side timer prevents that, and it fits the incident timeline here. Net: the instrumentation is proven, no code change is needed, and this still waits on a live occurrence to settle backpressure versus client binding. The watchdog now guarantees that the occurrence documents itself.

hexajon commented

2026-08-17 15:46:35 +00:00

Author

Owner

Third live occurrence, 2026-07-20 around 20:05 local, and the first one the instrumentation caught end to end.

serve.log (pid 27537): keepalive ping failed; closing session with context deadline exceeded at 20:05:41, then a clean session close at 20:06:36 (cause=clean_shutdown, no transport error). serve-crash.log: empty, 0 bytes. The write watchdog never fired.

Machine context at the time: load average 45-54 on 40 threads, with several concurrent heavy build and test pipelines saturating the box. So the client side was CPU-starved, missed the 45s keepalive's response deadline, and the server closed the session BY DESIGN. That is the #143 hardening doing exactly what it was built to do. The client then reported the server disconnected, and the impact matched this issue exactly: every madt_* call gone until a manual /mcp reconnect. New data point: processes spawned under the same client inherit the dead binding, so nothing on that side can recover it.

What this discriminates: a silent watchdog plus an empty crash file rules out both stdout backpressure and process death. The evidence now points at the third leg, a starved-but-alive client binding. That raises the design question this occurrence puts on the table. Closing a session on a keepalive miss, when the client is merely SLOW, converts a stall that would have recovered into a hard drop that needs a human. The pre-#143 behavior would have ridden out the load spike. A stdio transport cannot half-break the way HTTP can, because the pipe either works or EOFs, so the ping's real job here is orphan detection, not liveness. Options to consider: a much more generous deadline (minutes, not 22.5s), ping retries before closing, or scaling the deadline when the machine is under load.

A side casualty worth its own note: the drop killed an madt_commit mid-staging and left a stale index.lock, which then blocked every later commit on that worktree. Filed as #319 with a proposed detect-or-teach fix.

Evidence preserved: a serve.log copy plus the process listing from the incident window, in my notes.

Third live occurrence, 2026-07-20 around 20:05 local, and the first one the instrumentation caught end to end. serve.log (pid 27537): `keepalive ping failed; closing session` with `context deadline exceeded` at 20:05:41, then a clean session close at 20:06:36 (`cause=clean_shutdown`, no transport error). serve-crash.log: empty, 0 bytes. The write watchdog never fired. Machine context at the time: load average 45-54 on 40 threads, with several concurrent heavy build and test pipelines saturating the box. So the client side was CPU-starved, missed the 45s keepalive's response deadline, and the server closed the session BY DESIGN. That is the #143 hardening doing exactly what it was built to do. The client then reported the server disconnected, and the impact matched this issue exactly: every madt_* call gone until a manual /mcp reconnect. New data point: processes spawned under the same client inherit the dead binding, so nothing on that side can recover it. What this discriminates: a silent watchdog plus an empty crash file rules out both stdout backpressure and process death. The evidence now points at the third leg, a starved-but-alive client binding. That raises the design question this occurrence puts on the table. Closing a session on a keepalive miss, when the client is merely SLOW, converts a stall that would have recovered into a hard drop that needs a human. The pre-#143 behavior would have ridden out the load spike. A stdio transport cannot half-break the way HTTP can, because the pipe either works or EOFs, so the ping's real job here is orphan detection, not liveness. Options to consider: a much more generous deadline (minutes, not 22.5s), ping retries before closing, or scaling the deadline when the machine is under load. A side casualty worth its own note: the drop killed an madt_commit mid-staging and left a stale index.lock, which then blocked every later commit on that worktree. Filed as #319 with a proposed detect-or-teach fix. Evidence preserved: a serve.log copy plus the process listing from the incident window, in my notes.

hexajon commented

2026-08-17 15:46:44 +00:00

Author

Owner

3rd recurrence, 2026-07-21 around 18:24 local, with new evidence for the load hypothesis.

Timeline: a 4-item docs batch was running the full ./scripts/gate.sh verification in parallel worktrees, and each gate spawns go test -race ./... plus parallel analyzers. Load average peaked at 118 on the 40-thread machine. In that window, plain git status and git switch on the primary checkout exceeded 120s timeouts, and the session's MCP connection dropped: every madt_* tool returned "No such tool available", and the client marked the server disconnected.

Process evidence at 18:25: one madtea serve process, started the previous evening, still alive with fd 0/1 bound to intact sockets. That is the same signature as the first two occurrences: the server process survives, and the session-side stdio binding is what dies. The session's own serve process was gone from the process table.

The impact is confirmed as filed, plus one escalation: the CLI fallback steering now covers git add and git commit too, so a disconnected session cannot even make LOCAL commits. The lockout is total: forge operations, staging, commits and worktree management. Two of the sessions in that batch responded by working around the steering, one with script indirection and one with git plumbing. The plumbing commit bypassed the repo-local identity config, and I had to catch it in review. A dead-MCP session actively pushes toward hook circumvention. That is worth weighing against a liveness-aware fallback in the steering hooks, which would permit raw local git when the MCP server is provably down, or against a serve-side fix for the disconnect itself.

New data point for the diagnosis ask: this occurrence correlates with extreme machine load, rather than with concurrent multi-client batch reads. That is consistent with a starved stdio pipe, or with a missed heartbeat or timeout on the client side while the server was descheduled. serve still leaves no trace on death or disconnect, so the stderr logging ask from the original report stands.

3rd recurrence, 2026-07-21 around 18:24 local, with new evidence for the load hypothesis. Timeline: a 4-item docs batch was running the full `./scripts/gate.sh` verification in parallel worktrees, and each gate spawns `go test -race ./...` plus parallel analyzers. Load average peaked at 118 on the 40-thread machine. In that window, plain `git status` and `git switch` on the primary checkout exceeded 120s timeouts, and the session's MCP connection dropped: every madt_* tool returned "No such tool available", and the client marked the server disconnected. Process evidence at 18:25: one `madtea serve` process, started the previous evening, still alive with fd 0/1 bound to intact sockets. That is the same signature as the first two occurrences: the server process survives, and the session-side stdio binding is what dies. The session's own serve process was gone from the process table. The impact is confirmed as filed, plus one escalation: the CLI fallback steering now covers `git add` and `git commit` too, so a disconnected session cannot even make LOCAL commits. The lockout is total: forge operations, staging, commits and worktree management. Two of the sessions in that batch responded by working around the steering, one with script indirection and one with git plumbing. The plumbing commit bypassed the repo-local identity config, and I had to catch it in review. A dead-MCP session actively pushes toward hook circumvention. That is worth weighing against a liveness-aware fallback in the steering hooks, which would permit raw local git when the MCP server is provably down, or against a serve-side fix for the disconnect itself. New data point for the diagnosis ask: this occurrence correlates with extreme machine load, rather than with concurrent multi-client batch reads. That is consistent with a starved stdio pipe, or with a missed heartbeat or timeout on the client side while the server was descheduled. serve still leaves no trace on death or disconnect, so the stderr logging ask from the original report stands.

hexajon commented

2026-08-17 15:46:56 +00:00

Author

Owner

I went to retune the keepalive and hit a constraint worth recording before any change lands.

The go-sdk's keepalive has no miss tolerance. From v1.6.1 mcp/shared.go:593-626:

ticker := time.NewTicker(interval)
...
pingCtx, pingCancel := context.WithTimeout(context.Background(), interval/2)
err := session.Ping(pingCtx, nil)
if err != nil {
    if errors.Is(err, jsonrpc2.ErrMethodNotFound) {
        return // peer doesn't support ping, stop keepalive
    }
    logger.Error("keepalive ping failed; closing session", "error", err)
    _ = session.Close()
    return
}

One ping, one timeout of interval/2, and the first failure closes the session. ServerOptions.KeepAlive is a single duration, so the interval and the deadline are not independently settable either. The deadline is always half the interval.

That matters, because the occurrence recorded above was a client that was merely CPU-starved, not gone. Tolerating consecutive misses is exactly the property that would have ridden it out, and it is the one thing the config field cannot express. Lengthening the interval alone only widens the single window: a starved moment that lands on that one tick still drops the session, and a longer interval also delays detection of a genuinely dead peer by the same amount.

So there are two shapes, and they differ in what we own, not only in timing:

Keep using ServerOptions.KeepAlive with a longer interval. No new code, one constant. A 6-minute effective tolerance means an interval around 360s with a 180s deadline. It is still a single probe, so a transient stall that lands on it is still fatal.
Replace it with our own ping loop. Leave ServerOptions.KeepAlive unset, run our own ticker calling ServerSession.Ping, and close only after N consecutive failures. This gets an independent interval and deadline, plus real miss tolerance: a client would have to stay unresponsive across several separate probes before the session closes. It costs roughly the loop above, plus the ErrMethodNotFound case (a peer that does not implement ping must stop the loop, not count as a failure), plus a test.

I lean to (2), because miss tolerance is the property the recorded incident actually needed, and (1) cannot provide it at any interval. It does mean owning a small piece of what the SDK currently does for us, which is a maintenance call rather than a tuning one.

Open until I decide. Nothing has changed yet.

I went to retune the keepalive and hit a constraint worth recording before any change lands. The go-sdk's keepalive has no miss tolerance. From v1.6.1 `mcp/shared.go:593-626`: ```go ticker := time.NewTicker(interval) ... pingCtx, pingCancel := context.WithTimeout(context.Background(), interval/2) err := session.Ping(pingCtx, nil) if err != nil { if errors.Is(err, jsonrpc2.ErrMethodNotFound) { return // peer doesn't support ping, stop keepalive } logger.Error("keepalive ping failed; closing session", "error", err) _ = session.Close() return } ``` One ping, one timeout of `interval/2`, and the first failure closes the session. `ServerOptions.KeepAlive` is a single duration, so the interval and the deadline are not independently settable either. The deadline is always half the interval. That matters, because the occurrence recorded above was a client that was merely CPU-starved, not gone. Tolerating consecutive misses is exactly the property that would have ridden it out, and it is the one thing the config field cannot express. Lengthening the interval alone only widens the single window: a starved moment that lands on that one tick still drops the session, and a longer interval also delays detection of a genuinely dead peer by the same amount. So there are two shapes, and they differ in what we own, not only in timing: 1. **Keep using `ServerOptions.KeepAlive` with a longer interval.** No new code, one constant. A 6-minute effective tolerance means an `interval` around 360s with a 180s deadline. It is still a single probe, so a transient stall that lands on it is still fatal. 2. **Replace it with our own ping loop.** Leave `ServerOptions.KeepAlive` unset, run our own ticker calling `ServerSession.Ping`, and close only after N consecutive failures. This gets an independent interval and deadline, plus real miss tolerance: a client would have to stay unresponsive across several separate probes before the session closes. It costs roughly the loop above, plus the `ErrMethodNotFound` case (a peer that does not implement ping must stop the loop, not count as a failure), plus a test. I lean to (2), because miss tolerance is the property the recorded incident actually needed, and (1) cannot provide it at any interval. It does mean owning a small piece of what the SDK currently does for us, which is a maintenance call rather than a tuning one. Open until I decide. Nothing has changed yet.

hexajon referenced this issue

2026-08-17 15:59:04 +00:00

mcp: aim at the draft spec #414

hexajon referenced this issue

2026-08-27 17:18:59 +00:00

hooks/tests: release-gate.test.sh still scores a crashed gate as "allow" - and the audit scope is an open question #417

Rows
Columns

bug(serve): session MCP connection drops mid-session while madtea serve stays alive (2nd recurrence) #410

Summary

Timeline (2nd occurrence, 2026-07-02)

Process evidence at around 11:27

Impact

Asks

Notes

How stdio client death manifests server-side - three distinct signatures

What go-sdk v1.6.x handles, and what it does not

The SSH angle

Does this explain "client says disconnected, server alive, sockets intact"?

Recommended hardening, queued to build

bug(serve): session MCP connection drops mid-session while `madtea serve` stays alive (2nd recurrence) #410