From 3137be917fc92ac50250819c16ee5afd70b5bf80 Mon Sep 17 00:00:00 2001 From: nickyleach <331803+nickyleach@users.noreply.github.com> Date: Fri, 11 Sep 2026 18:23:04 +0000 Subject: [PATCH 1/7] feat(acpx-engine): observe ACP permission handoff receipt and settlement Add a permission observer that watches the ACP permission handoff and writes receipt and settlement events to the run log. The observer always returns undefined, so it never answers, approves, denies, or changes a permission decision. It lets an operator tell a stalled handoff from a normal wait, with no change to run behavior. Co-authored-by: Paperclip --- .../adapter-utils/src/acpx-engine/execute.ts | 31 +++ .../acpx-engine/permission-observer.test.ts | 247 ++++++++++++++++++ .../src/acpx-engine/permission-observer.ts | Bin 0 -> 9093 bytes 3 files changed, 278 insertions(+) create mode 100644 packages/adapter-utils/src/acpx-engine/permission-observer.test.ts create mode 100644 packages/adapter-utils/src/acpx-engine/permission-observer.ts diff --git a/packages/adapter-utils/src/acpx-engine/execute.ts b/packages/adapter-utils/src/acpx-engine/execute.ts index ae10093fcb..f4976f04a1 100644 --- a/packages/adapter-utils/src/acpx-engine/execute.ts +++ b/packages/adapter-utils/src/acpx-engine/execute.ts @@ -116,6 +116,7 @@ import type { TurnCompletion, } from "./run-contracts.js"; import { createRunResourceLedger } from "./run-resource-ledger.js"; +import { createAcpPermissionObserver, type AcpPermissionObserver } from "./permission-observer.js"; import { settleAcpRun, type SettlementSteps } from "./settlement-sequence.js"; import { runAttempt, @@ -3978,6 +3979,12 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { let prepared!: AcpxPreparedRuntime; let runtime!: AcpRuntime; let sessionHandle!: AcpRuntimeHandle; + // Observes the ACP permission handoff for the run log; it never answers + // a permission request. Assigned once `prepared` is ready (it reads the + // effective permission mode and the execution transport), so it stays + // undefined on a build failure that never reaches that point — the + // ledger would hold no entries at that point anyway. + let permissionObserver: AcpPermissionObserver | undefined; let childStderrState!: ChildStderrState; let processIdentitySink!: AcpxProcessIdentitySink; let resumedSession = false; @@ -4109,6 +4116,20 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { }), ); buildRuntimeSettled = true; + const observedExecutionTarget = ctx.executionTarget; + permissionObserver = createAcpPermissionObserver({ + permissionMode: prepared.permissionMode, + // A missing execution target means the local environment, the same + // convention `describeAdapterExecutionTarget` already uses. + transport: !observedExecutionTarget || observedExecutionTarget.kind === "local" + ? "local" + : observedExecutionTarget.transport, + emitLog: (payload) => { + // Fire-and-forget: the observer's caller must not await a log + // write on the permission critical path. + void emitAcpxLog(ctx, payload).catch(() => {}); + }, + }); // Capture the run's staging lease release now that the runtime built. The // run root `finally` releases it as the final settlement act. releaseStagingLease = prepared.sessionStagingLeaseRelease; @@ -4195,6 +4216,9 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { agentRegistry: prepared.agentRegistry, permissionMode: prepared.permissionMode, nonInteractivePermissions: prepared.nonInteractivePermissions, + // Observation only: this hook always resolves to `undefined`, so it + // never changes which permission option acpx resolves on its own. + onPermissionRequest: permissionObserver?.handlePermissionRequest, mcpServers: prepared.mcpServers, timeoutMs: prepared.timeoutSec > 0 ? prepared.timeoutSec * 1000 : undefined, // Scope ACPX runtime verbose logs to the claude agent only. Codex @@ -4793,6 +4817,10 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { kind: event.kind ?? previous?.kind, status: event.status ?? previous?.status, }); + permissionObserver?.noteToolCallEvent(sessionHandle.backendSessionId, { + toolCallId: event.toolCallId, + status: event.status, + }); } } if (event.type === "text_delta" && event.stream !== "thought") { @@ -5313,6 +5341,9 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { const report = await settleAcpRun(runResourceLedger, cause, settlementSteps); recordDispositionReport(report); if (childStderrState) flushChildStderr(childStderrState); + // Report every permission request the run never saw settle. Not on + // the permission critical path, so this may await its log writes. + await permissionObserver?.finalizeRun(); }, reproduceResult: async (): Promise => { if (!capturedResult) { diff --git a/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts b/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts new file mode 100644 index 0000000000..a7103dfc7c --- /dev/null +++ b/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts @@ -0,0 +1,247 @@ +import { describe, expect, it } from "vitest"; +import type { AcpPermissionRequest } from "acpx/runtime"; +import { + createAcpPermissionObserver, + mapPermissionObserverMethod, + mapPermissionObserverOutcome, + mapPermissionObserverToolKind, + type PermissionObserverLogEvent, +} from "./permission-observer.js"; + +function buildRequest(overrides: Partial = {}): AcpPermissionRequest { + return { + sessionId: "session-1", + inferredKind: "execute", + raw: { + sessionId: "session-1", + toolCall: { toolCallId: "tool-1" }, + options: [], + }, + ...overrides, + } as AcpPermissionRequest; +} + +describe("permission-observer closed-enum mappers", () => { + it("maps a recognized method and returns 'unknown' for anything else", () => { + expect(mapPermissionObserverMethod("session/request_permission")).toBe("session/request_permission"); + expect(mapPermissionObserverMethod("session/other_method")).toBe("unknown"); + expect(mapPermissionObserverMethod(undefined)).toBe("unknown"); + expect(mapPermissionObserverMethod(42)).toBe("unknown"); + }); + + it("maps a recognized tool kind and returns 'unknown' for anything else", () => { + expect(mapPermissionObserverToolKind("execute")).toBe("execute"); + expect(mapPermissionObserverToolKind("teleport")).toBe("unknown"); + expect(mapPermissionObserverToolKind(undefined)).toBe("unknown"); + }); + + it("maps a terminal outcome and returns 'unknown' for a non-terminal or unrecognized status", () => { + expect(mapPermissionObserverOutcome("completed")).toBe("completed"); + expect(mapPermissionObserverOutcome("failed")).toBe("failed"); + expect(mapPermissionObserverOutcome("pending")).toBe("unknown"); + expect(mapPermissionObserverOutcome("something-else")).toBe("unknown"); + }); +}); + +describe("createAcpPermissionObserver — handlePermissionRequest", () => { + it("resolves to undefined for a normal request", async () => { + const events: PermissionObserverLogEvent[] = []; + const observer = createAcpPermissionObserver({ + emitLog: (event) => events.push(event), + permissionMode: "approve-all", + transport: "sandbox", + }); + const result = await observer.handlePermissionRequest(buildRequest(), { signal: new AbortController().signal }); + expect(result).toBeUndefined(); + }); + + it("resolves to undefined for a request that carries unknown fields", async () => { + const events: PermissionObserverLogEvent[] = []; + const observer = createAcpPermissionObserver({ + emitLog: (event) => events.push(event), + permissionMode: "approve-all", + transport: "sandbox", + }); + const request = buildRequest({ + inferredKind: "not-a-real-kind" as unknown as AcpPermissionRequest["inferredKind"], + raw: { + sessionId: "session-1", + toolCall: { toolCallId: "tool-1" }, + options: [], + _meta: { anExtraField: "some value nobody declared" }, + } as AcpPermissionRequest["raw"], + }); + const result = await observer.handlePermissionRequest(request, { signal: new AbortController().signal }); + expect(result).toBeUndefined(); + }); + + it("resolves to undefined even when the injected log sink throws", async () => { + const observer = createAcpPermissionObserver({ + emitLog: () => { + throw new Error("sink failure"); + }, + permissionMode: "approve-all", + transport: "sandbox", + }); + const result = await observer.handlePermissionRequest(buildRequest(), { signal: new AbortController().signal }); + expect(result).toBeUndefined(); + }); + + it("never awaits the log write on the hook path", async () => { + let logCalled = false; + const observer = createAcpPermissionObserver({ + // A log sink that returns a promise which never resolves. If the hook + // awaited it internally, the assertion below would never run. + emitLog: () => { + logCalled = true; + return new Promise(() => {}) as unknown as void; + }, + permissionMode: "approve-all", + transport: "sandbox", + }); + let settled = false; + const promise = observer.handlePermissionRequest(buildRequest(), { signal: new AbortController().signal }); + void promise.then(() => { + settled = true; + }); + // Flush one microtask turn. A synchronous hook body resolves within it; + // an awaited I/O call would not. + await Promise.resolve(); + await Promise.resolve(); + expect(settled).toBe(true); + expect(logCalled).toBe(true); + }); + + it("emits only allow-listed scalar fields, never the raw request payload", async () => { + const events: PermissionObserverLogEvent[] = []; + const observer = createAcpPermissionObserver({ + emitLog: (event) => events.push(event), + permissionMode: "approve-all", + transport: "sandbox", + }); + const longString = "x".repeat(10_000); + const request = buildRequest({ + raw: { + sessionId: "session-1", + toolCall: { + toolCallId: "tool-1", + rawInput: { command: "rm -rf /", nested: { secret: "s3cr3t" } }, + }, + options: [], + _meta: { note: longString }, + } as unknown as AcpPermissionRequest["raw"], + }); + (request as unknown as { error: unknown }).error = { data: { stack: "leaked stack trace" } }; + await observer.handlePermissionRequest(request, { signal: new AbortController().signal }); + + expect(events).toHaveLength(1); + const [event] = events; + const serialized = JSON.stringify(event); + expect(serialized).not.toContain("rm -rf"); + expect(serialized).not.toContain("s3cr3t"); + expect(serialized).not.toContain("leaked stack trace"); + expect(serialized).not.toContain(longString); + expect(Object.keys(event).sort()).toEqual( + ["method", "permissionMode", "sessionId", "stage", "toolCallId", "toolKind", "transport", "type"].sort(), + ); + }); + + it("maps an unmapped tool kind to exactly 'unknown', dropping the source string", async () => { + const events: PermissionObserverLogEvent[] = []; + const observer = createAcpPermissionObserver({ + emitLog: (event) => events.push(event), + permissionMode: "approve-all", + transport: "sandbox", + }); + const request = buildRequest({ inferredKind: "levitate" as unknown as AcpPermissionRequest["inferredKind"] }); + await observer.handlePermissionRequest(request, { signal: new AbortController().signal }); + expect(events[0]?.toolKind).toBe("unknown"); + expect(JSON.stringify(events[0])).not.toContain("levitate"); + }); +}); + +describe("createAcpPermissionObserver — ledger lifecycle", () => { + it("opens an entry on receipt, closes it on the terminal tool_call_update, and reports the age", async () => { + let clock = 1_000; + const events: PermissionObserverLogEvent[] = []; + const observer = createAcpPermissionObserver({ + emitLog: (event) => events.push(event), + permissionMode: "approve-all", + transport: "sandbox", + now: () => clock, + }); + await observer.handlePermissionRequest(buildRequest(), { signal: new AbortController().signal }); + clock += 4_200; + observer.noteToolCallEvent("session-1", { toolCallId: "tool-1", status: "completed" }); + + const settled = events.find((event) => event.type === "acpx.permission_settled"); + expect(settled).toMatchObject({ + type: "acpx.permission_settled", + sessionId: "session-1", + toolCallId: "tool-1", + outcome: "completed", + ageMs: 4_200, + }); + + // A settled entry must not resurface at finalization. + events.length = 0; + await observer.finalizeRun(); + expect(events).toHaveLength(0); + }); + + it("reports one unsettled event per still-open entry at run finalization, with the last observed stage", async () => { + let clock = 0; + const events: PermissionObserverLogEvent[] = []; + const observer = createAcpPermissionObserver({ + emitLog: (event) => events.push(event), + permissionMode: "approve-all", + transport: "sandbox", + now: () => clock, + }); + await observer.handlePermissionRequest(buildRequest(), { signal: new AbortController().signal }); + await observer.handlePermissionRequest( + buildRequest({ + raw: { sessionId: "session-1", toolCall: { toolCallId: "tool-2" }, options: [] } as AcpPermissionRequest["raw"], + }), + { signal: new AbortController().signal }, + ); + // tool-1 advances to "in_progress" but never reaches a terminal status. + observer.noteToolCallEvent("session-1", { toolCallId: "tool-1", status: "in_progress" }); + clock = 27 * 60 * 1000; + + await observer.finalizeRun(); + + const unsettled = events.filter((event) => event.type === "acpx.permission_unsettled"); + expect(unsettled).toHaveLength(2); + const byToolCallId = Object.fromEntries(unsettled.map((event) => [event.toolCallId, event])); + expect(byToolCallId["tool-1"]).toMatchObject({ stage: "in_progress", ageMs: 27 * 60 * 1000 }); + expect(byToolCallId["tool-2"]).toMatchObject({ stage: "requested", ageMs: 27 * 60 * 1000 }); + + // Finalization drains the ledger; a second call reports nothing new. + events.length = 0; + await observer.finalizeRun(); + expect(events).toHaveLength(0); + }); + + it("does not close an entry on a non-terminal tool_call status", () => { + const events: PermissionObserverLogEvent[] = []; + const observer = createAcpPermissionObserver({ + emitLog: (event) => events.push(event), + permissionMode: "approve-all", + transport: "sandbox", + }); + observer.noteToolCallEvent("session-1", { toolCallId: "tool-1", status: "pending" }); + expect(events.filter((event) => event.type === "acpx.permission_settled")).toHaveLength(0); + }); + + it("ignores a tool_call event for a toolCallId it never opened", () => { + const events: PermissionObserverLogEvent[] = []; + const observer = createAcpPermissionObserver({ + emitLog: (event) => events.push(event), + permissionMode: "approve-all", + transport: "sandbox", + }); + observer.noteToolCallEvent("session-1", { toolCallId: "never-opened", status: "completed" }); + expect(events).toHaveLength(0); + }); +}); diff --git a/packages/adapter-utils/src/acpx-engine/permission-observer.ts b/packages/adapter-utils/src/acpx-engine/permission-observer.ts new file mode 100644 index 0000000000000000000000000000000000000000..cb09275ede07f90c0f53f96acb2ed36c3b3327f2 GIT binary patch literal 9093 zcmbtZ?M~y$8SZbcVm3NDO;*9ss_KuhETWJ-C)y1`kXDt@iVXH7vDWdV9-EM|NWF+& zVXvgmJ6|3{l7(}Sb}{zMJMZW7eoVSp%A#cDdMVf=JB^o@qFAI#r7}MkaZ10t&DU4r zUzJcLdt%ciT1R_(2k+nSvG;6rr$lkjOAy$XdA4SADZjBaFC{DI zf}NgSvZX(Y&3T^4=`>=4lI7xF6pZI;B?`qj5i87@`g0*-StJVYVv#OOEKHaZWtoYE z$V;4{>4PDb$r)1;3z)=Fyp#peit%?TvW#)2N}gpRai<%BILl?R;2B%-w2ZKWHub^M znu$ePmRLVcMV7E7S4t?HR>*2L2e~+t3SUKDE$BE%&Ljk3ce2V8kq{jf^Nbe}8$$&P znN*pu;!b6;;v^O+r{F8CplQJuqN`t(Qf82CS(RN7B~m-e|7t%fAP!sS9Z+)e0X>iEIIw9e>=RU_kRKLzaF~( z{&Yy|_QZqs6GQT{e>EIjUk^qXx1+yZ_pkl|y2JkX*U>oG_~*5Zf6`v6hl$YWdeF_S|F!v$Elqg==@F;U)guos`78ST;=48KjeBm8hyF_ zJh(87?=jXY1W#IBdJ;)mnx{l$q7>$NA@A*z61<4#cI|_RE4QSar};PYekw}0M6FUh z-@@v4zcwD0y{=Qo&wNTsia&SO`>Nplji=_%aU&4EU1W zJnc~TX^2s>D#4NRFrFZqLa8P3xwFs*N<&TCRZZqv2mB(^Q;m*W`VbZcbo8-JpxtJsmF7@ ziya>y!@!zsi~amFbA%~Ryg0TKrFooHiBN65yVKD`8CI56ksC&6r)S^@XFlPdT@WOP zC!ZcdCDdAO<{@)lDC4%3nj?E$L#yq;D9_WT)nVso@3m~XT<{vk+}gLXR;Q5$ce}Mk zN1eep0Gh}auVK!>EBVH&m1fYk!Ig!W-OO1udkt3(_};{q!@;+6=JDz^y!pj%w5P|q zxARv!JAuz@m~8HN8>c~_Xh?1FYx|2czSN~Z6^Hw?3biv;;Ib%0W=iiA7+a<&)eBdC zpg6%RYAUG0L3co9v@4m}C0~jn&eA3OCd87~AUzw5vOR@POU!i^goj5|@aTSpNckEb zFVW_p&mjCPD32>tgr+L@9vbuIz_a*LqXrVS-dm2bc#hz`F}wp+~9ul;&wE zu(-p%e`gEDKCnYC1$qt7{g9XQ2z5|fKcLIX6WV1MH2sPJOmvl^nDSV#+UvfEWG0G! zUZQWKAhtcp02#}umJXuwiqNY07TsbllGAeN#c^w?`0fRVxE$dCmeyrll^WAFEz}>h z2I0o+ltH=_y=Iqqs$%3Y_{x1MR=ybYJ zQb@=v$&8j31W7fu7EVItC=KDkt2#C9qW?wC0@8@io|zFu2roNXxV5bVS`YMVG(ZSH znr43Uw<>pEN!2&s#M*KE)#v6ght`ZXMjK8Sqa_tTN^3#m3PTvfMn!2bB7s5f(4*5N zVO79uo1KpvRnVls0tR}1*a*B4w0MD8jLj*ETEGn=@qhpMFUAn)sQ?r-zA%Ze%Mz*k zun8xE6WvVZ3OHuSO=w7xiQ2`lOb0gsu;91@{7(Z4=)cF>+FdqzpfgX09e-r^GEGR4 zAf?8JsIRlNrLG5xZSVGAmutQB4i;1f4l4&kdy87Ib@P9XU zqm76AwKb~-PTpYKrcp_{iOgRrPtT+p{dOjp_WW~0nU?U?QjZB zuBr1CY$x(m;5XERst=7FtZD{jCKX8SYLT5J-9i3%PGbg8Gc_&hYDyW}V<}~bqL4)w zR5o&?{l-knXaKcB}^w8XL1+c?$J9BGxDl@C2k1gWj(85ZAROn9yTU{AD4 z8|4xcz*LD3jo@-~L&Ub%;799aM&M5ZV=~Sr1U$DC2ouVxG(cnq<}kG*q(h$$4A&Do zJzK+`1;-GDR7D_dr~$@+@iGVeQy3c9V$=`7jJA=E7(t$KT=HNXgFUK>=k`QtiP5of zg(?ErXj8^f$V+8LeuxX67Od^F3Z`^Emvqp97}kiIW)IE}tg3BpPRk;HL=XZo(aIHEq z`MM-Vax6u|FCFN&O(-I{Z~Sa?0xFn|pEazQ{uuCtHr!H+=&zF#c8+7|nH=6MvtE3R zY_VcPzWiY7k8V&$1jWk7HfkETway^6=LfXZ5atA`-{|7pG1S}~Q1xI7?l%(j4Te)y zs%@qhI{=ho2tnzp!DM8Llpzv&`-~W%2ON2G)wT+46tI3f#5mVYAl0rM4D?wIT<+2NyZM&>(H;a;eK!b3_;24mprF zr54d4wrY=eS&l#j(`anRcv;ZJi2bqh;XIPBtE1X|^Y%5_(7bjw8zkY|MynuK?N0cS zwvaW#cR_a$OyKJkPu>hPwW1#v&bGE|8^@(D)cWo!u4}3rB-$j;LSMP`HiLq>k7@6^ z+zF(ADLYIyBX(^V(JlxMH|G!!=xmOETNTlUB)*xGsOSo>xp_bpA! zyRSjh+RI)*qCRs60=^Bj%yFg^bWj(~OmusmG_vV6Zr(ter5}s^_NHem;!?SW_K+r< zmVE<6jT5w^o4K~TihO>Y<{|P}0NvW#R(Uv6bhMC(L@dRjGw2c)DgyxD#q3lAlxNphS*z9p>2Yj42 z;o`{l_P91g?4m5i%w@)0ysOHLo6xM8PDLA`4*E>WCC~#`ph>|~>O+7F)RCYMAbHJ= zs@`M@U42IphIpgs-4fivny|_V;@G$~DWZ=i3H>QN?Iwya5v0Z{(&ItZ?tC>Sw{PPN z7u%)^WxCyOhrxyW;eejIfB6k*%6A??9`NqrT*1Gn4gWfS(edP{_&}?v{66>bcx;jS aQRjvYvzaapbef%B*ELMk&=9OY?foA)sqX~< literal 0 HcmV?d00001 From 7f1b1d47608d1ba357e5405b54464aeec76b1d70 Mon Sep 17 00:00:00 2001 From: nickyleach <331803+nickyleach@users.noreply.github.com> Date: Fri, 11 Sep 2026 18:40:48 +0000 Subject: [PATCH 2/7] fix(acpx-engine): keep the permission observer text-diffable and closed Write the ledger key separator as a Unicode escape so every byte in the module stays printable ASCII. A raw NUL byte made git treat the file as binary and hid the diff from every reader. Open a ledger entry only when the request carries a real session identifier and a real tool-call identifier. Before this change, a missing identifier still opened an entry that could never close, so it always reported as unsettled at run end. The observation event still reports the missing field as "unknown"; only the unsettlable entry is gone. Add tests that drive a permission request through the runtime's onPermissionRequest hook, then a terminal tool-call event through the same drain loop the engine uses, and confirm the settle step calls the observer's run-finalization step. These tests were the one gap in the prior commit: the module had unit coverage, but the three points where the engine wires it to the runtime had none. Correct two comments that claimed a call awaits a log write. The log sink returns void, so neither call awaits anything. Co-authored-by: Paperclip --- .../src/acpx-engine/execute.test.ts | 134 ++++++++++++++++++ .../adapter-utils/src/acpx-engine/execute.ts | 3 +- .../acpx-engine/permission-observer.test.ts | 51 +++++++ .../src/acpx-engine/permission-observer.ts | Bin 9093 -> 9551 bytes 4 files changed, 187 insertions(+), 1 deletion(-) diff --git a/packages/adapter-utils/src/acpx-engine/execute.test.ts b/packages/adapter-utils/src/acpx-engine/execute.test.ts index 5981cc79cf..5dc6887608 100644 --- a/packages/adapter-utils/src/acpx-engine/execute.test.ts +++ b/packages/adapter-utils/src/acpx-engine/execute.test.ts @@ -2488,6 +2488,140 @@ describe("shared ACPX engine runtime behavior", () => { }); }); +describe("ACPX engine permission-observer wiring", () => { + function parseLogEvents(logs: Array<{ stream: string; text: string }>): Array> { + return logs + .filter((entry) => entry.stream === "stdout") + .map((entry) => { + try { + return JSON.parse(entry.text) as Record; + } catch { + return null; + } + }) + .filter((parsed): parsed is Record => parsed !== null); + } + + it("passes the observer's hook as onPermissionRequest, and the settle step reports a request the turn never saw settle", async () => { + const root = await makeTempRoot(); + const stateDir = path.join(root, "state"); + const logs: Array<{ stream: string; text: string }> = []; + const runtimeOptions: Array<{ onPermissionRequest?: (...args: unknown[]) => unknown }> = []; + const execute = createAcpxEngineExecutor({ + createRuntime: (options) => { + runtimeOptions.push(options as unknown as { onPermissionRequest?: (...args: unknown[]) => unknown }); + // The engine wires this before it calls createRuntime, so calling it + // here reproduces the same order acpx uses: request arrives, then the + // turn's tool-call events drain (or, as here, never arrive). + void options.onPermissionRequest?.( + { + sessionId: "backend-session", + inferredKind: "execute", + raw: { sessionId: "backend-session", toolCall: { toolCallId: "tool-never-closes" }, options: [] }, + } as never, + { signal: new AbortController().signal }, + ); + return { + ensureSession: async () => ({ + backendSessionId: "backend-session", + agentSessionId: "agent-session", + runtimeSessionName: "runtime-session", + }), + startTurn: () => ({ + events: (async function* () { + yield { type: "done", stopReason: "end_turn" }; + })(), + result: Promise.resolve({ status: "completed", stopReason: "end_turn" }), + cancel: async () => {}, + }), + close: async () => {}, + } as never; + }, + }); + + const result = await execute({ + runId: "run-permission-wiring-unsettled", + agent: { id: "agent-1", companyId: "company-1" }, + runtime: {}, + config: { agent: "custom", agentCommand: "node ./fake-acp.js", stateDir }, + context: {}, + onLog: async (stream: "stdout" | "stderr", text: string) => { + logs.push({ stream, text }); + }, + onMeta: async () => {}, + } as never); + + expect(result.exitCode).toBe(0); + expect(typeof runtimeOptions[0]?.onPermissionRequest).toBe("function"); + + const events = parseLogEvents(logs); + const observed = events.find((event) => event.type === "acpx.permission_observed"); + expect(observed).toMatchObject({ toolCallId: "tool-never-closes", sessionId: "backend-session" }); + const unsettled = events.find((event) => event.type === "acpx.permission_unsettled"); + expect(unsettled).toMatchObject({ toolCallId: "tool-never-closes", sessionId: "backend-session" }); + }); + + it("settles a permission request when the tool-call drain loop reports a matching terminal event", async () => { + const root = await makeTempRoot(); + const stateDir = path.join(root, "state"); + const logs: Array<{ stream: string; text: string }> = []; + const execute = createAcpxEngineExecutor({ + createRuntime: (options) => { + void options.onPermissionRequest?.( + { + sessionId: "backend-session", + inferredKind: "execute", + raw: { sessionId: "backend-session", toolCall: { toolCallId: "tool-1" }, options: [] }, + } as never, + { signal: new AbortController().signal }, + ); + return { + ensureSession: async () => ({ + backendSessionId: "backend-session", + agentSessionId: "agent-session", + runtimeSessionName: "runtime-session", + }), + startTurn: () => ({ + events: (async function* () { + yield { + type: "tool_call", + text: "Bash (completed)", + title: "Bash", + status: "completed", + toolCallId: "tool-1", + tag: "tool_call", + }; + yield { type: "done", stopReason: "end_turn" }; + })(), + result: Promise.resolve({ status: "completed", stopReason: "end_turn" }), + cancel: async () => {}, + }), + close: async () => {}, + } as never; + }, + }); + + const result = await execute({ + runId: "run-permission-wiring-settled", + agent: { id: "agent-1", companyId: "company-1" }, + runtime: {}, + config: { agent: "custom", agentCommand: "node ./fake-acp.js", stateDir }, + context: {}, + onLog: async (stream: "stdout" | "stderr", text: string) => { + logs.push({ stream, text }); + }, + onMeta: async () => {}, + } as never); + + expect(result.exitCode).toBe(0); + + const events = parseLogEvents(logs); + const settled = events.find((event) => event.type === "acpx.permission_settled"); + expect(settled).toMatchObject({ toolCallId: "tool-1", sessionId: "backend-session", outcome: "completed" }); + expect(events.find((event) => event.type === "acpx.permission_unsettled")).toBeUndefined(); + }); +}); + describe("findAncestorBin", () => { async function writeFakeBin(dir: string, name: string) { const binDir = path.join(dir, "node_modules", ".bin"); diff --git a/packages/adapter-utils/src/acpx-engine/execute.ts b/packages/adapter-utils/src/acpx-engine/execute.ts index f4976f04a1..795f1adcc8 100644 --- a/packages/adapter-utils/src/acpx-engine/execute.ts +++ b/packages/adapter-utils/src/acpx-engine/execute.ts @@ -5342,7 +5342,8 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { recordDispositionReport(report); if (childStderrState) flushChildStderr(childStderrState); // Report every permission request the run never saw settle. Not on - // the permission critical path, so this may await its log writes. + // the permission critical path. `emitLog` returns `void`, so this + // call awaits no log write. await permissionObserver?.finalizeRun(); }, reproduceResult: async (): Promise => { diff --git a/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts b/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts index a7103dfc7c..1a4b4cd05b 100644 --- a/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts +++ b/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts @@ -244,4 +244,55 @@ describe("createAcpPermissionObserver — ledger lifecycle", () => { observer.noteToolCallEvent("session-1", { toolCallId: "never-opened", status: "completed" }); expect(events).toHaveLength(0); }); + + it("does not open a ledger entry for a request with no tool-call identifier", async () => { + const events: PermissionObserverLogEvent[] = []; + const observer = createAcpPermissionObserver({ + emitLog: (event) => events.push(event), + permissionMode: "approve-all", + transport: "sandbox", + }); + const request = buildRequest({ + raw: { sessionId: "session-1", toolCall: {}, options: [] } as unknown as AcpPermissionRequest["raw"], + }); + await observer.handlePermissionRequest(request, { signal: new AbortController().signal }); + + const observed = events.filter((event) => event.type === "acpx.permission_observed"); + expect(observed).toHaveLength(1); + expect(observed[0]).toMatchObject({ toolCallId: "unknown" }); + + events.length = 0; + await observer.finalizeRun(); + expect(events).toHaveLength(0); + }); + + it("does not let two requests with a missing session identifier share one ledger entry", async () => { + const events: PermissionObserverLogEvent[] = []; + const observer = createAcpPermissionObserver({ + emitLog: (event) => events.push(event), + permissionMode: "approve-all", + transport: "sandbox", + }); + const firstRequest = buildRequest({ + sessionId: undefined as unknown as string, + raw: { toolCall: { toolCallId: "tool-1" }, options: [] } as unknown as AcpPermissionRequest["raw"], + }); + const secondRequest = buildRequest({ + sessionId: undefined as unknown as string, + raw: { toolCall: { toolCallId: "tool-2" }, options: [] } as unknown as AcpPermissionRequest["raw"], + }); + await observer.handlePermissionRequest(firstRequest, { signal: new AbortController().signal }); + await observer.handlePermissionRequest(secondRequest, { signal: new AbortController().signal }); + + // Neither request carried a real session identifier, so neither one opened + // a ledger entry. A terminal tool_call event for either tool call must + // find nothing to settle. + observer.noteToolCallEvent(undefined, { toolCallId: "tool-1", status: "completed" }); + observer.noteToolCallEvent(undefined, { toolCallId: "tool-2", status: "completed" }); + expect(events.filter((event) => event.type === "acpx.permission_settled")).toHaveLength(0); + + events.length = 0; + await observer.finalizeRun(); + expect(events).toHaveLength(0); + }); }); diff --git a/packages/adapter-utils/src/acpx-engine/permission-observer.ts b/packages/adapter-utils/src/acpx-engine/permission-observer.ts index cb09275ede07f90c0f53f96acb2ed36c3b3327f2..f17e33c0016b8c80dd41d88e68ef217466f8caf2 100644 GIT binary patch delta 587 zcmYk3L2DF25QPZ{f(Rm*U}j`}8Dcb1H_6p7gy2Dgc+1_hzrcfMYbMF=_Nky>ef8?q*H;&>fAZ2^`xbx=bm-Xf+fa5;5f3XL z(K!jW=sZIV;J%IM8s}g}#&U!YaG}JgvP|bcmVPg+M2gV{zhB@fvJb;8eVLXVf_tfr z`-ObJf3{nh(cx5>>!?pdioDyNcJI_~^mT)e43!^E0mvcca<;G|Y3uRrd6FEoHg42f zIbHrZ+1$h)92F&1AkWoUoqGiD#)!o12+pwn*&Zw-3`ln!S?}wbnfd-Ff&8^P=V delta 167 zcmX@_)#|>XL`+pjp*WvQK|w)FA+tmwH?dM7u{;sT$}A~X$jMJvC@;z^NiE*IRqPg{ zOoB>vacXgKW`3S$N-cv*bxD4Hj&ov84v?2Hd4ojL Date: Fri, 11 Sep 2026 19:02:25 +0000 Subject: [PATCH 3/7] fix(acpx-engine): bound the permission observer's ledger and log volume The agent process is untrusted. It can send an unbounded number of session/request_permission frames, and each one grew the observer's ledger and produced one run-log event. Add a fixed per-run budget: 256 ledger entries, 256 observed events, and 256 settled-or-unsettled events. The ledger entry and the observed event use separate budgets so an agent cannot spend the whole budget on one event type and starve the other. A run that hits any limit emits one summary event at finalization with the three suppressed counts, and no other value. Co-authored-by: Paperclip --- .../src/acpx-engine/execute.test.ts | 58 ++++++++ .../acpx-engine/permission-observer.test.ts | 123 ++++++++++++++++ .../src/acpx-engine/permission-observer.ts | 134 +++++++++++++----- 3 files changed, 282 insertions(+), 33 deletions(-) diff --git a/packages/adapter-utils/src/acpx-engine/execute.test.ts b/packages/adapter-utils/src/acpx-engine/execute.test.ts index 5dc6887608..6af6c9f98f 100644 --- a/packages/adapter-utils/src/acpx-engine/execute.test.ts +++ b/packages/adapter-utils/src/acpx-engine/execute.test.ts @@ -2620,6 +2620,64 @@ describe("ACPX engine permission-observer wiring", () => { expect(settled).toMatchObject({ toolCallId: "tool-1", sessionId: "backend-session", outcome: "completed" }); expect(events.find((event) => event.type === "acpx.permission_unsettled")).toBeUndefined(); }); + + it("bounds the observer's run-log event count when the agent sends more than 256 permission requests", async () => { + const root = await makeTempRoot(); + const stateDir = path.join(root, "state"); + const logs: Array<{ stream: string; text: string }> = []; + const REQUEST_COUNT = 300; + const execute = createAcpxEngineExecutor({ + createRuntime: (options) => { + for (let i = 0; i < REQUEST_COUNT; i += 1) { + void options.onPermissionRequest?.( + { + sessionId: "backend-session", + inferredKind: "execute", + raw: { sessionId: "backend-session", toolCall: { toolCallId: `tool-${i}` }, options: [] }, + } as never, + { signal: new AbortController().signal }, + ); + } + return { + ensureSession: async () => ({ + backendSessionId: "backend-session", + agentSessionId: "agent-session", + runtimeSessionName: "runtime-session", + }), + startTurn: () => ({ + events: (async function* () { + yield { type: "done", stopReason: "end_turn" }; + })(), + result: Promise.resolve({ status: "completed", stopReason: "end_turn" }), + cancel: async () => {}, + }), + close: async () => {}, + } as never; + }, + }); + + const result = await execute({ + runId: "run-permission-wiring-bounded", + agent: { id: "agent-1", companyId: "company-1" }, + runtime: {}, + config: { agent: "custom", agentCommand: "node ./fake-acp.js", stateDir }, + context: {}, + onLog: async (stream: "stdout" | "stderr", text: string) => { + logs.push({ stream, text }); + }, + onMeta: async () => {}, + } as never); + + expect(result.exitCode).toBe(0); + + const events = parseLogEvents(logs); + const observed = events.filter((event) => event.type === "acpx.permission_observed"); + const unsettled = events.filter((event) => event.type === "acpx.permission_unsettled"); + const summaries = events.filter((event) => event.type === "acpx.permission_observer_truncated"); + expect(observed.length).toBeLessThanOrEqual(256); + expect(unsettled.length).toBeLessThanOrEqual(256); + expect(summaries).toHaveLength(1); + }); }); describe("findAncestorBin", () => { diff --git a/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts b/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts index 1a4b4cd05b..51a9233a1f 100644 --- a/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts +++ b/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts @@ -296,3 +296,126 @@ describe("createAcpPermissionObserver — ledger lifecycle", () => { expect(events).toHaveLength(0); }); }); + +describe("createAcpPermissionObserver — per-run budgets", () => { + function buildRequestFor(sessionId: string, toolCallId: string): AcpPermissionRequest { + return buildRequest({ + sessionId, + raw: { sessionId, toolCall: { toolCallId }, options: [] } as AcpPermissionRequest["raw"], + }); + } + + it("caps the ledger and the observed-event count when more than 256 requests never settle", async () => { + const events: PermissionObserverLogEvent[] = []; + const observer = createAcpPermissionObserver({ + emitLog: (event) => events.push(event), + permissionMode: "approve-all", + transport: "sandbox", + }); + const signal = new AbortController().signal; + for (let i = 0; i < 300; i += 1) { + await observer.handlePermissionRequest(buildRequestFor(`session-${i}`, `tool-${i}`), { signal }); + } + + const observed = events.filter((event) => event.type === "acpx.permission_observed"); + expect(observed.length).toBeLessThanOrEqual(256); + + events.length = 0; + await observer.finalizeRun(); + const unsettled = events.filter((event) => event.type === "acpx.permission_unsettled"); + expect(unsettled.length).toBeLessThanOrEqual(256); + const summaries = events.filter((event) => event.type === "acpx.permission_observer_truncated"); + expect(summaries).toHaveLength(1); + }); + + it("bounds cumulative emissions at 512 detailed events across more than 1000 open-and-settle cycles", async () => { + const events: PermissionObserverLogEvent[] = []; + const observer = createAcpPermissionObserver({ + emitLog: (event) => events.push(event), + permissionMode: "approve-all", + transport: "sandbox", + }); + const signal = new AbortController().signal; + for (let i = 0; i < 1_100; i += 1) { + const sessionId = `session-${i}`; + const toolCallId = `tool-${i}`; + await observer.handlePermissionRequest(buildRequestFor(sessionId, toolCallId), { signal }); + observer.noteToolCallEvent(sessionId, { toolCallId, status: "completed" }); + } + + const detailed = events.filter((event) => event.type !== "acpx.permission_observer_truncated"); + expect(detailed.length).toBeLessThanOrEqual(512); + + events.length = 0; + await observer.finalizeRun(); + expect(events.filter((event) => event.type === "acpx.permission_observer_truncated")).toHaveLength(1); + }); + + it("keeps the settled-event budget reachable after the observed budget is spent", async () => { + const events: PermissionObserverLogEvent[] = []; + const observer = createAcpPermissionObserver({ + emitLog: (event) => events.push(event), + permissionMode: "approve-all", + transport: "sandbox", + }); + const signal = new AbortController().signal; + const opened: Array<{ sessionId: string; toolCallId: string }> = []; + for (let i = 0; i < 256; i += 1) { + const sessionId = `session-${i}`; + const toolCallId = `tool-${i}`; + opened.push({ sessionId, toolCallId }); + await observer.handlePermissionRequest(buildRequestFor(sessionId, toolCallId), { signal }); + } + // The observed budget is now fully spent. A further request emits no + // "acpx.permission_observed" event. + await observer.handlePermissionRequest(buildRequestFor("session-extra", "tool-extra"), { signal }); + expect(events.filter((event) => event.type === "acpx.permission_observed")).toHaveLength(256); + + events.length = 0; + for (const { sessionId, toolCallId } of opened) { + observer.noteToolCallEvent(sessionId, { toolCallId, status: "completed" }); + } + + const settled = events.filter((event) => event.type === "acpx.permission_settled"); + expect(settled.length).toBe(256); + }); + + it("emits a summary event with only the three counters and the type, using an exact key match", async () => { + const events: PermissionObserverLogEvent[] = []; + const observer = createAcpPermissionObserver({ + emitLog: (event) => events.push(event), + permissionMode: "approve-all", + transport: "sandbox", + }); + const signal = new AbortController().signal; + for (let i = 0; i < 300; i += 1) { + await observer.handlePermissionRequest(buildRequestFor(`session-${i}`, `tool-${i}`), { signal }); + } + + events.length = 0; + await observer.finalizeRun(); + const summary = events.find((event) => event.type === "acpx.permission_observer_truncated"); + expect(summary).toBeDefined(); + expect(Object.keys(summary as object).sort()).toEqual( + ["suppressedLedgerEntries", "suppressedObservedEvents", "suppressedTerminalEvents", "type"].sort(), + ); + expect(typeof summary?.suppressedLedgerEntries).toBe("number"); + expect(typeof summary?.suppressedObservedEvents).toBe("number"); + expect(typeof summary?.suppressedTerminalEvents).toBe("number"); + }); + + it("still resolves handlePermissionRequest to undefined, and throws nothing, once every cap is reached", async () => { + const observer = createAcpPermissionObserver({ + emitLog: () => {}, + permissionMode: "approve-all", + transport: "sandbox", + }); + const signal = new AbortController().signal; + for (let i = 0; i < 300; i += 1) { + await observer.handlePermissionRequest(buildRequestFor(`session-${i}`, `tool-${i}`), { signal }); + } + const result = await observer.handlePermissionRequest(buildRequestFor("session-last", "tool-last"), { signal }); + expect(result).toBeUndefined(); + await expect(observer.finalizeRun()).resolves.toBeUndefined(); + }); +}); diff --git a/packages/adapter-utils/src/acpx-engine/permission-observer.ts b/packages/adapter-utils/src/acpx-engine/permission-observer.ts index f17e33c001..7da8f15573 100644 --- a/packages/adapter-utils/src/acpx-engine/permission-observer.ts +++ b/packages/adapter-utils/src/acpx-engine/permission-observer.ts @@ -13,6 +13,22 @@ import type { AcpPermissionDecision, AcpPermissionRequest } from "acpx/runtime"; const MAX_IDENTIFIER_LENGTH = 200; const MAX_AGE_MS = 24 * 60 * 60 * 1000; +// The agent process is untrusted. It picks how many permission requests it +// sends, so the observer must cap its own memory and log volume against that +// input. Each run gets its own budget: every counter below lives inside the +// observer closure, not at module scope. +// +// The ledger, the "observed" count, and the "settled or unsettled" count each +// get a separate budget of 256, instead of one shared budget of 512. A shared +// budget lets an agent that sends 512 requests spend the whole budget on +// "observed" events, so the observer would then emit no "unsettled" event at +// finalization — the one signal this observer exists to produce. Two budgets +// keep that signal reachable no matter how the agent spends the "observed" +// side. +const MAX_LEDGER_ENTRIES = 256; +const MAX_OBSERVED_EVENTS = 256; +const MAX_TERMINAL_EVENTS = 256; + export const PERMISSION_OBSERVER_METHODS = ["session/request_permission"] as const; export type PermissionObserverMethod = (typeof PERMISSION_OBSERVER_METHODS)[number] | "unknown"; @@ -106,7 +122,11 @@ export interface PermissionObserverToolCallEvent { } export interface PermissionObserverLogEvent { - type: "acpx.permission_observed" | "acpx.permission_settled" | "acpx.permission_unsettled"; + type: + | "acpx.permission_observed" + | "acpx.permission_settled" + | "acpx.permission_unsettled" + | "acpx.permission_observer_truncated"; [key: string]: unknown; } @@ -155,6 +175,15 @@ export function createAcpPermissionObserver(options: AcpPermissionObserverOption const permissionMode = mapPermissionObserverPermissionMode(options.permissionMode); const transport = mapPermissionObserverTransport(options.transport); + // Per-run budget state. Each counter tracks a cumulative count of emitted + // events, not the live ledger size, so an agent cannot reset a counter by + // opening and settling requests in a loop (the churn case). + let observedEventCount = 0; + let terminalEventCount = 0; + let suppressedLedgerEntries = 0; + let suppressedObservedEvents = 0; + let suppressedTerminalEvents = 0; + const ledgerKey = (sessionId: string, toolCallId: string) => sessionId + "\u0000" + toolCallId; const handlePermissionRequest: AcpPermissionObserver["handlePermissionRequest"] = async (request) => { @@ -170,28 +199,42 @@ export function createAcpPermissionObserver(options: AcpPermissionObserverOption if (typeof rawSessionId === "string" && typeof rawToolCallId === "string") { const key = ledgerKey(sessionId, toolCallId); if (!ledger.has(key)) { - // The ledger entry always opens as "requested": the observer has not - // yet seen a settlement for this tool call, whatever status the - // permission request itself carried. - ledger.set(key, { - sessionId, - toolCallId, - openedAtMs: now(), - toolKind, - lastStage: "requested", - }); + if (ledger.size < MAX_LEDGER_ENTRIES) { + // The ledger entry always opens as "requested": the observer has + // not yet seen a settlement for this tool call, whatever status + // the permission request itself carried. + ledger.set(key, { + sessionId, + toolCallId, + openedAtMs: now(), + toolKind, + lastStage: "requested", + }); + } else { + suppressedLedgerEntries += 1; + } } } - options.emitLog({ - type: "acpx.permission_observed", - sessionId, - toolCallId, - method: mapPermissionObserverMethod("session/request_permission"), - toolKind, - stage: "requested", - permissionMode, - transport, - }); + // Count every emission against the budget, not the live ledger size, so + // an agent cannot refill the budget by settling old requests. + if (observedEventCount < MAX_OBSERVED_EVENTS) { + observedEventCount += 1; + options.emitLog({ + type: "acpx.permission_observed", + sessionId, + toolCallId, + method: mapPermissionObserverMethod("session/request_permission"), + toolKind, + stage: "requested", + permissionMode, + transport, + }); + } else { + // Emit nothing, not even a reduced event: that keeps every + // attacker-controlled identifier out of the log once the budget runs + // out. + suppressedObservedEvents += 1; + } } catch { // The observer is diagnostic only. An internal error here must never // affect the permission handoff, so every failure resolves the same @@ -212,14 +255,22 @@ export function createAcpPermissionObserver(options: AcpPermissionObserverOption entry.lastStage = stage; const outcome = mapPermissionObserverOutcome(event?.status); if (outcome === "unknown") return; + // Delete the entry (freeing the ledger memory) even when the terminal + // budget below is spent: the ledger must not hold a settled entry just + // because the observer could not log its settlement. ledger.delete(key); - options.emitLog({ - type: "acpx.permission_settled", - sessionId: entry.sessionId, - toolCallId: entry.toolCallId, - outcome, - ageMs: boundedAgeMs(now() - entry.openedAtMs), - }); + if (terminalEventCount < MAX_TERMINAL_EVENTS) { + terminalEventCount += 1; + options.emitLog({ + type: "acpx.permission_settled", + sessionId: entry.sessionId, + toolCallId: entry.toolCallId, + outcome, + ageMs: boundedAgeMs(now() - entry.openedAtMs), + }); + } else { + suppressedTerminalEvents += 1; + } } catch { // Diagnostic only; never let a logging failure surface into the event // loop that drains the turn's tool-call events. @@ -230,12 +281,29 @@ export function createAcpPermissionObserver(options: AcpPermissionObserverOption const openEntries = [...ledger.values()]; ledger.clear(); for (const entry of openEntries) { + if (terminalEventCount < MAX_TERMINAL_EVENTS) { + terminalEventCount += 1; + options.emitLog({ + type: "acpx.permission_unsettled", + sessionId: entry.sessionId, + toolCallId: entry.toolCallId, + stage: entry.lastStage, + ageMs: boundedAgeMs(now() - entry.openedAtMs), + }); + } else { + suppressedTerminalEvents += 1; + } + } + // Emit one summary event for the whole run, and only when the observer + // suppressed something. It carries only the three counters: no session + // identifier, no tool-call identifier, and no other agent-controlled + // value. + if (suppressedLedgerEntries > 0 || suppressedObservedEvents > 0 || suppressedTerminalEvents > 0) { options.emitLog({ - type: "acpx.permission_unsettled", - sessionId: entry.sessionId, - toolCallId: entry.toolCallId, - stage: entry.lastStage, - ageMs: boundedAgeMs(now() - entry.openedAtMs), + type: "acpx.permission_observer_truncated", + suppressedLedgerEntries, + suppressedObservedEvents, + suppressedTerminalEvents, }); } }; From df9b4d69d46d46ad08881e3bc93e4f99ba4eb7cf Mon Sep 17 00:00:00 2001 From: nickyleach <331803+nickyleach@users.noreply.github.com> Date: Fri, 11 Sep 2026 19:09:47 +0000 Subject: [PATCH 4/7] fix(acpx-engine): give the unsettled permission event its own budget MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The settled and unsettled permission events shared one counter and one limit of 256. A normal long run settles 256 permission requests during the turn, so the shared budget was empty by the time the run ended. A later stall then emitted no acpx.permission_unsettled event — the one signal that tells an operator a handoff stalled. Split the shared counter into four independent per-run budgets: the ledger, the observed count, the settled count, and the unsettled count. Each stays at 256 and each is bounded by the same 256-entry ledger cap, so the worst case per run stays a constant. Make finalizeRun idempotent so a second settle-step call cannot emit a second summary event. Co-authored-by: Paperclip --- .../acpx-engine/permission-observer.test.ts | 78 +++++++++++++++++-- .../src/acpx-engine/permission-observer.ts | 63 +++++++++------ 2 files changed, 114 insertions(+), 27 deletions(-) diff --git a/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts b/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts index 51a9233a1f..c281659a46 100644 --- a/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts +++ b/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts @@ -328,7 +328,7 @@ describe("createAcpPermissionObserver — per-run budgets", () => { expect(summaries).toHaveLength(1); }); - it("bounds cumulative emissions at 512 detailed events across more than 1000 open-and-settle cycles", async () => { + it("bounds cumulative settled emissions at 256 across more than 1000 open-and-settle cycles", async () => { const events: PermissionObserverLogEvent[] = []; const observer = createAcpPermissionObserver({ emitLog: (event) => events.push(event), @@ -343,14 +343,75 @@ describe("createAcpPermissionObserver — per-run budgets", () => { observer.noteToolCallEvent(sessionId, { toolCallId, status: "completed" }); } - const detailed = events.filter((event) => event.type !== "acpx.permission_observer_truncated"); - expect(detailed.length).toBeLessThanOrEqual(512); + const settled = events.filter((event) => event.type === "acpx.permission_settled"); + expect(settled.length).toBeLessThanOrEqual(256); events.length = 0; await observer.finalizeRun(); expect(events.filter((event) => event.type === "acpx.permission_observer_truncated")).toHaveLength(1); }); + it("keeps the unsettled-event budget reachable after a normal run spends the settled budget", async () => { + const events: PermissionObserverLogEvent[] = []; + const observer = createAcpPermissionObserver({ + emitLog: (event) => events.push(event), + permissionMode: "approve-all", + transport: "sandbox", + }); + const signal = new AbortController().signal; + // A normal run: 256 requests open and settle during the turn. + for (let i = 0; i < 256; i += 1) { + const sessionId = `session-${i}`; + const toolCallId = `tool-${i}`; + await observer.handlePermissionRequest(buildRequestFor(sessionId, toolCallId), { signal }); + observer.noteToolCallEvent(sessionId, { toolCallId, status: "completed" }); + } + // One more request opens and never settles. This is the stall. + await observer.handlePermissionRequest(buildRequestFor("session-stall", "tool-stall"), { signal }); + + events.length = 0; + await observer.finalizeRun(); + const unsettled = events.filter((event) => event.type === "acpx.permission_unsettled"); + expect(unsettled).toHaveLength(1); + expect(unsettled[0]).toMatchObject({ toolCallId: "tool-stall" }); + }); + + it("bounds cumulative unsettled emissions at 256 when more than 256 requests never settle", async () => { + const events: PermissionObserverLogEvent[] = []; + const observer = createAcpPermissionObserver({ + emitLog: (event) => events.push(event), + permissionMode: "approve-all", + transport: "sandbox", + }); + const signal = new AbortController().signal; + for (let i = 0; i < 300; i += 1) { + await observer.handlePermissionRequest(buildRequestFor(`session-${i}`, `tool-${i}`), { signal }); + } + + events.length = 0; + await observer.finalizeRun(); + const unsettled = events.filter((event) => event.type === "acpx.permission_unsettled"); + expect(unsettled.length).toBeLessThanOrEqual(256); + }); + + it("emits exactly one truncated summary event across two finalizeRun calls", async () => { + const events: PermissionObserverLogEvent[] = []; + const observer = createAcpPermissionObserver({ + emitLog: (event) => events.push(event), + permissionMode: "approve-all", + transport: "sandbox", + }); + const signal = new AbortController().signal; + for (let i = 0; i < 300; i += 1) { + await observer.handlePermissionRequest(buildRequestFor(`session-${i}`, `tool-${i}`), { signal }); + } + + events.length = 0; + await observer.finalizeRun(); + await observer.finalizeRun(); + expect(events.filter((event) => event.type === "acpx.permission_observer_truncated")).toHaveLength(1); + }); + it("keeps the settled-event budget reachable after the observed budget is spent", async () => { const events: PermissionObserverLogEvent[] = []; const observer = createAcpPermissionObserver({ @@ -397,11 +458,18 @@ describe("createAcpPermissionObserver — per-run budgets", () => { const summary = events.find((event) => event.type === "acpx.permission_observer_truncated"); expect(summary).toBeDefined(); expect(Object.keys(summary as object).sort()).toEqual( - ["suppressedLedgerEntries", "suppressedObservedEvents", "suppressedTerminalEvents", "type"].sort(), + [ + "suppressedLedgerEntries", + "suppressedObservedEvents", + "suppressedSettledEvents", + "suppressedUnsettledEvents", + "type", + ].sort(), ); expect(typeof summary?.suppressedLedgerEntries).toBe("number"); expect(typeof summary?.suppressedObservedEvents).toBe("number"); - expect(typeof summary?.suppressedTerminalEvents).toBe("number"); + expect(typeof summary?.suppressedSettledEvents).toBe("number"); + expect(typeof summary?.suppressedUnsettledEvents).toBe("number"); }); it("still resolves handlePermissionRequest to undefined, and throws nothing, once every cap is reached", async () => { diff --git a/packages/adapter-utils/src/acpx-engine/permission-observer.ts b/packages/adapter-utils/src/acpx-engine/permission-observer.ts index 7da8f15573..822f2b9cf2 100644 --- a/packages/adapter-utils/src/acpx-engine/permission-observer.ts +++ b/packages/adapter-utils/src/acpx-engine/permission-observer.ts @@ -18,16 +18,20 @@ const MAX_AGE_MS = 24 * 60 * 60 * 1000; // input. Each run gets its own budget: every counter below lives inside the // observer closure, not at module scope. // -// The ledger, the "observed" count, and the "settled or unsettled" count each -// get a separate budget of 256, instead of one shared budget of 512. A shared -// budget lets an agent that sends 512 requests spend the whole budget on -// "observed" events, so the observer would then emit no "unsettled" event at -// finalization — the one signal this observer exists to produce. Two budgets -// keep that signal reachable no matter how the agent spends the "observed" -// side. +// The ledger, the "observed" count, the "settled" count, and the "unsettled" +// count each get a separate budget of 256, instead of one shared budget. A +// diagnostic event class must never share a budget with an event class that +// the agent drives. "acpx.permission_settled" fires once for each tool call +// the agent completes, so a normal long run can spend a shared budget before +// the run ends. "acpx.permission_unsettled" is the one signal this observer +// exists to produce: it tells an operator that a handoff stalled. A shared +// budget would let a normal run silence that signal at the exact time it +// matters most. Four separate budgets keep each event class reachable no +// matter how the agent spends the others. const MAX_LEDGER_ENTRIES = 256; const MAX_OBSERVED_EVENTS = 256; -const MAX_TERMINAL_EVENTS = 256; +const MAX_SETTLED_EVENTS = 256; +const MAX_UNSETTLED_EVENTS = 256; export const PERMISSION_OBSERVER_METHODS = ["session/request_permission"] as const; export type PermissionObserverMethod = (typeof PERMISSION_OBSERVER_METHODS)[number] | "unknown"; @@ -179,10 +183,13 @@ export function createAcpPermissionObserver(options: AcpPermissionObserverOption // events, not the live ledger size, so an agent cannot reset a counter by // opening and settling requests in a loop (the churn case). let observedEventCount = 0; - let terminalEventCount = 0; + let settledEventCount = 0; + let unsettledEventCount = 0; let suppressedLedgerEntries = 0; let suppressedObservedEvents = 0; - let suppressedTerminalEvents = 0; + let suppressedSettledEvents = 0; + let suppressedUnsettledEvents = 0; + let hasFinalized = false; const ledgerKey = (sessionId: string, toolCallId: string) => sessionId + "\u0000" + toolCallId; @@ -255,12 +262,12 @@ export function createAcpPermissionObserver(options: AcpPermissionObserverOption entry.lastStage = stage; const outcome = mapPermissionObserverOutcome(event?.status); if (outcome === "unknown") return; - // Delete the entry (freeing the ledger memory) even when the terminal + // Delete the entry (freeing the ledger memory) even when the settled // budget below is spent: the ledger must not hold a settled entry just // because the observer could not log its settlement. ledger.delete(key); - if (terminalEventCount < MAX_TERMINAL_EVENTS) { - terminalEventCount += 1; + if (settledEventCount < MAX_SETTLED_EVENTS) { + settledEventCount += 1; options.emitLog({ type: "acpx.permission_settled", sessionId: entry.sessionId, @@ -269,7 +276,7 @@ export function createAcpPermissionObserver(options: AcpPermissionObserverOption ageMs: boundedAgeMs(now() - entry.openedAtMs), }); } else { - suppressedTerminalEvents += 1; + suppressedSettledEvents += 1; } } catch { // Diagnostic only; never let a logging failure surface into the event @@ -278,11 +285,17 @@ export function createAcpPermissionObserver(options: AcpPermissionObserverOption }; const finalizeRun: AcpPermissionObserver["finalizeRun"] = async () => { + // The engine's settle step can call finalizeRun more than one time for + // the same run. Only the first call may drain the ledger and emit the + // summary event; every later call is a no-op. + if (hasFinalized) return; + hasFinalized = true; + const openEntries = [...ledger.values()]; ledger.clear(); for (const entry of openEntries) { - if (terminalEventCount < MAX_TERMINAL_EVENTS) { - terminalEventCount += 1; + if (unsettledEventCount < MAX_UNSETTLED_EVENTS) { + unsettledEventCount += 1; options.emitLog({ type: "acpx.permission_unsettled", sessionId: entry.sessionId, @@ -291,19 +304,25 @@ export function createAcpPermissionObserver(options: AcpPermissionObserverOption ageMs: boundedAgeMs(now() - entry.openedAtMs), }); } else { - suppressedTerminalEvents += 1; + suppressedUnsettledEvents += 1; } } // Emit one summary event for the whole run, and only when the observer - // suppressed something. It carries only the three counters: no session - // identifier, no tool-call identifier, and no other agent-controlled - // value. - if (suppressedLedgerEntries > 0 || suppressedObservedEvents > 0 || suppressedTerminalEvents > 0) { + // suppressed something. It carries only the four counters and the type + // field: no session identifier, no tool-call identifier, and no other + // agent-controlled value. + if ( + suppressedLedgerEntries > 0 || + suppressedObservedEvents > 0 || + suppressedSettledEvents > 0 || + suppressedUnsettledEvents > 0 + ) { options.emitLog({ type: "acpx.permission_observer_truncated", suppressedLedgerEntries, suppressedObservedEvents, - suppressedTerminalEvents, + suppressedSettledEvents, + suppressedUnsettledEvents, }); } }; From 06ed04b483f61db374a9ab03dd6f3f5c35995199 Mon Sep 17 00:00:00 2001 From: nickyleach <331803+nickyleach@users.noreply.github.com> Date: Fri, 11 Sep 2026 19:21:34 +0000 Subject: [PATCH 5/7] test(acpx-engine): fix stale counter count in permission observer test title The test title said "three counters" but the assertion checks four counters plus the type. An earlier design had three counters. A later change added the fourth counter without updating the title. Co-authored-by: Paperclip --- .../adapter-utils/src/acpx-engine/permission-observer.test.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts b/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts index c281659a46..3fedca7c70 100644 --- a/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts +++ b/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts @@ -441,7 +441,7 @@ describe("createAcpPermissionObserver — per-run budgets", () => { expect(settled.length).toBe(256); }); - it("emits a summary event with only the three counters and the type, using an exact key match", async () => { + it("emits a summary event with only the four counters and the type, using an exact key match", async () => { const events: PermissionObserverLogEvent[] = []; const observer = createAcpPermissionObserver({ emitLog: (event) => events.push(event), From ae90fe3f4c4fb86f3acffd2b2feebbfd116929b3 Mon Sep 17 00:00:00 2001 From: nickyleach <331803+nickyleach@users.noreply.github.com> Date: Fri, 11 Sep 2026 19:29:46 +0000 Subject: [PATCH 6/7] docs(run-log-events): document the ACP permission observer events Document the four run-log event types from the ACP permission handoff observer: acpx.permission_observed, acpx.permission_settled, acpx.permission_unsettled, and acpx.permission_observer_truncated. Cover their safe fields, the per-event-type emission budgets, and the observation-only permission behavior. Co-authored-by: Paperclip --- doc/run-log-events.md | 93 +++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 93 insertions(+) diff --git a/doc/run-log-events.md b/doc/run-log-events.md index 62105ed90b..428468d709 100644 --- a/doc/run-log-events.md +++ b/doc/run-log-events.md @@ -107,6 +107,99 @@ The payload never carries a command, an argument, a path, an environment value, or a raw identifier. The event rides the `ctx.onEvent` run-event bridge and is run-log-only. It needs no OTLP endpoint. +## ACP Permission Handoff Observer Run-Log Events + +Paperclip writes four run-log event types for the ACP permission handoff. The +producer is `createAcpPermissionObserver` in +`packages/adapter-utils/src/acpx-engine/permission-observer.ts`. These events +are run-log records, not first-party telemetry events. The generated +telemetry contract does not cover them, so this section is their canonical +contract. + +The observer is observation-only. It never answers, approves, or denies a +permission request. It only records receipt and settlement, so an operator +can tell a stalled handoff from a normal wait. An internal error in the +observer resolves the hook to `undefined`, the same as a normal observation; +the observer never blocks or changes the permission decision. + +Each field passes through a closed enumeration or a bounded scalar. The +event never carries the raw ACP frame, the tool input, or another free-form +payload. A session ID and a tool-call ID are capped at 200 characters each +before they enter the payload. + +### `acpx.permission_observed` + +Paperclip writes this event when the engine receives a permission request. + +| Field | Type | Meaning | +| --- | --- | --- | +| `sessionId` | string | The session ID, capped at 200 characters. | +| `toolCallId` | string | The tool-call ID, capped at 200 characters. | +| `method` | string | The ACP method name, from a closed allowlist (`session/request_permission` or `unknown`). | +| `toolKind` | string | The inferred tool kind, from a closed allowlist (`read`, `edit`, `delete`, `move`, `search`, `execute`, `think`, `fetch`, `switch_mode`, `other`, or `unknown`). | +| `stage` | string | Always `requested` for this event. | +| `permissionMode` | string | The run's effective permission mode, from a closed allowlist (`approve-all`, `approve-reads`, `deny-all`, or `unknown`). | +| `transport` | string | The run's execution transport, from a closed allowlist (`local`, `ssh`, `sandbox`, or `unknown`). | + +### `acpx.permission_settled` + +Paperclip writes this event when a tracked tool call reaches a terminal +status (`completed` or `failed`). + +| Field | Type | Meaning | +| --- | --- | --- | +| `sessionId` | string | The session ID, capped at 200 characters. | +| `toolCallId` | string | The tool-call ID, capped at 200 characters. | +| `outcome` | string | The terminal outcome (`completed` or `failed`). | +| `ageMs` | number | The time from receipt to settlement, in milliseconds, clamped to a maximum of 24 hours. | + +### `acpx.permission_unsettled` + +Paperclip writes one of these events for each permission request still open +when the run finalizes. This is the signal that a handoff stalled. + +| Field | Type | Meaning | +| --- | --- | --- | +| `sessionId` | string | The session ID, capped at 200 characters. | +| `toolCallId` | string | The tool-call ID, capped at 200 characters. | +| `stage` | string | The last known tool-call stage, from a closed allowlist (`requested`, `pending`, `in_progress`, `completed`, `failed`, or `unknown`). | +| `ageMs` | number | The time from receipt to run finalization, in milliseconds, clamped to a maximum of 24 hours. | + +### `acpx.permission_observer_truncated` + +Paperclip writes this event once per run, only when the observer suppressed +an entry or an event. It carries no session ID, no tool-call ID, and no other +agent-controlled value. + +| Field | Type | Meaning | +| --- | --- | --- | +| `suppressedLedgerEntries` | number | The count of open permission requests the observer could not track because the ledger was full. | +| `suppressedObservedEvents` | number | The count of `acpx.permission_observed` events the observer dropped because that event's own budget was full. | +| `suppressedSettledEvents` | number | The count of `acpx.permission_settled` events the observer dropped because that event's own budget was full. | +| `suppressedUnsettledEvents` | number | The count of `acpx.permission_unsettled` events the observer dropped because that event's own budget was full. | + +### Bounded output + +The agent process is untrusted, so it picks how many permission requests it +sends. The observer bounds its own memory and log volume against that input +instead of trusting a limit the agent could exceed. + +The observer tracks open requests in a ledger capped at 256 entries. It also +gives each event type its own emission budget of 256 events for the run. The +four budgets are separate: `acpx.permission_settled` fires once per tool call +the agent completes, so a normal long run can spend a shared budget before +the run ends. A separate budget for `acpx.permission_unsettled` keeps that +signal reachable even when the agent's normal traffic would otherwise spend +a shared budget first. + +Each budget counts the cumulative number of emitted events for the run, not +the live ledger size, so an agent cannot refill a budget by opening and +settling requests in a loop. When a budget is spent, the observer emits +nothing further for that event type; it never emits a reduced event. The run +finalization step emits at most one `acpx.permission_unsettled` event per +still-open ledger entry, and at most one `acpx.permission_observer_truncated` +event for the whole run. + ## Related instrumentation The sandbox duplex transport also writes one run-log event as one of its three From 5fdf869f11e329cf67f177c08cd63f997bb42ccf Mon Sep 17 00:00:00 2001 From: nickyleach <331803+nickyleach@users.noreply.github.com> Date: Fri, 11 Sep 2026 19:55:17 +0000 Subject: [PATCH 7/7] fix(acpx-engine): drain the permission observer's pending log writes at finalization The observer starts each durable log write and does not await it on the permission critical path. finalizeRun could return before its own acpx.permission_unsettled or acpx.permission_observer_truncated write, or an earlier still-pending write, reached the log sink. finalizeRun now tracks every write it starts and waits for the full set to settle before it returns, so a caller that awaits finalizeRun sees every queued record land first. Co-authored-by: Paperclip --- .../adapter-utils/src/acpx-engine/execute.ts | 16 ++- .../acpx-engine/permission-observer.test.ts | 125 +++++++++++++++--- .../src/acpx-engine/permission-observer.ts | 50 +++++-- 3 files changed, 156 insertions(+), 35 deletions(-) diff --git a/packages/adapter-utils/src/acpx-engine/execute.ts b/packages/adapter-utils/src/acpx-engine/execute.ts index 795f1adcc8..35779d257b 100644 --- a/packages/adapter-utils/src/acpx-engine/execute.ts +++ b/packages/adapter-utils/src/acpx-engine/execute.ts @@ -4124,11 +4124,12 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { transport: !observedExecutionTarget || observedExecutionTarget.kind === "local" ? "local" : observedExecutionTarget.transport, - emitLog: (payload) => { - // Fire-and-forget: the observer's caller must not await a log - // write on the permission critical path. - void emitAcpxLog(ctx, payload).catch(() => {}); - }, + // Return the write's promise; do not swallow it here. The observer + // never awaits this on the permission critical path, but it keeps + // the promise so `finalizeRun` can drain every pending write before + // it returns, so the run never finalizes with a write still in + // flight. + emitLog: (payload) => emitAcpxLog(ctx, payload), }); // Capture the run's staging lease release now that the runtime built. The // run root `finally` releases it as the final settlement act. @@ -5342,8 +5343,9 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { recordDispositionReport(report); if (childStderrState) flushChildStderr(childStderrState); // Report every permission request the run never saw settle. Not on - // the permission critical path. `emitLog` returns `void`, so this - // call awaits no log write. + // the permission critical path. This call waits for every queued + // log write, including one still in flight from an earlier + // permission event, to reach durable storage before it returns. await permissionObserver?.finalizeRun(); }, reproduceResult: async (): Promise => { diff --git a/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts b/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts index 3fedca7c70..bc41f57989 100644 --- a/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts +++ b/packages/adapter-utils/src/acpx-engine/permission-observer.test.ts @@ -47,7 +47,9 @@ describe("createAcpPermissionObserver — handlePermissionRequest", () => { it("resolves to undefined for a normal request", async () => { const events: PermissionObserverLogEvent[] = []; const observer = createAcpPermissionObserver({ - emitLog: (event) => events.push(event), + emitLog: (event) => { + events.push(event); + }, permissionMode: "approve-all", transport: "sandbox", }); @@ -58,7 +60,9 @@ describe("createAcpPermissionObserver — handlePermissionRequest", () => { it("resolves to undefined for a request that carries unknown fields", async () => { const events: PermissionObserverLogEvent[] = []; const observer = createAcpPermissionObserver({ - emitLog: (event) => events.push(event), + emitLog: (event) => { + events.push(event); + }, permissionMode: "approve-all", transport: "sandbox", }); @@ -115,7 +119,9 @@ describe("createAcpPermissionObserver — handlePermissionRequest", () => { it("emits only allow-listed scalar fields, never the raw request payload", async () => { const events: PermissionObserverLogEvent[] = []; const observer = createAcpPermissionObserver({ - emitLog: (event) => events.push(event), + emitLog: (event) => { + events.push(event); + }, permissionMode: "approve-all", transport: "sandbox", }); @@ -149,7 +155,9 @@ describe("createAcpPermissionObserver — handlePermissionRequest", () => { it("maps an unmapped tool kind to exactly 'unknown', dropping the source string", async () => { const events: PermissionObserverLogEvent[] = []; const observer = createAcpPermissionObserver({ - emitLog: (event) => events.push(event), + emitLog: (event) => { + events.push(event); + }, permissionMode: "approve-all", transport: "sandbox", }); @@ -165,7 +173,9 @@ describe("createAcpPermissionObserver — ledger lifecycle", () => { let clock = 1_000; const events: PermissionObserverLogEvent[] = []; const observer = createAcpPermissionObserver({ - emitLog: (event) => events.push(event), + emitLog: (event) => { + events.push(event); + }, permissionMode: "approve-all", transport: "sandbox", now: () => clock, @@ -193,7 +203,9 @@ describe("createAcpPermissionObserver — ledger lifecycle", () => { let clock = 0; const events: PermissionObserverLogEvent[] = []; const observer = createAcpPermissionObserver({ - emitLog: (event) => events.push(event), + emitLog: (event) => { + events.push(event); + }, permissionMode: "approve-all", transport: "sandbox", now: () => clock, @@ -226,7 +238,9 @@ describe("createAcpPermissionObserver — ledger lifecycle", () => { it("does not close an entry on a non-terminal tool_call status", () => { const events: PermissionObserverLogEvent[] = []; const observer = createAcpPermissionObserver({ - emitLog: (event) => events.push(event), + emitLog: (event) => { + events.push(event); + }, permissionMode: "approve-all", transport: "sandbox", }); @@ -237,7 +251,9 @@ describe("createAcpPermissionObserver — ledger lifecycle", () => { it("ignores a tool_call event for a toolCallId it never opened", () => { const events: PermissionObserverLogEvent[] = []; const observer = createAcpPermissionObserver({ - emitLog: (event) => events.push(event), + emitLog: (event) => { + events.push(event); + }, permissionMode: "approve-all", transport: "sandbox", }); @@ -248,7 +264,9 @@ describe("createAcpPermissionObserver — ledger lifecycle", () => { it("does not open a ledger entry for a request with no tool-call identifier", async () => { const events: PermissionObserverLogEvent[] = []; const observer = createAcpPermissionObserver({ - emitLog: (event) => events.push(event), + emitLog: (event) => { + events.push(event); + }, permissionMode: "approve-all", transport: "sandbox", }); @@ -269,7 +287,9 @@ describe("createAcpPermissionObserver — ledger lifecycle", () => { it("does not let two requests with a missing session identifier share one ledger entry", async () => { const events: PermissionObserverLogEvent[] = []; const observer = createAcpPermissionObserver({ - emitLog: (event) => events.push(event), + emitLog: (event) => { + events.push(event); + }, permissionMode: "approve-all", transport: "sandbox", }); @@ -308,7 +328,9 @@ describe("createAcpPermissionObserver — per-run budgets", () => { it("caps the ledger and the observed-event count when more than 256 requests never settle", async () => { const events: PermissionObserverLogEvent[] = []; const observer = createAcpPermissionObserver({ - emitLog: (event) => events.push(event), + emitLog: (event) => { + events.push(event); + }, permissionMode: "approve-all", transport: "sandbox", }); @@ -331,7 +353,9 @@ describe("createAcpPermissionObserver — per-run budgets", () => { it("bounds cumulative settled emissions at 256 across more than 1000 open-and-settle cycles", async () => { const events: PermissionObserverLogEvent[] = []; const observer = createAcpPermissionObserver({ - emitLog: (event) => events.push(event), + emitLog: (event) => { + events.push(event); + }, permissionMode: "approve-all", transport: "sandbox", }); @@ -354,7 +378,9 @@ describe("createAcpPermissionObserver — per-run budgets", () => { it("keeps the unsettled-event budget reachable after a normal run spends the settled budget", async () => { const events: PermissionObserverLogEvent[] = []; const observer = createAcpPermissionObserver({ - emitLog: (event) => events.push(event), + emitLog: (event) => { + events.push(event); + }, permissionMode: "approve-all", transport: "sandbox", }); @@ -379,7 +405,9 @@ describe("createAcpPermissionObserver — per-run budgets", () => { it("bounds cumulative unsettled emissions at 256 when more than 256 requests never settle", async () => { const events: PermissionObserverLogEvent[] = []; const observer = createAcpPermissionObserver({ - emitLog: (event) => events.push(event), + emitLog: (event) => { + events.push(event); + }, permissionMode: "approve-all", transport: "sandbox", }); @@ -397,7 +425,9 @@ describe("createAcpPermissionObserver — per-run budgets", () => { it("emits exactly one truncated summary event across two finalizeRun calls", async () => { const events: PermissionObserverLogEvent[] = []; const observer = createAcpPermissionObserver({ - emitLog: (event) => events.push(event), + emitLog: (event) => { + events.push(event); + }, permissionMode: "approve-all", transport: "sandbox", }); @@ -415,7 +445,9 @@ describe("createAcpPermissionObserver — per-run budgets", () => { it("keeps the settled-event budget reachable after the observed budget is spent", async () => { const events: PermissionObserverLogEvent[] = []; const observer = createAcpPermissionObserver({ - emitLog: (event) => events.push(event), + emitLog: (event) => { + events.push(event); + }, permissionMode: "approve-all", transport: "sandbox", }); @@ -444,7 +476,9 @@ describe("createAcpPermissionObserver — per-run budgets", () => { it("emits a summary event with only the four counters and the type, using an exact key match", async () => { const events: PermissionObserverLogEvent[] = []; const observer = createAcpPermissionObserver({ - emitLog: (event) => events.push(event), + emitLog: (event) => { + events.push(event); + }, permissionMode: "approve-all", transport: "sandbox", }); @@ -487,3 +521,60 @@ describe("createAcpPermissionObserver — per-run budgets", () => { await expect(observer.finalizeRun()).resolves.toBeUndefined(); }); }); + +describe("createAcpPermissionObserver — asynchronous log persistence", () => { + it("waits for a write still pending from an earlier event before finalizeRun resolves", async () => { + const durable: PermissionObserverLogEvent[] = []; + const releaseWrite: Array<() => void> = []; + const observer = createAcpPermissionObserver({ + // A durable log sink that starts a write and only completes it when the + // test calls the matching release function. This stands in for a real + // write to storage that takes more than one microtask turn. + emitLog: (event) => + new Promise((resolve) => { + releaseWrite.push(() => { + durable.push(event); + resolve(); + }); + }), + permissionMode: "approve-all", + transport: "sandbox", + }); + const signal = new AbortController().signal; + // This request's "observed" write starts but does not finish. The tool + // call it opened never settles, so the entry is still open at + // finalization. + await observer.handlePermissionRequest(buildRequest(), { signal }); + expect(durable).toHaveLength(0); + + const finalizePromise = observer.finalizeRun(); + // finalizeRun has started its own "unsettled" write for the still-open + // entry. That write is also pending. Flush a few microtask turns: if + // finalizeRun dropped either write's promise, it would resolve here even + // though neither write has completed. + await Promise.resolve(); + await Promise.resolve(); + await Promise.resolve(); + expect(durable).toHaveLength(0); + + // Release both writes, the one queued before finalizeRun ran and the one + // finalizeRun queued itself. + for (const release of releaseWrite) release(); + await finalizePromise; + + expect(durable.map((event) => event.type).sort()).toEqual( + ["acpx.permission_observed", "acpx.permission_unsettled"].sort(), + ); + }); + + it("resolves finalizeRun without throwing when a queued write rejects", async () => { + const observer = createAcpPermissionObserver({ + emitLog: () => Promise.reject(new Error("durable sink unavailable")), + permissionMode: "approve-all", + transport: "sandbox", + }); + const signal = new AbortController().signal; + await observer.handlePermissionRequest(buildRequest(), { signal }); + await expect(observer.finalizeRun()).resolves.toBeUndefined(); + }); +}); diff --git a/packages/adapter-utils/src/acpx-engine/permission-observer.ts b/packages/adapter-utils/src/acpx-engine/permission-observer.ts index 822f2b9cf2..33652b4fb5 100644 --- a/packages/adapter-utils/src/acpx-engine/permission-observer.ts +++ b/packages/adapter-utils/src/acpx-engine/permission-observer.ts @@ -136,11 +136,12 @@ export interface PermissionObserverLogEvent { export interface AcpPermissionObserverOptions { /** - * Starts the durable log write. The observer never awaits this on the - * permission critical path — call it and return, do not `await` it inside - * `handlePermissionRequest`. + * Starts the durable log write and returns a promise for it. The observer + * never awaits this promise on the permission critical path — call it and + * return, do not `await` it inside `handlePermissionRequest`. The observer + * still tracks the promise so `finalizeRun` can wait for it later. */ - emitLog: (event: PermissionObserverLogEvent) => void; + emitLog: (event: PermissionObserverLogEvent) => Promise | void; /** The engine's effective permission mode for this run. */ permissionMode: unknown; /** The run's execution transport. */ @@ -166,9 +167,12 @@ export interface AcpPermissionObserver { */ noteToolCallEvent: (sessionId: string | undefined, event: PermissionObserverToolCallEvent) => void; /** - * Emit one `acpx.permission_unsettled` event per entry still open. Call - * this once, at run finalization. Not on the permission critical path. - * `emitLog` returns `void`, so this call awaits no log write. + * Emit one `acpx.permission_unsettled` event per entry still open, then + * wait for every log write this observer started — including a write + * still in flight from an earlier `handlePermissionRequest` or + * `noteToolCallEvent` call — to finish. Call this once, at run + * finalization. A caller that awaits this method sees every one of the + * observer's log writes land before it returns. */ finalizeRun: () => Promise; } @@ -191,6 +195,26 @@ export function createAcpPermissionObserver(options: AcpPermissionObserverOption let suppressedUnsettledEvents = 0; let hasFinalized = false; + // Every write `emitLog` starts stays in this set until it settles. A write + // started from the permission critical path (`handlePermissionRequest`, + // `noteToolCallEvent`) is never awaited there, so it can still be pending + // when `finalizeRun` runs. `finalizeRun` drains this whole set before it + // returns, so a caller that awaits `finalizeRun` never sees it resolve + // before every queued write, including its own unsettled and truncation + // records, has reached the log sink. + const pendingWrites = new Set>(); + + const queueLog = (event: PermissionObserverLogEvent): void => { + const write = (async () => { + await options.emitLog(event); + })().catch(() => { + // The log sink is diagnostic only; a write failure must never surface + // into the permission critical path or into `finalizeRun`. + }); + pendingWrites.add(write); + void write.finally(() => pendingWrites.delete(write)); + }; + const ledgerKey = (sessionId: string, toolCallId: string) => sessionId + "\u0000" + toolCallId; const handlePermissionRequest: AcpPermissionObserver["handlePermissionRequest"] = async (request) => { @@ -226,7 +250,7 @@ export function createAcpPermissionObserver(options: AcpPermissionObserverOption // an agent cannot refill the budget by settling old requests. if (observedEventCount < MAX_OBSERVED_EVENTS) { observedEventCount += 1; - options.emitLog({ + queueLog({ type: "acpx.permission_observed", sessionId, toolCallId, @@ -268,7 +292,7 @@ export function createAcpPermissionObserver(options: AcpPermissionObserverOption ledger.delete(key); if (settledEventCount < MAX_SETTLED_EVENTS) { settledEventCount += 1; - options.emitLog({ + queueLog({ type: "acpx.permission_settled", sessionId: entry.sessionId, toolCallId: entry.toolCallId, @@ -296,7 +320,7 @@ export function createAcpPermissionObserver(options: AcpPermissionObserverOption for (const entry of openEntries) { if (unsettledEventCount < MAX_UNSETTLED_EVENTS) { unsettledEventCount += 1; - options.emitLog({ + queueLog({ type: "acpx.permission_unsettled", sessionId: entry.sessionId, toolCallId: entry.toolCallId, @@ -317,7 +341,7 @@ export function createAcpPermissionObserver(options: AcpPermissionObserverOption suppressedSettledEvents > 0 || suppressedUnsettledEvents > 0 ) { - options.emitLog({ + queueLog({ type: "acpx.permission_observer_truncated", suppressedLedgerEntries, suppressedObservedEvents, @@ -325,6 +349,10 @@ export function createAcpPermissionObserver(options: AcpPermissionObserverOption suppressedUnsettledEvents, }); } + // Wait for every write this observer started, including a write still in + // flight from an earlier call, so the caller sees every record reach the + // log sink before this method returns. + await Promise.allSettled([...pendingWrites]); }; return { handlePermissionRequest, noteToolCallEvent, finalizeRun };