action: surface agent hang context in progress comment (#733)

* action: surface agent hang context in progress comment

When the activity-timeout watchdog kills a stalled opencode subprocess,
the user used to see a bare "activity timeout: no output for 30Xs" — no
provider context, no stderr trace, no clue why the run died. Investigation
of the six runs in #728 showed the same shape every time: opencode hangs
after a non-retryable provider event (auth 401, 502 stream lost, free-tier
flake), and the only useful signal was buried in stderr where the user
couldn't see it without diving into Actions logs.

Stop trying to prevent the hang. Surface it.

Add a small `AgentDiagnostic` handle on `toolState` that the harness
mutates as a run progresses (recent stderr ring buffer reference, last
provider-error label, event count). `formatAgentHangBody` renders that
into a markdown body — bold headline, one-line explanation, collapsible
`<details>` with the last ~10 stderr lines (capped to 3KB) — used by
both the agent harness's own catch path and main.ts's outer catch when
the watchdog wins the race against the harness.

Both paths converge on one formatter; the existing
"View workflow run ➔" footer affordance in `reportErrorToComment` is
unchanged, so the user still has one click from the comment to the raw
logs to develop their own thesis.

* address review: gate hang body on isHang; fix contradictory copy

- Only render `hangBody` when `isHang`. The harness sets
  `agentDiagnostic` on entry, so any non-hang throw past `runOpenCode`'s
  own catch (post-success `output_schema` validator, late cleanup throws)
  was rendering "Pullfrog failed — N events processed…" with the real
  exception message dropped — including for runs that actually succeeded
  before a late throw.

- When `lastProviderError` already names the cause in the headline, the
  zero-events sentence "check whether the model provider is reachable"
  contradicts it (a 401 produces zero events but isn't a reachability
  issue). Drop the nudge in that case; keep it for the silent-stall path
  where it's still actionable.

* address copilot review: fence escape, idle parsing, secret redaction, tests

- pick a backtick fence longer than any backtick run in the rendered
  stderr tail. opencode error JSON occasionally embeds triple backticks
  in tool input dumps; the fixed three-tick fence let those terminate
  the fence early and corrupt the rest of the comment markdown.

- parse idle seconds out of the timer reject string ("activity timeout:
  no output for 301s") and use that for the hang explanation. previously
  rendered total runtime, which overstated the stall by 20+ minutes for
  runs that streamed for a long time before going quiet (e.g.
  Rohithgilla12/data-peek#25784038918, 1230s elapsed but 304s idle).

- redact sensitive env-var values from the rendered stderr tail before
  it lands in the PR comment / job summary. workflow log writes already
  go through `core.setSecret` masking; PR comments and summaries bypass
  that pipeline entirely. matches against `isSensitiveEnvName` (the same
  *_KEY/*_TOKEN/*_SECRET/*_PASSWORD/*_CREDENTIAL surface that
  `normalizeEnv` registers with the runner) and only redacts values
  >= 8 chars to avoid false-positive substring hits.

- add `agentHangReport.test.ts` covering the branchy bits: idle-seconds
  parsing, eventCount-zero copy with and without provider error,
  fence-escape against embedded triple backticks, 3 KB tail truncation,
  null-on-no-diagnostic, and secret redaction.

`startedAtMs` is dropped from `AgentDiagnostic` — total runtime was the
only consumer and idle seconds replaces it.

* strip slop: drop tests, drop redactSecrets, simplify ternary

- delete `agentHangReport.test.ts`. half the cases just pinned literal
  copy ("**Pullfrog stalled**", "check whether the model provider is
  reachable") which is exactly the "performative tests to every string
  utility" pattern AGENTS.md flags. the other half tested 2-5 line pure
  helpers (parseIdleSec / pickFence / truncation) that code review
  catches. the formatter is a best-effort string output; pinning it in
  tests creates churn without catching real regressions.

- remove `redactSecrets` and revert the formatter's import. theatrical
  defense: opencode doesn't dump env on startup, bearer tokens aren't
  in request bodies, bash is denied. the action has many other
  PR-comment write paths that don't redact (comment.ts, errorReport.ts,
  the progress writer) — if PR-comment secret hygiene matters, it's a
  cross-cutting concern at the comment-write layer, not bolted onto
  one formatter.

- factor the explanation triple-ternary into `formatExplanation` with
  early returns. same logic, easier to read.

`isHang` gate, fence-length escaping, and idle-seconds parsing stay —
those are real correctness fixes.
This commit is contained in:
Colin McDonnell
2026-05-14 04:13:26 +00:00
committed by pullfrog[bot]
parent b9383bbcfd
commit ba7f5a0b89
4 changed files with 177 additions and 8 deletions
+27 -4
View File
@@ -17,7 +17,9 @@ import { join } from "node:path";
import { performance } from "node:perf_hooks";
import { pullfrogMcpName } from "../external.ts";
import { BEDROCK_MODEL_ID_ENV, modelAliases } from "../models.ts";
import type { ToolState } from "../toolState.ts";
import { getIdleMs, markActivity } from "../utils/activity.ts";
import { type AgentDiagnostic, formatAgentHangBody } from "../utils/agentHangReport.ts";
import { formatJsonValue, log } from "../utils/cli.ts";
import { installFromNpmTarball } from "../utils/install.ts";
import { findProviderErrorMatch } from "../utils/providerErrors.ts";
@@ -312,8 +314,11 @@ interface OpenCodeStepFinishEvent {
* `session/message-v2.ts`). error parts carry the reason on `error`,
* completed parts on `output` — reading the wrong field is what caused
* the silent `(no error message)` log in #662.
*
* Named `ToolPartState` locally (not `ToolState`) so it doesn't shadow the
* action-wide `ToolState` imported above.
*/
type ToolState =
type ToolPartState =
| { status: "pending" | "running"; input?: unknown }
| { status: "completed"; input?: unknown; output: string }
| { status: "error"; input?: unknown; error: string };
@@ -326,7 +331,7 @@ interface OpenCodeToolUseEvent {
id?: string;
callID?: string;
tool?: string;
state?: ToolState;
state?: ToolPartState;
};
[key: string]: unknown;
}
@@ -335,7 +340,7 @@ interface OpenCodeToolResultEvent {
type: "tool_result";
timestamp?: number;
sessionID?: string;
part?: { callID?: string; state?: ToolState };
part?: { callID?: string; state?: ToolPartState };
tool_id?: string;
status?: "success" | "error";
output?: string;
@@ -420,6 +425,7 @@ type RunParams = {
args: string[];
cwd: string;
env: Record<string, string | undefined>;
toolState: ToolState;
todoTracker?: TodoTracker | undefined;
onActivityTimeout?: (() => void) | undefined;
onToolUse?: ((event: { toolName: string; input: unknown }) => void) | undefined;
@@ -936,6 +942,19 @@ async function runOpenCode(params: RunParams): Promise<AgentResult> {
let lastProviderError: string | null = null;
let agentErrorEvent: OpenCodeErrorEvent | null = null;
// shared with main.ts via toolState. updated in place as events stream and
// stderr accumulates so the outer activity-timeout catch sees the same
// context the harness's own catch path uses to format `result.error`.
// recentStderr is shared by reference; the scalar fields are mirrored on
// each update below.
const diagnostic: AgentDiagnostic = {
label: params.label,
recentStderr,
lastProviderError: undefined,
eventCount: 0,
};
params.toolState.agentDiagnostic = diagnostic;
// capped accumulator for the agent's narration. used as a post-run fallback
// when `finalOutput` (the orchestrator's final assistant message) is empty.
// unbounded `output += text` previously grew to ~1 GiB on multi-lens Reviews
@@ -994,6 +1013,7 @@ async function runOpenCode(params: RunParams): Promise<AgentResult> {
}
eventCount++;
diagnostic.eventCount = eventCount;
log.debug(JSON.stringify(event, null, 2));
const timeSinceLastActivity = getIdleMs();
@@ -1035,6 +1055,7 @@ async function runOpenCode(params: RunParams): Promise<AgentResult> {
const match = findProviderErrorMatch(trimmed);
if (match) {
lastProviderError = match.label;
diagnostic.lastProviderError = match.label;
log.info(`» provider error detected (${match.label}): ${match.excerpt}`);
} else {
log.debug(trimmed);
@@ -1166,10 +1187,11 @@ async function runOpenCode(params: RunParams): Promise<AgentResult> {
`» recent stderr (last ${Math.min(recentStderr.length, 10)} lines):\n${stderrContext}`
);
const body = formatAgentHangBody({ diagnostic, isHang: isActivityTimeout, errorMessage });
return {
success: false,
output: finalOutput || output.toString(),
error: `${errorMessage} [${diagnosis}]`,
error: body ?? `${errorMessage} [${diagnosis}]`,
usage: buildUsage(),
};
}
@@ -1262,6 +1284,7 @@ export const opencode = agent({
cliPath,
cwd: repoDir,
env,
toolState: ctx.toolState,
todoTracker: ctx.todoTracker,
onActivityTimeout: ctx.onActivityTimeout,
onToolUse: ctx.onToolUse,
+28 -4
View File
@@ -16,6 +16,7 @@ import {
DEFAULT_ACTIVITY_TIMEOUT_MS,
} from "./utils/activity.ts";
import { resolveAgent, resolveModel } from "./utils/agent.ts";
import { formatAgentHangBody } from "./utils/agentHangReport.ts";
import { apiFetch } from "./utils/apiFetch.ts";
import {
formatApiKeyErrorSummary,
@@ -1123,12 +1124,32 @@ export async function main(): Promise<MainResult> {
? new BillingError(errorMessage, { code: "router_keylimit_exhausted" })
: null;
// when the activity-timeout watchdog wins the race against the agent
// harness's own catch, the bare timer reject reason ("activity timeout:
// no output for 302s") tells the user nothing actionable. the harness
// keeps a structured diagnostic on toolState as it runs — recent stderr,
// last provider-error label, event count — and `formatAgentHangBody`
// renders that as a markdown body suitable for both the job summary tab
// and the PR progress comment.
//
// gated on isHang because the harness sets `agentDiagnostic` on entry,
// so any non-hang throw that hits the outer catch (e.g. the post-success
// output_schema validator, or a late cleanup throw after the run already
// succeeded) would otherwise render "Pullfrog failed" with stale event
// counts and silently drop the real `errorMessage`.
const isHang =
errorMessage.startsWith("activity timeout") || errorMessage.startsWith("agent still pending");
const hangBody = isHang
? formatAgentHangBody({ diagnostic: toolState.agentDiagnostic, isHang: true, errorMessage })
: null;
const apiKeySource = hangBody ?? errorMessage;
const apiKeyErrorSummary =
!billingError && isApiKeyAuthError(errorMessage)
!billingError && isApiKeyAuthError(apiKeySource)
? formatApiKeyErrorSummary({
owner: runContext.repo.owner,
name: runContext.repo.name,
raw: errorMessage,
raw: apiKeySource,
})
: null;
@@ -1136,7 +1157,10 @@ export async function main(): Promise<MainResult> {
try {
const errorSummary = billingError
? formatBillingErrorSummary(billingError, runContext.repo.owner)
: (apiKeyErrorSummary ?? `### ❌ Pullfrog failed\n\n\`\`\`\n${errorMessage}\n\`\`\``);
: (apiKeyErrorSummary ??
(hangBody
? `### ❌ Pullfrog failed\n\n${hangBody}`
: `### ❌ Pullfrog failed\n\n\`\`\`\n${errorMessage}\n\`\`\``));
const usageSummary = formatUsageSummary(toolState.usageEntries);
const parts = [errorSummary, toolState.lastProgressBody, usageSummary].filter(Boolean);
await writeSummary(parts.join("\n\n"));
@@ -1145,7 +1169,7 @@ export async function main(): Promise<MainResult> {
try {
const commentBody = billingError
? formatBillingErrorSummary(billingError, runContext.repo.owner)
: (apiKeyErrorSummary ?? errorMessage);
: (apiKeyErrorSummary ?? hangBody ?? errorMessage);
await reportErrorToComment({ toolState, error: commentBody });
} catch {
// error reporting failed, but don't let it mask the original error
+7
View File
@@ -1,5 +1,6 @@
import type { AgentUsage } from "./agents/shared.ts";
import type { PrepResult } from "./prep/types.ts";
import type { AgentDiagnostic } from "./utils/agentHangReport.ts";
import { log } from "./utils/cli.ts";
import type { DiffCoverageState } from "./utils/diffCoverage.ts";
import {
@@ -157,6 +158,12 @@ export interface ToolState {
model?: string | undefined;
todoTracker?: TodoTracker | undefined;
diffCoverage?: DiffCoverageState | undefined;
// mutable handle the agent harness writes to as a run progresses (recent
// stderr ring buffer reference, last provider-error label, event count).
// read by main.ts's outer catch so a watchdog-fired activity timeout still
// surfaces the same agent-side context the harness's own catch path returns
// via `result.error`. see `utils/agentHangReport.ts`.
agentDiagnostic?: AgentDiagnostic | undefined;
}
interface InitToolStateParams {
+115
View File
@@ -0,0 +1,115 @@
const MAX_STDERR_BYTES = 3000;
/**
* mutable per-run handle the agent harness writes to as a run progresses.
* the action's outer try/catch in `main.ts` reads this off `toolState` when
* the activity-timeout watchdog wins the race against the harness's own
* catch — the bare timer reject reason ("activity timeout: no output for
* 302s") tells the user nothing actionable, but `recentStderr` +
* `lastProviderError` together usually point straight at the upstream cause.
*
* `recentStderr` is shared by reference with the harness's bounded ring
* buffer, so the diagnostic always reflects the latest captured tail.
*/
export type AgentDiagnostic = {
/** display label for the agent, e.g. "Pullfrog". used in the headline. */
label: string;
/** shared reference to the harness's bounded stderr ring buffer. */
recentStderr: string[];
/** most-recent provider-error label from `detectProviderError`, if any. */
lastProviderError: string | undefined;
/** count of stdout events successfully parsed before the failure. */
eventCount: number;
};
/**
* Build a user-facing markdown body for an agent hang or failure.
*
* Rendered into both the PR progress comment and the GitHub Actions job
* summary. Returns `null` when no diagnostic is available, which signals to
* the caller to fall back to its bare-error rendering.
*
* `errorMessage` is the underlying timer / spawn reject string (e.g.
* `activity timeout: no output for 301s`). The idle seconds are parsed out
* of it for the hang explanation — total runtime would overstate the stall
* for runs that streamed for a long time before going quiet.
*/
export function formatAgentHangBody(input: {
diagnostic: AgentDiagnostic | undefined;
isHang: boolean;
errorMessage: string;
}): string | null {
if (!input.diagnostic) return null;
const verb = input.isHang ? "stalled" : "failed";
const cause = input.diagnostic.lastProviderError
? ` — likely cause: \`${input.diagnostic.lastProviderError}\``
: "";
const headline = `**${input.diagnostic.label} ${verb}**${cause}`;
const explanation = formatExplanation({
isHang: input.isHang,
errorMessage: input.errorMessage,
});
const parts = [headline, "", `${explanation} ${formatEventsPart(input.diagnostic)}`];
const tail = renderStderrTail(input.diagnostic.recentStderr);
if (tail) {
// pick a fence longer than any backtick run in the body so a stderr line
// containing ``` (provider error JSON occasionally embeds it) can't
// terminate the fence early and corrupt the rest of the markdown.
const fence = pickFence(tail);
parts.push(
"",
"<details><summary>Recent agent stderr</summary>",
"",
fence,
tail,
fence,
"",
"</details>"
);
}
return parts.join("\n");
}
function formatExplanation(input: { isHang: boolean; errorMessage: string }): string {
if (!input.isHang) return `The agent exited unexpectedly: ${input.errorMessage}`;
const idleSec = parseIdleSec(input.errorMessage);
if (idleSec === undefined) {
return "The agent stopped emitting events and was killed by the activity-timeout watchdog.";
}
return `The agent stopped emitting events for ${idleSec}s and was killed by the activity-timeout watchdog.`;
}
function parseIdleSec(message: string): number | undefined {
const match = /no output for (\d+)s/.exec(message);
return match ? Number(match[1]) : undefined;
}
function formatEventsPart(diagnostic: AgentDiagnostic): string {
if (diagnostic.eventCount > 0) {
return `${diagnostic.eventCount} events were processed before the failure.`;
}
// when the provider-error label already names the cause in the headline,
// the reachability nudge below contradicts it (e.g. an immediate 401 also
// produces zero events but isn't a reachability problem). suppress it.
if (diagnostic.lastProviderError) return "No events were emitted before the failure.";
return "No events were emitted — check whether the model provider is reachable.";
}
function renderStderrTail(lines: readonly string[]): string {
if (lines.length === 0) return "";
const joined = lines.join("\n");
if (joined.length <= MAX_STDERR_BYTES) return joined;
return `... (older lines truncated)\n${joined.slice(-MAX_STDERR_BYTES)}`;
}
function pickFence(content: string): string {
let max = 0;
for (const match of content.matchAll(/`+/g)) {
if (match[0].length > max) max = match[0].length;
}
return "`".repeat(Math.max(3, max + 1));
}