feat(observability): instrument stage.sync host steps and home the agent process span (#11301)
## Thinking Path > - Paperclip is the open source app people use to manage AI agents for work. > - It runs each agent in a remote sandbox and emits OpenTelemetry spans for the sandbox bring-up and the run. > - A real trace showed two gaps. `stage.sync` had about 3 seconds of unattributed host work before its `pack` span. The persistent agent process showed a `sandbox.exec` span that outlived its parent by about 50 seconds. > - The gaps hide real cost and make the trace read as a sequencing bug, so an operator cannot see where startup time goes. > - This pull request wraps the two pre-`pack` host steps in their own spans. It also homes the long-lived process in a run-scoped `sandbox.agentProcess` span. > - The benefit is that startup time is fully attributed and the process reads as a resource that overlaps the turn, not a child that outlives its parent. ## Linked Issues or Issue Description No public issue exists. This is an enhancement to existing telemetry. It is described inline below, following `.github/ISSUE_TEMPLATE/enhancement.yml`. Prior related work: the merged PR #10999 added the run-time wrapper spans and the telemetry data-contract section this PR extends. **What existing behavior does this improve?** The sandbox bring-up and run OpenTelemetry trace. It closes two attribution gaps in that trace. **Subsystem affected** Observability for sandbox execution. The code lives in `packages/adapter-utils`. The span contract lives in `packages/shared/src/telemetry`. **Current behavior** `stage.sync` opens a `pack` span, but the git enumeration and the baseline content-hash walk that run before `pack` have no span, so about 3 seconds read as a gap. On the streamed process-session path the agent process launches fire-and-forget inside the ~2.3 second `bridge.process-session` bring-up step, so its `sandbox.exec` span parents to that step and then runs about 50 seconds. The child dangles past its parent and overlaps `agent.turn`. **Proposed behavior** Wrap the two pre-`pack` host operations in `snapshot.git` and `snapshot.baseline` spans under `stage.sync`. Wrap the streamed launch in a run-scoped `sandbox.agentProcess` span that parents to the live run root (`task.run` at launch). **Reason and benefit** Startup time is fully attributed. The long-lived process reads as a resource that overlaps the sibling `agent.turn`, not a mis-parented child. **Breaking changes** None. The spans are opt-in and export only when an OTLP endpoint is configured. The span seam is a no-op when no runner is injected. No first-party telemetry event changes. ## What Changed - `sandbox-managed-runtime.ts`: add `snapshot.git` and `snapshot.baseline` spans around the git enumeration and the baseline content-hash walk, nested under `stage.sync`, through a shared `runStepSpan` helper that `pack` now also uses. - `execution-target.ts`: wrap the fire-and-forget streamed launch in a run-rooted `sandbox.agentProcess` span, so it parents to the live run root and holds the inner `sandbox.exec`. The `.then`/`.catch` chain became try/catch inside the span callback, with identical frame-ingestion behavior. - `packages/shared/src/telemetry/README.md`: update the span table and the parenting prose. Add `snapshot.git`, `snapshot.baseline`, `pack`, and `sandbox.agentProcess`, and document the intended `sandbox.agentProcess` / `agent.turn` overlap. - Tests: update the executor span-tree test (`childNames` and parent assertions), update the `sandbox-managed-runtime` span-set and nesting tests, and add two `execution-target-sandbox` tests (the launch opens `sandbox.agentProcess`; it parents to the run root, not the bring-up step). ## Verification - Run `npx vitest run` on the three affected test files. Result: 174 tests pass. This includes the updated executor span-tree test and the new `sandbox.agentProcess` open and parenting tests. - Run `tsc --noEmit` in `packages/adapter-utils`. Result: no errors in the changed source or test files. - The full 37-test streamed process-session suite passes unchanged. This confirms the try/catch restructure preserves frame delivery and exit/error behavior. - Pre-existing and unrelated to this PR (present on `master`): `tsc` errors in `execute.ts` / `execute.test.ts` / `remote-spawn-smoke.test.ts` (`onAgentStderr` / `spawnCwd`), and a `check:forbidden-tokens` failure from internal `PAP-###` ids in `ui/src/components/IssueRecoveryActionCard.test.tsx`. This PR does not touch those files, and its own diff is token-clean. ## Risks Low. The change adds instrumentation on the opt-in span path and does not change control flow on the default path. The one production restructure is the streamed launch, which stays fire-and-forget, so bring-up does not block on it. Only the streamed path gains `sandbox.agentProcess`; the legacy poll path launches the process detached and has no host-side long-lived span to home. ## Model Used Anthropic Claude Opus 4.8 (`claude-opus-4-8`), about 200K-token context, agentic tool use through Claude Code. The trace was reviewed through the Honeycomb MCP. The code was written and tested with the model. ## 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: Claude Opus 4.8 <noreply@anthropic.com>
This commit is contained in:
Nicky Leach
GitHub
parent
61a5b7c6f9
commit
04bf7a6ab5
|
|
@ -3272,8 +3272,10 @@ describe("ACPX engine sandbox-start spans (opt-in root + child parenting)", () =
|
|||
|
||||
// A codex bring-up over the remote sandbox lane crosses all 7 boundaries.
|
||||
// Each boundary span parents to the sandbox bring-up span, not to the run
|
||||
// root or the turn span. The `stage.sync` step also opens one host `pack`
|
||||
// span around the workspace tarball build, so it nests one level deeper.
|
||||
// root or the turn span. The `stage.sync` step also opens three host
|
||||
// sub-step spans — `snapshot.git`, `snapshot.baseline`, and `pack` — around
|
||||
// its git enumeration, baseline content-hash walk, and workspace tarball
|
||||
// build, so those nest one level deeper.
|
||||
const childNames = spans
|
||||
.filter((span) => span !== runRootSpan && span !== startupSpan && span !== turnSpan)
|
||||
.map((span) => span.name)
|
||||
|
|
@ -3286,26 +3288,35 @@ describe("ACPX engine sandbox-start spans (opt-in root + child parenting)", () =
|
|||
"codex-home.seed",
|
||||
"pack",
|
||||
"skills.reconcile",
|
||||
"snapshot.baseline",
|
||||
"snapshot.git",
|
||||
"stage.sync",
|
||||
"workspace.resolve",
|
||||
],
|
||||
);
|
||||
|
||||
// The host `pack` span nests under the `stage.sync` step span (the host
|
||||
// tarball build runs inside that step), not directly under the bring-up
|
||||
// span.
|
||||
// The three host sub-step spans nest under the `stage.sync` step span (that
|
||||
// host work runs inside the step), not directly under the bring-up span.
|
||||
const stageSyncSpan = spans.find((span) => span.name === "stage.sync");
|
||||
const packSpan = spans.find((span) => span.name === "pack");
|
||||
const snapshotGitSpan = spans.find((span) => span.name === "snapshot.git");
|
||||
const snapshotBaselineSpan = spans.find((span) => span.name === "snapshot.baseline");
|
||||
expect(stageSyncSpan).toBeTruthy();
|
||||
expect(packSpan).toBeTruthy();
|
||||
expect(snapshotGitSpan).toBeTruthy();
|
||||
expect(snapshotBaselineSpan).toBeTruthy();
|
||||
expect(packSpan!.parent).toBe(stageSyncSpan);
|
||||
expect(snapshotGitSpan!.parent).toBe(stageSyncSpan);
|
||||
expect(snapshotBaselineSpan!.parent).toBe(stageSyncSpan);
|
||||
expect(packSpan!.ended).toBe(true);
|
||||
|
||||
// Every boundary step span parents to the sandbox bring-up span and ends.
|
||||
// The `pack` span is the one exception: it parents to `stage.sync` above.
|
||||
// The three `stage.sync` sub-step spans are the exceptions: they parent to
|
||||
// `stage.sync` above.
|
||||
const stageSyncChildren = new Set([packSpan, snapshotGitSpan, snapshotBaselineSpan]);
|
||||
for (const span of spans) {
|
||||
if (span === runRootSpan || span === startupSpan || span === turnSpan) continue;
|
||||
if (span === packSpan) continue;
|
||||
if (stageSyncChildren.has(span)) continue;
|
||||
expect(span.parent, `span "${span.name}" must parent to the startup span`).toBe(startupSpan);
|
||||
expect(span.ended, `span "${span.name}" must end`).toBe(true);
|
||||
}
|
||||
|
|
|
|||
|
|
@ -23,13 +23,55 @@ import {
|
|||
startAdapterExecutionTargetPaperclipBridge,
|
||||
type AdapterSandboxExecutionTarget,
|
||||
} from "./execution-target.js";
|
||||
import { getActiveStepContext } from "./acpx-engine/startup-timing.js";
|
||||
import {
|
||||
createRuntimeSpanRunner,
|
||||
getActiveStepContext,
|
||||
type StartupSpan,
|
||||
type StartupTraceContext,
|
||||
type StartupTracer,
|
||||
} from "./acpx-engine/startup-timing.js";
|
||||
import { createSandboxRunLogTailFactory } from "./sandbox-run-log-stream.js";
|
||||
import { runChildProcess } from "./server-utils.js";
|
||||
import { shellQuote } from "./ssh.js";
|
||||
|
||||
const execFileAsync = promisify(execFile);
|
||||
|
||||
type RecordedSpan = { name: string; parentName: string | null; ended: boolean };
|
||||
|
||||
/**
|
||||
* A structural tracer that records each opened span's name, parent, and end
|
||||
* state, so a test can assert the trace shape a runtime span runner produces.
|
||||
* Mirrors the recorder used for the `pack`/`stage.sync` nesting tests.
|
||||
*/
|
||||
function createRecordingTraceContext(): {
|
||||
traceContext: StartupTraceContext;
|
||||
spans: RecordedSpan[];
|
||||
} {
|
||||
const spans: RecordedSpan[] = [];
|
||||
const byHandle = new WeakMap<StartupSpan, RecordedSpan>();
|
||||
const tracer: StartupTracer = {
|
||||
startSpan(name, _options, context) {
|
||||
const parent = context as RecordedSpan | undefined;
|
||||
const record: RecordedSpan = { name, parentName: parent?.name ?? null, ended: false };
|
||||
spans.push(record);
|
||||
const handle: StartupSpan = {
|
||||
setAttribute() {},
|
||||
setStatus() {},
|
||||
end() {
|
||||
record.ended = true;
|
||||
},
|
||||
};
|
||||
byHandle.set(handle, record);
|
||||
return handle;
|
||||
},
|
||||
};
|
||||
const traceContext: StartupTraceContext = {
|
||||
tracer,
|
||||
contextWithSpan: (span) => byHandle.get(span),
|
||||
};
|
||||
return { traceContext, spans };
|
||||
}
|
||||
|
||||
describe("sandbox adapter execution targets", () => {
|
||||
const cleanupDirs: string[] = [];
|
||||
|
||||
|
|
@ -950,6 +992,187 @@ describe("sandbox adapter execution targets", () => {
|
|||
}
|
||||
});
|
||||
|
||||
it("wraps the long-lived streamed launch in a sandbox.agentProcess span", async () => {
|
||||
// The streamed launch is fire-and-forget and lives for the whole run, so
|
||||
// its span must open under the live run root (not the ephemeral bring-up
|
||||
// step) and stay open around the launch. Record the opened span names and
|
||||
// prove `sandbox.agentProcess` is among them, and that a normal exchange
|
||||
// still works through the wrap.
|
||||
const rootDir = await mkdtemp(path.join(os.tmpdir(), "paperclip-process-session-stream-span-"));
|
||||
cleanupDirs.push(rootDir);
|
||||
const childPath = path.join(rootDir, "echo-acp-child.mjs");
|
||||
await writeFile(
|
||||
childPath,
|
||||
[
|
||||
"process.stdin.on('data', (chunk) => {",
|
||||
" process.stdout.write('out:' + chunk.toString());",
|
||||
"});",
|
||||
].join("\n"),
|
||||
"utf8",
|
||||
);
|
||||
const target: AdapterSandboxExecutionTarget = {
|
||||
kind: "remote",
|
||||
transport: "sandbox",
|
||||
providerKey: "local-test",
|
||||
remoteCwd: rootDir,
|
||||
timeoutMs: 30_000,
|
||||
runner: createLocalSandboxRunner(),
|
||||
};
|
||||
|
||||
const spanNames: string[] = [];
|
||||
const bridge = await startAdapterExecutionTargetProcessSessionBridge({
|
||||
runId: "run-stream-span",
|
||||
target,
|
||||
runtimeRootDir: path.posix.join(rootDir, ".paperclip-runtime", "acpx"),
|
||||
adapterKey: "acpx",
|
||||
command: process.execPath,
|
||||
args: [childPath],
|
||||
cwd: rootDir,
|
||||
env: {},
|
||||
timeoutSec: 5,
|
||||
onLog: async () => {},
|
||||
streamOutputViaSession: true,
|
||||
// Record each wrapper span name, then run the wrapped work.
|
||||
runtimeSpan: async (name, work) => {
|
||||
spanNames.push(name);
|
||||
return work();
|
||||
},
|
||||
});
|
||||
expect(bridge).not.toBeNull();
|
||||
|
||||
try {
|
||||
// The launch span opens synchronously as the bridge starts, before any
|
||||
// frame flows, so it is observable as soon as the handle resolves.
|
||||
expect(spanNames).toContain("sandbox.agentProcess");
|
||||
const result = await runProxyWithInput(bridge!.agentCommand, "hello\n");
|
||||
expect(result.code).toBe(0);
|
||||
expect(result.stdout).toBe("out:hello\n");
|
||||
} finally {
|
||||
await bridge?.stop();
|
||||
}
|
||||
});
|
||||
|
||||
it("parents the sandbox.agentProcess span to the live run root, not the bring-up step", async () => {
|
||||
// The launch runs for the whole run, so its span must parent to the live
|
||||
// run root (here a stand-in `task.run`) rather than the ephemeral
|
||||
// `bridge.process-session` bring-up step — otherwise it dangles past its
|
||||
// parent and overlaps `agent.turn`. Build the real run-rooted runner from a
|
||||
// recording trace context and assert the recorded parent.
|
||||
const rootDir = await mkdtemp(path.join(os.tmpdir(), "paperclip-process-session-stream-parent-"));
|
||||
cleanupDirs.push(rootDir);
|
||||
const childPath = path.join(rootDir, "noop-acp-child.mjs");
|
||||
await writeFile(childPath, "process.stdin.on('data', () => {});\n", "utf8");
|
||||
const target: AdapterSandboxExecutionTarget = {
|
||||
kind: "remote",
|
||||
transport: "sandbox",
|
||||
providerKey: "local-test",
|
||||
remoteCwd: rootDir,
|
||||
timeoutMs: 30_000,
|
||||
runner: createLocalSandboxRunner(),
|
||||
};
|
||||
|
||||
const { traceContext, spans } = createRecordingTraceContext();
|
||||
// The run root stands in for `task.run` — the parent the run-rooted runner
|
||||
// resolves at launch time, since no turn has started yet.
|
||||
const runRoot = traceContext.tracer.startSpan("task.run", undefined, undefined);
|
||||
const runRootContext = traceContext.contextWithSpan(runRoot);
|
||||
const runtimeSpan = createRuntimeSpanRunner(traceContext, () => runRootContext);
|
||||
|
||||
const bridge = await startAdapterExecutionTargetProcessSessionBridge({
|
||||
runId: "run-stream-parent",
|
||||
target,
|
||||
runtimeRootDir: path.posix.join(rootDir, ".paperclip-runtime", "acpx"),
|
||||
adapterKey: "acpx",
|
||||
command: process.execPath,
|
||||
args: [childPath],
|
||||
cwd: rootDir,
|
||||
env: {},
|
||||
timeoutSec: 5,
|
||||
onLog: async () => {},
|
||||
streamOutputViaSession: true,
|
||||
runtimeSpan,
|
||||
});
|
||||
expect(bridge).not.toBeNull();
|
||||
|
||||
try {
|
||||
const agentProcess = spans.find((span) => span.name === "sandbox.agentProcess");
|
||||
expect(agentProcess).toBeDefined();
|
||||
expect(agentProcess!.parentName).toBe("task.run");
|
||||
} finally {
|
||||
await bridge?.stop();
|
||||
}
|
||||
});
|
||||
|
||||
it("ends the sandbox.agentProcess span at stop() even when the process lingers", async () => {
|
||||
// The span must not outlive the run root. When the remote process lingers
|
||||
// past bridge teardown (`execute` has no cancel), the span still has to end
|
||||
// at `stop()`, which the caller awaits before it ends `task.run`. Use a
|
||||
// child that ignores stdin and never exits on its own, so the launch
|
||||
// command stays pending across `stop()`, and prove the span ends anyway.
|
||||
const rootDir = await mkdtemp(path.join(os.tmpdir(), "paperclip-process-session-stream-linger-"));
|
||||
cleanupDirs.push(rootDir);
|
||||
const childPath = path.join(rootDir, "linger-acp-child.mjs");
|
||||
await writeFile(
|
||||
childPath,
|
||||
[
|
||||
"process.stdin.on('data', () => {});",
|
||||
// Stay alive well past the assertions, then self-exit so the test
|
||||
// leaves no lingering process.
|
||||
"setTimeout(() => process.exit(0), 3000);",
|
||||
].join("\n"),
|
||||
"utf8",
|
||||
);
|
||||
const target: AdapterSandboxExecutionTarget = {
|
||||
kind: "remote",
|
||||
transport: "sandbox",
|
||||
providerKey: "local-test",
|
||||
remoteCwd: rootDir,
|
||||
timeoutMs: 30_000,
|
||||
runner: createLocalSandboxRunner(),
|
||||
};
|
||||
|
||||
// Track when each wrapper span's work settles (i.e. when its span ends).
|
||||
const spanRecords: Array<{ name: string; ended: boolean }> = [];
|
||||
const bridge = await startAdapterExecutionTargetProcessSessionBridge({
|
||||
runId: "run-stream-linger",
|
||||
target,
|
||||
runtimeRootDir: path.posix.join(rootDir, ".paperclip-runtime", "acpx"),
|
||||
adapterKey: "acpx",
|
||||
command: process.execPath,
|
||||
args: [childPath],
|
||||
cwd: rootDir,
|
||||
env: {},
|
||||
timeoutSec: 10,
|
||||
onLog: async () => {},
|
||||
streamOutputViaSession: true,
|
||||
runtimeSpan: (name, work) => {
|
||||
const record = { name, ended: false };
|
||||
spanRecords.push(record);
|
||||
const promise = work();
|
||||
void promise.then(
|
||||
() => {
|
||||
record.ended = true;
|
||||
},
|
||||
() => {
|
||||
record.ended = true;
|
||||
},
|
||||
);
|
||||
return promise;
|
||||
},
|
||||
});
|
||||
expect(bridge).not.toBeNull();
|
||||
|
||||
const record = spanRecords.find((span) => span.name === "sandbox.agentProcess");
|
||||
expect(record).toBeDefined();
|
||||
// The launch command is still running, so the span is still open.
|
||||
expect(record!.ended).toBe(false);
|
||||
|
||||
// Teardown ends the span promptly, without waiting for the lingering command.
|
||||
await bridge!.stop();
|
||||
await new Promise((resolve) => setTimeout(resolve, 50));
|
||||
expect(record!.ended).toBe(true);
|
||||
});
|
||||
|
||||
it("buffers streamed output until the local proxy connects", async () => {
|
||||
const rootDir = await mkdtemp(path.join(os.tmpdir(), "paperclip-process-session-stream-buffer-"));
|
||||
cleanupDirs.push(rootDir);
|
||||
|
|
|
|||
|
|
@ -1514,6 +1514,13 @@ export async function startAdapterExecutionTargetProcessSessionBridge(input: {
|
|||
|
||||
let socket: net.Socket | null = null;
|
||||
let stopping = false;
|
||||
// Resolves when `stop()` tears the bridge down. The streamed `sandbox.agentProcess`
|
||||
// span races its work against this, so the span ends at teardown at the latest
|
||||
// even when the remote process lingers, and never outlives the run root span.
|
||||
let signalStopped: () => void = () => {};
|
||||
const stopped = new Promise<void>((resolve) => {
|
||||
signalStopped = resolve;
|
||||
});
|
||||
let stdinSeq = 0;
|
||||
let pollTimer: NodeJS.Timeout | null = null;
|
||||
const pendingRemoteEvents: Array<{
|
||||
|
|
@ -1742,39 +1749,63 @@ export async function startAdapterExecutionTargetProcessSessionBridge(input: {
|
|||
// persistent session so the provider streams the wrapper stdout back through
|
||||
// `onLog`. On resolve, the terminal re-parse fills any frames the live stream
|
||||
// missed; on reject, deliver one error frame so the local proxy fails loud.
|
||||
void runner
|
||||
.execute({
|
||||
command: shellCommand,
|
||||
args: shellCommandArgs(`node ${shellQuote(remoteScriptPath)}`),
|
||||
cwd: target.remoteCwd,
|
||||
env: {
|
||||
PAPERCLIP_PROCESS_SESSION_DIR: sessionDir,
|
||||
PAPERCLIP_PROCESS_SESSION_COMMAND_B64: streamCommandPayload,
|
||||
PAPERCLIP_SANDBOX_EXEC_CHANNEL: "bridge",
|
||||
},
|
||||
timeoutMs,
|
||||
useSession: true,
|
||||
onLog: async (stream, chunk) => {
|
||||
if (stream === "stdout") ingestStreamChunk(chunk);
|
||||
},
|
||||
})
|
||||
.then((result) => {
|
||||
ingestFinalText(result.stdout);
|
||||
if (!sawTerminal && !stopping) {
|
||||
deliverRemoteEvent({
|
||||
type: "exit",
|
||||
code: typeof result.exitCode === "number" ? result.exitCode : null,
|
||||
//
|
||||
// Wrap the launch in a `sandbox.agentProcess` span. `runRuntimeWork` parents
|
||||
// it to the LIVE RUN root (`task.run` at launch time — no turn has started
|
||||
// yet), not to the ephemeral `bridge.process-session` bring-up step, and it
|
||||
// stays open for the whole process lifetime. The inner `sandbox.exec` nests
|
||||
// under it. Without the wrapper the raw exec's span inherits the ~2.28s
|
||||
// bring-up step as its parent and then dangles ~50s past it, overlapping
|
||||
// `agent.turn` — a child outliving its parent. As a run-scoped span it reads
|
||||
// instead as a resource that OVERLAPS the sibling `agent.turn`, which is the
|
||||
// correct shape (the persistent process hosts the turn; it is not a child of
|
||||
// it, and on multi-turn runs one process spans several turns). `runRuntimeWork`
|
||||
// is voided, not awaited, so bring-up never blocks on the long-lived command,
|
||||
// and it defaults to a no-op parent when no span runner is injected.
|
||||
//
|
||||
// The span is bounded to the bridge lifecycle: it ends when the command
|
||||
// settles OR when `stop()` runs, whichever comes first. `stop()` runs during
|
||||
// run teardown, before the caller ends the `task.run` root span, so the span
|
||||
// never outlives the run root even if the remote process lingers past
|
||||
// teardown (`execute` has no cancel, so a lingering process cannot be forced
|
||||
// to resolve). The command promise keeps running after the span ends so its
|
||||
// frame handlers still deliver; they no-op once `stopping` is set.
|
||||
void runRuntimeWork("sandbox.agentProcess", async () => {
|
||||
const commandSettled = (async () => {
|
||||
try {
|
||||
const result = await runner.execute({
|
||||
command: shellCommand,
|
||||
args: shellCommandArgs(`node ${shellQuote(remoteScriptPath)}`),
|
||||
cwd: target.remoteCwd,
|
||||
env: {
|
||||
PAPERCLIP_PROCESS_SESSION_DIR: sessionDir,
|
||||
PAPERCLIP_PROCESS_SESSION_COMMAND_B64: streamCommandPayload,
|
||||
PAPERCLIP_SANDBOX_EXEC_CHANNEL: "bridge",
|
||||
},
|
||||
timeoutMs,
|
||||
useSession: true,
|
||||
onLog: async (stream, chunk) => {
|
||||
if (stream === "stdout") ingestStreamChunk(chunk);
|
||||
},
|
||||
});
|
||||
ingestFinalText(result.stdout);
|
||||
if (!sawTerminal && !stopping) {
|
||||
deliverRemoteEvent({
|
||||
type: "exit",
|
||||
code: typeof result.exitCode === "number" ? result.exitCode : null,
|
||||
});
|
||||
}
|
||||
} catch (error) {
|
||||
if (!stopping) {
|
||||
deliverRemoteEvent({
|
||||
type: "error",
|
||||
message: error instanceof Error ? error.message : String(error),
|
||||
});
|
||||
}
|
||||
}
|
||||
})
|
||||
.catch((error) => {
|
||||
if (!stopping) {
|
||||
deliverRemoteEvent({
|
||||
type: "error",
|
||||
message: error instanceof Error ? error.message : String(error),
|
||||
});
|
||||
}
|
||||
});
|
||||
})();
|
||||
await Promise.race([commandSettled, stopped]);
|
||||
});
|
||||
} else {
|
||||
schedulePoll();
|
||||
}
|
||||
|
|
@ -1783,6 +1814,9 @@ export async function startAdapterExecutionTargetProcessSessionBridge(input: {
|
|||
agentCommand,
|
||||
stop: async () => {
|
||||
stopping = true;
|
||||
// End the `sandbox.agentProcess` span now, before the caller ends the run
|
||||
// root span, even if the remote command has not resolved yet.
|
||||
signalStopped();
|
||||
if (pollTimer) clearTimeout(pollTimer);
|
||||
for (const liveSocket of liveSockets) liveSocket.destroy();
|
||||
await new Promise<void>((resolve) => server.close(() => resolve())).catch(() => undefined);
|
||||
|
|
|
|||
|
|
@ -2029,8 +2029,9 @@ describe("sandbox managed runtime", () => {
|
|||
await writeFile(path.join(localWorkspaceDir, "README.md"), "workspace body\n", "utf8");
|
||||
|
||||
// Record every span name the runner opens and run the wrapped work, so the
|
||||
// test proves the host opens exactly one `pack` span around the tarball
|
||||
// build for the usual (plain) workspace sync.
|
||||
// test proves the host opens a span around each host-side staging sub-step
|
||||
// for the usual (plain) workspace sync: the git enumeration, the baseline
|
||||
// content-hash walk, and the tarball build, in that order.
|
||||
const openedSpans: string[] = [];
|
||||
const runtimeSpan: RuntimeSpanRunner = async (name, work) => {
|
||||
openedSpans.push(name);
|
||||
|
|
@ -2052,7 +2053,7 @@ describe("sandbox managed runtime", () => {
|
|||
runtimeSpan,
|
||||
});
|
||||
|
||||
expect(openedSpans).toEqual(["pack"]);
|
||||
expect(openedSpans).toEqual(["snapshot.git", "snapshot.baseline", "pack"]);
|
||||
// The tarball build still lands the workspace inside the span, so the wrap
|
||||
// changes no staging behavior.
|
||||
await expect(readFile(path.join(remoteWorkspaceDir, "README.md"), "utf8")).resolves.toBe("workspace body\n");
|
||||
|
|
@ -2120,5 +2121,14 @@ describe("sandbox managed runtime", () => {
|
|||
// The `pack` span parents to `stage.sync`, not to the root span, so it nests
|
||||
// under the step in a real trace.
|
||||
expect(packSpan!.parentName).toBe("stage.sync");
|
||||
|
||||
// The two pre-`pack` staging sub-steps nest under `stage.sync` the same way,
|
||||
// so the previously hidden gap at the head of the step is now attributed.
|
||||
for (const name of ["snapshot.git", "snapshot.baseline"]) {
|
||||
const span = spans.find((candidate) => candidate.name === name);
|
||||
expect(span, name).toBeDefined();
|
||||
expect(span!.ended).toBe(true);
|
||||
expect(span!.parentName).toBe("stage.sync");
|
||||
}
|
||||
});
|
||||
});
|
||||
|
|
|
|||
|
|
@ -714,7 +714,23 @@ export async function prepareSandboxManagedRuntime(input: {
|
|||
const workspaceRemoteDir = input.workspaceRemoteDir ?? input.spec.remoteCwd;
|
||||
const runtimeRootDir = path.posix.join(workspaceRemoteDir, ".paperclip-runtime", input.adapterKey);
|
||||
const syncWorkspace = input.syncWorkspace !== false;
|
||||
const gitSnapshot = syncWorkspace ? await readGitWorkspaceSnapshot(input.workspaceLocalDir) : null;
|
||||
|
||||
// Wrap a host-side staging sub-step in its own span when the caller injects a
|
||||
// runtime span runner. Mirrors the `pack` span below: the runner defaults to a
|
||||
// no-op, so a caller with no injected runner keeps the current control flow,
|
||||
// and a throwing runner never changes it (see `createRuntimeSpanRunner`). Each
|
||||
// span parents under the `stage.sync` step, so the two pre-`pack` operations —
|
||||
// the git enumeration and the baseline content-hash walk — stop showing up as
|
||||
// a hidden gap at the head of the step.
|
||||
const runStepSpan = <T>(name: string, work: () => Promise<T>): Promise<T> =>
|
||||
input.runtimeSpan ? input.runtimeSpan(name, work) : work();
|
||||
|
||||
// The git enumeration (`git status --ignored`, the HEAD diffs, `ls-files`).
|
||||
// It reads git's own bookkeeping to decide what to include/exclude, so it is
|
||||
// usually fast, but on a large working tree the `--ignored` walk is not free.
|
||||
const gitSnapshot = syncWorkspace
|
||||
? await runStepSpan("snapshot.git", () => readGitWorkspaceSnapshot(input.workspaceLocalDir))
|
||||
: null;
|
||||
const gitIgnoredExcludes = gitSnapshot?.ignoredPaths;
|
||||
const workspaceArchiveExclude = mergeExcludes(
|
||||
SANDBOX_WORKSPACE_HEAVY_DIR_EXCLUDES,
|
||||
|
|
@ -730,8 +746,14 @@ export async function prepareSandboxManagedRuntime(input: {
|
|||
input.workspaceExclude,
|
||||
gitIgnoredExcludes,
|
||||
);
|
||||
// The baseline "before" snapshot: a recursive walk of the whole workspace that
|
||||
// `lstat`s every entry and SHA-256-hashes every file's bytes. This is the
|
||||
// dominant cost in the pre-`pack` window — it reads the content of every
|
||||
// non-excluded file, serially — so it earns its own span.
|
||||
const baselineSnapshot = syncWorkspace
|
||||
? await captureDirectorySnapshot(input.workspaceLocalDir, { exclude: restoreExclude })
|
||||
? await runStepSpan("snapshot.baseline", () =>
|
||||
captureDirectorySnapshot(input.workspaceLocalDir, { exclude: restoreExclude }),
|
||||
)
|
||||
: null;
|
||||
|
||||
// Every inbound staging step delegates to the provider through `client.syncIn`:
|
||||
|
|
@ -849,9 +871,7 @@ export async function prepareSandboxManagedRuntime(input: {
|
|||
// span, so `pack` measures only the host tar-build cost. The runner
|
||||
// defaults to a no-op, so a caller with no injected runner keeps the
|
||||
// current behavior and control flow.
|
||||
const runPackSpan = <T>(work: () => Promise<T>): Promise<T> =>
|
||||
input.runtimeSpan ? input.runtimeSpan("pack", work) : work();
|
||||
await runPackSpan(async () => {
|
||||
await runStepSpan("pack", async () => {
|
||||
// 1. git-history tar (git-backed workspace only). Both tar targets live under
|
||||
// `runtimeRootDir` (`.paperclip-runtime/<adapterKey>`). The git extract
|
||||
// wipes the target tree EXCEPT `.paperclip-runtime`, so the overlay tar,
|
||||
|
|
|
|||
|
|
@ -90,21 +90,39 @@ absent, never a misleading `0`.
|
|||
| `codex-home.seed` | Managed-home seed step. | `sandbox.startup` |
|
||||
| `skills.reconcile` | Skills reconcile step. | `sandbox.startup` |
|
||||
| `stage.sync` | Workspace stage-sync step. | `sandbox.startup` |
|
||||
| `snapshot.git` | Host-side git workspace enumeration inside `stage.sync` (`git status --ignored`, the HEAD diffs, `ls-files`). | `stage.sync` |
|
||||
| `snapshot.baseline` | Host-side baseline workspace content-hash walk inside `stage.sync`, kept for restore. | `stage.sync` |
|
||||
| `pack` | Host-side workspace tarball build inside `stage.sync`. | `stage.sync` |
|
||||
| `bridge.paperclip` | Paperclip bridge start step. | `sandbox.startup` |
|
||||
| `bridge.process-session` | Process-session bridge start step. | `sandbox.startup` |
|
||||
| `acp.handshake` | ACP session handshake step. | `sandbox.startup` |
|
||||
| `sandbox.agentSession.sendInput` | One outbound ACP message to the agent — the socket handler's one `writeTextFile` exec. | the active run span |
|
||||
| `sandbox.agentSession.pollOutput` | One 100 ms poll tick — `list`, then `read`+`remove` per file found (`1 + 2n` execs). | the active run span |
|
||||
| `sandbox.callbackBridge.relayRequest` | One Paperclip-API callback request — read the request, write the response, remove it. | the active run span |
|
||||
| `sandbox.agentProcess` | The persistent streamed agent process the process-session bridge launches; open until the process settles or the bridge tears down, whichever comes first. | the active run span |
|
||||
| `sandbox.exec` | One host-to-sandbox execution. | the active step or wrapper span |
|
||||
|
||||
A step span name is the step name. The `sandbox.exec` span parents to the step
|
||||
span that runs the execution, so each execution nests under its step. A run-time
|
||||
span that runs the execution, so each execution nests under its step. Within
|
||||
`stage.sync`, the host-side sub-steps `snapshot.git`, `snapshot.baseline`, and
|
||||
`pack` open as child spans of the step, so the host work at the head of the step
|
||||
is attributed rather than showing as a gap. A run-time
|
||||
`sandbox.exec` span parents instead to the run-time wrapper span that runs it
|
||||
(`sandbox.agentSession.sendInput`, `sandbox.agentSession.pollOutput`, or
|
||||
`sandbox.callbackBridge.relayRequest`). Each run-time wrapper span parents to the
|
||||
live run span (`agent.turn` during the turn, `task.run` otherwise). With no
|
||||
active trace context the exec span opens unparented.
|
||||
(`sandbox.agentSession.sendInput`, `sandbox.agentSession.pollOutput`,
|
||||
`sandbox.callbackBridge.relayRequest`, or `sandbox.agentProcess`). Each run-time
|
||||
wrapper span parents to the live run span (`agent.turn` during the turn,
|
||||
`task.run` otherwise). With no active trace context the exec span opens
|
||||
unparented.
|
||||
|
||||
`sandbox.agentProcess` wraps the persistent streamed agent process. The
|
||||
process-session bridge launches it during `bridge.process-session`, so it opens
|
||||
under `task.run` — no turn has started yet. It therefore overlaps the sibling
|
||||
`agent.turn` rather than nesting under it or dangling off the short-lived bring-up
|
||||
step. The span ends when the process settles or when the bridge tears down,
|
||||
whichever comes first. The bridge tears down before the run root span ends, so
|
||||
the span never outlives `task.run` even when the process lingers past teardown
|
||||
(the sandbox `execute` has no cancel, so a lingering process cannot be forced to
|
||||
resolve).
|
||||
|
||||
The root span sets the error status when the bring-up fails. Each step span sets
|
||||
the error status when its step fails. The `sandbox.exec` span sets the error
|
||||
|
|
|
|||
Loading…
Reference in New Issue