From 088ba2f8398a1a9799fec13974ab1f9ccf2db813 Mon Sep 17 00:00:00 2001 From: xarmian Date: Thu, 14 May 2026 15:45:51 -0400 Subject: [PATCH] fix(mcp): raise MCP per-token burst + classify 429 as ErrRateLimited (BUG-1430) (#546) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * fix(mcp): raise MCP per-token burst + classify 429 as ErrRateLimited (BUG-1430) BUG-1409 reported an agent hitting "Pad backend 500s on parallel writes" during workspace onboarding via remote MCP on Pad Cloud. Triage split that umbrella into three children; this PR addresses BUG-1430 (the parallel-writes symptom). Root cause investigation showed the underlying write path is fine — local SQLite handled 24 parallel item-create POSTs cleanly (busy_timeout + BEGIN IMMEDIATE + WAL serialize writers without errors). The most plausible cause of the agent's "500 on parallel writes" report is the MCP per-token rate limiter (burst 20, 60/min) rejecting requests 21-24 of an onboarding burst with HTTP 429, which the dispatcher's classifier then collapsed into a generic ErrServerError envelope. Changes: - middleware_ratelimit.go: MCPPerToken burst 20 → 60. Sustained rate unchanged at 60/min/token. Matches the general API limiter's burst-60 per-user cap so the MCP path no longer imposes a tighter ceiling than the equivalent /api/v1 path. Comment expanded to record the rationale. - internal/mcp/errors.go: add ErrRateLimited error code and an explicit case http.StatusTooManyRequests in classifyHTTPStatusKind. 429s now surface as a first-class rate-limited envelope with an actionable hint pointing at Retry-After and the per-token cap, instead of landing in the generic ErrServerError "other 4xx" bucket. Agents implementing exponential backoff can switch on code without parsing free-form text. - handlers_cloud.go: add slog.Error instrumentation to enforcePlanLimit and enforceUserPlanLimit error paths. These are cloud-mode-only 500 candidates we couldn't exercise locally (local dev runs cloudMode=false); the structured logs give operators a grep-able tag the next time the symptom surfaces on real Pad Cloud, so we can rule the path in or out empirically without another investigation pass. - tests: bump iteration counts past the new burst (20 → 60), add 429 case to classifyHTTPStatus code-mapping table + envelope hint-shape table. Investigation context (full triage in BUG-1430): - ../pad-cloud sidecar is NOT in the /api/v1 or /mcp request path (nginx-router proxies those directly to pad backend). - featureCount + advisory-lock contention on Postgres remain plausible 500 candidates under heavy bursts; the new logging is intended to catch those if they fire. Siblings BUG-1431 (status field placement) and BUG-1432 (tags field) are tracked separately and not addressed here. * fix(mcp): drop hardcoded cap from rate-limit hint per Codex review (round 1) Codex round 1 [P2] caught that rateLimitHintFor's "the per-token cap is 60 req/min with a burst of 60" text was misleading: classifyHTTPStatusKind handles 429s from the dispatcher's SYNTHESIZED /api/v1/... requests, which come from the general API limiter (600/min, burst 60), the Search limiter (30/min, burst 10), and potentially others — NOT the MCP per-token limiter (which fires before the dispatcher runs and so never lands in this classifier path). Generalize the hint: point at Retry-After (which carries the correct limiter-specific wait) and drop the cap from prose. Update the matching test assertion to assert the generic shape ("burst-heavy" instead of "60 req/min"). --- .../dispatch_http_envelope_uniform_test.go | 16 +++++ internal/mcp/errors.go | 60 +++++++++++++++++++ internal/mcp/errors_test.go | 5 ++ internal/server/handlers_cloud.go | 24 ++++++++ internal/server/handlers_mcp_test.go | 17 ++++-- internal/server/middleware_mcp_audit_test.go | 7 ++- internal/server/middleware_ratelimit.go | 46 ++++++++++---- 7 files changed, 155 insertions(+), 20 deletions(-) diff --git a/internal/mcp/dispatch_http_envelope_uniform_test.go b/internal/mcp/dispatch_http_envelope_uniform_test.go index bf911e79..b8b0e1ae 100644 --- a/internal/mcp/dispatch_http_envelope_uniform_test.go +++ b/internal/mcp/dispatch_http_envelope_uniform_test.go @@ -180,12 +180,28 @@ func TestClassifyHTTPStatus_HintsAreActionable(t *testing.T) { body: []byte(`{"error":{"message":"db down"}}`), mustContain: []string{"transient", "retry", "500"}, }, + { + // BUG-1430: 429 hint points at backoff + Retry-After so + // agents implementing backoff can adjust without parsing + // free-form prose. Cap is intentionally NOT named in the + // hint — classifyHTTPStatusKind handles synthesized + // /api/v1/... 429s which can come from several limiters + // with different sizing (Codex review #546 round 1 [P2]). + name: "429 hint suggests backoff + points at Retry-After", + kind: ResourceItem, // kind doesn't matter for 429 + ref: "TASK-7", + route: "/api/v1/workspaces/foo/items/TASK-7", + body: []byte(`{"error":{"code":"rate_limited","message":"Too many requests."}}`), + mustContain: []string{"Rate-limited", "Retry-After", "burst-heavy"}, + }, } for _, tc := range cases { t.Run(tc.name, func(t *testing.T) { status := 404 if strings.Contains(tc.name, "5xx") { status = 500 + } else if strings.Contains(tc.name, "429") { + status = 429 } res := classifyHTTPStatusKind(context.Background(), "test cmd", tc.route, status, tc.body, nil, tc.kind, tc.ref) diff --git a/internal/mcp/errors.go b/internal/mcp/errors.go index 20124c68..146d6c2b 100644 --- a/internal/mcp/errors.go +++ b/internal/mcp/errors.go @@ -114,6 +114,19 @@ const ( // from exec, etc. The wrapped message preserves the underlying // detail for debugging without promising any structured shape. ErrServerError ErrorCode = "server_error" + + // ErrRateLimited fires on HTTP 429 responses — either the + // general API limiter (per-user, 600/min, burst 60) or the + // MCP per-token limiter (60/min/token, burst 60 post-BUG-1430) + // rejecting a synthesized request. Distinct from + // ErrServerError so agents implementing exponential backoff + // can switch on code without parsing free-form text. Pre- + // BUG-1430 this collapsed into ErrServerError, which led the + // triggering agent to describe a 429 burst as "backend 500s + // on parallel writes" — see BUG-1409. The hint includes the + // upstream message so agents have a chance of recognizing + // transient vs persistent throttling. + ErrRateLimited ErrorCode = "rate_limited" ) // ErrorEnvelope is the wire shape returned to MCP clients on tool @@ -632,6 +645,23 @@ func classifyHTTPStatusKind( Message: "Validation failed.", Hint: validationHintFor(bodyMessage, route), }) + case http.StatusTooManyRequests: + // BUG-1430: pre-existing behavior collapsed 429 into the + // generic ErrServerError "other 4xx" bucket, which led + // the triggering agent to report a parallel-write burst + // as "backend 500s." Surface 429 as a first-class + // ErrRateLimited so agents can implement code-based + // backoff instead of parsing free-form text. The hint + // mentions the Retry-After header (set on the response + // by writeRateLimitResponse / writeMCPRateLimit) since + // the dispatcher's body-only signature loses the headers + // — a future enhancement could surface the parsed value + // directly in the envelope. + return NewErrorResult(ErrorPayload{ + Code: ErrRateLimited, + Message: fmt.Sprintf("pad %s rate-limited (HTTP 429)", cmdKey), + Hint: rateLimitHintFor(bodyMessage, route), + }) } if status >= 500 { @@ -927,6 +957,36 @@ func serverHintFor(bodyMsg, route string, status int) string { return strings.Join(parts, " ") } +// rateLimitHintFor generates the actionable hint for ErrRateLimited. +// 429s are recoverable with backoff — the hint encodes that bias and +// points at the Retry-After response header. BUG-1430 added this +// helper alongside the dedicated case in classifyHTTPStatusKind so +// agents see a distinct envelope for "back off" vs ErrServerError's +// "file a bug" framing. +// +// The hint is intentionally generic about the cap. classifyHTTPStatusKind +// handles 429s from the dispatcher's SYNTHESIZED /api/v1/... requests, +// which can fire from several different limiters with different sizing +// (the general API limiter at 600/min/burst-60, the Search limiter at +// 30/min/burst-10, etc.) — Codex review #546 round 1 [P2] caught the +// first draft of this hint hard-coding the MCP per-token cap, which +// fires BEFORE the dispatcher runs and so never lands here. The +// Retry-After header carries the limiter-specific wait time; agents +// honoring it get correct backoff without needing the cap in prose. +func rateLimitHintFor(bodyMsg, route string) string { + parts := []string{ + "Rate-limited by the backend. Retry after a backoff (see the Retry-After response header for the suggested wait).", + "For burst-heavy workflows (agent onboarding, bulk import), space out tool calls or sequence them.", + } + if route != "" { + parts = append(parts, fmt.Sprintf("Route: %s.", route)) + } + if bodyMsg != "" { + parts = append(parts, fmt.Sprintf("Backend: %s", bodyMsg)) + } + return strings.Join(parts, " ") +} + // ───────────────────────────────────────────────────────────────────── // Helpers for non-HTTP error paths (TASK-1077 — replace plain-string // NewToolResultErrorf with structured envelopes uniformly). diff --git a/internal/mcp/errors_test.go b/internal/mcp/errors_test.go index 9f4468a2..d1243d6d 100644 --- a/internal/mcp/errors_test.go +++ b/internal/mcp/errors_test.go @@ -176,6 +176,11 @@ func TestClassifyHTTPStatus(t *testing.T) { // "backend hiccup, retry" from "dispatcher bug, escalate." {"500_upstream", http.StatusInternalServerError, "boom", ErrUpstreamError}, {"503_upstream", http.StatusServiceUnavailable, "down", ErrUpstreamError}, + // BUG-1430: 429 is now a first-class ErrRateLimited code, + // distinct from the generic ErrServerError "other 4xx" bucket + // it landed in pre-fix. Agents implementing backoff key off + // the code without parsing free-form text. + {"429_rate_limited", http.StatusTooManyRequests, "rate_limited", ErrRateLimited}, {"418_other", http.StatusTeapot, "weird", ErrServerError}, } for _, tc := range cases { diff --git a/internal/server/handlers_cloud.go b/internal/server/handlers_cloud.go index 70cc2698..d38229c0 100644 --- a/internal/server/handlers_cloud.go +++ b/internal/server/handlers_cloud.go @@ -1058,6 +1058,21 @@ func (s *Server) enforcePlanLimit(w http.ResponseWriter, workspaceID, feature st result, err := s.store.CheckLimit(workspaceID, feature) if err != nil { + // BUG-1430 follow-up: enforcePlanLimit is one of the few + // cloud-mode-only 500 paths in the item-create handler chain + // (it fans out into 3 Postgres queries — workspace owner + // lookup, user fetch, feature count). Under bursty workloads + // like agent onboarding (24 parallel item creates fanned out + // from a single MCP session) it's a plausible source of + // "backend 500" symptoms that local SQLite testing can't + // reproduce. Logging with workspace_id + feature + the + // underlying error gives operators a grep-able tag for the + // next time the symptom surfaces on real Pad Cloud. Costs + // nothing in the happy path. + slog.Error("enforcePlanLimit: CheckLimit failed", + "workspace_id", workspaceID, + "feature", feature, + "error", err) writeInternalError(w, err) return false } @@ -1078,6 +1093,15 @@ func (s *Server) enforceUserPlanLimit(w http.ResponseWriter, userID, feature str result, err := s.store.CheckUserLimit(userID, feature) if err != nil { + // BUG-1430 follow-up: symmetric observability for the + // user-scoped sibling. Same rationale as enforcePlanLimit — + // any DB error here surfaces to the agent as a generic 500 + // (which the MCP dispatcher then relays as ErrUpstreamError), + // and we want a grep-able tag in the logs to debug. + slog.Error("enforceUserPlanLimit: CheckUserLimit failed", + "user_id", userID, + "feature", feature, + "error", err) writeInternalError(w, err) return false } diff --git a/internal/server/handlers_mcp_test.go b/internal/server/handlers_mcp_test.go index 278aa0c7..24032484 100644 --- a/internal/server/handlers_mcp_test.go +++ b/internal/server/handlers_mcp_test.go @@ -951,8 +951,13 @@ func TestMCPRateLimit_PerToken_BucketEnforced(t *testing.T) { srv := mcpEnabledTestServer(t) pat := mustCreatePATForTest(t, srv, "rate-limit-bucket") + // Bucket is burst=60 (raised from 20 under BUG-1430 to accommodate + // agent-onboarding bursts). Loop slightly past the burst to give + // the limiter time to deny the (burst+1)th request — the rate + // (1/sec) refills slowly enough that we won't accidentally pad + // our way through. got429 := false - for i := 0; i < 30; i++ { + for i := 0; i < 80; i++ { req := httptest.NewRequest("POST", "/mcp", strings.NewReader(`{}`)) req.Header.Set("Authorization", "Bearer "+pat) req.RemoteAddr = "192.0.2.1:1234" @@ -968,7 +973,7 @@ func TestMCPRateLimit_PerToken_BucketEnforced(t *testing.T) { } } if !got429 { - t.Errorf("expected 429 within 30 requests on a single token bucket (60/min, burst 20); never saw it") + t.Errorf("expected 429 within 80 requests on a single token bucket (60/min, burst 60); never saw it") } } @@ -986,7 +991,9 @@ func TestMCPRateLimit_PerToken_TwoTokensIndependent(t *testing.T) { pat2 := mustCreatePATForTest(t, srv, "rate-limit-pat-2") hammer := func(bearer string) (rrs []*httptest.ResponseRecorder) { - for i := 0; i < 30; i++ { + // BUG-1430 raised burst to 60; loop past it so the (burst+1)th + // request drains the bucket and 429s. + for i := 0; i < 80; i++ { req := httptest.NewRequest("POST", "/mcp", strings.NewReader(`{}`)) req.Header.Set("Authorization", "Bearer "+bearer) req.RemoteAddr = "192.0.2.1:1234" @@ -1204,8 +1211,10 @@ func TestMCPRateLimit_429EnvelopeShape(t *testing.T) { srv := mcpEnabledTestServer(t) pat := mustCreatePATForTest(t, srv, "rate-limit-envelope") + // BUG-1430 raised the MCP per-token burst to 60. Loop past it so + // the (burst+1)th request drains the bucket. var limited *httptest.ResponseRecorder - for i := 0; i < 30; i++ { + for i := 0; i < 80; i++ { req := httptest.NewRequest("POST", "/mcp", strings.NewReader(`{}`)) req.Header.Set("Authorization", "Bearer "+pat) req.RemoteAddr = "192.0.2.1:1234" diff --git a/internal/server/middleware_mcp_audit_test.go b/internal/server/middleware_mcp_audit_test.go index c6376296..0f0d0207 100644 --- a/internal/server/middleware_mcp_audit_test.go +++ b/internal/server/middleware_mcp_audit_test.go @@ -300,9 +300,10 @@ func TestMCPAudit_RateLimited_RecordsDeniedRow(t *testing.T) { } // Hammer until we see a 429 — same pattern as the existing - // rate-limit tests. + // rate-limit tests. BUG-1430 raised burst to 60, so loop past it + // to drain the bucket; the (burst+1)th request 429s. got429 := false - for i := 0; i < 30; i++ { + for i := 0; i < 80; i++ { req := httptest.NewRequest("POST", "/mcp", strings.NewReader(`{"jsonrpc":"2.0","id":1,"method":"tools/call","params":{"name":"pad_item"}}`)) req.Header.Set("Authorization", "Bearer "+pat) @@ -316,7 +317,7 @@ func TestMCPAudit_RateLimited_RecordsDeniedRow(t *testing.T) { } } if !got429 { - t.Fatal("never hit 429 within 30 requests") + t.Fatal("never hit 429 within 80 requests") } // Wait for the async audit writer to drain. Burst sent + 1 denied diff --git a/internal/server/middleware_ratelimit.go b/internal/server/middleware_ratelimit.go index e91914c1..5525dc7a 100644 --- a/internal/server/middleware_ratelimit.go +++ b/internal/server/middleware_ratelimit.go @@ -154,12 +154,17 @@ type RateLimiters struct { // for other tokens. Keyed by SHA-256(bearer) so the raw token // never lives in the limiter map. // - // 60 requests / minute / token, burst 20. Sized for chatty - // usage (Claude Desktop sends `tools/list` + a handful of tool - // calls per session) without leaving headroom for sustained - // abuse. Retention 5 minutes — long enough to remember a quiet - // token between calls, short enough that the limiter doesn't - // hold dead tokens forever after revocation. + // 60 requests / minute / token, burst 60 (post-BUG-1430; was + // originally 20). The original burst was sized for chatty + // interactive usage; agentic batch onboarding regularly fans + // out 20-30 parallel tool calls (workspace setup, item-create + // bursts), so the burst was raised to match the general API + // limiter's burst-60-per-user cap. Sustained rate stays 60/min + // — abuse still gets throttled, just after a roomier burst. + // + // Retention 5 minutes — long enough to remember a quiet token + // between calls, short enough that the limiter doesn't hold + // dead tokens forever after revocation. MCPPerToken *ipRateLimiter } @@ -227,18 +232,33 @@ func NewRateLimiters() *RateLimiters { Rate: rate.Limit(6.0 / 3600.0), Burst: 6, }), - // MCP per-token: 60 req/min sustained, burst 20. PLAN-943 - // TASK-959. 60/60 = 1 req/sec — written with explicit math - // rather than `rate.Limit(1)` so adjacent limiters' "X / - // 60" idiom stays consistent at a glance, but staticcheck - // SA4000 flags identical-numerator-denominator division — - // hence the explicit literal. + // MCP per-token: 60 req/min sustained, burst 60. PLAN-943 + // TASK-959, bumped under BUG-1430. 60/60 = 1 req/sec — + // written with explicit math rather than `rate.Limit(1)` + // so adjacent limiters' "X / 60" idiom stays consistent at + // a glance, but staticcheck SA4000 flags identical- + // numerator-denominator division — hence the explicit + // literal. + // + // Burst was originally 20, sized for "chatty interactive + // use (Claude Desktop sends tools/list + a handful of tool + // calls per session)." Agentic batch onboarding workloads + // regularly exceed that — a fresh-workspace setup may fan + // out 20-30 parallel `pad_item create` tool calls, and the + // 21st+ failing with rate_limited (HTTP 429) on a brand-new + // connection is a hostile first impression. Raising to 60 + // matches the general API limiter's burst (per-user, + // 600/min, burst 60), so the MCP path doesn't impose a + // tighter ceiling than the equivalent /api/v1 path. The + // sustained 60/min rate stays unchanged — abuse still gets + // throttled, just after a roomier burst. + // // The 5-minute retention lets the limiter forget dead // tokens reasonably quickly after revocation while still // surviving idle periods between tool calls. MCPPerToken: newIPRateLimiter(rateLimitConfig{ Rate: rate.Limit(1.0), // 60 req/min = 1 req/sec - Burst: 20, + Burst: 60, Retention: 5 * time.Minute, }), }