From b448710986d0e79d73341c07470459fa11956965 Mon Sep 17 00:00:00 2001 From: Dotta <34892728+cryppadotta@users.noreply.github.com> Date: Mon, 19 Oct 2026 21:52:57 -0500 Subject: [PATCH] fix: derive startup warmth from per-layer reuse evidence (#16908) ## Thinking Path > - Paperclip helps people manage AI agents and inspect their work. > - Agent startup can reuse a lease, workspace, Runner, process, or session. > - A session ID can remain the same when other resources are new. > - The old cold/warm label did not show these separate decisions. > - This pull request records closed reuse receipts and derives labels from them. > - Reports now show partial reuse and missing evidence. ## Linked Issues or Issue Description Refs #11685. That issue tracks a specific ACPX fingerprint repair. This change records reuse evidence across startup resources. It does not repeat that repair. **What existing behavior does this improve?** Startup labels in the operator trace and Product E2E reports. **Current behavior** A cached runtime or a continuous session can suggest a warm startup even when workspace staging or provider launch work occurs. **Proposed behavior** Record each layer's reuse decision and a closed reason. Record observed provider launch counts. Use `warm`, `cold`, `partial_reuse`, or `unknown` from those receipts. Keep old runs unknown when they have no receipts. ## What Changed - Add local run-log receipts for the lease, workspace, Runner, provider process, and provider session. - Count physical ACPX launches, including respawns. Preserve the reason for a new process. - Reuse native workspace adoption and session lifecycle evidence. Keep native and bridged remote provider-process reuse and launch counts unknown where physical evidence is absent. - Show the per-run summary in retained results and the dashboard. Keep missing legacy values explicit. - Set the legacy trace boolean only for fully evidenced cold or warm startup. Keep the operator OTLP gate. Add no first-party Telemetry. - Test full reuse, workspace invalidation, two direct provider launches with session continuity, and report generation. - Start the final diagnostic write without waiting for persistence. Keep lease cleanup independent of a stalled event sink. - Keep remote provider evidence unknown after runtime setup fails or the host relay starts twice. - Align a stale Pi support-test expectation with current master profile 28 and its suite fingerprint. Keep the qualification rules unchanged. ## Verification - Passed: all 319 runtime, startup-timing, reuse-summary, and native workspace-history tests. Disposable local Git tests used the native Git binary. - Passed on the current commit: all 2,768 Runner E2E support tests across 128 files. This includes report and history tests for generated HTML and normalized JSON. - Passed: `pnpm --filter @paperclipai/adapter-utils typecheck`. - Passed on `df60f8dbdbfcb6d80c84cd3bf563f8d58b2f9f03`: all PR CI gates, including repository typecheck and build, all test shards, and browser tests. Both automated reviews are 5/5. GitHub reports 55 successful checks, one neutral review, and two skipped Storybook checks. - The first server shard run failed because an unchanged workspace-runtime fixture did not accept health connections within 10 seconds. Its isolated local test and the single failed-jobs rerun both pass. This establishes recovery; the cause of the first timeout remains unknown. - Passed in the hosted source run on this exact commit: recursive typecheck, token gates, the large Runner E2E typecheck, Runner E2E unit tests, and build. The retained `source.txt` matches this PR head. - The extra unsharded `pnpm test:run` reached its 60-minute limit (exit 124). It has no complete verdict. The broad workflow therefore reports failure. No assertion-failure marker appears in the retained partial log. Full-suite acceptance uses the passing canonical PR CI partitions. A read-only inventory check found no gaps across 1,023 general server files, 161 serialized suites, and 20 workspace projects. The separate chat/native Runner lanes cover the excluded server files. No tests or timeouts were weakened. The local environment has 4 GiB of memory. Use CI for the large Runner E2E typecheck. - The initial report tests failed because the harness could not resolve package imports from the repository root. Relative source imports fixed that failure. - The first broad local run had timeouts from the environment Git bridge. Native Git resolves the ancestry timeout and all runtime tests pass. The added report fixture lacked its required screenshot; the corrected report tests pass. A stale master assertion expected Pi profile 27, while the generated profile is 28. Updated its expectation and exact suite fingerprint; all 78 targeted support tests pass. The clean full support run passes all 2,768 tests. - The three review regression cases failed before repair. They showed remote counts of zero and two, and a completed run that waited for the final diagnostic sink. They now pass. The stalled-sink case keeps persistence pending while the run returns, both bridge stops run once, and the staging lock map becomes empty. - Hosted evidence for this commit: [source verification](https://github.com/paperclipai/paperclip/actions/runs/39335475416), [retained command logs and status table](https://github.com/paperclipai/paperclip/actions/runs/39335475416/artifacts/12228829282). All listed commands exited zero except the incomplete unsharded test command described above. - The physical-launch test drives the executor's spawn callback twice. The native workspace test uses real Git repositories and verifies reuse and invalidation. These are deterministic tests, not a paid provider qualification campaign. ## Risks - Consumers must handle `partial_reuse` and `unknown`. Partial evidence no longer produces a legacy cold/warm boolean. - Native and remote bridged provider process evidence is still unavailable on some paths. The report shows unknown values for those paths. - Receipt emission is best effort. Missing receipts reduce confidence in a label and must not change execution or settlement. - No schema migration, first-party Telemetry event, or endpoint default changes are included. ## Model Used OpenAI Codex, based on GPT-6, used reasoning, repository tools, and code execution. The exact provider model ID and context window are not exposed to this session. The existing implementation checkpoint was preserved from the earlier agent run. ## Checklist - [x] I have included a thinking path that traces from project context to this change - [x] I have specified the model used (with version and capability details) - [x] I have checked ROADMAP.md and confirmed this PR does not duplicate planned core work - [x] I have searched GitHub for duplicate or related PRs and linked them above - [x] I have either (a) linked existing issues with `Fixes: #` / `Closes #` / `Refs #` OR (b) described the issue in-PR following the relevant issue template - [x] I have not referenced internal/instance-local Paperclip issues or links (only public GitHub `#NNN` / `github.com/paperclipai/paperclip` URLs) - [x] My branch name describes the change (e.g. `docs/...`, `fix/...`) and contains no internal Paperclip ticket id or instance-derived details - [x] I have run tests locally and they pass - [x] I have added or updated tests where applicable - [x] I have updated relevant documentation to reflect my changes - [x] I have considered and documented any risks above - [x] All Paperclip CI gates are green - [x] Greptile is 5/5 with no open P2s, recommendations, or follow-ups - [x] I will address all Greptile and reviewer comments before requesting merge --------- Co-authored-by: Paperclip Co-authored-by: devinfoley <139239+devinfoley@users.noreply.github.com> --- doc/observability.md | 9 +- doc/run-log-events.md | 32 ++++ .../src/acpx-engine/execute.test.ts | 162 +++++++++++++----- .../adapter-utils/src/acpx-engine/execute.ts | 78 +++++++-- .../src/acpx-engine/run-site-host.ts | 2 + .../src/acpx-engine/startup-timing.ts | 6 +- .../adapter-utils/src/startup-reuse.test.ts | 66 +++++++ packages/adapter-utils/src/startup-reuse.ts | 107 ++++++++++++ .../native-workspace-sync-history.test.ts | 7 +- .../services/heartbeat/runtime-selection.ts | 1 + .../native-runtime/native-session-executor.ts | 13 ++ .../native-runtime/native-workspace-sync.ts | 12 ++ tests/runner-e2e/README.md | 8 + tests/runner-e2e/dashboard.ts | 9 + tests/runner-e2e/history.ts | 4 + tests/runner-e2e/pi-controls-evidence.test.ts | 6 +- tests/runner-e2e/report.test.ts | 45 +++++ tests/runner-e2e/result-validation.ts | 10 ++ tests/runner-e2e/runner.spec.ts | 6 + tests/runner-e2e/types.ts | 1 + 20 files changed, 521 insertions(+), 63 deletions(-) create mode 100644 packages/adapter-utils/src/startup-reuse.test.ts create mode 100644 packages/adapter-utils/src/startup-reuse.ts diff --git a/doc/observability.md b/doc/observability.md index d842247b315..27e8f7e1691 100644 --- a/doc/observability.md +++ b/doc/observability.md @@ -1517,7 +1517,8 @@ The `sandbox.startup` root span uses this closed attribute allowlist. | `paperclip.sandbox.startup.root.work_ms` | number | no | The sum of the step wall times. | | `paperclip.sandbox.startup.root.diff_ms` | number | no | `work_ms − wall_ms`; the overlap the parallel steps saved. | | `paperclip.sandbox.startup.provider` | string | yes | The normalized provider family. | -| `paperclip.sandbox.startup.cold_start` | boolean | yes | Whether the bring-up is a cold start. | +| `paperclip.sandbox.startup.cold_start` | boolean | yes | Legacy value, set only when receipts establish cold or warm startup. | +| `paperclip.sandbox.startup.warmth` | string | yes | Receipt-derived `cold`, `warm`, `partial_reuse`, or `unknown`. | | `paperclip.sandbox.startup.region` | string | yes | The clamped region label. | | `paperclip.sandbox.startup.image_id` | string | yes | The hashed image id. | | `paperclip.sandbox.startup.sandbox_id` | string | yes | The hashed sandbox id. | @@ -1525,6 +1526,12 @@ The `sandbox.startup` root span uses this closed attribute allowlist. ### Step span attributes +The root's warmth uses the per-layer receipts documented in +[run-log-events.md](./run-log-events.md#startup-reuse-evidence). Partial and +unknown evidence omit the legacy `cold_start` boolean. A reused session ID or +runtime object alone cannot establish warmth. These attributes retain the +operator OTLP endpoint gate and are no-operations without that endpoint. + Each bring-up step span uses this closed attribute allowlist. The step name rides the span name, so no `step` attribute repeats it. diff --git a/doc/run-log-events.md b/doc/run-log-events.md index 138f118b5a1..f9e315896f7 100644 --- a/doc/run-log-events.md +++ b/doc/run-log-events.md @@ -5,6 +5,38 @@ Run-log events write to the `heartbeat_run_events` table Paperclip Telemetry events, and they are not OpenTelemetry exports. A run-log event needs no operator endpoint. +## Startup reuse evidence + +`run.startup.reuse` uses schema `paperclip.startup-reuse.v1`. Each receipt names +one layer: `environment` (the lease), `workspace`, `runner`, `provider_process`, +or `provider_session`. Its state is `reused`, `fresh`, `unknown`, or +`not_applicable`. Reasons use a closed set: `verified_reuse`, `created`, +`replacement`, `not_found`, `expired`, `identity_mismatch`, `resume_failed`, +`configuration_changed`, `tools_changed`, `workspace_changed`, `cache_miss`, +`not_applicable`, and `evidence_missing`. No paths, identifiers, configuration +values, or exception messages enter these fields. + +Provider-process receipts carry a cumulative `providerLaunchCount` for the run. +`null` means unobserved; zero requires a physical launch observer. Direct ACPX +processes count initial launches and respawns, including launches during retries. +On the remote process-session bridge, ACPX observes the host relay rather than +the sandbox provider. Provider-process reuse and launch counts stay unknown on +that transport. Native Runner session events establish session continuity, but +do not establish provider-process reuse or its launch count. Those values stay +unknown without physical evidence. The final ACPX receipt does not wait for +persistence, so a stalled diagnostic sink cannot hold the staging lease. +The existing successful `runner.process.launch` performance receipt establishes +a fresh Runner process, independently of provider-session continuity. + +The Product E2E result stores `startupReuse` by run, and its dashboard displays +each layer, its reason, and the launch count. `warm` requires all applicable +layers to be reused and zero observed provider launches. `cold` requires all +applicable layers to be fresh. Some reuse with other fresh or missing evidence +is `partial_reuse`; otherwise the label is `unknown`. Fresh decisions dominate +later reuse receipts within a run. Legacy runs without receipts retain unknown +layers and a null launch count. Session IDs and follow-up turns never establish +warmth. These events stay in the local run log; they add no first-party Telemetry. + ## Ordinary event persistence Events without a native source identity or retry-exhaustion receipt use one diff --git a/packages/adapter-utils/src/acpx-engine/execute.test.ts b/packages/adapter-utils/src/acpx-engine/execute.test.ts index 5cc2713bdc2..81830e29a16 100644 --- a/packages/adapter-utils/src/acpx-engine/execute.test.ts +++ b/packages/adapter-utils/src/acpx-engine/execute.test.ts @@ -1,4 +1,5 @@ import fs from "node:fs/promises"; +import { summarizeStartupReuse } from "../startup-reuse.js"; import os from "node:os"; import path from "node:path"; import { parse as parseToml } from "smol-toml"; @@ -376,6 +377,7 @@ const ALLOWED_STARTUP_SPAN_ATTRIBUTE_KEYS = new Set([ A.rootWorkMs, A.rootDiffMs, A.coldStart, + A.warmth, A.region, A.imageId, A.sandboxId, @@ -5918,8 +5920,9 @@ describe("ACPX engine sandbox-start spans (opt-in root + child parenting)", () = expect(Number.isFinite(rootSpan!.attributes[key] as number)).toBe(true); } expect(rootSpan!.attributes[A.rootWorkMs] as number).toBeGreaterThanOrEqual(0); - // A cold start (no warm handle) and the clamped provider family. - expect(rootSpan!.attributes[A.coldStart]).toBe(true); + // Missing lease/process evidence must not manufacture a cold label. + expect(rootSpan!.attributes).not.toHaveProperty(A.coldStart); + expect(rootSpan!.attributes[A.warmth]).toBe("unknown"); expect(rootSpan!.attributes[A.provider]).toBe("plugin"); // The lease id rides only as a non-reversible hash, never the raw value. expect(rootSpan!.attributes[A.leaseId]).toMatch(/^[0-9a-f]{12}$/); @@ -6593,6 +6596,43 @@ describe("ACPX engine per-step startup timing (run.startup.step events)", () => } }); + it.each([true, false])("derives warmth from physical reuse when the provider session stays continuous: cached=%s", async cached => { + const root = await makeTempRoot(); + const warmHandles = new Map(); + const events: Array<{ eventType: string; payload?: Record }> = []; + let runtimeOptions: AcpRuntimeOptions; + const runtime = buildRuntime(undefined, () => { + // Exercise the real engine spawn observer, including a second launch in + // the same ensure call. A session ID cannot hide either startup cost. + void runtimeOptions.onAgentSpawn?.({ pid: process.pid, startedAt: new Date().toISOString() }); + void runtimeOptions.onAgentSpawn?.({ pid: process.pid, startedAt: new Date().toISOString() }); + }); + const execute = createAcpxEngineExecutor({ warmHandles, createRuntime: options => { + runtimeOptions = options; + return runtime as never; + } }); + const base = { agent: { id: "agent-1", companyId: "company-1" }, + config: { agent: "custom", agentCommand: "node ./fake-acp.js", stateDir: path.join(root, "state"), mode: "persistent" }, + context: {}, onLog: async () => {}, onMeta: async () => {} }; + const first = await execute({ ...base, runId: "reuse-first", runtime: {} } as never); + const params = first.sessionParams!; + if (cached) warmHandles.set(params.sessionKey, { runtime, + handle: { backendSessionId: first.sessionId, agentSessionId: "agent-session", runtimeSessionName: "runtime-session" }, + fingerprint: params.configFingerprint, lastUsedAt: Date.now(), + processIdentitySink: { current: undefined, latest: null }, + childStderrState: { logPath: null, pendingLiveLine: "" } }); + const second = await execute({ ...base, runId: "reuse-second", runtime: { sessionParams: params }, + onEvent: async (event: { eventType: string; payload?: Record }) => { events.push(event); }, + } as never); + expect(first.exitCode).toBe(0); + expect(second.exitCode).toBe(0); + expect(second.sessionId).toBe(first.sessionId); + expect(summarizeStartupReuse(events)).toMatchObject({ + warmth: cached ? "warm" : "partial_reuse", providerLaunchCount: cached ? 0 : 2, + layers: { provider_session: { state: "reused" }, provider_process: { state: cached ? "reused" : "fresh" } }, + }); + }); + it("runs a fresh acp.handshake on a compatible second run (host lane re-creates, no warm hit)", async () => { const root = await makeTempRoot(); const stateDir = path.join(root, "state"); @@ -6717,48 +6757,86 @@ describe("ACPX engine run lifecycle corrections (F1: settle every failure after expect(result.summary).toContain("createRuntime boom"); }); - it("test_runtime_create_failure_stops_bridges_and_releases_staging_lease", async () => { - const { stateDir, localCwd, executionTarget } = await setupRemoteSandbox(); - const paperclipStop = vi.fn(async () => {}); - const processStop = vi.fn(async () => {}); - vi.mocked(startAdapterExecutionTargetPaperclipBridge).mockImplementationOnce( - async () => ({ env: {}, stop: paperclipStop }) as never, - ); - vi.mocked(startAdapterExecutionTargetProcessSessionBridge).mockImplementationOnce( - async () => ({ agentCommand: null, stop: processStop }) as never, - ); - const stagingLocks = new Map>(); - const execute = createAcpxEngineExecutor({ - stagingLocks, - warmHandles: new Map(), - stagedRuntimes: new Map(), - createRuntime: () => { - throw new Error("createRuntime boom"); - }, - }); + it.each(["create_failure", "relay_respawn", "stalled_receipt"])( + "keeps remote provider evidence unknown and releases the staging lease on %s", async (scenario) => { + const { stateDir, localCwd, executionTarget } = await setupRemoteSandbox(); + const paperclipStop = vi.fn(async () => {}); + const processStop = vi.fn(async () => {}); + vi.mocked(startAdapterExecutionTargetPaperclipBridge).mockImplementationOnce( + async () => ({ env: {}, stop: paperclipStop }) as never, + ); + vi.mocked(startAdapterExecutionTargetProcessSessionBridge).mockImplementationOnce( + async () => ({ agentCommand: null, stop: processStop }) as never, + ); + const stagingLocks = new Map>(); + const events: Array<{ eventType: string; payload?: Record }> = []; + let releaseReceipt!: () => void; + const receiptGate = new Promise((resolve) => { releaseReceipt = resolve; }); + let receiptStarted!: () => void; + const receiptReady = new Promise((resolve) => { receiptStarted = resolve; }); + const execute = createAcpxEngineExecutor({ + stagingLocks, + warmHandles: new Map(), + stagedRuntimes: new Map(), + createRuntime: (options) => { + // The bridge models an already-started sandbox provider. This observer + // sees only the host relay, including relay respawns. + expect(startAdapterExecutionTargetProcessSessionBridge).toHaveBeenCalledTimes(1); + expect(stagingLocks.size).toBe(1); + if (scenario === "create_failure") throw new Error("createRuntime boom"); + return buildRuntime(undefined, () => { + void options.onAgentSpawn?.({ pid: process.pid, startedAt: new Date().toISOString() }); + void options.onAgentSpawn?.({ pid: process.pid, startedAt: new Date().toISOString() }); + }) as never; + }, + }); - const result = await execute({ - runId: "run-create-fail-remote", - agent: { id: "agent-1", companyId: "company-1" }, - runtime: {}, - config: { agent: "custom", agentCommand: "node ./fake-acp.js", stateDir, cwd: localCwd }, - context: {}, - authToken: "real-run-jwt", - executionTarget, - onLog: async () => {}, - onMeta: async () => {}, - onEvent: async () => {}, - } as never); + const execution = execute({ + runId: "run-create-fail-remote", + agent: { id: "agent-1", companyId: "company-1" }, + runtime: {}, + config: { agent: "custom", agentCommand: "node ./fake-acp.js", stateDir, cwd: localCwd }, + context: {}, + authToken: "real-run-jwt", + executionTarget, + onLog: async () => {}, + onMeta: async () => {}, + onEvent: async (event: { eventType: string; payload?: Record }) => { + events.push(event); + if (event.eventType === "run.startup.reuse" && event.payload?.layer === "provider_process" + && (scenario !== "stalled_receipt" || processStop.mock.calls.length > 0)) { + receiptStarted(); + if (scenario === "stalled_receipt") await receiptGate; + } + }, + } as never); - expect(result.exitCode).toBe(1); - expect(result.resultJson?.phase).toBe("create_runtime"); - // Both live bridges stop exactly once. - expect(paperclipStop).toHaveBeenCalledTimes(1); - expect(processStop).toHaveBeenCalledTimes(1); - // The per-session staging lease released, so the lock map does not strand the - // next same-session run. - expect(stagingLocks.size).toBe(0); - }); + let completed = false; + void execution.then(() => { completed = true; }, () => {}); + try { + await Promise.race([receiptReady, execution]); + // Keep the persistence await open while checking real cleanup and return. + await expect.poll(() => completed, { timeout: 500 }).toBe(true); + expect(stagingLocks.size).toBe(0); + } finally { + releaseReceipt(); + await execution; + } + const result = await execution; + expect(result.exitCode).toBe(scenario === "create_failure" ? 1 : 0); + if (scenario === "create_failure") expect(result.resultJson?.phase).toBe("create_runtime"); + expect(summarizeStartupReuse(events)).toMatchObject({ + providerLaunchCount: null, + layers: { provider_process: { state: "unknown", reason: "evidence_missing" } }, + }); + // Both live bridges stop exactly once. + expect(paperclipStop).toHaveBeenCalledTimes(1); + expect(processStop).toHaveBeenCalledTimes(1); + // The per-session staging lease released, so the lock map does not strand the + // next same-session run. + expect(stagingLocks.size).toBe(0); + }, + ); it.each(["prompt", "metadata", "dispatch"])("records whether provider work could have started on %s failure", async (failure) => { const root = await makeTempRoot(); diff --git a/packages/adapter-utils/src/acpx-engine/execute.ts b/packages/adapter-utils/src/acpx-engine/execute.ts index c856bee0193..2065537d83a 100644 --- a/packages/adapter-utils/src/acpx-engine/execute.ts +++ b/packages/adapter-utils/src/acpx-engine/execute.ts @@ -2,6 +2,7 @@ import { isOpenRouterUrl, openRouterClaudeHeaders } from "@paperclipai/shared/op import { prepareAcpxCodexObservabilityHome } from "../codex-observability-home.js"; import { AGENT_OBSERVABILITY_ENV_KEYS, applyObservabilityEnvironment } from "../agent-observability.js"; import { cancellableSandboxStartup } from "./startup-cancellation.js"; +import { emitStartupReuse, environmentStartupReuse, summarizeStartupReuse, type StartupReuseReason } from "../startup-reuse.js"; import { withAdapterExecutionPhase, type AdapterExecutionPhase } from "../execution-phase.js"; import fs from "node:fs/promises"; import fsSync from "node:fs"; @@ -1821,6 +1822,7 @@ async function disposeFreshStagedRuntime(input: { async function buildRuntime(input: { ctx: AdapterExecutionContext; + onWorkspaceReuse?: (reused: boolean, compatible: boolean) => Promise; engine: AcpxEngineSettings; deps: AcpxEngineExecutorOptions; // The run resource ledger. `executeAcpxEngine` creates the one ledger for the @@ -2529,6 +2531,7 @@ async function buildRuntime(input: { await sandboxSite.placeWorkspace({ sessionKey } as unknown as AcpRunContext); await emitRunPhaseTiming(input.ctx, "place_workspace", nowMs() - placeWorkspaceStart, "ok"); const placedStaged = sandboxSite.staged; + await input.onWorkspaceReuse?.(placedStaged?.reused === true, isCompatibleResume); stagedRuntime = placedStaged?.stagedRuntime ?? null; remoteManagedHomeTeardown = placedStaged?.teardown ?? null; remoteStagingDispose = placedStaged?.dispose ?? null; @@ -4087,6 +4090,14 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { ? startupExecutionTarget : null; const targetsRemoteSandbox = sandboxTarget !== null; + const reuseEvents: import("../types.js").AdapterRuntimeEvent[] = []; + const onReuseEvent: NonNullable = async event => { + reuseEvents.push(event); + await ctx.onEvent?.(event); + }; + let providerLaunchCount: number | null = null; + let reusedProviderProcess = false; + let providerProcessReason: StartupReuseReason = "evidence_missing"; const tracing = targetsRemoteSandbox && ctx.startupTraceContext ? ctx.startupTraceContext @@ -4187,6 +4198,13 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { executionRecovery: { kind: "bootstrap", providerWorkStarted: false }, resultJson: { executionCancellation: { state: "acknowledged", acknowledgedAt: new Date().toISOString(), forced: false } }, }; + await emitStartupReuse(onReuseEvent, "environment", environmentStartupReuse(startupExecutionTarget)); + // ACPX has no separate native Runner process. Its runtime object is not + // evidence that a provider process or a staged workspace was reused. + await emitStartupReuse(onReuseEvent, "runner", { state: "not_applicable", reason: "not_applicable" }); + if (!startupExecutionTarget || startupExecutionTarget.kind === "local") { + await emitStartupReuse(onReuseEvent, "workspace", { state: "not_applicable", reason: "not_applicable" }); + } // Evict idle staged runtimes BEFORE building the runtime, since buildRuntime // consults the staged cache to decide whether a compatible resume may reuse // an already-staged runtime — an expired entry must not be reused. @@ -4201,22 +4219,22 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { // the parallel steps saved). Every step reports its wall time through // `onWallMs`; a skipped step adds zero. let stepWallSumMs = 0; - // Whether this bring-up is a cold start (no warm handle). Set once the warm- - // handle lookup runs below; it stays undefined on an early build failure, so - // the root span omits the attribute (fail open). - let coldStart: boolean | undefined; - const rootSpan = openStartupRootSpan(tracing, now, runRootSpan.parentContext, () => ({ - workMs: stepWallSumMs, - context: { - coldStart, + const rootSpan = openStartupRootSpan(tracing, now, runRootSpan.parentContext, () => { + const warmth = summarizeStartupReuse(reuseEvents).warmth; + return { + workMs: stepWallSumMs, + context: { + warmth, + coldStart: warmth === "cold" ? true : warmth === "warm" ? false : undefined, // The provider key and the lease id are the only low-cardinality // context values this provider-agnostic layer holds. The region, the // image id, and the sandbox id are not threaded here, so the root span // omits them (fail open). The lease id rides only as a hash. - provider: sandboxTarget?.providerKey ?? undefined, - leaseId: sandboxTarget?.leaseId ?? undefined, - }, - })); + provider: sandboxTarget?.providerKey ?? undefined, + leaseId: sandboxTarget?.leaseId ?? undefined, + }, + }; + }); const spanParent: Pick< StartupStepMeasureOptions, "tracer" | "parentContext" | "contextWithSpan" | "onWallMs" @@ -4368,6 +4386,10 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { prepared = await runWithRuntimeParent(spanParent.parentContext, () => buildRuntime({ ctx: startupCancellation.context, + onWorkspaceReuse: (reused, compatible) => emitStartupReuse(onReuseEvent, "workspace", { + state: reused ? "reused" : "fresh", + reason: reused ? "verified_reuse" : compatible ? "cache_miss" : "identity_mismatch", + }), engine, deps, ledger: runResourceLedger, @@ -4425,10 +4447,13 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { // the reused runtime cannot expire under its own timer while this run uses // it (today's `clearWarmHandleTimer(cached)` after the reuse decision). let cached = canResume ? hostStore.borrow(prepared.sessionKey) : undefined; + providerProcessReason = canResume ? "cache_miss" : Object.keys(previousParams).length ? "identity_mismatch" : "created"; if (cached && (cached.observabilityCompatibilityKey !== ctx.observability?.compatibilityKey || ctx.context.refreshTools === true || asString(previousParams.mcpFingerprint, "") !== shortHash(prepared.mcpIdentity) // MCP bearer credentials are run-scoped, even for an unchanged catalog. || prepared.mcpServers.length > 0)) { + providerProcessReason = cached.observabilityCompatibilityKey !== ctx.observability?.compatibilityKey + ? "configuration_changed" : "tools_changed"; await hostStore.discard(prepared.sessionKey); cached = undefined; } @@ -4441,6 +4466,15 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { // target mutable so a later agent respawn records identity on the current // heartbeat instead of the run that originally created the runtime. processIdentitySink.current = ctx.onSpawn; + // The process-session bridge starts its provider inside the sandbox. + // ACPX observes only the host relay on that lane, so neither its spawn + // callback nor a cached relay establishes physical provider reuse. + const observesProviderProcess = !prepared.processSessionBridge; + providerLaunchCount = observesProviderProcess ? 0 : null; + reusedProviderProcess = observesProviderProcess && Boolean(cached?.handle); + processIdentitySink.onLaunch = observesProviderProcess + ? () => { providerLaunchCount = (providerLaunchCount ?? 0) + 1; } + : undefined; flushChildStderr(childStderrState); childStderrState.logPath = prepared.childStderrLogPath; const persistedRuntimeStore = createRuntimeStore({ stateDir: prepared.stateDir }); @@ -4480,6 +4514,7 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { ? (chunk) => routeChildStderr(childStderrState, chunk) : undefined, onAgentSpawn: async (meta) => { + processIdentitySink.onLaunch?.(); processIdentitySink.latest = meta; processIdentitySink.localProcess = prepared.processSessionBridge ? undefined : captureLocalProcess(meta.pid); await processIdentitySink.current?.({ @@ -4499,9 +4534,7 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { // reuses `cached.runtime`, so `createRuntimeMs` stays undefined and the // split reports nothing for it. let createRuntimeMs: number | undefined; - // A warm handle reuses the running ACP runtime; a miss constructs one. The - // root span records this as `cold_start`. - coldStart = !cached?.runtime; + // Runtime construction alone does not establish startup warmth. if (cached?.runtime) { runtime = cached.runtime; } else { @@ -4667,6 +4700,14 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { resumedSession = false; clearSession = true; } + if (handle) await emitStartupReuse(onReuseEvent, "provider_session", { + state: resumedSession ? "reused" : "fresh", + reason: resumedSession ? "verified_reuse" : clearSession ? "resume_failed" : providerProcessReason, + }); + await emitStartupReuse(onReuseEvent, "provider_process", { + state: providerLaunchCount !== null && providerLaunchCount > 0 ? "fresh" : reusedProviderProcess ? "reused" : "unknown", + reason: providerLaunchCount !== null && providerLaunchCount > 0 ? providerProcessReason : reusedProviderProcess ? "verified_reuse" : "evidence_missing", + }, providerLaunchCount); // A compatible warm handle reuses the already-running ACP agent and does // not emit another spawn event. Persist its known identity on this run // before the next prompt starts so every running heartbeat is adoptable. @@ -5839,6 +5880,13 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { }; return await runAttempt(plan); } finally { + // Record the in-memory evidence synchronously, but never let diagnostic + // persistence hold the staging lease or delay the completed run's return. + // The emitter catches sink failures, including a later rejection. + void emitStartupReuse(onReuseEvent, "provider_process", { + state: providerLaunchCount !== null && providerLaunchCount > 0 ? "fresh" : reusedProviderProcess ? "reused" : "unknown", + reason: providerLaunchCount !== null && providerLaunchCount > 0 ? providerProcessReason : reusedProviderProcess ? "verified_reuse" : "evidence_missing", + }, providerLaunchCount); clearTimeout(stopTimer); removeStopListener?.(); removeLossListener?.(); diff --git a/packages/adapter-utils/src/acpx-engine/run-site-host.ts b/packages/adapter-utils/src/acpx-engine/run-site-host.ts index dd44c3bf558..e5fba94c0ed 100644 --- a/packages/adapter-utils/src/acpx-engine/run-site-host.ts +++ b/packages/adapter-utils/src/acpx-engine/run-site-host.ts @@ -36,6 +36,8 @@ export type AcpxAgentProcessIdentity = { pid: number; startedAt: string }; */ export type AcpxProcessIdentitySink = { current: AdapterExecutionContext["onSpawn"]; + /** Counts physical spawns on the current run, including respawns on a cached runtime. */ + onLaunch?: () => void; latest: AcpxAgentProcessIdentity | null; localProcess?: ChildProcess; }; diff --git a/packages/adapter-utils/src/acpx-engine/startup-timing.ts b/packages/adapter-utils/src/acpx-engine/startup-timing.ts index 2c3fbe8f4cd..74f1977c5c3 100644 --- a/packages/adapter-utils/src/acpx-engine/startup-timing.ts +++ b/packages/adapter-utils/src/acpx-engine/startup-timing.ts @@ -95,8 +95,10 @@ export const SANDBOX_STARTUP_SPAN_ATTRS = { rootWorkMs: `${SANDBOX_STARTUP_SPAN_ATTR_PREFIX}root.work_ms`, /** The difference between the work sum and the wall time (overlap). */ rootDiffMs: `${SANDBOX_STARTUP_SPAN_ATTR_PREFIX}root.diff_ms`, - /** Whether this bring-up is a cold start (no warm handle). */ + /** Legacy boolean, emitted only for completely evidenced cold/warm startup. */ coldStart: `${SANDBOX_STARTUP_SPAN_ATTR_PREFIX}cold_start`, + /** Derived from per-layer receipts: cold, warm, partial_reuse, or unknown. */ + warmth: `${SANDBOX_STARTUP_SPAN_ATTR_PREFIX}warmth`, /** The clamped region label (through `clampSpanLabel`). */ region: `${SANDBOX_STARTUP_SPAN_ATTR_PREFIX}region`, /** The hashed image-id label (through `clampSpanLabel`). */ @@ -707,6 +709,7 @@ export interface SandboxRootSpanTimings { */ export interface SandboxRootSpanContext { coldStart?: boolean; + warmth?: "cold" | "warm" | "partial_reuse" | "unknown"; provider?: string; region?: string; imageId?: string; @@ -731,6 +734,7 @@ export function setSandboxRootSpanAttributes( setFiniteNumberAttr(span, A.rootWorkMs, timings.workMs); setFiniteNumberAttr(span, A.rootDiffMs, timings.workMs - timings.wallMs); if (context.coldStart !== undefined) span.setAttribute(A.coldStart, context.coldStart); + if (context.warmth !== undefined) span.setAttribute(A.warmth, context.warmth); if (context.provider !== undefined) { span.setAttribute(A.provider, normalizeProviderFamily(context.provider)); } diff --git a/packages/adapter-utils/src/startup-reuse.test.ts b/packages/adapter-utils/src/startup-reuse.test.ts new file mode 100644 index 00000000000..9b4ae7bc012 --- /dev/null +++ b/packages/adapter-utils/src/startup-reuse.test.ts @@ -0,0 +1,66 @@ +import { describe, expect, it } from "vitest"; +import { emitStartupReuse, environmentStartupReuse, STARTUP_REUSE_LAYERS, STARTUP_REUSE_SCHEMA, summarizeStartupReuse, type StartupReuseLayer } from "./startup-reuse.js"; + +function receipt(layer: StartupReuseLayer, state = "reused", reason = "verified_reuse", providerLaunchCount: number | null = 0) { + return { eventType: "run.startup.reuse", payload: { schema: STARTUP_REUSE_SCHEMA, layer, state, reason, + ...(layer === "provider_process" ? { providerLaunchCount } : {}) } }; +} +const fullReuse = () => STARTUP_REUSE_LAYERS.map(layer => receipt(layer)); + +describe("startup reuse evidence", () => { + it("labels a fully observed reuse with zero provider launches warm", () => { + expect(summarizeStartupReuse(fullReuse())).toMatchObject({ warmth: "warm", providerLaunchCount: 0 }); + }); + it("shows a deliberate workspace-only invalidation despite continuous sessions", () => { + const events = fullReuse().map(event => event.payload.layer === "workspace" + ? receipt("workspace", "fresh", "workspace_changed") : event); + const summary = summarizeStartupReuse(events); + expect(summary.warmth).toBe("partial_reuse"); + expect(summary.layers.workspace).toEqual({ state: "fresh", reason: "workspace_changed" }); + expect(summary.layers.provider_session.state).toBe("reused"); + }); + it("does not turn a restored session with two physical launches into a warm process", () => { + const events = fullReuse().map(event => event.payload.layer === "provider_process" + ? receipt("provider_process", "fresh", "configuration_changed", 2) : event); + expect(summarizeStartupReuse(events)).toMatchObject({ warmth: "partial_reuse", providerLaunchCount: 2, + layers: { provider_session: { state: "reused" }, provider_process: { state: "fresh", reason: "configuration_changed" } } }); + }); + it("requires evidence beyond session continuity, follow-up turns and old timing spans", () => { + expect(summarizeStartupReuse([{ eventType: "run.performance.span", payload: { span: "runner.session.resume", mode: "warm", sessionId: "same" } }])) + .toEqual(summarizeStartupReuse([])); + expect(summarizeStartupReuse([])).toMatchObject({ warmth: "unknown", providerLaunchCount: null }); + }); + it("keeps missing layers and launch coverage explicit", () => { + expect(summarizeStartupReuse([receipt("provider_session")])).toMatchObject({ warmth: "partial_reuse", providerLaunchCount: null, + layers: { workspace: { state: "unknown" } } }); + expect(summarizeStartupReuse(fullReuse().map(event => event.payload.layer === "provider_process" + ? receipt("provider_process", "reused", "verified_reuse", null) : event)).warmth).toBe("partial_reuse"); + }); + it("labels a completely observed fresh startup cold", () => { + expect(summarizeStartupReuse(STARTUP_REUSE_LAYERS.map(layer => receipt(layer, "fresh", "created", 1))).warmth).toBe("cold"); + }); + it("excludes inapplicable layers and preserves fresh work across same-run retries", () => { + const events = fullReuse().map(event => event.payload.layer === "environment" ? receipt("environment", "not_applicable", "not_applicable") : event); + expect(summarizeStartupReuse(events).warmth).toBe("warm"); + expect(summarizeStartupReuse([receipt("workspace", "fresh", "workspace_changed"), ...events]).warmth).toBe("partial_reuse"); + }); + it("counts cumulative launch observations once, including a later respawn", () => { + expect(summarizeStartupReuse([...fullReuse(), receipt("provider_process", "fresh", "created", 2), receipt("provider_process", "fresh", "created", 2)]).providerLaunchCount).toBe(2); + }); + it("reads the existing native physical Runner launch receipt without inferring provider launches", () => { + expect(summarizeStartupReuse([{ eventType: "run.performance.span", payload: { schema: "paperclip.run-performance-span.v1", span: "runner.process.launch", outcome: "ok" } }])) + .toMatchObject({ warmth: "unknown", providerLaunchCount: null, layers: { runner: { state: "fresh" }, provider_process: { state: "unknown" } } }); + }); + it("drops unknown reasons and never projects identifiers or free-form payloads", () => { + const event = receipt("workspace", "fresh", "/private/secret"); + expect(summarizeStartupReuse([event])).toEqual(summarizeStartupReuse([])); + expect(JSON.stringify(summarizeStartupReuse([{ ...receipt("workspace"), payload: { ...receipt("workspace").payload, command: "secret", token: "secret" } }]))).not.toContain("secret"); + }); + it("reuses the closed environment acquisition receipt and bounds replacement reasons", () => { + expect(environmentStartupReuse({ kind: "remote", transport: "sandbox", sandboxLeaseAcquisition: { outcome: "resumed" } })).toEqual({ state: "reused", reason: "verified_reuse" }); + expect(environmentStartupReuse({ kind: "remote", transport: "sandbox", sandboxLeaseAcquisition: { outcome: "replacement", reason: "sensitive" } })).toEqual({ state: "fresh", reason: "replacement" }); + }); + it("keeps a failing diagnostic sink out of the execution path", async () => { + await expect(emitStartupReuse(async () => { throw new Error("sink unavailable"); }, "workspace", { state: "reused", reason: "verified_reuse" })).resolves.toBeUndefined(); + }); +}); diff --git a/packages/adapter-utils/src/startup-reuse.ts b/packages/adapter-utils/src/startup-reuse.ts new file mode 100644 index 00000000000..749602bec08 --- /dev/null +++ b/packages/adapter-utils/src/startup-reuse.ts @@ -0,0 +1,107 @@ +import type { AdapterRuntimeEvent } from "./types.js"; + +/** Local run-log evidence; never a first-party Telemetry event. */ +export const STARTUP_REUSE_EVENT = "run.startup.reuse"; +export const STARTUP_REUSE_SCHEMA = "paperclip.startup-reuse.v1"; +export const STARTUP_REUSE_LAYERS = [ + "environment", "workspace", "runner", "provider_process", "provider_session", +] as const; +export type StartupReuseLayer = (typeof STARTUP_REUSE_LAYERS)[number]; +export type StartupReuseState = "reused" | "fresh" | "unknown" | "not_applicable"; +export const STARTUP_REUSE_REASONS = [ + "verified_reuse", "created", "replacement", "not_found", "expired", + "identity_mismatch", "resume_failed", "configuration_changed", "tools_changed", + "workspace_changed", "cache_miss", "not_applicable", "evidence_missing", +] as const; +export type StartupReuseReason = (typeof STARTUP_REUSE_REASONS)[number]; +export interface StartupReuseDecision { + state: StartupReuseState; + reason: StartupReuseReason; +} +export interface StartupReuseSummary { + warmth: "cold" | "warm" | "partial_reuse" | "unknown"; + layers: Record; + /** Null means unobserved, including older runs. Zero requires launch coverage. */ + providerLaunchCount: number | null; +} + +export async function emitStartupReuse( + onEvent: ((event: AdapterRuntimeEvent) => Promise) | undefined, + layer: StartupReuseLayer, + decision: StartupReuseDecision, + providerLaunchCount?: number | null, +): Promise { + try { + await onEvent?.({ + eventType: STARTUP_REUSE_EVENT, stream: "system", level: "info", + message: `startup reuse: ${layer} (${decision.state})`, + payload: { schema: STARTUP_REUSE_SCHEMA, layer, ...decision, + ...(layer === "provider_process" ? { providerLaunchCount: providerLaunchCount ?? null } : {}) }, + }); + } catch { + // Diagnostic evidence must not change execution or settlement. + } +} + +export function environmentStartupReuse(target: { + kind: string; transport?: string; + sandboxLeaseAcquisition?: { outcome: string; reason?: string } | null; +} | null | undefined): StartupReuseDecision { + if (!target || target.kind === "local") return { state: "not_applicable", reason: "not_applicable" }; + const acquisition = target.sandboxLeaseAcquisition; + if (target.transport !== "sandbox" || !acquisition) return { state: "unknown", reason: "evidence_missing" }; + if (acquisition.outcome === "resumed") return { state: "reused", reason: "verified_reuse" }; + if (acquisition.outcome === "created") return { state: "fresh", reason: "created" }; + if (acquisition.outcome === "replacement") return { state: "fresh", reason: + STARTUP_REUSE_REASONS.includes(acquisition.reason as StartupReuseReason) + ? acquisition.reason as StartupReuseReason : "replacement" }; + return { state: "unknown", reason: "evidence_missing" }; +} + +function record(value: unknown): Record { + return value && typeof value === "object" && !Array.isArray(value) ? value as Record : {}; +} + +/** Read closed receipts, preserving absent/legacy evidence. No session-ID inference. + * A fresh decision dominates reuse within a run (including same-run retries). + */ +export function summarizeStartupReuse(events: readonly { eventType?: string; payload?: unknown }[]): StartupReuseSummary { + const layers = Object.fromEntries(STARTUP_REUSE_LAYERS.map(layer => + [layer, { state: "unknown", reason: "evidence_missing" }])) as StartupReuseSummary["layers"]; + const observed = new Set(); + let providerLaunchCount: number | null = null; + for (const event of events) { + const p = record(event.payload); + // Existing native physical-launch receipt. A session bootstrap/resume span + // alone says nothing about the lifetime of its Runner or provider process. + if (event.eventType === "run.performance.span" && p.schema === "paperclip.run-performance-span.v1" && + p.span === "runner.process.launch" && p.outcome === "ok") { + layers.runner = { state: "fresh", reason: "created" }; + observed.add("runner"); + } + if (event.eventType !== STARTUP_REUSE_EVENT || p.schema !== STARTUP_REUSE_SCHEMA || + !STARTUP_REUSE_LAYERS.includes(p.layer as StartupReuseLayer)) continue; + const layer = p.layer as StartupReuseLayer; + if (typeof p.state !== "string" || !["reused", "fresh", "unknown", "not_applicable"].includes(p.state) || + !STARTUP_REUSE_REASONS.includes(p.reason as StartupReuseReason)) continue; + const decision = { state: p.state, reason: p.reason } as StartupReuseDecision; + if (!observed.has(layer) || layers[layer].state !== "fresh") layers[layer] = decision; + observed.add(layer); + if (layer === "provider_process") { + // The receipt is a cumulative observation for this invocation, not a delta. + const count = p.providerLaunchCount; + providerLaunchCount = typeof count === "number" && Number.isSafeInteger(count) && count >= 0 + ? Math.max(providerLaunchCount ?? 0, count) : null; + } + } + if (providerLaunchCount !== null && providerLaunchCount > 0 && layers.provider_process.state !== "fresh") { + layers.provider_process = { state: "fresh", reason: "created" }; + } + const applicable = Object.values(layers).filter(layer => layer.state !== "not_applicable"); + const reused = applicable.some(layer => layer.state === "reused"); + const allReused = applicable.length > 0 && applicable.every(layer => layer.state === "reused"); + const warmth = allReused && providerLaunchCount === 0 ? "warm" + : reused ? "partial_reuse" + : applicable.length > 0 && applicable.every(layer => layer.state === "fresh") ? "cold" : "unknown"; + return { warmth, layers, providerLaunchCount }; +} diff --git a/server/src/__tests__/native-workspace-sync-history.test.ts b/server/src/__tests__/native-workspace-sync-history.test.ts index a1f2e0edcdb..ef1c83ba0f4 100644 --- a/server/src/__tests__/native-workspace-sync-history.test.ts +++ b/server/src/__tests__/native-workspace-sync-history.test.ts @@ -1,4 +1,5 @@ import { execFile } from "node:child_process"; +import { summarizeStartupReuse } from "@paperclipai/adapter-utils/startup-reuse"; import { mkdir, mkdtemp, readFile, readdir, rm, writeFile } from "node:fs/promises"; import os from "node:os"; import path from "node:path"; @@ -158,7 +159,8 @@ describe("native warm workspace Git history", () => { return result; }, }; - const second = (await prepareNativeWorkspaceSync({ ...input, runId: "second", target: { + const reuseEvents: import("@paperclipai/adapter-utils").AdapterRuntimeEvent[] = []; + const second = (await prepareNativeWorkspaceSync({ ...input, runId: "second", onEvent: async event => { reuseEvents.push(event); }, target: { ...target, runner: secondRunner, sandboxLeaseAcquisition: { outcome: "resumed", providerLeaseId: "sandbox" }, } }))!; try { @@ -167,6 +169,9 @@ describe("native warm workspace Git history", () => { if (invalidRunSeed) expect(invalidatedRunSeed).toBe(true); if (change === "remote_commit_corrupt_seed" || change === "remote_commit_missing_seed") expect(packClone).toHaveBeenCalled(); expect(second.mode).toBe(change === "unchanged" ? "adopt_remote" : "host_current"); + expect(summarizeStartupReuse(reuseEvents).layers.workspace).toEqual(change === "unchanged" + ? { state: "reused", reason: "verified_reuse" } + : { state: "fresh", reason: "workspace_changed" }); expect(await readFile(path.join(remoteRepo, "file.txt"), "utf8")).toBe(expectedContents); if (change === "host_bytes_cache_refused") expect(await readFile(path.join(remote, "extra.txt"), "utf8")).toBe("new host file\n"); expect(await git(remoteRepo, "rev-parse", "HEAD")).toBe(expectedHead); diff --git a/server/src/services/heartbeat/runtime-selection.ts b/server/src/services/heartbeat/runtime-selection.ts index 0344a78278f..03282c9f448 100644 --- a/server/src/services/heartbeat/runtime-selection.ts +++ b/server/src/services/heartbeat/runtime-selection.ts @@ -1040,6 +1040,7 @@ export async function selectHeartbeatRuntime(db: Db, input: HeartbeatRuntimeSele resourceDisposition: providerResourceDispositionForRun, onCheckpoint: input.workspace.onCheckpoint, onPhase: input.workspace.onPhase, + onEvent: onAdapterEvent, })); } else { const legacyWarmLifecycle = diff --git a/server/src/services/native-runtime/native-session-executor.ts b/server/src/services/native-runtime/native-session-executor.ts index 4947db3a769..1daf89666d3 100644 --- a/server/src/services/native-runtime/native-session-executor.ts +++ b/server/src/services/native-runtime/native-session-executor.ts @@ -168,6 +168,7 @@ import { } from "./remote-runner-recovery-diagnostics.js"; import { readRemoteRunnerRecoveryProbe, REMOTE_RUNNER_RECOVERY_PROBE_BUDGET_MS } from "./remote-runner-recovery-probe.js"; import { inspectRemoteWarmSessionRecovery, type RemoteWarmSessionRecovery } from "./remote-warm-session-recovery.js"; +import { emitStartupReuse, environmentStartupReuse } from "@paperclipai/adapter-utils/startup-reuse"; import { persistActivity, publishActivity } from "../activity-log.js"; import { commitNativeStatusDecision } from "./status-decision-committer.js"; import { resolvePaperclipInstanceRoot } from "../../home-paths.js"; @@ -7777,6 +7778,10 @@ async function executePaperclipNativeSessionWithinScope( startedAtMs: preparationStarts.runStartedAtMs, onEvent: input.onEvent, }); + await emitStartupReuse(input.onEvent, "environment", environmentStartupReuse(input.runnerExecutionTarget)); + if (!input.runnerExecutionTarget || input.runnerExecutionTarget.kind === "local") { + await emitStartupReuse(input.onEvent, "workspace", { state: "not_applicable", reason: "not_applicable" }); + } const toolTrace = createNativeToolTrace(trace); const taskPrepareScope = trace.start("task.prepare", { parentName: "task.provider_session", @@ -8285,6 +8290,7 @@ async function executePaperclipNativeSessionWithinScope( ) { sessionStartedAtMs = milestoneAtMs; sessionStartupMode = "bootstrap"; + await emitStartupReuse(input.onEvent, "provider_session", { state: "fresh", reason: "created" }); await trace.record({ name: "runner.session.bootstrap", parentName: "runner.session.startup", @@ -8292,6 +8298,9 @@ async function executePaperclipNativeSessionWithinScope( endedAtMs: milestoneAtMs, }); } + if (event.eventType === "session.resumed") { + await emitStartupReuse(input.onEvent, "provider_session", { state: "reused", reason: "verified_reuse" }); + } if ( event.eventType === "turn.submitted" && turnSubmittedAtMs === null @@ -8610,6 +8619,8 @@ async function executePaperclipNativeSessionWithinScope( if (entry.idleTimer !== null) clearTimeout(entry.idleTimer); entry.idleTimer = null; existingWarmSession = entry.session; + await emitStartupReuse(input.onEvent, "runner", { state: "reused", reason: "verified_reuse" }); + await emitStartupReuse(input.onEvent, "provider_session", { state: "reused", reason: "verified_reuse" }); githubAccess = entry.githubAccess; } } else { @@ -8779,6 +8790,8 @@ async function executePaperclipNativeSessionWithinScope( if (!recovered?.recovered || !recovered.session) throw new Error("runner_state_identity_mismatch: remote_warm_session_unproven"); if (remoteWarmRecovery.reuseProcess) { existingWarmSession = recovered.session; + await emitStartupReuse(input.onEvent, "runner", { state: "reused", reason: "verified_reuse" }); + await emitStartupReuse(input.onEvent, "provider_session", { state: "reused", reason: "verified_reuse" }); persistedWarmSession = null; } else { await recovered.session.close({ reason: "recovered warm session requires current process configuration" }); diff --git a/server/src/services/native-runtime/native-workspace-sync.ts b/server/src/services/native-runtime/native-workspace-sync.ts index 99fe0a61c83..d6b716e3412 100644 --- a/server/src/services/native-runtime/native-workspace-sync.ts +++ b/server/src/services/native-runtime/native-workspace-sync.ts @@ -1,4 +1,6 @@ import { measureRunPhase } from "../execution-preparation-timing.js"; +import { emitStartupReuse, type StartupReuseReason } from "@paperclipai/adapter-utils/startup-reuse"; +import type { AdapterRuntimeEvent } from "@paperclipai/adapter-utils"; import type { WorkspaceCheckpointMetrics } from "@paperclipai/adapter-utils/workspace-checkpoint"; import type { RuntimeSpanRunner } from "@paperclipai/adapter-utils/acpx-engine/startup-timing"; import fs from "node:fs/promises"; @@ -881,6 +883,7 @@ export async function prepareNativeWorkspaceSync(input: { resourceDisposition?: NativeWorkspaceResourceDisposition; onPhase?: RuntimeSpanRunner; onCheckpoint?: (metrics: WorkspaceCheckpointMetrics) => Promise; + onEvent?: (event: AdapterRuntimeEvent) => Promise; }): Promise { if (input.target?.kind !== "remote" || input.target.transport !== "sandbox") { return null; @@ -908,6 +911,7 @@ export async function prepareNativeWorkspaceSync(input: { let runtime: PreparedAdapterExecutionTargetRuntime | undefined; let descriptor: NativeWorkspaceSyncDescriptor; let mode: WorkspaceInboundMode = "host_current"; + let reuseReason: StartupReuseReason = "created"; const seedPaths = durableSeedPaths(input.runId); await measureRunPhase("workspace_sync.descriptor_directory", () => ensurePrivateDirectory(descriptorDirectory(input.runId))); @@ -934,6 +938,7 @@ export async function prepareNativeWorkspaceSync(input: { sameRunRecovery: input.sameRunRecovery, sameProviderLease, }); + reuseReason = sameProviderLease ? "verified_reuse" : "replacement"; const durableSeed = mode === "durable_seed" ? existing.descriptor.seed @@ -969,6 +974,7 @@ export async function prepareNativeWorkspaceSync(input: { }; } else { const acquisition = target.sandboxLeaseAcquisition?.outcome ?? null; + reuseReason = acquisition === "resumed" ? "cache_miss" : acquisition === "replacement" ? "replacement" : "created"; const priorStamp = leaseStamp({ lease: input.lease, workspaceId: input.workspaceId, @@ -1013,8 +1019,10 @@ export async function prepareNativeWorkspaceSync(input: { (await measureRunPhase("workspace_sync.warm_stamp", () => remoteStampMatches({ target, expected: priorStamp, gitSnapshot: currentSnapshot.gitSnapshot, repositories: currentSnapshot.repositories }))); if (verifiedWarmAdoption) { mode = "adopt_remote"; + reuseReason = "verified_reuse"; } else { mode = "host_current"; + reuseReason = "workspace_changed"; let preparedSeed: WorkspaceDurableSeedPaths | undefined; try { preparedSeed = await measureRunPhase("workspace_sync.durable_seed_verify", () => verifiedDurableSeed({ runId: input.runId, @@ -1075,6 +1083,10 @@ export async function prepareNativeWorkspaceSync(input: { const preparedRuntime = runtime; let reference = await measureRunPhase("workspace_sync.descriptor_write", () => writeDescriptor(descriptor)); await measureRunPhase("workspace_sync.reference_write", () => persistRunReference(input.db, input.runId, reference)); + await emitStartupReuse(input.onEvent, "workspace", { + state: mode === "adopt_remote" ? "reused" : "fresh", + reason: reuseReason, + }); let restorePromise: Promise | null = null; return { mode, diff --git a/tests/runner-e2e/README.md b/tests/runner-e2e/README.md index be25c94edab..28e6d517234 100644 --- a/tests/runner-e2e/README.md +++ b/tests/runner-e2e/README.md @@ -1699,6 +1699,14 @@ separate capability gap; these callback tests do not claim that export works. ### Remote native evidence and warm continuation +Results can include a `startupReuse` entry for each run. The dashboard shows +receipt-derived warmth, the environment/lease, workspace, Runner, provider +process and session decisions, and observed provider launches. Private attempt +evidence includes `snapshots/startup-reuse.json`. See the +[run-log contract](../../doc/run-log-events.md#startup-reuse-evidence) for the +closed states and reasons. Historical runs without receipts show unknown +values. Provider-session continuity does not establish physical process reuse. + All three native suites use an operator-published instruction file to withhold actual work until independent observers are armed inside the exact owned Daytona sandbox. The initial task only reads that file. Explicitly typed setup reads are diff --git a/tests/runner-e2e/dashboard.ts b/tests/runner-e2e/dashboard.ts index ee6a46c860a..039900d6a82 100644 --- a/tests/runner-e2e/dashboard.ts +++ b/tests/runner-e2e/dashboard.ts @@ -1,4 +1,5 @@ import { isIncompleteFirstTaskResult, renderCaseOutcome } from "./case-outcome.js"; +import { STARTUP_REUSE_LAYERS, summarizeStartupReuse } from "../../packages/adapter-utils/src/startup-reuse.js"; import { renderFirstTaskDetails } from "./first-task-report.js"; import { discoverReportCatalog, @@ -250,6 +251,13 @@ function renderCase( `, ) .join(""); + const startupReuseRows = (entry?.result.startupReuse ?? (entry?.result.runIds ?? []).map(runId => ({ + runId, ...summarizeStartupReuse([]), + }))).map(reuse => ` + ${html(reuse.runId)}${html(reuse.warmth)} + ${STARTUP_REUSE_LAYERS.map(layer => `${html(reuse.layers[layer].state)} (${html(reuse.layers[layer].reason)})`).join("")} + ${html(reuse.providerLaunchCount === null ? "unknown" : reuse.providerLaunchCount)} + `).join(""); const gallery = screenshots.length ? `
${screenshots .map( @@ -328,6 +336,7 @@ function renderCase( }

${html(detail)}

${turnTimingRows ? `
${turnTimingRows}
TurnRunLeaseSchedulerRun durationResponse
` : ""} + ${startupReuseRows ? `
${startupReuseRows}
Startup reuse evidence
RunWarmthEnvironment/leaseWorkspaceRunnerProvider processProvider sessionProvider launches
` : ""} ${matcherRows ? `
${matcherRows}
ResultMatcherExpectationDetail
` : `

No matcher result was recorded.

`} ${entry ? `
Usage and billing metadata
${html(JSON.stringify({ billing, rawUsage: entry.result.usage ?? null }, null, 2))}
` : ""} diff --git a/tests/runner-e2e/history.ts b/tests/runner-e2e/history.ts index 3ddb7632d28..203535ffffc 100644 --- a/tests/runner-e2e/history.ts +++ b/tests/runner-e2e/history.ts @@ -1,4 +1,5 @@ import { isIncompleteFirstTaskResult } from "./case-outcome.js"; +import { summarizeStartupReuse } from "../../packages/adapter-utils/src/startup-reuse.js"; import { validateRetainedRunnerResult } from "./result-validation.js"; import { discoverReportCatalog, @@ -28,6 +29,9 @@ export function canonicalExecutionId(id: string) { export function upgradeRunnerResult(result: RunnerE2EResult): RunnerE2EResult { validateRetainedRunnerResult(result); + result = { ...result, startupReuse: result.startupReuse ?? (result.runIds ?? []).map(runId => ({ + runId, ...summarizeStartupReuse([]), + })) }; const executionId = canonicalExecutionId(result.executionId); const execution = runnerMatrix.find( (candidate) => candidate.id === executionId, diff --git a/tests/runner-e2e/pi-controls-evidence.test.ts b/tests/runner-e2e/pi-controls-evidence.test.ts index 34dc9359ab6..ee1c59828d1 100644 --- a/tests/runner-e2e/pi-controls-evidence.test.ts +++ b/tests/runner-e2e/pi-controls-evidence.test.ts @@ -189,8 +189,8 @@ describe("Pi controls catalog admission", () => { // Extended v3 states the strict file oracle's task-wide Bash limit. const pi = runnerMatrix.find(c => c.profile.qualificationCandidate === "pi")!.profile; expect(pi.modelQualification?.qualificationId).toBe("pi:0.0.33:1.0.0:openrouter"); - expect(runnerSuites.find(s => s.id === "pi-native")!.definitionMetadata).toMatchObject({ version: 23, remoteProcExit: "separately-confirmed-absence-after-read-failure", taskCreation: "explicit-title-and-creation-response-id", agentMemoryParent: "public-managed-file-seed-before-admission", incompleteTerminalCleanup: "retirement-retained-with-failed-watch", profileVersion: 27, agentMemoryContent: "utf8-nonce-plus-final-lf", agentMemoryPrompt: "single-json-write-and-content-bound-native-read-both-runs", agentMemoryReadAuthority: "local-withheld-or-exact-remote-agent-run-file", taskPromptTransport: "fenced-markdown-paste-and-multiline-literal-escapes", nativeFinish: "current-contract-objective-evidence-refs", providerFaultExecutable: "stable-preinstalled-runner-link-and-snapshot-node-inode-with-held-bootstrap-fd-3-or-7" }); - expect(runnerSuites.find(s => s.id === "pi-controls")!.definitionMetadata).toMatchObject({ version: 10, remoteProcExit: "separately-confirmed-absence-after-read-failure", taskCreation: "explicit-title-and-creation-response-id", profileVersion: 27, + expect(runnerSuites.find(s => s.id === "pi-native")!.definitionMetadata).toMatchObject({ version: 23, remoteProcExit: "separately-confirmed-absence-after-read-failure", taskCreation: "explicit-title-and-creation-response-id", agentMemoryParent: "public-managed-file-seed-before-admission", incompleteTerminalCleanup: "retirement-retained-with-failed-watch", profileVersion: 28, agentMemoryContent: "utf8-nonce-plus-final-lf", agentMemoryPrompt: "single-json-write-and-content-bound-native-read-both-runs", agentMemoryReadAuthority: "local-withheld-or-exact-remote-agent-run-file", taskPromptTransport: "fenced-markdown-paste-and-multiline-literal-escapes", nativeFinish: "current-contract-objective-evidence-refs", providerFaultExecutable: "stable-preinstalled-runner-link-and-snapshot-node-inode-with-held-bootstrap-fd-3-or-7" }); + expect(runnerSuites.find(s => s.id === "pi-controls")!.definitionMetadata).toMatchObject({ version: 10, remoteProcExit: "separately-confirmed-absence-after-read-failure", taskCreation: "explicit-title-and-creation-response-id", profileVersion: 28, remoteProcessIdentity: "observer-pid-startTicks-bootId", controlPlaneSettlement: "required-scoped-result-and-terminal-after-runner" }); expect(runnerSuites.find(s => s.id === "extended-harnesses")!.definitionMetadata).toMatchObject({ version: 5, piFileArtifactTitle: "exact-filename", piFileCommandTransport: "fenced-bash-markdown-paste" }); @@ -200,7 +200,7 @@ describe("Pi controls catalog admission", () => { } const hashes = Object.fromEntries(runnerSuites.filter(s => ["pi-native", "native-active-stop", "extended-harnesses", "rich-acp-warm-continuity"].includes(s.id)).map(s => [s.id, suiteDefinitionHash(s)])); expect(hashes).toEqual({ - "pi-native": "7bf1477d5ca92569aad29d31278fad220ff59baa9f6622c8c9b1302ecaa47b83", + "pi-native": "914b35a061fe7e0fbd7a288bfb970ba1a73f9ed725667a7edf81cfdee33ab5df", "native-active-stop": "2d4fdeeb75bd531b309bd1b35cfa5680ceefdeee6b7155b068dd011ce9901980", "rich-acp-warm-continuity": "331b88d9538a132670789fb7864df7df5f4bf294ae19b62f53d8a02f901774f0", "extended-harnesses": "5de4fac78d4d581bc0954f07b5cf2df2862d37f8b0205325eede6d9ef6d9f5e6", diff --git a/tests/runner-e2e/report.test.ts b/tests/runner-e2e/report.test.ts index 7bbea6e5a7a..1a43b5d25c6 100644 --- a/tests/runner-e2e/report.test.ts +++ b/tests/runner-e2e/report.test.ts @@ -4,6 +4,7 @@ import { mkdir, mkdtemp, readFile, rm, writeFile } from "node:fs/promises"; import os from "node:os"; import path from "node:path"; import { afterEach, describe, expect, it } from "vitest"; +import { STARTUP_REUSE_LAYERS, STARTUP_REUSE_SCHEMA, summarizeStartupReuse } from "../../packages/adapter-utils/src/startup-reuse.js"; import type { RunnerE2EResult } from "./types.js"; const execFileAsync = promisify(execFile); @@ -18,6 +19,46 @@ afterEach(async () => { }); describe("runner E2E report aggregation", () => { + it("retains full reuse and a workspace-only invalidation in the generated report", async () => { + const root = await mkdtemp(path.join(os.tmpdir(), "runner-reuse-report-")); + cleanupDirectories.push(root); + const executionId = "core-compatibility.runner-codex.local.message-marker"; + const directory = path.join(root, "attempt-1"); + await mkdir(directory); + const startupReuse = [false, true].map(invalidate => ({ + runId: invalidate ? "workspace-invalidated" : "fully-reused", + ...summarizeStartupReuse(STARTUP_REUSE_LAYERS.map(layer => ({ + eventType: "run.startup.reuse", + payload: { schema: STARTUP_REUSE_SCHEMA, layer, + state: invalidate && layer === "workspace" ? "fresh" : "reused", + reason: invalidate && layer === "workspace" ? "workspace_changed" : "verified_reuse", + ...(layer === "provider_process" ? { providerLaunchCount: 0 } : {}) }, + }))), + })); + const result: RunnerE2EResult = { + schema: "paperclip.runner-e2e.result/v2", executionId, suiteId: "core-compatibility", + attempt: 1, status: "passed", profileId: "runner-codex", environmentId: "local", + caseId: "message-marker", provider: "codex", model: "fixture-model", runtimeMode: "native", + startedAt: "2026-09-23T00:00:00Z", finishedAt: "2026-09-23T00:00:01Z", durationMs: 1000, + cleanup: "passed", runIds: startupReuse.map(reuse => reuse.runId), startupReuse, + }; + await writeFile(path.join(directory, "result.json"), JSON.stringify(result)); + await writeFile(path.join(directory, "final-state.png"), "fake-png"); + await writeFile(path.join(directory, "evidence-manifest.json"), JSON.stringify({ files: ["final-state.png"], leaks: [], missing: [] })); + const output = path.join(root, "merged"); + await execFileAsync(process.execPath, [path.join(repositoryRoot, "cli/node_modules/tsx/dist/cli.mjs"), path.join(repositoryRoot, "tests/runner-e2e/report.ts")], { + cwd: repositoryRoot, + env: { ...process.env, PAPERCLIP_RUNNER_E2E_REPORT_ROOT: root, PAPERCLIP_RUNNER_E2E_REPORT_OUT: output, PAPERCLIP_RUNNER_E2E_EXPECTED_IDS: JSON.stringify([executionId]) }, + }); + const normalized = JSON.parse(await readFile(path.join(output, "normalized-results.json"), "utf8")); + expect(normalized.results[0].startupReuse).toEqual(startupReuse); + expect(startupReuse.map(reuse => reuse.warmth)).toEqual(["warm", "partial_reuse"]); + const dashboard = await readFile(path.join(output, "index.html"), "utf8"); + expect(dashboard).toContain("warm"); + expect(dashboard).toContain("partial_reuse"); + expect(dashboard).toContain("fresh (workspace_changed)"); + }); + it.each([ { name: "missing", usage: null, runIds: ["run-1"], tokens: "Unavailable", cost: "Unavailable", htmlTokens: "Unavailable" }, { name: "partial", usage: { runs: [{ usage: { inputTokens: 1250, outputTokens: 75, cachedInputTokens: 500, costUsd: 0.0125 } }, { usage: null }] }, runIds: ["run-1", "run-2"], tokens: "1250 input / 75 output / 500 cached (partial: 1/2 runs)", cost: "$0.012500 (partial: 1/2 runs)", htmlTokens: "1,250 (partial: 1/2 runs)" }, @@ -59,6 +100,10 @@ describe("runner E2E report aggregation", () => { const normalized = JSON.parse(await readFile(path.join(output, "normalized-results.json"), "utf8")); expect(normalized.passed).toBe(1); expect(normalized.results[0].usage).toEqual(usage); + expect(normalized.results[0].startupReuse).toHaveLength(runIds.length); + expect(normalized.results[0].startupReuse.every((reuse: { warmth: string; providerLaunchCount: number | null }) => + reuse.warmth === "unknown" && reuse.providerLaunchCount === null)).toBe(true); + expect(dashboard).toContain("Startup reuse evidence"); }); it("keeps interrupted journeys incomplete unless their evidence is invalid", async () => { diff --git a/tests/runner-e2e/result-validation.ts b/tests/runner-e2e/result-validation.ts index 7996fc45505..577b5ea059c 100644 --- a/tests/runner-e2e/result-validation.ts +++ b/tests/runner-e2e/result-validation.ts @@ -1,4 +1,5 @@ import { connectionCheckpoints, connectionEvidencePasses, connectionRunSignals } from "./connection-evidence.js"; +import { STARTUP_REUSE_LAYERS, STARTUP_REUSE_REASONS } from "../../packages/adapter-utils/src/startup-reuse.js"; import type { RunnerE2EResult } from "./types.js"; type Rule = (value: unknown, at: string) => void; @@ -194,6 +195,15 @@ const fields = { issueId: optional(string), issueIdentifier: optional(nullable(string)), runIds: optional(array(string)), + startupReuse: optional(array(shape({ + runId: string, + warmth: oneOf("cold", "warm", "partial_reuse", "unknown"), + providerLaunchCount: nullable(integer), + layers: shape(Object.fromEntries(STARTUP_REUSE_LAYERS.map(layer => [layer, shape({ + state: oneOf("fresh", "reused", "unknown", "not_applicable"), + reason: oneOf(...STARTUP_REUSE_REASONS), + })]))), + }))), turnTimings: optional( array( shape({ diff --git a/tests/runner-e2e/runner.spec.ts b/tests/runner-e2e/runner.spec.ts index 642f2bafc90..aef7d88aae6 100644 --- a/tests/runner-e2e/runner.spec.ts +++ b/tests/runner-e2e/runner.spec.ts @@ -14,6 +14,7 @@ import { captureNativeDefault, gradeNativeDefault, nativeCompletionWorkspaceDige import { gradeNativeCompletion, gradeNativeCompletionFinalAnswer } from "./native-completion-scoring.js"; import { assertNativeBlockerReply } from "./native-blocker-visible.js"; import { warmManagedFileEvidence } from "./warm-managed-files.js"; +import { summarizeStartupReuse } from "../../packages/adapter-utils/src/startup-reuse.js"; import { gitFinalizationEvidence, gitStreamingEvidence, setupGitStreamingWorkspace } from "./daytona-git-streaming.js"; import { runsCompletionUpdateProbe, completionQualityControls, completionQualityStatus, judgeCompletionQuality, reserveCompletionQuality, type CompletionQualityRecord } from "./completion-quality.js"; import { runNativeProviderLossFlow } from "./native-provider-loss-flow.js"; @@ -639,6 +640,7 @@ for (const execution of executions) { }; let firstTaskEvidence: RunnerE2EResult["firstTask"]; let turnTimings: NonNullable | undefined; + let startupReuse: RunnerE2EResult["startupReuse"]; const turnSubmissionTimesMs: number[] = []; const screenshots: NonNullable = []; let primaryError: unknown; @@ -2755,6 +2757,9 @@ for (const execution of executions) { } } + startupReuse = runEventsByRun.map(captured => ({ runId: captured.runId, + ...summarizeStartupReuse(captured.error ? [] : captured.events) })); + await writeSanitizedJson(snapshotsDir, "startup-reuse.json", startupReuse, secrets); await writeSanitizedJson( snapshotsDir, "api-state.json", @@ -3143,6 +3148,7 @@ for (const execution of executions) { issueIdentifier: issue?.identifier ?? null, runIds: selectedRuns.map((run) => run.id), ...(turnTimings ? { turnTimings } : {}), + ...(startupReuse ? { startupReuse } : {}), startedAt, finishedAt: new Date(finishedAtMs).toISOString(), durationMs: finishedAtMs - startedAtMs, diff --git a/tests/runner-e2e/types.ts b/tests/runner-e2e/types.ts index dd9a1011bcc..8b8baf8ba0e 100644 --- a/tests/runner-e2e/types.ts +++ b/tests/runner-e2e/types.ts @@ -308,6 +308,7 @@ export interface RunnerE2EResult { issueId?: string; issueIdentifier?: string | null; runIds?: string[]; + startupReuse?: Array<{ runId: string } & import("../../packages/adapter-utils/src/startup-reuse.js").StartupReuseSummary>; turnTimings?: Array<{ turn: number; submittedAt: string;