feat(daemon): E-lite root-cause telemetry for inactivity_timeout attribution (#5775)

* feat(daemon): E-lite root-cause telemetry for inactivity_timeout attribution

Add four run_finished fields that separate WHY a stalled run died, which
the coarse `last_observed_phase` (WHICH phase) cannot:

- approval_requested: an ACP approval/permission gate fired. Only the ACP
  path is daemon-observable (stream/CLI runtimes pass a skip-permissions
  flag so no gate fires); surfaced via an acp_approval_request diagnostic
  and folded in by summarizeRunDiagnosticsForAnalytics.
- stdin_backpressure: the prompt write to the child's stdin was queued
  because the OS pipe buffer was full (the child was not draining stdin) —
  the corroborating signal for a stdin_write-phase stall.
- tool_result_sent: a tool_result came back for the run's LAST tool_use.
  A stall with tool_call_seen && !tool_result_sent is the
  tool-result-not-delivered root cause.
- last_progress_age_ms: age of the last agent activity at finish (the
  inactivity-watchdog clock). Near the ceiling on a stall, ~0 on a clean
  finish.

Contract fields on RunFinishedProps; daemon populates two off the run
object (stdin_backpressure, last_progress_age_ms) and derives two from
run.events in the diagnostics summarizer (tool_result_sent,
approval_requested).

* fix(daemon): pair tool_result_sent by id so parallel tools attribute correctly

Review catch (nettee/Looper): the first cut flipped `tool_result_sent` to
true on any tool_result after a tool_use, so a multi-tool turn like
tool_use(A), tool_use(B), tool_result(A) reported delivered even though B
was still outstanding — bucketing multi-tool stalls as "provider stalled
after delivery" instead of "tool result not delivered".

Now paired by id (`tool_use.id` <-> `tool_result.toolUseId`, the same
pairing summarizeRunTimingAnalytics uses): `tool_result_sent` is true only
when EVERY committed tool_use received a matching tool_result (outstanding
set empty). Tests cover the reviewer's regression case plus parallel
all-resolved and sequential-last-outstanding.

* fix(daemon): count-pair id-less tool events so degraded stalls aren't "delivered"

Second review catch (nettee/Looper): id-based pairing alone still fell
through to `tool_result_sent: true` when a runtime emits a tool_use with a
null id, because those were counted in `sawAnyToolUse` but never tracked as
outstanding. That is not hypothetical — `agent-protocol/pi-rpc/events.ts`
and `copilot-stream.ts` both emit `toolCallId ?? null` for tool_use.id AND
tool_result.toolUseId on degraded provider events, so an unpaired id-less
tool call would mask exactly the stall this metric attributes.

Id-less tool events are now paired by count alongside the id-keyed set:
`tool_result_sent` requires both an empty outstanding-id set and at least as
many id-less results as id-less uses. Tests cover an unpaired id-less stall
and an id-less pair that did resolve.

* fix(daemon): capture stdin backpressure on the default text-input path

Third review catch (nettee/Looper): `stdin_backpressure` never recorded
anything for non-`stream-json` runtimes. `child.stdin.end(composed, ...)`
returns the stream rather than a boolean, and `writableNeedDrain` is already
back to false by the time it returns — even for a chunk that `write(chunk)`
would have rejected. Claude is the only runtime on the stream-json path, so
the field was permanently false on exactly the runs whose `stdin_write`
stalls it exists to attribute.

The write and the close are now issued separately through
`writePromptAndEndStdin`, which returns the boolean the OS pipe actually
gave us. Extracted into chat-run-lifecycle.ts so it is unit-testable:
tests cover the backpressured write, the accepted write, and the flush
callback still firing (the `stdin_write_end` lifecycle mark). Verified red
against the previous behavior.

Author: lefarcen

apps/daemon/src/agent-protocol/acp/session.ts

@@ -446,6 +446,16 @@ export function attachAcpSession({
       fail(`unhandled ACP permission request: ${JSON.stringify(raw)}`);
       return;
     }
+    // E-lite: the ACP path is the only daemon-observable approval gate. Surface
+    // it so `run_finished.approval_requested` can attribute a `tool_execution`
+    // stall to an approval hang even though we auto-approve here.
+    send('agent', {
+      type: 'diagnostic',
+      name: 'acp_approval_request',
+      source: 'acp-json-rpc',
+      elapsedMs: Date.now() - runStartedAt,
+      optionId,
+    });
     resetStageTimer('session/request_permission');
     try {
       sendRpcResult(stdin, raw.id, {

apps/daemon/src/routes/runs.ts

@@ -161,6 +161,11 @@ interface ChatRun {
   clients: Set<SseClient>;
   analyticsContext?: AnalyticsContext;
   analyticsTelemetry?: RunTelemetryTimestamps;
+  // E-lite root-cause telemetry read at run_finished. `stdinBackpressure`: the
+  // prompt write to child stdin was queued (pipe buffer full). `lastAgentActivityAt`:
+  // the inactivity-watchdog clock, used to derive `last_progress_age_ms`.
+  stdinBackpressure?: boolean;
+  lastAgentActivityAt?: number;
   retryAttemptCount?: number;
   retryFinalResult?: string;
   retrySuppressedReason?: string;
@@ -1260,6 +1265,12 @@ export function registerRunRoutes(app: Express, ctx: RegisterRunRoutesDeps) {
             } : {}),
             ...timingAnalytics,
             ...diagnosticsAnalytics,
+            // E-lite: `approval_requested`/`tool_result_sent` ride in via
+            // `...diagnosticsAnalytics`; these two come off the run object.
+            stdin_backpressure: run.stdinBackpressure === true,
+            ...(typeof run.lastAgentActivityAt === 'number'
+              ? { last_progress_age_ms: Math.max(0, analyticsCapturedAt - run.lastAgentActivityAt) }
+              : {}),
             langfuse_trace_id: run.id,
             ...langfuseDeliveryForAnalytics,
             ...(errorCode ? { error_code: errorCode } : {}),

apps/daemon/src/run-diagnostics.ts

@@ -39,6 +39,15 @@ export interface RunDiagnosticsAnalytics {
   first_token_seen: boolean;
   user_visible_output_seen: boolean;
   tool_call_seen: boolean;
+  // True when every committed tool_use received a matching tool_result — paired
+  // by id where the runtime supplies one, by count for degraded events that emit
+  // a null id on both sides. A stall with `tool_call_seen && !tool_result_sent`
+  // is the tool-result-not-delivered root cause (a tool_use whose result never
+  // came back — including a still-outstanding tool in a parallel turn).
+  tool_result_sent: boolean;
+  // True when an approval/permission gate fired. Only ACP runtimes surface this
+  // (via an `acp_approval_request` diagnostic); stream/CLI runtimes bypass gates.
+  approval_requested: boolean;
   artifact_write_seen: boolean;
   live_artifact_seen: boolean;
   // True when this run transparently re-seeded after an upstream session resume
@@ -160,6 +169,22 @@ export function summarizeRunDiagnosticsForAnalytics(args: {
   let stdout = '';
   let userVisibleOutputSeen = false;
   let toolCallSeen = false;
+  // `tool_result_sent` = EVERY committed tool_use received a matching tool_result.
+  // Paired by id (`tool_use.id` <-> `tool_result.toolUseId`, the same pairing
+  // summarizeRunTimingAnalytics uses), because a plain "any tool_result after a
+  // tool_use" flag reports delivered for a parallel turn like tool_use(A),
+  // tool_use(B), tool_result(A) where B is still outstanding.
+  //
+  // Degraded provider events carry NO id, symmetrically on both sides — see
+  // `agent-protocol/pi-rpc/events.ts` and `copilot-stream.ts`, which both emit
+  // `toolCallId ?? null` for tool_use.id AND tool_result.toolUseId. Those are
+  // paired by count instead; skipping them would let an unpaired id-less tool
+  // call fall through to "delivered" and mask exactly the stall we're attributing.
+  const outstandingToolUseIds = new Set<string>();
+  let idlessToolUses = 0;
+  let idlessToolResults = 0;
+  let sawAnyToolUse = false;
+  let approvalRequested = false;
   let artifactWriteSeen = args.artifactWriteSeen === true;
   let liveArtifactSeen = args.liveArtifactSeen === true;
   let recordedCloseReason: RunCloseReason | null = null;
@@ -183,7 +208,19 @@ export function summarizeRunDiagnosticsForAnalytics(args: {
       const delta = typeof data.delta === 'string' ? data.delta : '';
       if (delta.length > 0) userVisibleOutputSeen = true;
     }
-    if (data.type === 'tool_use') toolCallSeen = true;
+    if (data.type === 'tool_use') {
+      toolCallSeen = true;
+      sawAnyToolUse = true;
+      if (typeof data.id === 'string') outstandingToolUseIds.add(data.id);
+      else idlessToolUses += 1;
+    }
+    if (data.type === 'tool_result') {
+      if (typeof data.toolUseId === 'string') outstandingToolUseIds.delete(data.toolUseId);
+      else idlessToolResults += 1;
+    }
+    if (data.type === 'diagnostic' && data.name === 'acp_approval_request') {
+      approvalRequested = true;
+    }
     if (event.event === 'diagnostic' && data.type === 'agent_resume_auto_reseed') {
       resumeAutoReseeded = true;
     }
@@ -254,6 +291,11 @@ export function summarizeRunDiagnosticsForAnalytics(args: {
     first_token_seen: args.firstTokenSeen === true,
     user_visible_output_seen: userVisibleOutputSeen,
     tool_call_seen: toolCallSeen,
+    tool_result_sent:
+      sawAnyToolUse &&
+      outstandingToolUseIds.size === 0 &&
+      idlessToolResults >= idlessToolUses,
+    approval_requested: approvalRequested,
     artifact_write_seen: artifactWriteSeen,
     live_artifact_seen: liveArtifactSeen,
     resume_auto_reseeded: resumeAutoReseeded,

apps/daemon/src/runtimes/chat-run-lifecycle.ts

@@ -236,3 +236,31 @@ export function bufferedAntigravityGeminiFirstTokenAt(
   }
   return null;
 }
+
+/**
+ * Writes the composed prompt as the final chunk on the child's stdin, closes
+ * it, and reports whether that write was backpressured.
+ *
+ * `end(chunk)` cannot report this: it returns the stream rather than a boolean,
+ * and `writableNeedDrain` is already back to false by the time it returns — even
+ * for a chunk that `write(chunk)` would have rejected. Every runtime except
+ * Claude (which streams JSON and keeps stdin open) takes this path, so reading
+ * backpressure off `end()` left `stdin_backpressure` permanently false on
+ * exactly the runs whose `stdin_write` stalls it exists to attribute. Issuing
+ * the write and the close separately is what makes the signal real.
+ *
+ * Returns true when the chunk had to be buffered because the OS pipe was full,
+ * i.e. the child was not draining stdin.
+ */
+export function writePromptAndEndStdin(
+  stdin: {
+    write: (chunk: string, encoding: BufferEncoding, cb: (err?: Error | null) => void) => boolean;
+    end: () => void;
+  },
+  composed: string,
+  onFlush: (err?: Error | null) => void,
+): boolean {
+  const accepted = stdin.write(composed, 'utf8', onFlush);
+  stdin.end();
+  return accepted === false;
+}

apps/daemon/src/runtimes/runs.ts

@@ -109,6 +109,14 @@ export function createChatRunService({
       retryOriginFailure: null,
       retryOriginErrorCode: null,
       stdinOpen: false,
+      // E-lite root-cause telemetry. `stdinBackpressure` records whether the
+      // prompt write to the child's stdin was queued (pipe buffer full — a
+      // corroborating signal for a `stdin_write`-phase stall). `lastAgentActivityAt`
+      // is the clock the inactivity watchdog keys off, read at finish to derive
+      // `last_progress_age_ms`. (`approval_requested` and `tool_result_sent` are
+      // derived from run.events by summarizeRunDiagnosticsForAnalytics.)
+      stdinBackpressure: false,
+      lastAgentActivityAt: now,
       // Work-completeness signals (#1247 / #1060), folded from agent events by
       // captureRunWorkCompletenessSignals (server.ts). `lastTodoSnapshot` is the
       // most recent TodoWrite `todos` array; `truncatedMidTurn` records a

apps/daemon/src/server.ts

@@ -94,6 +94,7 @@ import {
   validateCodexGeneratedImagesDir,
 } from './runtimes/chat-prompt-inputs.js';
 import {
+  writePromptAndEndStdin,
   applyClaudeStreamJsonRunBookkeeping,
   assertValidRuntimeDefInactivityTimeoutMs,
   bufferedAntigravityGeminiFirstTokenAt,
@@ -6267,6 +6268,9 @@ export async function startServer({
         artifactRegistered,
       });
     const noteAgentActivity = () => {
+      // E-lite: stamp the last-activity clock BEFORE the disabled-watchdog bail
+      // so `last_progress_age_ms` is recorded even when the watchdog is off.
+      run.lastAgentActivityAt = Date.now();
       const delay = activeInactivityTimeoutMs();
       if (delay <= 0) return;
       clearInactivityWatchdog();
@@ -8080,7 +8084,11 @@ export async function startServer({
           },
         });
         try {
-          child.stdin.write(`${userMessage}\n`, 'utf8', markStdinWriteEnd);
+          // E-lite: `write` returns false when the chunk was buffered because the
+          // OS pipe is full (the child isn't draining stdin) — the corroborating
+          // signal for a `stdin_write`-phase inactivity stall.
+          const accepted = child.stdin.write(`${userMessage}\n`, 'utf8', markStdinWriteEnd);
+          run.stdinBackpressure = accepted === false;
         } catch (err) {
           // Swallow EPIPE here for the same reason as the listener above —
           // a fast-exiting child has already routed its failure through
@@ -8089,7 +8097,9 @@ export async function startServer({
         }
         run.stdinOpen = true;
       } else {
-        child.stdin.end(composed, 'utf8', markStdinWriteEnd);
+        // Split write + close so the boolean backpressure signal survives —
+        // see writePromptAndEndStdin for why `end(chunk)` cannot report it.
+        run.stdinBackpressure = writePromptAndEndStdin(child.stdin, composed, markStdinWriteEnd);
       }
     }
   };

apps/daemon/tests/chat-run-lifecycle-stdin.test.ts

@@ -0,0 +1,54 @@
+import { describe, expect, it } from 'vitest';
+
+import { writePromptAndEndStdin } from '../src/runtimes/chat-run-lifecycle.js';
+
+// Regression guard for `run_finished.stdin_backpressure`.
+//
+// The first cut wrote the prompt with `child.stdin.end(composed, ...)` and then
+// read `child.stdin.writableNeedDrain`. That reports nothing: `end(chunk)`
+// returns the stream rather than a boolean, and `writableNeedDrain` is already
+// back to false by the time it returns — even for a chunk `write(chunk)` would
+// have rejected. Every runtime except Claude takes this path, so the field was
+// permanently false on exactly the runs whose `stdin_write` stalls it exists to
+// attribute.
+describe('writePromptAndEndStdin', () => {
+  function fakeStdin(writeReturns: boolean) {
+    const calls: { chunk: string; encoding: string }[] = [];
+    const state = { ended: false, flushCb: null as null | ((err?: Error | null) => void) };
+    return {
+      calls,
+      state,
+      write(chunk: string, encoding: BufferEncoding, cb: (err?: Error | null) => void) {
+        calls.push({ chunk, encoding });
+        state.flushCb = cb;
+        return writeReturns;
+      },
+      end() {
+        state.ended = true;
+      },
+    };
+  }
+
+  it('reports backpressure when the pipe rejected the chunk, and still closes stdin', () => {
+    const stdin = fakeStdin(false);
+    expect(writePromptAndEndStdin(stdin, 'prompt body', () => {})).toBe(true);
+    expect(stdin.state.ended).toBe(true);
+    expect(stdin.calls).toEqual([{ chunk: 'prompt body', encoding: 'utf8' }]);
+  });
+
+  it('reports no backpressure when the chunk was accepted', () => {
+    const stdin = fakeStdin(true);
+    expect(writePromptAndEndStdin(stdin, 'prompt body', () => {})).toBe(false);
+    expect(stdin.state.ended).toBe(true);
+  });
+
+  it('forwards the flush callback so the stdin_write lifecycle mark still fires', () => {
+    const stdin = fakeStdin(true);
+    let flushed = 0;
+    writePromptAndEndStdin(stdin, 'prompt body', () => {
+      flushed += 1;
+    });
+    stdin.state.flushCb?.();
+    expect(flushed).toBe(1);
+  });
+});

apps/daemon/tests/run-diagnostics.test.ts

@@ -76,6 +76,8 @@ describe('run diagnostics', () => {
       first_token_seen: false,
       user_visible_output_seen: false,
       tool_call_seen: false,
+      tool_result_sent: false,
+      approval_requested: false,
       artifact_write_seen: false,
       live_artifact_seen: false,
       resume_auto_reseeded: false,
@@ -105,6 +107,8 @@ describe('run diagnostics', () => {
       first_token_seen: false,
       user_visible_output_seen: false,
       tool_call_seen: false,
+      tool_result_sent: false,
+      approval_requested: false,
       artifact_write_seen: false,
       live_artifact_seen: false,
       resume_auto_reseeded: false,
@@ -131,6 +135,8 @@ describe('run diagnostics', () => {
       first_token_seen: false,
       user_visible_output_seen: false,
       tool_call_seen: false,
+      tool_result_sent: false,
+      approval_requested: false,
       artifact_write_seen: false,
       live_artifact_seen: false,
       resume_auto_reseeded: false,
@@ -153,7 +159,7 @@ describe('run diagnostics', () => {
     const result = summarizeRunDiagnosticsForAnalytics({
       events: [
         { event: 'stdout', data: { chunk: 'hello\n' } },
-        { event: 'agent', data: { type: 'tool_use', name: 'Read' } },
+        { event: 'agent', data: { type: 'tool_use', name: 'Read', id: 'tool-1' } },
         { event: 'agent', data: { type: 'artifact' } },
       ],
       exitCode: null,
@@ -170,8 +176,102 @@ describe('run diagnostics', () => {
       first_token_seen: true,
       user_visible_output_seen: true,
       tool_call_seen: true,
+      // A tool_use with no following tool_result → not delivered.
+      tool_result_sent: false,
+      approval_requested: false,
       artifact_write_seen: true,
       live_artifact_seen: true,
     });
   });
+
+  it('flags tool_result_sent / approval_requested (E-lite root-cause discriminators)', () => {
+    // Every committed tool_use resolved (paired by id) → delivered.
+    const resolved = summarizeRunDiagnosticsForAnalytics({
+      events: [
+        { event: 'agent', data: { type: 'tool_use', name: 'Read', id: 't1' } },
+        { event: 'agent', data: { type: 'tool_result', toolUseId: 't1' } },
+      ],
+      exitCode: 0,
+      signal: null,
+    });
+    expect(resolved.tool_call_seen).toBe(true);
+    expect(resolved.tool_result_sent).toBe(true);
+
+    // Two parallel tool_uses both resolve (interleaved) → delivered.
+    const parallelResolved = summarizeRunDiagnosticsForAnalytics({
+      events: [
+        { event: 'agent', data: { type: 'tool_use', name: 'Read', id: 'a' } },
+        { event: 'agent', data: { type: 'tool_use', name: 'Grep', id: 'b' } },
+        { event: 'agent', data: { type: 'tool_result', toolUseId: 'a' } },
+        { event: 'agent', data: { type: 'tool_result', toolUseId: 'b' } },
+      ],
+      exitCode: 0,
+      signal: null,
+    });
+    expect(parallelResolved.tool_result_sent).toBe(true);
+
+    // The reviewer's regression case: tool_use(A), tool_use(B), tool_result(A).
+    // B is still outstanding, so a result arriving for A must NOT mark delivered.
+    const parallelHung = summarizeRunDiagnosticsForAnalytics({
+      events: [
+        { event: 'agent', data: { type: 'tool_use', name: 'Read', id: 'a' } },
+        { event: 'agent', data: { type: 'tool_use', name: 'Bash', id: 'b' } },
+        { event: 'agent', data: { type: 'tool_result', toolUseId: 'a' } },
+      ],
+      exitCode: null,
+      signal: 'SIGKILL',
+    });
+    expect(parallelHung.tool_call_seen).toBe(true);
+    expect(parallelHung.tool_result_sent).toBe(false);
+
+    // The last tool_use of a sequential turn has no result → not delivered.
+    const hung = summarizeRunDiagnosticsForAnalytics({
+      events: [
+        { event: 'agent', data: { type: 'tool_use', name: 'Read', id: 'a' } },
+        { event: 'agent', data: { type: 'tool_result', toolUseId: 'a' } },
+        { event: 'agent', data: { type: 'tool_use', name: 'Bash', id: 'b' } },
+      ],
+      exitCode: null,
+      signal: 'SIGKILL',
+    });
+    expect(hung.tool_call_seen).toBe(true);
+    expect(hung.tool_result_sent).toBe(false);
+
+    // Degraded provider events carry a null id on BOTH sides (pi-rpc,
+    // copilot-stream emit `toolCallId ?? null`). An unpaired id-less tool call
+    // must NOT fall through to "delivered".
+    const idlessHung = summarizeRunDiagnosticsForAnalytics({
+      events: [
+        { event: 'agent', data: { type: 'tool_use', name: 'Read', id: null } },
+      ],
+      exitCode: null,
+      signal: 'SIGKILL',
+    });
+    expect(idlessHung.tool_call_seen).toBe(true);
+    expect(idlessHung.tool_result_sent).toBe(false);
+
+    // ...but an id-less tool call that DID get its (also id-less) result counts.
+    const idlessResolved = summarizeRunDiagnosticsForAnalytics({
+      events: [
+        { event: 'agent', data: { type: 'tool_use', name: 'Read', id: null } },
+        { event: 'agent', data: { type: 'tool_result', toolUseId: null } },
+      ],
+      exitCode: 0,
+      signal: null,
+    });
+    expect(idlessResolved.tool_result_sent).toBe(true);
+
+    // An ACP approval diagnostic flips approval_requested.
+    const approved = summarizeRunDiagnosticsForAnalytics({
+      events: [
+        {
+          event: 'agent',
+          data: { type: 'diagnostic', name: 'acp_approval_request', optionId: 'allow_once' },
+        },
+      ],
+      exitCode: 0,
+      signal: null,
+    });
+    expect(approved.approval_requested).toBe(true);
+  });
 });