test(integration): harden flaky sleep-interception e2e against skipped tool calls (#4936)

The model sometimes answered the old prompts without ever calling the
shell tool, timing out waitForToolCall and burning ~230s per CI run
with retries. Prompts now explicitly require a run_shell_command call,
assertions key off recorded telemetry (blocked call with success:
false and Monitor guidance in the error) instead of model narration,
and failures print debug info.

integration-tests/cli/sleep-interception.test.ts

@@ -5,7 +5,11 @@
  */
 
 import { describe, it, expect, afterEach } from 'vitest';
-import { TestRig, validateModelOutput } from '../test-helper.js';
+import {
+  TestRig,
+  printDebugInfo,
+  validateModelOutput,
+} from '../test-helper.js';
 
 describe('sleep-interception', () => {
   let rig: TestRig;
@@ -16,24 +20,80 @@ describe('sleep-interception', () => {
     }
   });
 
+  type ShellCall = {
+    args: string;
+    success: boolean;
+    error?: string;
+  };
+
+  /**
+   * Poll telemetry for a run_shell_command call matching the predicate.
+   * The model's narration is unreliable (it may retry, paraphrase, or skip
+   * the scripted reply), so assertions key off the recorded tool calls —
+   * blocked calls are logged too, with success: false and the block
+   * message in the error attribute.
+   */
+  const waitForShellCall = (predicate: (call: ShellCall) => boolean) =>
+    rig.poll(
+      () =>
+        rig
+          .readToolLogs()
+          .some(
+            (log) =>
+              log.toolRequest.name === 'run_shell_command' &&
+              predicate(log.toolRequest),
+          ),
+      rig.getDefaultTimeout(),
+      100,
+    );
+
+  const shellCalls = (): ShellCall[] =>
+    rig
+      .readToolLogs()
+      .filter((log) => log.toolRequest.name === 'run_shell_command')
+      .map((log) => log.toolRequest);
+
   it('should block sleep >= 2s and mention Monitor in guidance', async () => {
     rig = new TestRig();
     await rig.setup('sleep-blocked');
 
     const result = await rig.run(
-      'Run this exact shell command: sleep 5. ' +
-        'If the command is blocked, say "BLOCKED" and explain why. ' +
-        'If it succeeds, say "SUCCESS".',
+      'Use the run_shell_command tool to run this exact command in the ' +
+        'foreground: sleep 5. You must actually call run_shell_command — ' +
+        'do not predict the outcome without calling the tool, do not set ' +
+        'is_background, and do not modify the command. If the tool reports ' +
+        'the command was blocked, say "BLOCKED". If it executed ' +
+        'successfully, say "SUCCESS".',
     );
 
-    validateModelOutput(result, null, 'sleep blocked');
+    const foundBlockedCall = await waitForShellCall(
+      (call) => call.args.includes('sleep 5') && !call.success,
+    );
 
-    // The model should report being blocked, since sleep 5 triggers interception
-    const foundShell = await rig.waitForToolCall('run_shell_command');
-    expect(foundShell).toBeTruthy();
+    if (!foundBlockedCall) {
+      printDebugInfo(rig, result, {
+        'Shell calls': JSON.stringify(shellCalls()),
+      });
+    }
 
-    // The model's output should mention it was blocked
-    expect(result.toLowerCase()).toContain('blocked');
+    expect(
+      foundBlockedCall,
+      'Expected a blocked (success: false) run_shell_command call for sleep 5',
+    ).toBeTruthy();
+
+    // The block guidance must point the model at the Monitor tool. The
+    // error attribute is only available from file-based telemetry; the
+    // podman stdout fallback leaves it undefined.
+    const blockedCall = shellCalls().find(
+      (call) => call.args.includes('sleep 5') && !call.success,
+    );
+    if (blockedCall?.error !== undefined) {
+      expect(blockedCall.error).toContain('Monitor');
+    }
+
+    // Narration is best-effort: warns instead of failing if the model
+    // phrases the block differently.
+    validateModelOutput(result, 'blocked', 'sleep blocked');
   });
 
   it('should allow sleep < 2s', async () => {
@@ -41,16 +101,27 @@ describe('sleep-interception', () => {
     await rig.setup('sleep-allowed');
 
     const result = await rig.run(
-      'Run this exact shell command: sleep 1. Then say "DONE".',
+      'Use the run_shell_command tool to run this exact command: sleep 1. ' +
+        'You must actually call run_shell_command with that command — do ' +
+        'not skip it. After it completes, say "DONE".',
     );
 
-    validateModelOutput(result, null, 'sleep allowed');
+    const foundSuccessfulCall = await waitForShellCall(
+      (call) => call.args.includes('sleep 1') && call.success,
+    );
 
-    const foundShell = await rig.waitForToolCall('run_shell_command');
-    expect(foundShell).toBeTruthy();
+    if (!foundSuccessfulCall) {
+      printDebugInfo(rig, result, {
+        'Shell calls': JSON.stringify(shellCalls()),
+      });
+    }
 
-    // Should not be blocked — model should complete successfully
-    expect(result.toLowerCase()).not.toContain('blocked');
+    expect(
+      foundSuccessfulCall,
+      'Expected a successful run_shell_command call for sleep 1',
+    ).toBeTruthy();
+
+    validateModelOutput(result, 'done', 'sleep allowed');
   });
 
   it('should allow retrying blocked sleep with an intentional sleep comment', async () => {
@@ -58,18 +129,32 @@ describe('sleep-interception', () => {
     await rig.setup('sleep-intentional-retry');
 
     const result = await rig.run(
-      'Run this exact shell command first: sleep 5. ' +
-        'If the command is blocked, retry with this exact shell command: ' +
-        'sleep 2 # intentional-sleep: wait for MCP rate limit reset. ' +
-        'Then say "DONE".',
+      'Use the run_shell_command tool to run this exact command in the ' +
+        'foreground: sleep 5. You must actually call run_shell_command — ' +
+        'do not predict the outcome without calling the tool. When that ' +
+        'call is blocked, call run_shell_command again with this exact ' +
+        'command: sleep 2 # intentional-sleep: wait for MCP rate limit ' +
+        'reset. Then say "DONE".',
     );
 
-    validateModelOutput(result, null, 'sleep intentional retry');
+    // The escape hatch worked iff a call carrying the intentional-sleep
+    // comment completed successfully.
+    const foundIntentionalCall = await waitForShellCall(
+      (call) => call.args.includes('intentional-sleep') && call.success,
+    );
 
-    const foundShell = await rig.waitForToolCall('run_shell_command');
-    expect(foundShell).toBeTruthy();
+    if (!foundIntentionalCall) {
+      printDebugInfo(rig, result, {
+        'Shell calls': JSON.stringify(shellCalls()),
+      });
+    }
 
-    expect(result.toLowerCase()).toContain('done');
+    expect(
+      foundIntentionalCall,
+      'Expected a successful run_shell_command call with an intentional-sleep comment',
+    ).toBeTruthy();
+
+    validateModelOutput(result, 'done', 'sleep intentional retry');
   });
 
   it('should block sleep >= 2s even when followed by a trailing comment', async () => {
@@ -81,17 +166,33 @@ describe('sleep-interception', () => {
     await rig.setup('sleep-blocked-trailing-comment');
 
     const result = await rig.run(
-      'Run this exact shell command: sleep 5 # wait for db. ' +
-        'If the command is blocked, say "BLOCKED" and explain why. ' +
-        'If it succeeds, say "SUCCESS".',
+      'Use the run_shell_command tool to run this exact command in the ' +
+        'foreground: sleep 5 # wait for db. You must actually call ' +
+        'run_shell_command — do not predict the outcome without calling ' +
+        'the tool, do not set is_background, and do not modify the ' +
+        'command. If the tool reports the command was blocked, say ' +
+        '"BLOCKED". If it executed successfully, say "SUCCESS".',
     );
 
-    validateModelOutput(result, null, 'sleep blocked with trailing comment');
+    const foundBlockedCall = await waitForShellCall(
+      (call) => call.args.includes('sleep 5') && !call.success,
+    );
 
-    const foundShell = await rig.waitForToolCall('run_shell_command');
-    expect(foundShell).toBeTruthy();
+    if (!foundBlockedCall) {
+      printDebugInfo(rig, result, {
+        'Shell calls': JSON.stringify(shellCalls()),
+      });
+    }
 
-    // Model must report it was blocked despite the trailing comment.
-    expect(result.toLowerCase()).toContain('blocked');
+    expect(
+      foundBlockedCall,
+      'Expected a blocked (success: false) run_shell_command call for sleep 5 with trailing comment',
+    ).toBeTruthy();
+
+    validateModelOutput(
+      result,
+      'blocked',
+      'sleep blocked with trailing comment',
+    );
   });
 });

integration-tests/test-helper.ts

@@ -129,6 +129,8 @@ interface ParsedLog {
     function_args?: string;
     success?: boolean;
     duration_ms?: number;
+    status?: string;
+    'error.message'?: string;
   };
   scopeMetrics?: {
     metrics: {
@@ -569,6 +571,8 @@ export class TestRig {
         args: string;
         success: boolean;
         duration_ms: number;
+        status?: string;
+        error?: string;
       };
     }[] = [];
 
@@ -760,6 +764,8 @@ export class TestRig {
         args: string;
         success: boolean;
         duration_ms: number;
+        status?: string;
+        error?: string;
       };
     }[] = [];
 
@@ -776,6 +782,8 @@ export class TestRig {
             args: logData.attributes.function_args,
             success: logData.attributes.success,
             duration_ms: logData.attributes.duration_ms,
+            status: logData.attributes.status,
+            error: logData.attributes['error.message'],
           },
         });
       }