From b9383bbcfdacdca83855f2d248cb528ebb0810fd Mon Sep 17 00:00:00 2001 From: Colin McDonnell Date: Thu, 14 May 2026 03:59:45 +0000 Subject: [PATCH] action: center provider-error log excerpt on the matched line (closes #703) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit the `» provider error detected (...)` excerpt was `chunk.substring(0, 500)` — the head of whatever stderr buffer node delivered. on big writes that's the front of an mcp tool-schema dump, not the matched error text. label was correct (regex.test on the whole chunk), excerpt was misleading. introduce findProviderErrorMatch(text) that returns { label, excerpt } where excerpt is a windowed slice centered on the regex match index: the matched line plus 1 line before and 2 lines after, hard-capped at 600 bytes. detectProviderError stays as a thin wrapper for label-only callers. both opencode and claude harnesses log match.excerpt instead of chunk.substring(0, 500). regression tests cover the multi-line buffer case, surrounding-line context, byte-cap fallback to matched-line-only, and head truncation of a single oversize line. --- agents/claude.ts | 10 +++--- agents/opencode.ts | 10 +++--- utils/providerErrors.test.ts | 64 +++++++++++++++++++++++++++++++++++- utils/providerErrors.ts | 62 ++++++++++++++++++++++++++++++++-- 4 files changed, 133 insertions(+), 13 deletions(-) diff --git a/agents/claude.ts b/agents/claude.ts index d0893bc..61eacdf 100644 --- a/agents/claude.ts +++ b/agents/claude.ts @@ -21,7 +21,7 @@ import { BEDROCK_MODEL_ID_ENV, isBedrockAnthropicId } from "../models.ts"; import { getIdleMs, markActivity } from "../utils/activity.ts"; import { formatJsonValue, log } from "../utils/cli.ts"; import { installFromNpmTarball } from "../utils/install.ts"; -import { detectProviderError } from "../utils/providerErrors.ts"; +import { findProviderErrorMatch } from "../utils/providerErrors.ts"; import { addSkill, installBundledSkills } from "../utils/skills.ts"; import { DEFAULT_MAX_RETAINED_BYTES, @@ -639,10 +639,10 @@ export async function runClaude(params: RunParams): Promise { recentStderr.push(trimmed); if (recentStderr.length > MAX_STDERR_LINES) recentStderr.shift(); - const providerError = detectProviderError(trimmed); - if (providerError) { - lastProviderError = providerError; - log.info(`» provider error detected (${providerError}): ${trimmed.substring(0, 500)}`); + const match = findProviderErrorMatch(trimmed); + if (match) { + lastProviderError = match.label; + log.info(`» provider error detected (${match.label}): ${match.excerpt}`); } else { log.debug(trimmed); } diff --git a/agents/opencode.ts b/agents/opencode.ts index 9ba3f4c..b497e0c 100644 --- a/agents/opencode.ts +++ b/agents/opencode.ts @@ -20,7 +20,7 @@ import { BEDROCK_MODEL_ID_ENV, modelAliases } from "../models.ts"; import { getIdleMs, markActivity } from "../utils/activity.ts"; import { formatJsonValue, log } from "../utils/cli.ts"; import { installFromNpmTarball } from "../utils/install.ts"; -import { detectProviderError } from "../utils/providerErrors.ts"; +import { findProviderErrorMatch } from "../utils/providerErrors.ts"; import { addSkill, installBundledSkills } from "../utils/skills.ts"; import { DEFAULT_MAX_RETAINED_BYTES, @@ -1032,10 +1032,10 @@ async function runOpenCode(params: RunParams): Promise { recentStderr.push(trimmed); if (recentStderr.length > MAX_STDERR_LINES) recentStderr.shift(); - const providerError = detectProviderError(trimmed); - if (providerError) { - lastProviderError = providerError; - log.info(`» provider error detected (${providerError}): ${trimmed.substring(0, 500)}`); + const match = findProviderErrorMatch(trimmed); + if (match) { + lastProviderError = match.label; + log.info(`» provider error detected (${match.label}): ${match.excerpt}`); } else { log.debug(trimmed); } diff --git a/utils/providerErrors.test.ts b/utils/providerErrors.test.ts index 45421e5..f0904f2 100644 --- a/utils/providerErrors.test.ts +++ b/utils/providerErrors.test.ts @@ -1,4 +1,8 @@ -import { detectProviderError, isRouterKeylimitExhaustedError } from "./providerErrors.ts"; +import { + detectProviderError, + findProviderErrorMatch, + isRouterKeylimitExhaustedError, +} from "./providerErrors.ts"; describe("detectProviderError", () => { describe("false positives previously seen in production", () => { @@ -116,6 +120,64 @@ describe("detectProviderError", () => { }); }); +describe("findProviderErrorMatch", () => { + // regression for issue #703: when stderr arrives as a multi-KB buffer + // (mcp tool-schema dump + the actual error message), the old + // `chunk.substring(0, 500)` excerpt showed the head of the buffer + // (schema) instead of the matched error text. the windowed excerpt + // must center on the matched line. + it("excerpt centers on the matched line, not the head of the buffer", () => { + const schemaDump = + "{".repeat(2000) + + '"name":"pullfrog_create_pull_request_review","description":"Submit a review..."'; + const errorLine = "ERROR 2026-05-13 service=session error=rate_limit_exceeded retry-after=30"; + const chunk = `${schemaDump}\n${errorLine}\ncaller stack at handler.ts:42`; + + const match = findProviderErrorMatch(chunk); + expect(match).not.toBeNull(); + expect(match?.label).toBe("rate limited"); + expect(match?.excerpt).toContain("rate_limit_exceeded"); + expect(match?.excerpt).toContain("retry-after=30"); + expect(match?.excerpt).not.toContain("pullfrog_create_pull_request_review"); + }); + + it("includes a small surrounding-line window for stack-trace context", () => { + const chunk = + "» about to call session.processor\n" + + "ERROR rate_limit_exceeded for key=abc\n" + + "at handler.ts:42\n" + + "at runtime.ts:88"; + const match = findProviderErrorMatch(chunk); + expect(match?.excerpt).toContain("about to call session.processor"); + expect(match?.excerpt).toContain("rate_limit_exceeded"); + expect(match?.excerpt).toContain("handler.ts:42"); + expect(match?.excerpt).toContain("runtime.ts:88"); + }); + + it("falls back to the matched line alone when adjacent lines are huge", () => { + const giantPrefix = "x".repeat(5000); + const errorLine = '"statusCode": 429, "message": "slow down"'; + const giantSuffix = "y".repeat(5000); + const chunk = `${giantPrefix}\n${errorLine}\n${giantSuffix}`; + + const match = findProviderErrorMatch(chunk); + expect(match?.label).toBe("rate limited (429)"); + expect(match?.excerpt).toBe(errorLine); + }); + + it("head-truncates the matched line if it alone exceeds the byte cap", () => { + const padding = "z".repeat(700); + const chunk = `${padding} "statusCode": 429 ${padding}`; + const match = findProviderErrorMatch(chunk); + expect(match?.label).toBe("rate limited (429)"); + expect(match?.excerpt.length).toBeLessThanOrEqual(600); + }); + + it("returns null when no pattern matches", () => { + expect(findProviderErrorMatch("just some normal log line\nnothing wrong here")).toBeNull(); + }); +}); + describe("isRouterKeylimitExhaustedError", () => { it("matches the canonical OpenRouter mid-run error", () => { expect( diff --git a/utils/providerErrors.ts b/utils/providerErrors.ts index c2d40c0..1cf071c 100644 --- a/utils/providerErrors.ts +++ b/utils/providerErrors.ts @@ -41,13 +41,71 @@ const PROVIDER_ERROR_PATTERNS: ProviderErrorPattern[] = [ { regex: /["']?\blimit\b["']?\s*:\s*0\b/, label: "zero quota" }, ]; -export function detectProviderError(text: string): string | null { +/** + * Result of a provider-error scan: the classification label plus a + * human-readable excerpt centered on the matched line. The excerpt is what + * gets surfaced in `» provider error detected (...)` log lines — see + * `extractExcerpt` for the windowing/byte-cap policy. + */ +export type ProviderErrorMatch = { + label: string; + excerpt: string; +}; + +// roughly half a wide terminal line by 4–5 lines of context; large enough +// to capture a structured error payload (request id, retry-after, model) +// plus its immediate stack/headers, small enough to not flood the log. +const EXCERPT_MAX_BYTES = 600; +const LINES_BEFORE = 1; +const LINES_AFTER = 2; + +export function findProviderErrorMatch(text: string): ProviderErrorMatch | null { for (const entry of PROVIDER_ERROR_PATTERNS) { - if (entry.regex.test(text)) return entry.label; + const m = entry.regex.exec(text); + if (!m) continue; + return { label: entry.label, excerpt: extractExcerpt(text, m.index) }; } return null; } +export function detectProviderError(text: string): string | null { + return findProviderErrorMatch(text)?.label ?? null; +} + +/** + * Slice a context window around `matchIndex`: the matched line plus + * `LINES_BEFORE`/`LINES_AFTER` neighbours. If the windowed slice exceeds + * `EXCERPT_MAX_BYTES` (giant adjacent lines, e.g. JSON tool-schema dumps), + * fall back to the matched line alone, head-truncated if still too long. + * Replaces the old `chunk.substring(0, 500)` head-anchored excerpt which + * surfaced whatever happened to be at the front of the stderr buffer + * instead of the error itself. See issue #703. + */ +function extractExcerpt(text: string, matchIndex: number): string { + const lineStart = text.lastIndexOf("\n", matchIndex - 1) + 1; + const lineEndRaw = text.indexOf("\n", matchIndex); + const lineEnd = lineEndRaw === -1 ? text.length : lineEndRaw; + + let start = lineStart; + for (let i = 0; i < LINES_BEFORE && start > 0; i++) { + const prev = text.lastIndexOf("\n", start - 2); + start = prev < 0 ? 0 : prev + 1; + } + + let end = lineEnd; + for (let i = 0; i < LINES_AFTER && end < text.length; i++) { + const next = text.indexOf("\n", end + 1); + end = next < 0 ? text.length : next; + } + + let excerpt = text.slice(start, end); + if (excerpt.length > EXCERPT_MAX_BYTES) { + excerpt = text.slice(lineStart, lineEnd); + if (excerpt.length > EXCERPT_MAX_BYTES) excerpt = excerpt.slice(0, EXCERPT_MAX_BYTES); + } + return excerpt.trim(); +} + /** * OpenRouter's response when the per-run key's remaining budget can't cover * the agent's `max_tokens` reservation. Distinct from a generic provider error