diff --git a/packages/adapter-utils/src/acpx-engine/startup-timing.ts b/packages/adapter-utils/src/acpx-engine/startup-timing.ts index ada1877fee..4bd2fbbc7f 100644 --- a/packages/adapter-utils/src/acpx-engine/startup-timing.ts +++ b/packages/adapter-utils/src/acpx-engine/startup-timing.ts @@ -86,6 +86,8 @@ export const SANDBOX_STARTUP_SPAN_ATTRS = { execNetworkMs: `${SANDBOX_STARTUP_SPAN_ATTR_PREFIX}exec.network_ms`, /** Whether one execution sits on the startup critical path. */ execCriticalPath: `${SANDBOX_STARTUP_SPAN_ATTR_PREFIX}exec.critical_path`, + /** Whether the provider served the sandbox handle from its warm cache. */ + execCacheHit: `${SANDBOX_STARTUP_SPAN_ATTR_PREFIX}exec.cache_hit`, /** The root-span wall time of the whole bring-up. */ rootWallMs: `${SANDBOX_STARTUP_SPAN_ATTR_PREFIX}root.wall_ms`, /** The sum of the step wall times of the whole bring-up. */ @@ -108,6 +110,12 @@ export const SANDBOX_STARTUP_SPAN_ATTRS = { handshakeEnsureSessionWallMs: `${SANDBOX_STARTUP_SPAN_ATTR_PREFIX}handshake.ensure_session.wall_ms`, /** A shared low-cardinality tag that marks two steps as one parallel batch. */ batch: `${SANDBOX_STARTUP_SPAN_ATTR_PREFIX}batch`, + /** The host-local wall time of the pack step (build the tarball). */ + packWallMs: `${SANDBOX_STARTUP_SPAN_ATTR_PREFIX}pack.wall_ms`, + /** The wall time of the transfer step (upload the files to the sandbox). */ + transferWallMs: `${SANDBOX_STARTUP_SPAN_ATTR_PREFIX}transfer.wall_ms`, + /** The number of serial guard round trips before one transfer. */ + transferGuardCount: `${SANDBOX_STARTUP_SPAN_ATTR_PREFIX}transfer.guard.count`, } as const; /** The closed value set for the `outcome` attribute. */ diff --git a/packages/plugins/sandbox-providers/daytona/src/file-sync.ts b/packages/plugins/sandbox-providers/daytona/src/file-sync.ts index e8f5c5bb0a..b1e1bcbfe7 100644 --- a/packages/plugins/sandbox-providers/daytona/src/file-sync.ts +++ b/packages/plugins/sandbox-providers/daytona/src/file-sync.ts @@ -11,9 +11,53 @@ import type { PluginSyncFileMapping, PluginSyncOperation, } from "@paperclipai/plugin-sdk"; +import { getPluginTracer } from "./plugin.js"; const execFileAsync = promisify(execFile); +// The span-attribute names. They mirror the host span-attribute contract by +// value. The plugin ships bundled, so it stays free of the host packages and +// repeats these strings; the host re-clamps a provider span by these exact keys. +const SPAN_ATTR_PREFIX = "paperclip.sandbox.startup."; +const SPAN_ATTR = { + provider: `${SPAN_ATTR_PREFIX}provider`, + packWallMs: `${SPAN_ATTR_PREFIX}pack.wall_ms`, + transferWallMs: `${SPAN_ATTR_PREFIX}transfer.wall_ms`, + transferGuardCount: `${SPAN_ATTR_PREFIX}transfer.guard.count`, +} as const; + +/** The value of `SpanStatusCode.ERROR` in `@opentelemetry/api`. The plugin stays + * OpenTelemetry-free, so it uses the numeric value directly. */ +const SPAN_STATUS_CODE_ERROR = 2; + +/** + * Run one span-wrapped step through the plugin tracer. The pack step and the + * transfer step share this helper. It seeds the provider family, runs the step, + * sets the wall time, marks a thrown step failed, and always ends the span. The + * tracer is a no-op until the host injects a live tracer, so the span never + * changes the sync control flow. + */ +async function withProviderSpan(input: { + name: string; + wallMsAttr: string; + attributes?: Record; + run: () => Promise; +}): Promise { + const span = getPluginTracer().startSpan(input.name, { + attributes: { [SPAN_ATTR.provider]: "daytona", ...(input.attributes ?? {}) }, + }); + const startedAtMs = Date.now(); + try { + return await input.run(); + } catch (error) { + span.setStatus({ code: SPAN_STATUS_CODE_ERROR }); + throw error; + } finally { + span.setAttribute(input.wallMsAttr, Date.now() - startedAtMs); + span.end(); + } +} + /** Convert a millisecond timeout to the whole-seconds value the Daytona SDK expects. */ function toTimeoutSeconds(timeoutMs: number): number { return Math.max(1, Math.ceil(timeoutMs / 1000)); @@ -404,9 +448,14 @@ async function syncInFileMappings(input: { bytesTransferred += (await fs.stat(mapping.sourcePath)).size; } + // Count the serial guard round trips before the transfer, so the transfer span + // records how much of the wall time is guard cost. + let guardRoundTrips = 0; + // Ensure every target directory exists before the bulk upload writes its temp. const mkdirCommand = [...parentDirs].map((dir) => `mkdir -p ${shellQuote(dir)}`).join(" && "); await assertSandboxCommandOk(sandbox, mkdirCommand, timeoutSeconds, "syncIn mkdir"); + guardRoundTrips += 1; // Defense-in-depth beyond the lexical `assertConfinedSandboxPath`: a sandbox // can replace a target parent with a symlink to `/etc` so the string check @@ -419,13 +468,19 @@ async function syncInFileMappings(input: { timeoutSeconds, label: "inbound symlink-escape guard", }); + guardRoundTrips += 1; // A failed upload or a mid-batch `mv -f` failure leaves reserved temps (some // targets promoted, others not) — sweep every staged temp on any error so a // retry never accumulates stale `.paperclip-upload-*` scratch. try { // One batched bulk upload (single /files/bulk-upload) for all file mappings. - await sandbox.fs.uploadFiles(uploads, timeoutSeconds); + await withProviderSpan({ + name: "transfer", + wallMsAttr: SPAN_ATTR.transferWallMs, + attributes: { [SPAN_ATTR.transferGuardCount]: guardRoundTrips }, + run: () => sandbox.fs.uploadFiles(uploads, timeoutSeconds), + }); // Apply the requested mode on the temp file BEFORE the rename so the target // never appears at a widened window — a secret lands `0600` at targetPath from @@ -490,16 +545,25 @@ async function syncInDirectoryMapping(input: { assertConfinedSandboxPath(remoteDir, mapping.targetPath, "target"); return withHostTempDir(async (tmp) => { const archivePath = path.join(tmp, "sync-in.tar"); - await createHostTarball({ - localDir: mapping.sourcePath, - archivePath, - exclude: mapping.exclude, - followSymlinks: mapping.followSymlinks, + // The pack step is host-local: it builds the tarball and makes no sandbox + // round trip. The `pack` span records its wall time. + await withProviderSpan({ + name: "pack", + wallMsAttr: SPAN_ATTR.packWallMs, + run: () => createHostTarball({ + localDir: mapping.sourcePath, + archivePath, + exclude: mapping.exclude, + followSymlinks: mapping.followSymlinks, + }), }); const bytesTransferred = (await fs.stat(archivePath)).size; // The tar bytes ride the native bulk channel (string source ⇒ streamed); // only the extract/cleanup control commands use exec. const remoteTar = path.posix.join(remoteDir, scratchName(".tar")); + // Count the serial guard round trips before the transfer, so the transfer + // span records how much of the wall time is guard cost. + let guardRoundTrips = 0; // Materialize the target dir first so the realpath guard resolves real // components, then confirm it (and any existing parent) canonicalizes inside // the remote dir — `tar -C` would otherwise follow a sandbox-planted symlink @@ -510,6 +574,7 @@ async function syncInDirectoryMapping(input: { timeoutSeconds, "syncIn mkdir", ); + guardRoundTrips += 1; await assertSandboxPathsConfined({ sandbox, remoteDir, @@ -517,7 +582,14 @@ async function syncInDirectoryMapping(input: { timeoutSeconds, label: "inbound symlink-escape guard", }); - await sandbox.fs.uploadFiles([{ source: archivePath, destination: remoteTar }], timeoutSeconds); + guardRoundTrips += 1; + await withProviderSpan({ + name: "transfer", + wallMsAttr: SPAN_ATTR.transferWallMs, + attributes: { [SPAN_ATTR.transferGuardCount]: guardRoundTrips }, + run: () => + sandbox.fs.uploadFiles([{ source: archivePath, destination: remoteTar }], timeoutSeconds), + }); // Bind validation and extraction into ONE sandbox invocation, then extract into // an OPEN directory inode rather than a path string. `exec 9<"$_pc_real"` itself // walks every ancestor of `$_pc_real` during the `open()` syscall, so a sandbox diff --git a/packages/plugins/sandbox-providers/daytona/src/plugin.test.ts b/packages/plugins/sandbox-providers/daytona/src/plugin.test.ts index 7f21b11b85..5cbc090ce2 100644 --- a/packages/plugins/sandbox-providers/daytona/src/plugin.test.ts +++ b/packages/plugins/sandbox-providers/daytona/src/plugin.test.ts @@ -33,8 +33,10 @@ import plugin, { setDaytonaHandleFreshnessClockForTest, __resetDaytonaSandboxHandleCacheForTest, __getDaytonaWritableDirsForTest, + __setDaytonaPluginContextForTest, buildBwrapCommand, } from "./plugin.js"; +import type { PluginContext } from "@paperclipai/plugin-sdk"; import manifest from "./manifest.js"; function createMockSandbox(overrides: { @@ -1157,6 +1159,41 @@ describe("Daytona sandbox provider plugin", () => { } }); + it("sets metadata.cacheHit false on a client.get miss and true on a warm-handle hit", async () => { + process.env.DAYTONA_API_KEY = "host-key"; + const sandbox = createMockSandbox(); + sandbox.process.executeCommand.mockResolvedValue({ + exitCode: 0, + result: "ok", + artifacts: { stdout: "ok" }, + }); + mockGet.mockResolvedValue(sandbox); + + const execParams = { + driverKey: "daytona" as const, + companyId: "company-1", + environmentId: "env-1", + config: { timeoutMs: 300000, reuseLease: false }, + lease: { providerLeaseId: "sandbox-123", metadata: {} }, + command: "printf", + args: ["hello"], + cwd: "/workspace", + timeoutMs: 1000, + }; + + // First execute: the handle cache is empty, so the lookup calls `client.get` + // and reports a miss. + const first = await plugin.definition.onEnvironmentExecute?.(execParams); + expect(first!.metadata).toMatchObject({ cacheHit: false }); + expect(mockGet).toHaveBeenCalledTimes(1); + + // Second execute: the warm handle cache serves the handle, so the lookup + // makes no `client.get` round trip and reports a hit. + const second = await plugin.definition.onEnvironmentExecute?.(execParams); + expect(second!.metadata).toMatchObject({ cacheHit: true }); + expect(mockGet).toHaveBeenCalledTimes(1); + }); + it("stages stdin in the sandbox filesystem when execution needs redirected input", async () => { process.env.DAYTONA_API_KEY = "host-key"; const sandbox = createMockSandbox(); @@ -2632,6 +2669,117 @@ describe("daytona native file-sync hooks", () => { }); }); + // A recording tracer that captures every provider span the file sync opens. + // It satisfies the structural plugin tracer contract. + function createRecordingPluginTracer() { + const spans: Array<{ + name: string; + attributes: Record; + status: { code: number; message?: string } | null; + ended: boolean; + }> = []; + const tracer = { + startSpan(name: string, options?: { attributes?: Record }) { + const span = { + name, + attributes: { ...(options?.attributes ?? {}) } as Record, + status: null as { code: number; message?: string } | null, + ended: false, + setAttribute(key: string, value: unknown) { + span.attributes[key] = value; + }, + setStatus(status: { code: number; message?: string }) { + span.status = status; + }, + end() { + span.ended = true; + }, + }; + spans.push(span); + return span; + }, + }; + return { tracer, spans }; + } + + it("opens a transfer span with the guard round-trip count around the bulk file upload", async () => { + const hostDir = await makeHostDir(); + const source = path.join(hostDir, "config.txt"); + await fs.writeFile(source, "plain"); + const sandbox = createMockSandbox(); + mockGet.mockResolvedValue(sandbox); + + const { tracer, spans } = createRecordingPluginTracer(); + const restore = __setDaytonaPluginContextForTest({ tracer } as unknown as PluginContext); + try { + await plugin.definition.onEnvironmentSyncIn?.({ + driverKey: "daytona", + companyId: "company-1", + environmentId: "env-1", + config: { timeoutMs: 300000, reuseLease: false }, + lease: syncLease(), + operations: [ + { + operationId: "sync-op-1", + files: [{ sourcePath: source, targetPath: `${REMOTE_DIR}/config.txt`, kind: "file" }], + }, + ], + }); + } finally { + restore(); + } + + const transfer = spans.find((span) => span.name === "transfer"); + expect(transfer).toBeDefined(); + expect(transfer!.ended).toBe(true); + // The two serial guard round trips before the transfer: mkdir + confinement. + expect(transfer!.attributes["paperclip.sandbox.startup.transfer.guard.count"]).toBe(2); + expect(transfer!.attributes["paperclip.sandbox.startup.provider"]).toBe("daytona"); + expect(typeof transfer!.attributes["paperclip.sandbox.startup.transfer.wall_ms"]).toBe("number"); + // A bulk file upload builds no host tarball, so it opens no pack span. + expect(spans.find((span) => span.name === "pack")).toBeUndefined(); + }); + + it("opens a pack span and a transfer span around a directory mapping sync", async () => { + const hostDir = await makeHostDir(); + const sourceDir = path.join(hostDir, "assets"); + await fs.mkdir(sourceDir, { recursive: true }); + await fs.writeFile(path.join(sourceDir, "a.txt"), "alpha"); + const sandbox = createMockSandbox(); + mockGet.mockResolvedValue(sandbox); + + const { tracer, spans } = createRecordingPluginTracer(); + const restore = __setDaytonaPluginContextForTest({ tracer } as unknown as PluginContext); + try { + await plugin.definition.onEnvironmentSyncIn?.({ + driverKey: "daytona", + companyId: "company-1", + environmentId: "env-1", + config: { timeoutMs: 300000, reuseLease: false }, + lease: syncLease(), + operations: [ + { + operationId: "sync-op-dir", + files: [ + { sourcePath: sourceDir, targetPath: `${REMOTE_DIR}/.paperclip-runtime/assets`, kind: "directory" }, + ], + }, + ], + }); + } finally { + restore(); + } + + const pack = spans.find((span) => span.name === "pack"); + expect(pack).toBeDefined(); + expect(pack!.ended).toBe(true); + expect(typeof pack!.attributes["paperclip.sandbox.startup.pack.wall_ms"]).toBe("number"); + + const transfer = spans.find((span) => span.name === "transfer"); + expect(transfer).toBeDefined(); + expect(transfer!.attributes["paperclip.sandbox.startup.transfer.guard.count"]).toBe(2); + }); + it("syncIn tars a directory mapping host-side honoring excludes and the followSymlinks flag, then extracts it in-sandbox via a single quoted tar command", async () => { const hostDir = await makeHostDir(); const sourceDir = path.join(hostDir, "assets"); diff --git a/packages/plugins/sandbox-providers/daytona/src/plugin.ts b/packages/plugins/sandbox-providers/daytona/src/plugin.ts index d12dfff0fa..cb2778c74b 100644 --- a/packages/plugins/sandbox-providers/daytona/src/plugin.ts +++ b/packages/plugins/sandbox-providers/daytona/src/plugin.ts @@ -9,8 +9,10 @@ import type { Resources, Sandbox, } from "@daytonaio/sdk"; -import { definePlugin } from "@paperclipai/plugin-sdk"; +import { definePlugin, NOOP_PLUGIN_TRACER } from "@paperclipai/plugin-sdk"; import type { + PluginContext, + PluginTracer, PluginEnvironmentAcquireLeaseParams, PluginEnvironmentCancelInteractiveSetupParams, PluginEnvironmentCancelInteractiveSetupResult, @@ -46,6 +48,33 @@ import { performSyncIn, performSyncOut } from "./file-sync.js"; // are deterministic. The timing path never calls `Date.now()` directly. let timingNow: () => number = () => Date.now(); +// The plugin context, hoisted to a module variable in `setup(ctx)`. The +// lifecycle hooks and the file-sync helpers have no closure over `ctx`, so they +// read the tracer through `getPluginTracer()`. Before `setup` runs (or in a +// test) the tracer is a no-op, so a span never throws. +let pluginContext: PluginContext | null = null; + +/** + * Return the plugin tracer. It is the injected `ctx.tracer` after `setup`, or a + * no-op before it. A provider span opened through it records only when tracing + * is on and an active host trace context is present. + */ +export function getPluginTracer(): PluginTracer { + return pluginContext?.tracer ?? NOOP_PLUGIN_TRACER; +} + +/** + * Test seam: set the module-level plugin context, and return a restore function. + * `plugin.test.ts` uses it to inject a recording tracer without running `setup`. + */ +export function __setDaytonaPluginContextForTest(ctx: PluginContext | null): () => void { + const previous = pluginContext; + pluginContext = ctx; + return () => { + pluginContext = previous; + }; +} + /** * Test seam: override the provider-timing clock and return a restore function. * Not used in production, where the default wall clock always applies. @@ -998,6 +1027,11 @@ type SandboxHandleCacheEntry = { type SandboxLookupOptions = { bypassTeardownGate?: boolean; + // Report the cache decision at the handle lookup. `true` means the warm + // handle cache served the handle; `false` means the lookup called + // `client.get`. The caller uses this to set the explicit exec `cache_hit` + // flag, instead of the old `providerGetMs == 0` proxy. + onCacheDecision?: (cacheHit: boolean) => void; }; type SandboxHandleTeardownGate = { @@ -1182,6 +1216,9 @@ const sandboxHandleCache = (() => { const entry = entries.get(key); if (entry) { + // The warm handle cache holds an entry, so this lookup serves the handle + // without a `client.get` round trip. Report the cache decision now. + options.onCacheDecision?.(true); const sandbox = await entry.sandbox; // Re-assert on every hit; evict + fail closed on any mismatch (C2). try { @@ -1205,6 +1242,9 @@ const sandboxHandleCache = (() => { } return sandbox; } + // The warm handle cache holds no entry, so this lookup calls `client.get`. + // Report the cache decision now, before the single-flight populate. + options.onCacheDecision?.(false); // Single-flight: the first miss stores the in-flight promise under the // composite key so concurrent misses on the same lease share one `client.get` // instead of double-fetching. The promise lives only under this key (C5). @@ -1496,6 +1536,9 @@ async function executeOneShot( const plugin = definePlugin({ async setup(ctx) { + // Hoist the context to a module variable so the lifecycle hooks and the + // file-sync helpers can read `ctx.tracer` — they have no closure over `ctx`. + pluginContext = ctx; ctx.logger.info("Daytona sandbox provider plugin ready"); }, @@ -2119,13 +2162,24 @@ const plugin = definePlugin({ // is a no-op for an already-started sandbox, so it is excluded from the get // measurement. const getStart = timingNow(); + // Decide the explicit `cache_hit` flag at the true cache decision: the + // handle lookup reports whether the warm cache served the handle or the + // lookup called `client.get`. This replaces the old `providerGetMs == 0` + // proxy. The default `false` covers the theoretical case where the lookup + // reports nothing. + let cacheHit = false; const sandbox = await getSandbox({ driverKey: params.driverKey, companyId: params.companyId, environmentId: params.environmentId, providerLeaseId, config, - }, { bypassTeardownGate: true }); + }, { + bypassTeardownGate: true, + onCacheDecision: (hit) => { + cacheHit = hit; + }, + }); const getDurationMs = timingNow() - getStart; await ensureSandboxStarted(sandbox, toTimeoutSeconds(resolveTimeoutMs(params.timeoutMs, config))); // Read the advisory bwrap flags from the lease metadata and read the @@ -2149,7 +2203,7 @@ const plugin = definePlugin({ } return { ...result, - metadata: { ...(result.metadata ?? {}), getDurationMs }, + metadata: { ...(result.metadata ?? {}), getDurationMs, cacheHit }, }; }); }, diff --git a/packages/plugins/sdk/src/host-client-factory.ts b/packages/plugins/sdk/src/host-client-factory.ts index 00f5d6efe3..f0c4db2de7 100644 --- a/packages/plugins/sdk/src/host-client-factory.ts +++ b/packages/plugins/sdk/src/host-client-factory.ts @@ -182,6 +182,14 @@ export interface HostServices { log(params: WorkerToHostMethods["log"][0]): Promise; }; + /** Provides `span.record`. The context carries the host-minted `traceparent`. */ + tracer: { + record( + params: WorkerToHostMethods["span.record"][0], + context?: WorkerHostCallContext, + ): Promise; + }; + /** Provides `companies.list`, `companies.get`. */ companies: { list(params: WorkerToHostMethods["companies.list"][0]): Promise; @@ -416,6 +424,10 @@ const METHOD_CAPABILITY_MAP: Record { + return services.tracer.record(params, context); + }), + // Companies "companies.list": gated("companies.list", async (params, context) => { const rows = await services.companies.list(params); diff --git a/packages/plugins/sdk/src/index.ts b/packages/plugins/sdk/src/index.ts index d601080095..c8f8f4d406 100644 --- a/packages/plugins/sdk/src/index.ts +++ b/packages/plugins/sdk/src/index.ts @@ -282,8 +282,13 @@ export type { PluginMetricsClient, PluginTelemetryClient, PluginLogger, + PluginTracer, + PluginSpan, } from "./types.js"; +// Tracer no-op default (a value, so it re-exports here, not in the type block). +export { NOOP_PLUGIN_TRACER, NOOP_PLUGIN_SPAN } from "./types.js"; + // Supporting types for context clients export type { ScopeKey, diff --git a/packages/plugins/sdk/src/protocol.ts b/packages/plugins/sdk/src/protocol.ts index 91d1d58f66..83e22a16b5 100644 --- a/packages/plugins/sdk/src/protocol.ts +++ b/packages/plugins/sdk/src/protocol.ts @@ -291,6 +291,14 @@ export interface PluginInvocationScope { export interface PluginInvocationContext { id: string; scope: PluginInvocationScope; + /** + * An optional W3C `traceparent` for the active host span. The host mints it + * per call from the active startup span. The worker treats it as opaque: it + * tags its provider span with it and never derives parentage from it. The host + * mints the parentage from its own invocation record, so a worker can never + * forge a parent. + */ + traceparent?: string; } /** @@ -300,6 +308,12 @@ export interface PluginInvocationContext { export interface WorkerHostCallContext { invocationScope?: PluginInvocationScope | null; invalidInvocationScope?: boolean; + /** + * The W3C `traceparent` the host minted for the echoed invocation. The host + * recovers it from its own invocation record, not from the worker, so a worker + * can never forge a span parent. The span host handler validates and uses it. + */ + traceparent?: string; } // --------------------------------------------------------------------------- @@ -1274,6 +1288,25 @@ export interface WorkerToHostMethods { result: void, ]; + // Provider span sink. The worker sends a finished provider span; the host + // re-clamps the label and the attributes at its trust boundary, mints the + // parentage from its own invocation record, and records the span through the + // real tracer. The worker never sends the parent `traceparent`; the host + // recovers it from the echoed invocation id. The RPC is capability-gated. + "span.record": [ + params: { + /** The bounded span name (for example `pack` or `transfer`). The host + * clamps it to a closed set, so a name never carries free-form data. */ + name: string; + /** The span attributes. The host drops every key that is not on the closed + * plugin-span allowlist and re-clamps each remaining value. */ + attributes?: Record; + /** The optional span status. */ + status?: { code: number; message?: string }; + }, + result: void, + ]; + // Companies (read) "companies.list": [ params: { limit?: number; offset?: number }, diff --git a/packages/plugins/sdk/src/testing.ts b/packages/plugins/sdk/src/testing.ts index e3255c8058..6fba7f9426 100644 --- a/packages/plugins/sdk/src/testing.ts +++ b/packages/plugins/sdk/src/testing.ts @@ -45,6 +45,7 @@ import type { PermissionKey, PrincipalType, } from "./types.js"; +import { NOOP_PLUGIN_TRACER } from "./types.js"; import type { PluginEnvironmentValidateConfigParams, PluginEnvironmentValidationResult, @@ -2502,6 +2503,7 @@ export function createTestHarness(options: TestHarnessOptions): TestHarness { logs.push({ level: "debug", message, meta }); }, }, + tracer: NOOP_PLUGIN_TRACER, }; const harness: TestHarness = { diff --git a/packages/plugins/sdk/src/types.ts b/packages/plugins/sdk/src/types.ts index 55e34cbddb..ed1daedbf4 100644 --- a/packages/plugins/sdk/src/types.ts +++ b/packages/plugins/sdk/src/types.ts @@ -1021,6 +1021,58 @@ export interface PluginLogger { debug(message: string, meta?: Record): void; } +// --------------------------------------------------------------------------- +// Plugin tracer +// --------------------------------------------------------------------------- + +/** + * `ctx.tracer` — a minimal, OpenTelemetry-free span contract. The plugin worker + * builds a real span through this surface; the host records it through the real + * tracer. The shape is a subset of the `@opentelemetry/api` `Span` shape, so the + * plugin SDK never imports `@opentelemetry/api`. + * + * A span with no active host trace context is a no-op: it accepts the calls and + * ends without an effect. So a lifecycle hook can always open a span, and the + * span records nothing until tracing is on. + */ +export interface PluginSpan { + /** Set one bounded attribute. The host re-clamps every attribute at its trust + * boundary, so an out-of-allowlist attribute never reaches a recorded span. */ + setAttribute(key: string, value: string | number | boolean): void; + /** Set the span status. The host maps it onto the recorded span. */ + setStatus(status: { code: number; message?: string }): void; + /** End the span. The worker sends the span data to the host once, here. */ + end(): void; +} + +/** + * `ctx.tracer` — a minimal, OpenTelemetry-free tracer contract. The plugin uses + * it the same way as `ctx.logger`. The default is a no-op that never throws, so + * a plugin span changes nothing until the host injects a live tracer and an + * active host trace context. + */ +export interface PluginTracer { + /** Start one span. `options.attributes` seeds the span attributes. */ + startSpan( + name: string, + options?: { attributes?: Record }, + ): PluginSpan; +} + +/** A shared no-op span. It satisfies the span contract and does nothing, so a + * plugin with no injected tracer changes no behavior. */ +export const NOOP_PLUGIN_SPAN: PluginSpan = { + setAttribute() {}, + setStatus() {}, + end() {}, +}; + +/** The default tracer. It opens no real span, so a lifecycle hook that wraps + * work in a span behaves exactly as before when no live tracer is injected. */ +export const NOOP_PLUGIN_TRACER: PluginTracer = { + startSpan: () => NOOP_PLUGIN_SPAN, +}; + // --------------------------------------------------------------------------- // Plugin metrics // --------------------------------------------------------------------------- @@ -2053,4 +2105,8 @@ export interface PluginContext { /** Structured logger. Output is captured and surfaced in the plugin health dashboard. */ logger: PluginLogger; + + /** Tracer for provider spans. The default is a no-op; the host records a span + * only when tracing is on and an active host trace context is present. */ + tracer: PluginTracer; } diff --git a/packages/plugins/sdk/src/worker-rpc-host.ts b/packages/plugins/sdk/src/worker-rpc-host.ts index 72dcf9238a..12739cf3d8 100644 --- a/packages/plugins/sdk/src/worker-rpc-host.ts +++ b/packages/plugins/sdk/src/worker-rpc-host.ts @@ -1392,6 +1392,46 @@ export function startWorkerRpcHost(options: WorkerRpcHostOptions): WorkerRpcHost notifyHost("log", { level: "debug", message, meta }); }, }, + + tracer: { + startSpan( + name: string, + options?: { attributes?: Record }, + ) { + // Read the active host trace context from the per-call invocation + // channel. A `traceparent` means a host span is active, so this span + // may record. No `traceparent` means tracing is off: the span is a + // no-op, so a lifecycle hook can always wrap work in a span. + const hasTraceContext = Boolean(invocationContextStorage.getStore()?.traceparent); + const attributes: Record = { + ...(options?.attributes ?? {}), + }; + let status: { code: number; message?: string } | undefined; + let ended = false; + return { + setAttribute(key: string, value: string | number | boolean): void { + attributes[key] = value; + }, + setStatus(next: { code: number; message?: string }): void { + status = next; + }, + end(): void { + if (ended) return; + ended = true; + if (!hasTraceContext) return; + // Send the finished span to the host once. The host re-clamps the + // name and the attributes, mints the parentage from its own + // invocation record, and records the span through the real tracer. + // Fire-and-forget: a span must never block or fail plugin work. + void callHost("span.record", { + name, + attributes, + ...(status ? { status } : {}), + }).catch(() => undefined); + }, + }; + }, + }, }; } diff --git a/packages/plugins/sdk/tests/worker-rpc-host.test.ts b/packages/plugins/sdk/tests/worker-rpc-host.test.ts index 8b0c709550..e34ca4de3c 100644 --- a/packages/plugins/sdk/tests/worker-rpc-host.test.ts +++ b/packages/plugins/sdk/tests/worker-rpc-host.test.ts @@ -484,3 +484,133 @@ describe("worker configChanged cross-tenant guard", () => { } }); }); + +describe("worker provider tracer", () => { + it("default plugin tracer is a no-op that starts and ends a span without throwing", async () => { + const { NOOP_PLUGIN_TRACER } = await import("../src/types.js"); + const span = NOOP_PLUGIN_TRACER.startSpan("pack", { attributes: { a: 1 } }); + expect(() => { + span.setAttribute("b", 2); + span.setStatus({ code: 1 }); + span.end(); + }).not.toThrow(); + }); + + // Drive a plugin data handler that opens a provider span, and capture the + // worker→host traffic. The host injects a `traceparent` on the invocation, so + // the worker must emit one `span.record` request that echoes the invocation id + // and carries the span name and attributes. + async function runSpanProbe(invocation: PluginInvocationContext) { + const hostToWorker = new PassThrough(); + const workerToHost = new PassThrough(); + const hostReadline = createInterface({ input: workerToHost }); + const pending = new Map void>(); + const spanRecords: Array<{ params: unknown; invocationId?: string }> = []; + let nextRequestId = 1; + + const plugin = definePlugin({ + async setup(ctx) { + ctx.data.register("probe", async () => { + const span = ctx.tracer.startSpan("pack", { + attributes: { "paperclip.sandbox.startup.pack.wall_ms": 12 }, + }); + span.setAttribute("paperclip.sandbox.startup.provider", "daytona"); + span.end(); + return { ok: true }; + }); + }, + }); + + const worker = startWorkerRpcHost({ plugin, stdin: hostToWorker, stdout: workerToHost }); + + function callWorker(method: string, params: unknown, inv?: PluginInvocationContext) { + const id = `host-${nextRequestId++}`; + const request = { + ...createRequest(method, params, id), + ...(inv ? { paperclipInvocation: inv } : {}), + }; + const result = new Promise((resolve, reject) => { + pending.set(id, (response) => { + if ("error" in response && response.error) { + reject(new Error(response.error.message)); + return; + } + resolve((response as { result?: unknown }).result); + }); + }); + hostToWorker.write(serializeMessage(request)); + return result; + } + + hostReadline.on("line", (line) => { + const message = parseMessage(line); + if (isJsonRpcResponse(message)) { + pending.get(String(message.id))?.(message); + pending.delete(String(message.id)); + return; + } + if (!isJsonRpcRequest(message)) return; + if (message.method === "span.record") { + spanRecords.push({ + params: message.params, + invocationId: (message as { paperclipInvocationId?: string }).paperclipInvocationId, + }); + hostToWorker.write(serializeMessage(createSuccessResponse(message.id, null))); + } + }); + + try { + await callWorker("initialize", { + manifest: { + id: "paperclip.tracer-test", + apiVersion: 1, + version: "1.0.0", + displayName: "Tracer test", + description: "Tracer test", + author: "Paperclip", + categories: ["automation"], + capabilities: ["environment.drivers.register"], + entrypoints: { worker: "dist/worker.js" }, + }, + config: {}, + instanceInfo: { instanceId: "test", hostVersion: "0.0.0" }, + apiVersion: 1, + }); + await callWorker("getData", { key: "probe", companyId: "company-a", params: {} }, invocation); + // Let the fire-and-forget span.record flush. + await new Promise((resolve) => setTimeout(resolve, 20)); + return spanRecords; + } finally { + worker.stop(); + hostReadline.close(); + hostToWorker.destroy(); + workerToHost.destroy(); + } + } + + it("emits one span.record with the name and attributes when a host trace context is active", async () => { + const spanRecords = await runSpanProbe({ + id: "invocation-a", + scope: { companyId: "company-a" }, + traceparent: "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01", + }); + expect(spanRecords).toHaveLength(1); + const record = spanRecords[0]!; + expect(record.invocationId).toBe("invocation-a"); + expect(record.params).toMatchObject({ + name: "pack", + attributes: { + "paperclip.sandbox.startup.pack.wall_ms": 12, + "paperclip.sandbox.startup.provider": "daytona", + }, + }); + }); + + it("emits no span.record when the invocation carries no traceparent (tracing off)", async () => { + const spanRecords = await runSpanProbe({ + id: "invocation-a", + scope: { companyId: "company-a" }, + }); + expect(spanRecords).toHaveLength(0); + }); +}); diff --git a/packages/shared/src/telemetry/README.md b/packages/shared/src/telemetry/README.md index b01540b661..b916542ae3 100644 --- a/packages/shared/src/telemetry/README.md +++ b/packages/shared/src/telemetry/README.md @@ -159,11 +159,73 @@ numeric attribute when the provider does not report the value. | `paperclip.sandbox.startup.exec.sandbox_ms` | number | yes | The in-sandbox run time of the execution. | | `paperclip.sandbox.startup.exec.network_ms` | number | yes | The transport time the host adds; `wall_ms − wait_before_ms − sandbox_ms`. | | `paperclip.sandbox.startup.exec.critical_path` | boolean | no | Whether the execution sits on the startup critical path. | +| `paperclip.sandbox.startup.exec.cache_hit` | boolean | yes | Whether the provider served the sandbox handle from its warm cache. | | `paperclip.sandbox.startup.outcome` | string | no | The execution outcome (`ok` or `failed`). | +The plugin decides the cache hit at the sandbox-handle lookup. The span no +longer infers a cache hit from `wait_before_ms == 0`. Paperclip omits the +`cache_hit` attribute when the provider does not report the value. + To add a span attribute, extend the `SANDBOX_STARTUP_SPAN_ATTRS` allowlist in the code first. Keep the attribute low-cardinality and free of user content. +### Provider spans + +A sandbox provider plugin also opens spans for its own sync steps. These spans +use the `sandbox.provider.` name prefix. They share the +`paperclip.sandbox.startup.` attribute prefix and obey the same opt-in and +no-user-content rules as the startup spans above. + +The plugin worker runs in a separate process from the host. So the host treats +every field of a worker-sent span as untrusted input. The host re-clamps the +span name and every attribute at one boundary, the `span.record` host handler, +before it records the span. + +| Span | Scope | Parent | +| --- | --- | --- | +| `sandbox.provider.pack` | The host-local pack step that builds the upload tarball. It makes no sandbox round trip. | the active startup step span | +| `sandbox.provider.transfer` | The transfer step that uploads the files to the sandbox. | the active startup step span | +| `sandbox.provider.other` | Any span name outside the known set. | the active startup step span | + +The host clamps the span name to the closed set `pack` and `transfer`. The host +maps a known name to `sandbox.provider.`. The host maps any other value to +`sandbox.provider.other`, so a span name never carries free-form data. + +The `sandbox.provider.*` spans use this closed attribute allowlist. The host +drops every other key, so a command, an argument, a path, an id, a standard +output, or a standard error never rides a provider span. The host records only +the attributes that the producer sends for one span. + +| Attribute | Type | Optional | Meaning | +| --- | --- | --- | --- | +| `paperclip.sandbox.startup.provider` | string | no | The normalized provider family. | +| `paperclip.sandbox.startup.outcome` | string | yes | The step outcome (`ok`, `skipped`, or `failed`). | +| `paperclip.sandbox.startup.pack.wall_ms` | number | yes | The host-local wall time of the pack step. It rides the `sandbox.provider.pack` span. | +| `paperclip.sandbox.startup.transfer.wall_ms` | number | yes | The wall time of the transfer step. It rides the `sandbox.provider.transfer` span. | +| `paperclip.sandbox.startup.transfer.guard.count` | number | yes | The number of serial guard round trips before one transfer. It rides the `sandbox.provider.transfer` span. | + +The `span.record` host handler enforces the allowlist. It re-maps `provider` +through the provider-family normalizer. It keeps `outcome` only when the value +is `ok`, `skipped`, or `failed`. It keeps a numeric attribute only when the +value is a finite number. It drops a status message and keeps only the numeric +status code. The handler never throws, because observability must not change the +sync control flow. + +The `span.record` host method needs the `environment.drivers.register` +capability. So only a plugin that registers an environment driver may emit a +provider span. The capability gate rejects a provider span from any other +plugin. + +The host parents each provider span to the active startup step span. The host +mints a W3C `traceparent` from the active step and passes it to the plugin +worker on the per-call invocation channel. The worker tags its span with the +`traceparent` and treats the value as opaque. The worker never derives the +parent from it. The host recovers the `traceparent` from its own invocation +record, so a worker can never forge a parent. The host validates the +`traceparent` and rejects a missing or malformed value. With no active host +trace context the worker sends no span, so the whole provider-span path is a +no-op. + ## Dimension Values Telemetry dimension values must be primitives. Use only the value types allowed diff --git a/server/src/__tests__/environment-execution-target.test.ts b/server/src/__tests__/environment-execution-target.test.ts index a07cb68759..61eb5fba5b 100644 --- a/server/src/__tests__/environment-execution-target.test.ts +++ b/server/src/__tests__/environment-execution-target.test.ts @@ -515,6 +515,7 @@ describe("resolveEnvironmentExecutionTarget", () => { A.execSandboxMs, A.execNetworkMs, A.execCriticalPath, + A.execCacheHit, A.outcome, ]); @@ -598,6 +599,50 @@ describe("resolveEnvironmentExecutionTarget", () => { expect(span.attributes[A.execWallMs] as number).toBeGreaterThanOrEqual(0); }); + it("carries the explicit exec cache_hit from result.metadata.cacheHit", async () => { + const { tracer, spans } = createRecordingExecTracer(); + const runner = await runnerFor({ + provider: "daytona", + execResult: { + exitCode: 0, + signal: null, + timedOut: false, + stdout: "ok", + stderr: "", + metadata: { durationMs: 600, getDurationMs: 0, cacheHit: true }, + }, + tracer, + }); + + await runner.execute({ command: "echo", args: ["a"] }); + + const span = spans[0]!; + // The flag comes from the metadata boolean, not from a zero handle-fetch. + expect(span.attributes[A.execCacheHit]).toBe(true); + }); + + it("omits exec cache_hit when the provider reports no cacheHit metadata", async () => { + const { tracer, spans } = createRecordingExecTracer(); + const runner = await runnerFor({ + provider: "daytona", + execResult: { + exitCode: 0, + signal: null, + timedOut: false, + stdout: "ok", + stderr: "", + metadata: { durationMs: 600, getDurationMs: 15 }, + }, + tracer, + }); + + await runner.execute({ command: "echo", args: ["a"] }); + + const span = spans[0]!; + // A provider that omits the boolean yields no attribute — never `false`. + expect(span.attributes).not.toHaveProperty(A.execCacheHit); + }); + it("omits each duration attribute when a provider returns no timing (does not throw, keeps provider)", async () => { const { tracer, spans } = createRecordingExecTracer(); const runner = await runnerFor({ diff --git a/server/src/__tests__/plugin-host-services-span.test.ts b/server/src/__tests__/plugin-host-services-span.test.ts new file mode 100644 index 0000000000..ea9e688e24 --- /dev/null +++ b/server/src/__tests__/plugin-host-services-span.test.ts @@ -0,0 +1,199 @@ +import { beforeEach, describe, expect, it, vi } from "vitest"; +import { createHostClientHandlers } from "../../../packages/plugins/sdk/src/host-client-factory.js"; +import type { WorkerHostCallContext } from "../../../packages/plugins/sdk/src/protocol.js"; +import { SANDBOX_STARTUP_SPAN_ATTRS as A } from "@paperclipai/adapter-utils/acpx-engine/startup-timing"; +import { + buildHostServices, + clampProviderSpanAttributes, + parseTraceparent, +} from "../services/plugin-host-services.js"; + +// Capture every span the host trust boundary hands to the real tracer. +const mockRecordSpan = vi.hoisted(() => vi.fn()); + +vi.mock("../instrumentation.js", () => ({ + recordProviderPluginSpan: mockRecordSpan, + traceparentFromContextToken: () => undefined, +})); + +function createEventBusStub() { + return { + forPlugin() { + return { emit: vi.fn(), subscribe: vi.fn() }; + }, + } as never; +} + +// A well-formed W3C traceparent (the host mints it; the handler validates it). +const VALID_TRACEPARENT = "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01"; + +function servicesFor() { + return buildHostServices({} as never, "plugin-record-id", "daytona", createEventBusStub()); +} + +function handlersFor(capabilities: readonly string[]) { + return createHostClientHandlers({ + pluginId: "daytona", + capabilities: capabilities as never, + services: servicesFor(), + }); +} + +describe("plugin provider span host handler", () => { + beforeEach(() => { + mockRecordSpan.mockReset(); + }); + + it("records a span with the clamped name and the allowlisted attributes", async () => { + const services = servicesFor(); + await services.tracer.record( + { + name: "pack", + attributes: { + [A.provider]: "daytona", + [A.packWallMs]: 12, + }, + }, + { traceparent: VALID_TRACEPARENT } as WorkerHostCallContext, + ); + + expect(mockRecordSpan).toHaveBeenCalledTimes(1); + const call = mockRecordSpan.mock.calls[0]![0] as { + name: string; + parent: { traceId: string; spanId: string; traceFlags: number }; + attributes: Record; + }; + expect(call.name).toBe("sandbox.provider.pack"); + expect(call.parent).toEqual({ + traceId: "0af7651916cd43dd8448eb211c80319c", + spanId: "b7ad6b7169203331", + traceFlags: 1, + }); + expect(call.attributes[A.provider]).toBe("daytona"); + expect(call.attributes[A.packWallMs]).toBe(12); + }); + + it("drops every forbidden attribute before the span reaches the tracer", async () => { + const services = servicesFor(); + await services.tracer.record( + { + name: "transfer", + attributes: { + [A.transferGuardCount]: 2, + // Forbidden fields that must never ride a span. + [A.execCommand]: "bash", + command: "rm -rf /", + args: "--force", + stdout: "secret output", + stderr: "secret error", + path: "/etc/passwd", + extra: "leak", + }, + }, + { traceparent: VALID_TRACEPARENT } as WorkerHostCallContext, + ); + + expect(mockRecordSpan).toHaveBeenCalledTimes(1); + const attributes = (mockRecordSpan.mock.calls[0]![0] as { attributes: Record }) + .attributes; + // Only the allowlisted key survives; every forbidden key is dropped. + expect(attributes).toEqual({ [A.transferGuardCount]: 2 }); + for (const forbidden of [A.execCommand, "command", "args", "stdout", "stderr", "path", "extra"]) { + expect(attributes).not.toHaveProperty(forbidden); + } + }); + + it("drops a status message (it could carry standard-stream text)", async () => { + const services = servicesFor(); + await services.tracer.record( + { name: "transfer", status: { code: 2, message: "secret error text" } }, + { traceparent: VALID_TRACEPARENT } as WorkerHostCallContext, + ); + const call = mockRecordSpan.mock.calls[0]![0] as { status?: { code: number; message?: string } }; + expect(call.status).toEqual({ code: 2 }); + expect(call.status).not.toHaveProperty("message"); + }); + + it("clamps an unknown span name to sandbox.provider.other", async () => { + const services = servicesFor(); + await services.tracer.record( + { name: "rm -rf / --no-preserve-root" }, + { traceparent: VALID_TRACEPARENT } as WorkerHostCallContext, + ); + expect((mockRecordSpan.mock.calls[0]![0] as { name: string }).name).toBe( + "sandbox.provider.other", + ); + }); + + it("rejects a malformed traceparent — no span is recorded", async () => { + const services = servicesFor(); + for (const bad of [ + undefined, + "not-a-traceparent", + "00-xyz-b7ad6b7169203331-01", + "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331", // missing flags + "00-00000000000000000000000000000000-b7ad6b7169203331-01", // all-zero trace id + ]) { + await services.tracer.record( + { name: "pack" }, + { traceparent: bad } as WorkerHostCallContext, + ); + } + expect(mockRecordSpan).not.toHaveBeenCalled(); + }); + + it("rejects a span from a plugin that lacks the environment-driver capability", async () => { + const handlers = handlersFor([]); + await expect( + handlers["span.record"]( + { name: "pack" }, + { traceparent: VALID_TRACEPARENT } as WorkerHostCallContext, + ), + ).rejects.toThrow(/capabilit/i); + expect(mockRecordSpan).not.toHaveBeenCalled(); + }); + + it("admits a span from a plugin that holds the environment-driver capability", async () => { + const handlers = handlersFor(["environment.drivers.register"]); + await handlers["span.record"]( + { name: "pack", attributes: { [A.provider]: "daytona" } }, + { traceparent: VALID_TRACEPARENT } as WorkerHostCallContext, + ); + expect(mockRecordSpan).toHaveBeenCalledTimes(1); + }); +}); + +describe("parseTraceparent", () => { + it("accepts a well-formed traceparent and returns the parts", () => { + expect(parseTraceparent(VALID_TRACEPARENT)).toEqual({ + traceId: "0af7651916cd43dd8448eb211c80319c", + spanId: "b7ad6b7169203331", + traceFlags: 1, + }); + }); + + it("rejects malformed, all-zero, and forbidden-version traceparents", () => { + expect(parseTraceparent(undefined)).toBeNull(); + expect(parseTraceparent("garbage")).toBeNull(); + expect(parseTraceparent("00-0af7651916cd43dd8448eb211c80319c-0000000000000000-01")).toBeNull(); + expect(parseTraceparent("ff-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01")).toBeNull(); + }); +}); + +describe("clampProviderSpanAttributes", () => { + it("keeps only allowlisted keys and normalizes the provider family", () => { + expect( + clampProviderSpanAttributes({ + [A.provider]: "some-operator-key", + [A.packWallMs]: 7, + [A.transferWallMs]: Number.NaN, + [A.execCommand]: "bash", + }), + ).toEqual({ + // An unknown provider key maps to `plugin`, never the raw key. + [A.provider]: "plugin", + [A.packWallMs]: 7, + // A non-finite number yields no attribute; `exec.command` is not allowed. + }); + }); +}); diff --git a/server/src/instrumentation.ts b/server/src/instrumentation.ts index b8f30c0cb3..246908ab00 100644 --- a/server/src/instrumentation.ts +++ b/server/src/instrumentation.ts @@ -171,6 +171,86 @@ export function getStartupTraceContext(name = "paperclip.startup"): StartupTrace } } +/** + * The parsed parts of a W3C `traceparent`. The host builds a remote parent span + * context from these parts to parent a plugin span to the active host span. + */ +export interface ParsedTraceparent { + traceId: string; + spanId: string; + traceFlags: number; +} + +/** + * Serialize an OTel context token to a W3C `traceparent` string. The host passes + * the token to the plugin worker per call, so the worker's provider span can + * parent to the active host span. The function reads the span context from the + * token and formats it by hand, so it needs no registered propagator. It returns + * `undefined` when `@opentelemetry/api` is absent, when the token holds no span + * context, or when the span context is invalid. + */ +export function traceparentFromContextToken(contextToken: unknown): string | undefined { + if (contextToken === undefined || contextToken === null) return undefined; + try { + const require = createRequire(import.meta.url); + const api = require("@opentelemetry/api") as { + trace?: { getSpanContext(context: unknown): { traceId: string; spanId: string; traceFlags: number } | undefined }; + }; + const spanContext = api.trace?.getSpanContext?.(contextToken); + if (!spanContext) return undefined; + const { traceId, spanId, traceFlags } = spanContext; + if (!/^[0-9a-f]{32}$/.test(traceId) || !/^[0-9a-f]{16}$/.test(spanId)) return undefined; + const flags = (traceFlags & 0xff).toString(16).padStart(2, "0"); + return `00-${traceId}-${spanId}-${flags}`; + } catch { + return undefined; + } +} + +/** + * Record a plugin-originated provider span through the real tracer, parented to + * a host span. The host handler validates and clamps the span data first (the + * trust boundary), then passes the parsed parent and the clamped attributes + * here. This function only does the OTel plumbing: it builds a remote parent + * span context, opens the span, sets its attributes and status, and ends it. It + * is a no-op when `@opentelemetry/api` is absent (the endpoint is unset) or when + * the parent parts are invalid. It never throws — observability must not change + * control flow. + */ +export function recordProviderPluginSpan(input: { + name: string; + parent: ParsedTraceparent; + attributes: Record; + status?: { code: number; message?: string }; +}): void { + try { + const require = createRequire(import.meta.url); + const api = require("@opentelemetry/api") as { + trace?: { + getTracer(n: string): StartupTracerHandle; + setSpanContext(context: unknown, spanContext: unknown): unknown; + }; + context?: { active(): unknown }; + }; + const trace = api.trace; + const context = api.context; + if (!trace?.getTracer || !trace.setSpanContext || !context?.active) return; + const remoteSpanContext = { + traceId: input.parent.traceId, + spanId: input.parent.spanId, + traceFlags: input.parent.traceFlags, + isRemote: true, + }; + const parentContext = trace.setSpanContext(context.active(), remoteSpanContext); + const tracer = trace.getTracer("paperclip.startup"); + const span = tracer.startSpan(input.name, { attributes: input.attributes }, parentContext); + if (input.status) span.setStatus(input.status); + span.end(); + } catch { + // Observability must not change control flow. + } +} + /** * Resolves once the OTel SDK has started (or once bootstrap has failed and * logged, or immediately when the feature is off). Await before constructing diff --git a/server/src/services/environment-execution-target.ts b/server/src/services/environment-execution-target.ts index 93611b0954..3c3e26aa9d 100644 --- a/server/src/services/environment-execution-target.ts +++ b/server/src/services/environment-execution-target.ts @@ -62,6 +62,13 @@ function toFiniteNumber(value: unknown): number | undefined { return typeof value === "number" && Number.isFinite(value) ? value : undefined; } +/** Read a free-form metadata value as a boolean, or `undefined`. The provider + * cache-hit flag rides the exec result's untyped `metadata`, so a provider that + * omits or mistypes it yields no attribute — never a misleading `false`. */ +function toBoolean(value: unknown): boolean | undefined { + return typeof value === "boolean" ? value : undefined; +} + /** * The closed input for one `sandbox.exec` span. The seam builds it from the * exec result and the active step context. Every field is already bounded or @@ -82,6 +89,8 @@ interface SandboxExecSpanInput { sandboxMs: number | undefined; /** Whether the execution sits on the startup critical path. */ criticalPath: boolean; + /** Whether the provider served the sandbox handle from its warm cache. */ + cacheHit: boolean | undefined; } /** @@ -111,6 +120,13 @@ function setSandboxExecSpanAttributes(span: ExecSpan, input: SandboxExecSpanInpu setFiniteNumberAttr(span, A.execNetworkMs, input.wallMs - input.waitBeforeMs - input.sandboxMs); } span.setAttribute(A.execCriticalPath, input.criticalPath); + // The explicit provider cache-hit flag, from `result.metadata.cacheHit`. The + // plugin decides it at the handle lookup, so the span no longer infers a + // cache hit from `wait_before_ms == 0`. A provider that omits it yields no + // attribute. + if (typeof input.cacheHit === "boolean") { + span.setAttribute(A.execCacheHit, input.cacheHit); + } const failed = input.exitCode !== 0; span.setAttribute( A.outcome, @@ -325,6 +341,7 @@ export async function resolveEnvironmentExecutionTarget(input: { waitBeforeMs: toFiniteNumber(result.metadata?.getDurationMs), sandboxMs: toFiniteNumber(result.metadata?.durationMs), criticalPath, + cacheHit: toBoolean(result.metadata?.cacheHit), }); } catch { // Observability must not change execution control flow. diff --git a/server/src/services/plugin-host-services.ts b/server/src/services/plugin-host-services.ts index 0c2d10e2e2..a156c02bc7 100644 --- a/server/src/services/plugin-host-services.ts +++ b/server/src/services/plugin-host-services.ts @@ -78,6 +78,12 @@ import { getTelemetryClient } from "../telemetry.js"; import { accessService } from "./access.js"; import { authorizationService, type AuthorizationActor } from "./authorization.js"; import { redactEventPayload, sanitizeRecord } from "../redaction.js"; +import type { WorkerHostCallContext } from "@paperclipai/plugin-sdk"; +import { + normalizeProviderFamily, + SANDBOX_STARTUP_SPAN_ATTRS, +} from "@paperclipai/adapter-utils/acpx-engine/startup-timing"; +import { recordProviderPluginSpan, type ParsedTraceparent } from "../instrumentation.js"; // --------------------------------------------------------------------------- // SSRF protection for plugin HTTP fetch @@ -490,6 +496,124 @@ if (_logFlushInterval.unref) _logFlushInterval.unref(); /** Maximum time (ms) to keep a session event subscription alive before forcing cleanup. */ const SESSION_EVENT_SUBSCRIPTION_TIMEOUT_MS = 30 * 60 * 1_000; // 30 minutes +// --------------------------------------------------------------------------- +// Provider span trust boundary (the `span.record` host handler) +// --------------------------------------------------------------------------- +// +// The plugin worker runs in a separate process, so the host treats every field +// of a worker-sent span as untrusted input. The host re-clamps the span name +// and every attribute here, before it records the span. A worker-side or +// plugin-side helper is not sufficient; this is the single boundary. + +const SPAN_ATTRS = SANDBOX_STARTUP_SPAN_ATTRS; + +/** The closed set of provider span names a plugin may emit. */ +const KNOWN_PROVIDER_SPAN_NAMES: ReadonlySet = new Set(["pack", "transfer"]); + +/** Clamp the span name to a closed, namespaced set. A known name maps to + * `sandbox.provider.`; any other value maps to `sandbox.provider.other`, + * so a span name never carries free-form data. */ +function clampProviderSpanName(raw: unknown): string { + const name = typeof raw === "string" && KNOWN_PROVIDER_SPAN_NAMES.has(raw) ? raw : "other"; + return `sandbox.provider.${name}`; +} + +/** The closed allowlist of attribute keys a provider span may carry. The host + * drops every other key, so a command, an argument, a path, an id, a standard + * output, a standard error, or an `extra` field can never ride a provider span. */ +const PROVIDER_SPAN_ATTR_ALLOWLIST: ReadonlySet = new Set([ + SPAN_ATTRS.provider, + SPAN_ATTRS.outcome, + SPAN_ATTRS.packWallMs, + SPAN_ATTRS.transferWallMs, + SPAN_ATTRS.transferGuardCount, +]); + +/** The subset of allowed keys that carry a finite number. */ +const PROVIDER_SPAN_NUMERIC_ATTRS: ReadonlySet = new Set([ + SPAN_ATTRS.packWallMs, + SPAN_ATTRS.transferWallMs, + SPAN_ATTRS.transferGuardCount, +]); + +/** The closed value set for the `outcome` attribute. */ +const KNOWN_SPAN_OUTCOMES: ReadonlySet = new Set(["ok", "skipped", "failed"]); + +/** + * Re-clamp the worker-sent attributes at the trust boundary. Drop every key that + * is not on the allowlist. Re-map `provider` through `normalizeProviderFamily`, + * bound `outcome` to its closed set, and keep a numeric attribute only when it + * is a finite number. The result holds only bounded, low-cardinality values. + */ +export function clampProviderSpanAttributes( + raw: Record | undefined, +): Record { + const clamped: Record = {}; + if (!raw) return clamped; + for (const [key, value] of Object.entries(raw)) { + if (!PROVIDER_SPAN_ATTR_ALLOWLIST.has(key)) continue; + if (key === SPAN_ATTRS.provider) { + clamped[key] = normalizeProviderFamily(typeof value === "string" ? value : undefined); + continue; + } + if (key === SPAN_ATTRS.outcome) { + if (typeof value === "string" && KNOWN_SPAN_OUTCOMES.has(value)) clamped[key] = value; + continue; + } + if (PROVIDER_SPAN_NUMERIC_ATTRS.has(key)) { + if (typeof value === "number" && Number.isFinite(value)) clamped[key] = value; + continue; + } + } + return clamped; +} + +/** + * Parse and validate a W3C `traceparent`. Return the parts, or `null` when the + * value is absent or malformed. The host mints the value, but this is the trust + * boundary, so it validates before use. It never logs the value. + */ +export function parseTraceparent(raw: string | undefined | null): ParsedTraceparent | null { + if (typeof raw !== "string") return null; + const match = /^([0-9a-f]{2})-([0-9a-f]{32})-([0-9a-f]{16})-([0-9a-f]{2})$/.exec(raw); + if (!match) return null; + const [, version, traceId, spanId, flags] = match; + if (version === "ff") return null; // the W3C spec forbids version 0xff + if (traceId === "0".repeat(32)) return null; // an all-zero trace id is invalid + if (spanId === "0".repeat(16)) return null; // an all-zero span id is invalid + return { traceId, spanId, traceFlags: parseInt(flags, 16) }; +} + +/** Keep only the numeric status code. A status message could carry free-form + * text, so the host drops it — never a standard-stream text on a span. */ +function clampSpanStatus( + status: { code?: unknown; message?: unknown } | undefined, +): { code: number } | undefined { + if (!status || typeof status.code !== "number" || !Number.isFinite(status.code)) return undefined; + return { code: status.code }; +} + +/** + * Record a worker-sent provider span through the real tracer. This is the host + * trust boundary: it validates the host-minted `traceparent`, re-clamps the span + * name and every attribute, mints the parentage host-side, and drops a status + * message. It rejects a span with a missing or malformed `traceparent`. It never + * throws — observability must not change control flow. + */ +export function recordWorkerProviderSpan( + params: { name: string; attributes?: Record; status?: { code?: unknown; message?: unknown } }, + context: WorkerHostCallContext | undefined, +): void { + const parent = parseTraceparent(context?.traceparent); + if (!parent) return; // reject a missing or malformed traceparent + recordProviderPluginSpan({ + name: clampProviderSpanName(params.name), + parent, + attributes: clampProviderSpanAttributes(params.attributes), + ...(clampSpanStatus(params.status) ? { status: clampSpanStatus(params.status) } : {}), + }); +} + export function buildHostServices( db: Db, pluginId: string, @@ -1485,6 +1609,17 @@ export function buildHostServices( }, }, + tracer: { + async record(params, context) { + // The host trust boundary: validate the host-minted `traceparent`, + // re-clamp the span name and every attribute, mint the parentage + // host-side, and record the span through the real tracer. The capability + // gate in `createHostClientHandlers` already rejected an ungranted + // plugin before this runs. + recordWorkerProviderSpan(params, context); + }, + }, + companies: { async list(params) { return applyWindow((await companies.list()) as Company[], params); diff --git a/server/src/services/plugin-worker-manager.ts b/server/src/services/plugin-worker-manager.ts index af2c6b78ba..e0a5cbd0d8 100644 --- a/server/src/services/plugin-worker-manager.ts +++ b/server/src/services/plugin-worker-manager.ts @@ -52,7 +52,9 @@ import type { WorkerToHostMethods, InitializeParams, } from "@paperclipai/plugin-sdk"; +import { getActiveStepContext } from "@paperclipai/adapter-utils/acpx-engine/startup-timing"; import { logger } from "../middleware/logger.js"; +import { traceparentFromContextToken } from "../instrumentation.js"; // --------------------------------------------------------------------------- // Constants @@ -260,6 +262,10 @@ interface PendingRequest { interface ActiveInvocation { scope: PluginInvocationScope; timer?: ReturnType; + // The host-minted W3C `traceparent` for the active startup span, or undefined + // when no startup span is active. The span host handler reads it to mint the + // parentage, so a worker never supplies the parent itself. + traceparent?: string; } // --------------------------------------------------------------------------- @@ -621,11 +627,20 @@ export function createPluginWorkerHandle( } function registerInvocation(scope: PluginInvocationScope, ttlMs?: number): PluginInvocationContext { + // Mint a W3C `traceparent` from the active startup span, so the worker's + // provider span can parent to it. The host keeps the value on its own record + // (below) and never trusts the worker to supply the parent. Outside a + // measured startup step there is no active span, so this is undefined. + const activeStep = getActiveStepContext(); + const traceparent = activeStep + ? traceparentFromContextToken(activeStep.parentContext) + : undefined; const invocation: PluginInvocationContext = { id: randomUUID(), scope, + ...(traceparent ? { traceparent } : {}), }; - const entry: ActiveInvocation = { scope }; + const entry: ActiveInvocation = { scope, traceparent }; if (ttlMs !== undefined) { entry.timer = setTimeout(() => { activeInvocations.delete(invocation.id); @@ -703,7 +718,7 @@ export function createPluginWorkerHandle( } const entry = activeInvocations.get(invocationId); if (!entry) return { invalidInvocationScope: true }; - return { invocationScope: entry.scope }; + return { invocationScope: entry.scope, traceparent: entry.traceparent }; } /**