From 933dd92c50c48c231782b6a4aa43c5bd35c44f4f Mon Sep 17 00:00:00 2001 From: packetloss404 Date: Sat, 5 Sep 2026 14:21:47 -0500 Subject: [PATCH] fix the two intermittent test failures, both of them real bugs Neither was a test defect. internal/mcp: reaperLoop calls cmd.Wait, and os/exec closes the pipes it created once Wait sees the child exit. A read still in flight then fails with "read |0: file already closed" instead of reporting EOF -- the reader simply lost a race. That error was recorded as the cause of death, and because markDead is first-writer-wins the reaper's clean exit status could never replace it, so Close reported a shutdown failure for a server that had stopped perfectly normally. On quit a user would see "mcp: server exited: read |0: file already closed" for a healthy server. os.ErrClosed is now classified exactly like EOF: provisional, leaving the reaper's status to win. The decision moves into exitReasonFromRead, a pure function, so it is tested directly rather than by losing the race on purpose. internal/acp: the session's active flag was cleared in a deferred function, which runs after the prompt response is already on the wire. A client that reads the response and immediately sends session/load -- which is what switching sessions looks like, and what the test does -- could be rejected with "session already has an active prompt". It is now cleared immediately before each terminal response, with the defer kept as a safety net for any future path that returns without sending one. The ordering the defer existed for is preserved: every trailing update is already written by then, so a replay still cannot interleave with this prompt's final updates. Evidence in both directions. With the acp clear reverted to defer-only, 300 iterations reproduce the exact CI failure; with the fix, 300 iterations pass and 100 more under -race. The mcp shutdown test passes 40 consecutive runs and the package passes three times under -race, and two subtests of the new classifier test fail when the ErrClosed handling is removed. Co-Authored-By: Claude Opus 5 --- internal/acp/server.go | 26 +++++++-- internal/mcp/client.go | 39 +++++++++---- internal/mcp/exit_reason_test.go | 99 ++++++++++++++++++++++++++++++++ 3 files changed, 148 insertions(+), 16 deletions(-) create mode 100644 internal/mcp/exit_reason_test.go diff --git a/internal/acp/server.go b/internal/acp/server.go index ed89f61..06d57d3 100644 --- a/internal/acp/server.go +++ b/internal/acp/server.go @@ -1323,14 +1323,26 @@ func (s *Server) runPrompt(ctx context.Context, requestID json.RawMessage, sessi cancelled := state.cancelled || ctx.Err() != nil state.cancel = nil state.mu.Unlock() - // active stays set until every trailing update and the prompt response have - // been written, so a session/load landing mid-teardown is rejected as busy - // instead of interleaving its replay with this prompt's final updates. - defer func() { + // active stays set until every trailing update for this prompt has been + // written, so a session/load landing mid-teardown cannot interleave its + // replay with them. It must then be cleared *before* the prompt response, + // not after: the response is the last thing the client sees for this + // prompt, so a client that reads it and immediately sends session/load is + // entitled to be served. Clearing in a deferred function ran after the + // response was already on the wire, leaving a window in which a perfectly + // well-behaved re-load was rejected with "session already has an active + // prompt" -- which is what made TestServerLoadSessionReplaysHistoryBeforeResponse + // fail intermittently, and would reject a real client doing the same thing. + // + // Each terminal path below calls this immediately before its response. The + // defer stays as a safety net for any future path that returns without + // sending one; clearing twice is harmless. + clearActive := func() { state.mu.Lock() state.active = false state.mu.Unlock() - }() + } + defer clearActive() if cancelled || runErr != nil { for id := range openCalls { @@ -1347,15 +1359,18 @@ func (s *Server) runPrompt(ctx context.Context, requestID json.RawMessage, sessi // Plan entries have no cancelled state in ACP v1. Replace the complete // plan with an empty list so clients do not retain an in-progress task. s.sendUpdate(sessionID, map[string]any{"sessionUpdate": "plan", "entries": []any{}}) + clearActive() s.sendResult(requestID, map[string]string{"stopReason": "cancelled"}) return } if runErr != nil { s.sendUpdate(sessionID, map[string]any{"sessionUpdate": "plan", "entries": []any{}}) + clearActive() s.sendError(requestID, codeInternalError, runErr.Error(), nil) return } if !done { + clearActive() s.sendError(requestID, codeInternalError, "agent event stream ended without a terminal event", nil) return } @@ -1374,6 +1389,7 @@ func (s *Server) runPrompt(ctx context.Context, requestID json.RawMessage, sessi fmt.Fprintf(s.log, "packetcode acp: read usage for session %s: %v\n", sessionID, err) } } + clearActive() s.sendResult(requestID, result) } diff --git a/internal/mcp/client.go b/internal/mcp/client.go index 5b49a37..df295f0 100644 --- a/internal/mcp/client.go +++ b/internal/mcp/client.go @@ -421,17 +421,7 @@ func (c *Client) readerLoop() { if err == nil { err = io.EOF } - // Provisional when there is still a child to reap. EOF on stdout is not a - // cause of death, it is the first symptom -- and recording it as the cause - // is worse than recording nothing, because "exited: EOF" reads like an - // explanation and displaces the real one. The reaper replaces this with the - // exit status. A scanner error is kept: that one really is what happened to - // the stream, and the reaper's status does not describe it. - if c.cmd != nil && errors.Is(err, io.EOF) { - c.markDead(pendingExit()) - } else { - c.markDead(eofExit(err)) - } + c.markDead(exitReasonFromRead(err, c.cmd != nil)) c.flushPendingExited() } @@ -450,6 +440,33 @@ func eofExit(underlying error) error { return &serverExitError{underlying: underlying} } +// exitReasonFromRead classifies the error that ended the reader loop. +// +// EOF on stdout is not a cause of death, it is the first symptom, and +// recording it as the cause is worse than recording nothing: "exited: EOF" +// reads like an explanation and displaces the real one. When there is still +// a child to reap, the reason is left provisional and the reaper replaces it +// with the exit status. +// +// os.ErrClosed is the same symptom wearing a different coat. os/exec closes +// the pipes it created once Wait sees the child exit, so a read still in +// flight fails with "file already closed" instead of reporting EOF -- the +// scanner simply lost a race with reaperLoop. It says nothing about the +// server's health, and because markDead is first-writer-wins, recording it +// as the cause makes it stick: the reaper's clean exit path cannot overwrite +// it, and Close then reports a shutdown failure for a server that stopped +// perfectly normally. That is the whole of the intermittent +// TestManager_Shutdown_AllClients failure. +// +// Any other scanner error is kept, because that one really is what happened +// to the stream and the reaper's status does not describe it. +func exitReasonFromRead(err error, haveChild bool) error { + if haveChild && (errors.Is(err, io.EOF) || errors.Is(err, os.ErrClosed)) { + return pendingExit() + } + return eofExit(err) +} + // DeathReasonWait is how long a diagnostic should wait for a dying server's // exit status. The gap between stdout closing and cmd.Wait returning is // normally sub-millisecond -- the reaper is already blocked in Wait when the diff --git a/internal/mcp/exit_reason_test.go b/internal/mcp/exit_reason_test.go new file mode 100644 index 0000000..54e1189 --- /dev/null +++ b/internal/mcp/exit_reason_test.go @@ -0,0 +1,99 @@ +package mcp + +import ( + "errors" + "fmt" + "io" + "os" + "testing" +) + +// The reader loop ends for several reasons and only some of them are the +// server's fault. Getting this wrong is not cosmetic: markDead is +// first-writer-wins, so a reason recorded here cannot be replaced by the +// reaper's clean exit status, and Close surfaces it as a shutdown failure. +func TestExitReasonFromRead(t *testing.T) { + tests := []struct { + name string + err error + haveChild bool + wantClean bool + }{ + { + name: "EOF with a child to reap is provisional", + err: io.EOF, + haveChild: true, + wantClean: true, + }, + { + // os/exec closes the pipes it created once Wait sees the child + // exit, so a read still in flight fails with "file already + // closed" rather than reporting EOF. The scanner lost a race with + // reaperLoop; the server is fine. + name: "a pipe closed by cmd.Wait is provisional", + err: &os.PathError{Op: "read", Path: "|0", Err: os.ErrClosed}, + haveChild: true, + wantClean: true, + }, + { + name: "a wrapped ErrClosed is still provisional", + err: fmt.Errorf("scanner: %w", os.ErrClosed), + haveChild: true, + wantClean: true, + }, + { + // With no child to reap, nothing is coming to replace the reason, + // so it records EOF concretely instead of staying provisional. It + // is still a clean shutdown: closeExitErr filters a wrapped EOF. + name: "EOF with no child records the exit and is still clean", + err: io.EOF, + haveChild: false, + wantClean: true, + }, + { + // A real stream failure is what happened, and the reaper's exit + // status does not describe it. + name: "a genuine read failure is kept", + err: errors.New("connection reset by peer"), + haveChild: true, + wantClean: false, + }, + } + + for _, tc := range tests { + t.Run(tc.name, func(t *testing.T) { + reason := exitReasonFromRead(tc.err, tc.haveChild) + if !errors.Is(reason, ErrServerExited) { + t.Fatalf("reason %v does not wrap ErrServerExited", reason) + } + + // closeExitErr is what decides whether Close reports a failure, + // so assert through it rather than on the shape of the value. + got := closeExitErr(reason) + if tc.wantClean && got != nil { + t.Errorf("Close would report %v, want a clean shutdown", got) + } + if !tc.wantClean && got == nil { + t.Errorf("Close would report success, want the reason surfaced") + } + }) + } +} + +// The pipe-closed case is the one that made TestManager_Shutdown_AllClients +// fail intermittently, so pin it end to end: the reason it produces must be +// the provisional one, which is what lets the reaper's exit status win. +func TestExitReasonFromRead_ClosedPipeStaysReplaceable(t *testing.T) { + reason := exitReasonFromRead(&os.PathError{Op: "read", Path: "|0", Err: os.ErrClosed}, true) + + var exit *serverExitError + if !errors.As(reason, &exit) { + t.Fatalf("reason %v is not a serverExitError", reason) + } + if !exit.pending { + t.Fatal("a pipe closed by cmd.Wait must be provisional, or the reaper cannot replace it") + } + if exit.underlying != nil { + t.Errorf("underlying = %v, want nil: the closed pipe is not the cause of death", exit.underlying) + } +}