Measure execute result size once per result object

.changeset/dedupe-result-size-walk.md

@@ -0,0 +1,7 @@
+---
+"@executor-js/execution": patch
+---
+
+**Large execute results are measured once, not once per span**
+
+The result-size telemetry probe serializes the whole returned value to count its characters, and that cost grows with the payload. The same result object was walked again every time it was stamped onto another span: an operator-approved run measured it twice (inner and outer span), and every retried `resume` that replayed a settled outcome measured it again. The measurement is now computed once per result object and reused, so a large result pays one size walk no matter how many spans report it. Response text, structured content, and span attribute values are unchanged.

e2e/scenarios/mcp-execute.test.ts

@@ -1,11 +1,23 @@
 // Cross-target: the MCP surface — connect with fully headless OAuth (DCR →
 // consent → code → token) and run code in the sandbox, exactly as an MCP
 // client (Claude, Cursor, …) would.
+import { randomUUID } from "node:crypto";
+
 import { expect } from "@effect/vitest";
 import { Effect } from "effect";
+import { composePluginApi } from "@executor-js/api/server";
 
 import { scenario } from "../src/scenario";
-import { Mcp, Target } from "../src/services";
+import { Api, Mcp, Target } from "../src/services";
+
+const coreApi = composePluginApi([] as const);
+
+/** The raw MCP tool result shape the fidelity scenarios assert against. */
+const rawResultOf = (result: { readonly raw: unknown }) =>
+  result.raw as {
+    content?: ReadonlyArray<{ type: string; text?: string }>;
+    structuredContent?: Record<string, unknown>;
+  };
 
 scenario(
   "MCP · OAuth connect, then execute code in the sandbox",
@@ -24,6 +36,137 @@ scenario(
   }),
 );
 
+// The exact value a sandbox script returns, non-ASCII included. The server
+// renders it into the text channel (pretty-printed JSON) and mirrors it into
+// `structuredContent`; both must reach the client byte-identical — a client
+// diffing retries or hashing results must never see the payload drift.
+const structuredPayload = {
+  greeting: "héllo — こんにちは ✅",
+  emoji: "🚀",
+  values: [1, 2, 3],
+  nested: { ok: true, label: "Zoë" },
+};
+
+scenario(
+  "MCP · a structured return value reaches the client byte-identical in text and structuredContent",
+  {},
+  Effect.gen(function* () {
+    const target = yield* Target;
+    const mcp = yield* Mcp;
+    const identity = yield* target.newIdentity();
+    const session = mcp.session(identity);
+    yield* session.listTools();
+
+    const result = yield* session.call("execute", {
+      code: `return ${JSON.stringify(structuredPayload)};`,
+    });
+    expect(result.ok, "the sandbox run completes without error").toBe(true);
+
+    const expectedText = JSON.stringify(structuredPayload, null, 2);
+    const raw = rawResultOf(result);
+    expect(raw.content?.length, "the result arrives as a single text block").toBe(1);
+    expect(raw.content?.[0]?.text, "the text channel carries the exact rendered value").toBe(
+      expectedText,
+    );
+    expect(result.text, "the joined text content matches byte-for-byte").toBe(expectedText);
+    expect(raw.structuredContent, "structuredContent mirrors the exact returned value").toEqual({
+      status: "completed",
+      result: structuredPayload,
+      logs: [],
+    });
+  }),
+);
+
+/** Sandbox code that runs ONE approval-gated call (the `policies.create` core
+ *  tool gates itself via its `requiresApproval` annotation — same hermetic
+ *  device as policy-tool-approval.test.ts) and then returns a deterministic
+ *  payload. The pattern is unique-per-run and matches no real tool, so the
+ *  created `block` rule is inert even if leaked. */
+const gatedThenReturnCode = (pattern: string, payload: unknown) => `
+await tools.executor.coreTools.policies.create({
+  owner: "user",
+  pattern: ${JSON.stringify(pattern)},
+  action: "block",
+});
+return ${JSON.stringify(payload)};
+`;
+
+scenario(
+  "MCP · a duplicate resume replays the identical settled result without re-running the tool",
+  {},
+  Effect.gen(function* () {
+    const target = yield* Target;
+    const apiSurface = yield* Api;
+    const mcp = yield* Mcp;
+    const identity = yield* target.newIdentity();
+    const client = yield* apiSurface.client(coreApi, identity);
+    const pattern = `mcp-resume-replay-${randomUUID().slice(0, 8)}.*`;
+    const replayPayload = { note: "resumed — résultat 完了 ✅", pattern };
+
+    const cleanup = client.policies.list().pipe(
+      Effect.flatMap((list) =>
+        Effect.forEach(
+          list.filter((p) => p.pattern === pattern),
+          (p) =>
+            client.policies
+              .remove({ params: { policyId: p.id }, payload: { owner: "user" } })
+              .pipe(Effect.ignore),
+        ),
+      ),
+      Effect.ignore,
+    );
+
+    yield* Effect.gen(function* () {
+      const session = mcp.session(identity);
+      yield* session.listTools();
+
+      const paused = yield* session.call("execute", {
+        code: gatedThenReturnCode(pattern, replayPayload),
+      });
+      expect(paused.text, "the gated call pauses for approval").toContain("Execution paused");
+      const match = /\bexecutionId:\s*(\S+)/.exec(paused.text);
+      expect(match, "the pause carries an executionId to resume").not.toBeNull();
+
+      // MCP clients retry `resume` when a response is lost in transit, so the
+      // duplicate uses the exact same arguments as the first delivery.
+      const resumeArgs = {
+        executionId: match![1]!,
+        action: "accept",
+        content: JSON.stringify({}),
+      };
+
+      const resumed = yield* session.call("resume", resumeArgs);
+      expect(resumed.ok, "the approved execution completes without error").toBe(true);
+      const expectedText = JSON.stringify(replayPayload, null, 2);
+      expect(resumed.text, "the resumed result carries the exact returned value").toBe(
+        expectedText,
+      );
+      expect(
+        rawResultOf(resumed).structuredContent,
+        "the resumed structuredContent mirrors the exact returned value",
+      ).toEqual({ status: "completed", result: replayPayload, logs: [] });
+
+      const replayed = yield* session.call("resume", resumeArgs);
+      expect(replayed.ok, "the duplicate resume succeeds instead of erroring").toBe(true);
+      expect(replayed.text, "the replayed text is byte-identical to the first delivery").toBe(
+        resumed.text,
+      );
+      expect(
+        rawResultOf(replayed).structuredContent,
+        "the replayed structuredContent is identical to the first delivery",
+      ).toEqual(rawResultOf(resumed).structuredContent);
+
+      // The replay served the recorded outcome — the gated tool did not run a
+      // second time.
+      const afterReplay = yield* client.policies.list();
+      expect(
+        afterReplay.filter((p) => p.pattern === pattern).length,
+        "the gated tool ran exactly once despite the duplicate resume",
+      ).toBe(1);
+    }).pipe(Effect.ensuring(cleanup));
+  }),
+);
+
 scenario(
   "MCP · a syntax error returns a descriptive message, not an opaque internal error",
   {},

e2e/scenarios/run-panel-auto-approve.test.ts

@@ -26,14 +26,24 @@ import { Api, Target } from "../src/services";
 
 const coreApi = composePluginApi([] as const);
 
+/** The deterministic value the gated script returns once approved. Asserting
+ *  the completed response against it byte-for-byte (non-ASCII included) pins
+ *  output fidelity on the autoApprove path — the panel must render exactly
+ *  what the script returned. */
+const approvedPayload = {
+  note: "auto-approved — résultat 完了 ✅",
+  values: [1, 2, 3],
+};
+
 /** Sandbox code that creates a policy through the approval-gated core tool. The
  *  pattern is unique-per-run and matches no real tool, so the rule is inert. */
 const createPolicyCode = (pattern: string) => `
-return await tools.executor.coreTools.policies.create({
+await tools.executor.coreTools.policies.create({
   owner: "user",
   pattern: ${JSON.stringify(pattern)},
   action: "block",
 });
+return ${JSON.stringify(approvedPayload)};
 `;
 
 // Why this was long skipped: `autoApprove: true` came back `"paused"` instead of
@@ -97,6 +107,12 @@ scenario(
       expect(approved.status, "autoApprove runs the gated tool to completion").toBe("completed");
       if (approved.status !== "completed") return; // narrowing only
       expect(approved.isError, "the auto-approved run is not an error").toBe(false);
+      expect(approved.text, "the returned value reaches the panel byte-identical").toBe(
+        JSON.stringify(approvedPayload, null, 2),
+      );
+      expect(approved.structured, "the structured result mirrors the exact returned value").toEqual(
+        { status: "completed", result: approvedPayload, logs: [] },
+      );
 
       const afterApproval = yield* client.policies.list();
       expect(

packages/core/execution/src/engine.test.ts

@@ -5,7 +5,7 @@ import { createExecutor, definePlugin } from "@executor-js/sdk";
 import { makeTestConfig } from "@executor-js/sdk/testing";
 import type { CodeExecutor, ExecuteResult } from "@executor-js/codemode-core";
 
-import { createExecutionEngine, formatPausedExecution } from "./engine";
+import { createExecutionEngine, formatExecuteResult, formatPausedExecution } from "./engine";
 import { FormElicitation } from "@executor-js/sdk/core";
 
 // Regression for the hang reported as the executor-MCP "180s timeout" against
@@ -140,3 +140,139 @@ describe("formatPausedExecution approval terms", () => {
     expect((result.structured["interaction"] as Record<string, unknown>)["meta"]).toBeUndefined();
   });
 });
+
+// Pins the exact preview and structured shapes so the serialization dedupe in
+// the engine cannot drift them: the preview stays pretty-printed (indent 2),
+// truncation keeps its exact suffix, and structured carries the raw value.
+describe("formatExecuteResult output identity", () => {
+  const MAX_PREVIEW_CHARS = 30_000;
+
+  it("renders an object result as pretty-printed JSON and keeps the raw value in structured", () => {
+    const value = { café: "naïve — ✓", emoji: "🎉", nested: { π: 3.14159 } };
+    const formatted = formatExecuteResult({ result: value, logs: [] });
+
+    expect(formatted.text).toBe(JSON.stringify(value, null, 2));
+    expect(formatted.structured).toEqual({ status: "completed", result: value, logs: [] });
+    expect(formatted.structured["result"]).toBe(value);
+    expect(formatted.isError).toBe(false);
+  });
+
+  it("truncates a long preview with the exact suffix and untouched structured value", () => {
+    const value = { data: "é🎉".repeat(12_000) };
+    const pretty = JSON.stringify(value, null, 2);
+    expect(pretty.length).toBeGreaterThan(MAX_PREVIEW_CHARS);
+
+    const formatted = formatExecuteResult({ result: value });
+
+    expect(formatted.text).toBe(
+      `${pretty.slice(0, MAX_PREVIEW_CHARS)}\n... [truncated ${pretty.length - MAX_PREVIEW_CHARS} chars]`,
+    );
+    expect(formatted.structured["result"]).toBe(value);
+  });
+
+  it("returns a string result verbatim", () => {
+    const formatted = formatExecuteResult({ result: "plain — ✓", logs: ["l1", "l2"] });
+
+    expect(formatted.text).toBe("plain — ✓\n\nLogs:\nl1\nl2");
+    expect(formatted.structured).toEqual({
+      status: "completed",
+      result: "plain — ✓",
+      logs: ["l1", "l2"],
+    });
+  });
+
+  it("renders an error result with logs and truncation", () => {
+    const formatted = formatExecuteResult({
+      result: null,
+      error: "boom",
+      errorKind: "tool_error",
+      logs: ["x".repeat(MAX_PREVIEW_CHARS)],
+    });
+
+    const untruncated = `Error: boom\n\nLogs:\n${"x".repeat(MAX_PREVIEW_CHARS)}`;
+    expect(formatted.text).toBe(
+      `${untruncated.slice(0, MAX_PREVIEW_CHARS)}\n... [truncated ${untruncated.length - MAX_PREVIEW_CHARS} chars]`,
+    );
+    expect(formatted.isError).toBe(true);
+    expect(formatted.structured).toEqual({
+      status: "error",
+      error: "boom",
+      logs: ["x".repeat(MAX_PREVIEW_CHARS)],
+    });
+  });
+});
+
+// The result-size span metric walks the whole result value with
+// `JSON.stringify`. A `toJSON` probe inside the fixture counts full walks:
+// every complete stringify of the value visits the probe exactly once.
+describe("execute outcome measurement cost", () => {
+  const instrumented = () => {
+    let walks = 0;
+    const probe = {
+      toJSON: () => {
+        walks += 1;
+        return "probe";
+      },
+    };
+    return { value: { data: [1, 2, 3], probe }, walks: () => walks };
+  };
+
+  const executorFor = (result: ExecuteResult): CodeExecutor<FakeRuntimeError> => ({
+    execute: () => Effect.succeed(result),
+  });
+
+  it.effect("walks the result value once on the pausable path", () =>
+    Effect.gen(function* () {
+      const executor = yield* makeExecutor();
+      const fixture = instrumented();
+      const engine = createExecutionEngine({
+        executor,
+        codeExecutor: executorFor({ result: fixture.value, logs: [] }),
+      });
+
+      const outcome = yield* engine.executeWithPause("noop");
+
+      expect(outcome.status).toBe("completed");
+      expect(fixture.walks()).toBe(1);
+    }),
+  );
+
+  it.effect("walks the result value once even when autoApprove stamps two spans", () =>
+    Effect.gen(function* () {
+      const executor = yield* makeExecutor();
+      const fixture = instrumented();
+      const engine = createExecutionEngine({
+        executor,
+        codeExecutor: executorFor({ result: fixture.value, logs: [] }),
+      });
+
+      // autoApprove runs the inline path (inner span annotation) and then
+      // annotates the outer pausable span with the same result.
+      const outcome = yield* engine.executeWithPause("noop", { autoApprove: true });
+
+      expect(outcome.status).toBe("completed");
+      expect(fixture.walks()).toBe(1);
+    }),
+  );
+
+  it.effect("a completed execution plus its preview pays two walks total", () =>
+    Effect.gen(function* () {
+      const executor = yield* makeExecutor();
+      const fixture = instrumented();
+      const engine = createExecutionEngine({
+        executor,
+        codeExecutor: executorFor({ result: fixture.value, logs: [] }),
+      });
+
+      const outcome = yield* engine.executeWithPause("noop");
+      expect(outcome.status).toBe("completed");
+      if (outcome.status !== "completed") return;
+
+      // One compact walk for the span size metric, one pretty walk for the
+      // preview. They produce different strings (compact vs indent 2), so
+      // neither can be derived from the other.
+      formatExecuteResult(outcome.result);
+      expect(fixture.walks()).toBe(2);
+    }),
+  );
+});