chore(pi-claude-cli): instrument subprocess lifecycle for hang diagnosis

Triage runs through pi-claude-cli still hang silently for 20+ minutes after
only 2 thinking-deltas before the engine's StuckTaskDetector kills them. We
can't tell from agentLogEntries whether the subprocess crashed, the MCP
server failed to attach, or Claude is in extended thinking that doesn't
stream.

Adds stderr lines tagged [pi-claude-cli] for:
- spawn (pid, model, mode, prompt sizes, mcp on/off)
- init (session id, model, permissionMode, mcp_servers status list)
- first-stdout-line (latency from spawn)
- tool_use (per top-level tool, with piKnown flag)
- break-early (when we kill at message_stop)
- close (exit code, signal, elapsed, broken-flag)

No behavioural change. Restart the dashboard, trigger triage, and these
lines tell us which phase silence sets in.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
This commit is contained in:
gsxdsm
2026-04-25 20:22:57 -07:00
parent 96e02928d2
commit 36e095d90c

View File

@@ -135,6 +135,12 @@ export function streamViaCli(
newSessionId: !resumeSessionId ? options?.sessionId : undefined,
});
const getStderr = captureStderr(proc);
const spawnTime = Date.now();
const procPid = proc.pid;
const traceMode = resumeSessionId ? "resume" : "new";
console.error(
`[pi-claude-cli] spawn pid=${procPid} model=${model.id} mode=${traceMode} effort=${effort ?? "default"} promptLen=${typeof prompt === "string" ? prompt.length : 0} systemPromptLen=${systemPrompt?.length ?? 0} mcp=${options?.mcpConfigPath ? "yes" : "no"}`,
);
// Register in global process registry for teardown cleanup
registerProcess(proc);
@@ -225,8 +231,12 @@ export function streamViaCli(
});
// Handle subprocess close -- surface crashes with stderr and exit code
proc.on("close", (code: number | null, _signal: string | null) => {
proc.on("close", (code: number | null, signal: string | null) => {
clearTimeout(inactivityTimer);
const elapsedMs = Date.now() - spawnTime;
console.error(
`[pi-claude-cli] close pid=${procPid} code=${code ?? "null"} signal=${signal ?? "null"} elapsedMs=${elapsedMs} broken=${broken}`,
);
if (broken) return; // Break-early kill, expected
if (code !== 0 && code !== null) {
const stderr = getStderr();
@@ -240,6 +250,9 @@ export function streamViaCli(
// Start inactivity timer after writing user message
resetInactivityTimer();
let firstLineLoggedAt = 0;
let lineCount = 0;
// Process NDJSON lines from stdout using event-based callback
// NOTE: Using 'line' event instead of `for await` because the async
// iterator batches lines, breaking real-time streaming to pi.
@@ -248,10 +261,36 @@ export function streamViaCli(
// Reset inactivity timer on each line of output
resetInactivityTimer();
lineCount++;
if (lineCount === 1) {
firstLineLoggedAt = Date.now();
console.error(
`[pi-claude-cli] first-stdout-line pid=${procPid} afterMs=${firstLineLoggedAt - spawnTime}`,
);
}
const msg = parseLine(line);
if (!msg) return;
// Log init system event so we can see MCP server status / model on stderr
if (
msg.type === "system" &&
(msg as { subtype?: string }).subtype === "init"
) {
const init = msg as unknown as {
session_id?: string;
mcp_servers?: Array<{ name: string; status: string }>;
model?: string;
permissionMode?: string;
};
const mcps = (init.mcp_servers ?? [])
.map((s) => `${s.name}=${s.status}`)
.join(",");
console.error(
`[pi-claude-cli] init pid=${procPid} session=${init.session_id ?? "?"} model=${init.model ?? "?"} permissionMode=${init.permissionMode ?? "?"} mcp=[${mcps}]`,
);
}
if (msg.type === "stream_event") {
// Only forward top-level events to pi's event bridge.
// Sub-agent events (parent_tool_use_id !== null) are internal to the CLI.
@@ -267,6 +306,11 @@ export function streamViaCli(
msg.event.content_block?.type === "tool_use"
) {
const toolName = msg.event.content_block.name;
if (toolName) {
console.error(
`[pi-claude-cli] tool_use pid=${procPid} name=${toolName} piKnown=${isPiKnownClaudeTool(toolName)}`,
);
}
if (toolName && isPiKnownClaudeTool(toolName)) {
// Built-in tool (Read/Write/etc.) OR custom MCP tool (mcp__custom-tools__*)
// Internal Claude Code tools (ToolSearch, Task, etc.) are excluded
@@ -281,6 +325,9 @@ export function streamViaCli(
msg.event.type === "message_stop" &&
sawBuiltInOrCustomTool
) {
console.error(
`[pi-claude-cli] break-early pid=${procPid} elapsedMs=${Date.now() - spawnTime} lines=${lineCount}`,
);
broken = true; // Set guard BEFORE rl.close() to prevent buffered lines
clearTimeout(inactivityTimer);
// Pi will execute these tools. Kill subprocess to prevent CLI from executing them.