diff --git a/.changeset/wise-otters-tap.md b/.changeset/wise-otters-tap.md new file mode 100644 index 000000000..7b6ef06e4 --- /dev/null +++ b/.changeset/wise-otters-tap.md @@ -0,0 +1,5 @@ +--- +"eve": patch +--- + +Local dev tracing now stays on when an agent authors `agent/instrumentation.ts`. Instead of standing down, `eve dev` observes the tracer provider your `setup` registered — including tracers your module took before it registered that provider — so your exporter keeps receiving everything it did before and additionally sees eve's `agent.*` spans, while `.eve/traces/v1`, `eve trace ls`, and `eve trace ` keep working. `setup` may now be `async`: eve awaits it before installing its writer. Neither sink receives the Workflow SDK's own spans any more — a turn runs inside a durable step, so a single turn used to send dozens of `step.execute`-style spans to your exporter, and eve now declines to create them while the dev server is running, reparenting anything nested under one onto the nearest span above it. If eve cannot observe spans in a given dev worker it logs a warning and leaves your instrumentation alone rather than failing the dev server. Production is unchanged; `EVE_TRACES=off` still opts out of the local writer. diff --git a/docs/guides/instrumentation.md b/docs/guides/instrumentation.md index b6ab7e1ab..8cb2ba0f4 100644 --- a/docs/guides/instrumentation.md +++ b/docs/guides/instrumentation.md @@ -9,13 +9,15 @@ If you intend to export telemetry, review the exporter destination, data categor ## Zero-config local traces -When no authored `instrumentation.ts` exists, `eve dev` records agent, AI SDK, and user-created OpenTelemetry spans under `.eve/traces/v1`. Each session has one trace, rooted independently from Workflow telemetry, with turns, model steps, and tool actions represented explicitly. Spans created by application code while a model or tool is executing inherit that active agent context. +`eve dev` records agent, AI SDK, and user-created OpenTelemetry spans under `.eve/traces/v1`. Each session has one trace, rooted independently from Workflow telemetry, with turns, model steps, and tool actions represented explicitly. Spans created by application code while a model or tool is executing inherit that active agent context. A span your code creates outside a session — in a channel route, say — belongs to no session trace, so it is not written to `.eve/traces/v1`; an exporter you configured yourself still receives it. The directory is an immutable OTLP/JSON spool and remains available after `eve dev` exits, subject to the [retention policy](#local-trace-retention) below. Inspection tools may build a query index from these segments, but the index is derived and can be rebuilt without changing the captured trace data. Use `eve trace ls` to list captured traces and `eve trace ` to inspect a session's span tree. -The local writer is an internal development default, not a second provider layered over authored instrumentation. When `instrumentation.ts` exists, its setup retains control and the zero-config writer is not installed. +The writer is always installed in `eve dev`, including when you author an `instrumentation.ts`. It does not compete with your provider: eve wraps the provider your `setup` registered rather than replacing it, so your exporter keeps receiving everything it received before, and in dev it additionally sees eve's `agent.*` spans. Because it observes your provider rather than running beside it, the local writer sees the spans your provider records: a sampler that drops a span drops it for `.eve/traces/v1` too. Production is unaffected — outside `eve dev`, authored instrumentation is the only provider and nothing is written to disk. Set `EVE_TRACES=off` to opt out of the local writer. + +eve is moving toward agent-centric traces — a trace that records what the agent did, not how eve ran it — and in `eve dev` that shapes what your exporter receives. The Workflow SDK's own spans are the first thing it applies to: a turn runs inside a durable step, so spans like `step.execute` arrive in the middle of the agent's trace and describe eve's execution machinery, dozens of them per turn. While the dev server is running, eve declines to create them at all, for your exporter as well as for `.eve/traces/v1`. Nesting is unaffected: a span started underneath one that was declined attaches to the nearest span above it, so your spans still sit under `agent.step`. In production nothing intercepts your provider, so it receives Workflow spans exactly as it does today. ### Local trace retention @@ -80,6 +82,8 @@ Export the result of `defineInstrumentation` as the default export. Use the `setup` callback to register your OTel provider (for example `registerOTel` from `@vercel/otel`). The framework invokes it at server startup with the resolved agent name. `context.agentName` is resolved at compile time from your project (the package's `name`, falling back to the app directory name), so you never hard-code a service name. +`setup` may be `async`. eve awaits it before anything else looks for a tracer provider, so a provider you register after an `await` is still in place for the first turn. + Any OTel-compatible backend works (Braintrust, Raindrop, Arize, Honeycomb, Datadog, Jaeger). Install the exporter package you need and configure it in the callback. Three more fields control what the AI SDK records inside those spans (see the AI SDK's [telemetry reference](https://ai-sdk.dev/docs/ai-sdk-core/telemetry)): @@ -136,7 +140,7 @@ Channel metadata is channel-owned. Built-in channels expose only the fields they ## Authored trace hierarchy -The existing authored `instrumentation.ts` path remains separate from zero-config local traces. When authored telemetry is enabled, each turn currently produces a trace like: +Your exporter receives the hierarchy the AI SDK produces. When authored telemetry is enabled, each turn currently produces a trace like: ```text ai.eve.turn {eve.session.id} diff --git a/packages/eve/scripts/vendor-compiled/declarations/@opentelemetry/api.d.ts b/packages/eve/scripts/vendor-compiled/declarations/@opentelemetry/api.d.ts index 7803d8add..62edcb47b 100644 --- a/packages/eve/scripts/vendor-compiled/declarations/@opentelemetry/api.d.ts +++ b/packages/eve/scripts/vendor-compiled/declarations/@opentelemetry/api.d.ts @@ -8,7 +8,8 @@ export interface SpanContext { export interface Span { addEvent(name: string, attributes?: Attributes): this; - end(): void; + end(endTime?: number): void; + isRecording?(): boolean; recordException( exception: Error | string | { message?: string; name?: string; stack?: string }, ): void; @@ -17,12 +18,25 @@ export interface Span { spanContext(): SpanContext; } +export interface SpanOptions { + attributes?: Attributes | undefined; + root?: boolean | undefined; +} + export interface Tracer { - startSpan( - name: string, - options?: { attributes?: Attributes | undefined; root?: boolean | undefined }, - context?: Context, - ): Span; + startSpan(name: string, options?: SpanOptions, context?: Context): Span; +} + +export interface TracerProvider { + getTracer(name: string, version?: string, options?: unknown): Tracer; +} + +export declare class ProxyTracerProvider implements TracerProvider { + getDelegate(): TracerProvider; + /** `undefined` until a delegate is set — how eve tells an unclaimed proxy from a claimed one. */ + getDelegateTracer(name: string, version?: string, options?: unknown): Tracer | undefined; + getTracer(name: string, version?: string, options?: unknown): Tracer; + setDelegate(delegate: TracerProvider): void; } export interface Context {} @@ -42,11 +56,16 @@ export declare const context: { export declare const trace: { getActiveSpan(): Span | undefined; + getSpanContext(context: Context): SpanContext | undefined; getTracer(name: string, version?: string): Tracer; + getTracerProvider(): TracerProvider; setSpan(context: Context, span: Span): Context; wrapSpanContext(spanContext: SpanContext): Span; }; +/** All-zero ids: what the API hands out when there is no span to refer to. */ +export declare const INVALID_SPAN_CONTEXT: SpanContext; + export declare enum SpanKind { INTERNAL = 0, SERVER = 1, diff --git a/packages/eve/src/harness/agent-trace-span-processor.test.ts b/packages/eve/src/harness/agent-trace-span-processor.test.ts index 3cbac6c22..86d1bd3b4 100644 --- a/packages/eve/src/harness/agent-trace-span-processor.test.ts +++ b/packages/eve/src/harness/agent-trace-span-processor.test.ts @@ -65,6 +65,32 @@ describe("AgentTraceSpanProcessor", () => { expect(child.onStart).toHaveBeenCalledTimes(1); expect(child.onEnd).not.toHaveBeenCalled(); }); + + // An authored `instrumentation.ts` chooses its own SDK version, and + // `@opentelemetry/sdk-trace-base` 1.x names this field `instrumentationLibrary`. + // Reading only the 2.x name would let a run's spans into the local store for + // anyone still on `@vercel/otel@1`. + it("excludes Workflow instrumentation reported under the pre-2.x field name", () => { + const child = { + forceFlush: vi.fn(async () => {}), + onEnd: vi.fn(), + onStart: vi.fn(), + shutdown: vi.fn(async () => {}), + }; + const processor = new AgentTraceSpanProcessor([child]); + processor.onStart(span("trace-1", { "agent.session.id": "session-1" }), {}); + + const workflow = { + attributes: {}, + instrumentationLibrary: { name: "workflow" }, + spanContext: () => ({ traceId: "trace-1" }), + }; + processor.onStart(workflow, {}); + processor.onEnd(workflow); + + expect(child.onStart).toHaveBeenCalledTimes(1); + expect(child.onEnd).not.toHaveBeenCalled(); + }); }); function span( diff --git a/packages/eve/src/harness/agent-trace-span-processor.ts b/packages/eve/src/harness/agent-trace-span-processor.ts index 39ea26ff3..75ab70b92 100644 --- a/packages/eve/src/harness/agent-trace-span-processor.ts +++ b/packages/eve/src/harness/agent-trace-span-processor.ts @@ -1,17 +1,32 @@ import type { SpanProcessor } from "#compiled/@vercel/otel/index.js"; +import { WORKFLOW_INSTRUMENTATION_SCOPE } from "#harness/workflow-instrumentation-scope.js"; + interface SpanLike { readonly attributes: Readonly>; + readonly instrumentationLibrary?: { readonly name?: string }; readonly instrumentationScope?: { readonly name?: string }; readonly spanContext: () => { readonly traceId: string }; } +/** + * The name of the instrumentation that created `span`. + * + * `@opentelemetry/sdk-trace-base` 2.x renamed `instrumentationLibrary` to + * `instrumentationScope`. eve reads spans from providers it did not build — an + * authored `instrumentation.ts` picks its own SDK version — so both shapes + * arrive here, and a span whose scope cannot be read is one this processor + * cannot decide about. + */ +function instrumentationName(span: SpanLike): string | undefined { + return span.instrumentationScope?.name ?? span.instrumentationLibrary?.name; +} + /** Routes spans from agent-owned traces to provider-neutral child processors. */ export class AgentTraceSpanProcessor implements SpanProcessor { readonly #children: readonly SpanProcessor[]; readonly #ownedTraceIds = new Set(); readonly #sessionTraceIds = new Map(); - #attached = false; constructor(children: readonly SpanProcessor[]) { this.#children = children; @@ -21,12 +36,7 @@ export class AgentTraceSpanProcessor implements SpanProcessor { await Promise.all(this.#children.map((child) => child.forceFlush())); } - isAttached(): boolean { - return this.#attached; - } - onStart(span: unknown, parentContext: unknown): void { - this.#attached = true; if (!isSpanLike(span)) return; const sessionId = span.attributes["agent.session.id"]; if (typeof sessionId === "string") { @@ -61,9 +71,17 @@ export class AgentTraceSpanProcessor implements SpanProcessor { await Promise.all(this.#children.map((child) => child.shutdown())); } + /** + * A run's internal spans are declined even inside a trace eve owns, so + * `eve trace` shows the session's own work. + * + * Still needed with `suppressWorkflowInstrumentation` in place: that only + * covers a provider eve intercepts, and on the zero-config path eve registers + * the provider itself, so the Workflow SDK's spans are real and arrive here. + */ #accepts(span: SpanLike): boolean { return ( - span.instrumentationScope?.name !== "workflow" && + instrumentationName(span) !== WORKFLOW_INSTRUMENTATION_SCOPE && this.#ownedTraceIds.has(span.spanContext().traceId) ); } diff --git a/packages/eve/src/harness/delegating-tracer-provider.test.ts b/packages/eve/src/harness/delegating-tracer-provider.test.ts new file mode 100644 index 000000000..287c02637 --- /dev/null +++ b/packages/eve/src/harness/delegating-tracer-provider.test.ts @@ -0,0 +1,83 @@ +import { describe, expect, it } from "vitest"; + +import { + ProxyTracerProvider, + type Span, + type Tracer, + type TracerProvider, +} from "#compiled/@opentelemetry/api/index.js"; +import { + hasTracerProviderDelegate, + isDelegatingTracerProvider, + type DelegatingTracerProvider, +} from "#harness/delegating-tracer-provider.js"; + +describe("isDelegatingTracerProvider", () => { + it("recognizes the real proxy provider", () => { + expect(isDelegatingTracerProvider(new ProxyTracerProvider())).toBe(true); + }); + + // The case `instanceof` cannot answer: an authored `instrumentation.ts` + // resolves its own copy of `@opentelemetry/api`, so the proxy eve meets at the + // global slot is an instance of a class eve has never seen. + it("recognizes a proxy from a foreign copy of the API", () => { + expect(isDelegatingTracerProvider(createForeignProxy())).toBe(true); + }); + + it("rejects a plain provider", () => { + expect(isDelegatingTracerProvider({ getTracer: () => createTracer() })).toBe(false); + }); +}); + +describe("hasTracerProviderDelegate", () => { + it("is false for a proxy nobody has claimed", () => { + expect(hasTracerProviderDelegate(new ProxyTracerProvider())).toBe(false); + expect(hasTracerProviderDelegate(createForeignProxy())).toBe(false); + }); + + it("is true once a delegate is set", () => { + const proxy = new ProxyTracerProvider(); + proxy.setDelegate({ getTracer: () => createTracer() }); + + expect(hasTracerProviderDelegate(proxy)).toBe(true); + }); + + // The probe must not leave a tracer behind in the delegate's cache under a + // name the author would later use, so it asks for one of eve's own. + it("probes under an eve-namespaced tracer name", () => { + const asked: string[] = []; + const proxy = createForeignProxy(); + proxy.setDelegate({ + getTracer: (name: string) => { + asked.push(name); + return createTracer(); + }, + }); + + expect(hasTracerProviderDelegate(proxy)).toBe(true); + expect(asked.every((name) => name.startsWith("eve."))).toBe(true); + }); +}); + +/** + * `ProxyTracerProvider` as another copy of the API would define it: same shape, + * unrelated class, and its own no-op provider that eve has no reference to. + */ +function createForeignProxy(): DelegatingTracerProvider { + let delegate: TracerProvider | undefined; + const noop: TracerProvider = { getTracer: () => createTracer() }; + return { + getDelegate: () => delegate ?? noop, + getDelegateTracer: (name: string, version?: string, options?: unknown) => + delegate?.getTracer(name, version, options), + getTracer: (name: string, version?: string, options?: unknown) => + delegate?.getTracer(name, version, options) ?? noop.getTracer(name), + setDelegate: (next: TracerProvider) => { + delegate = next; + }, + }; +} + +function createTracer(): Tracer { + return { startSpan: () => ({}) as Span }; +} diff --git a/packages/eve/src/harness/delegating-tracer-provider.ts b/packages/eve/src/harness/delegating-tracer-provider.ts new file mode 100644 index 000000000..86877f11d --- /dev/null +++ b/packages/eve/src/harness/delegating-tracer-provider.ts @@ -0,0 +1,47 @@ +import type { TracerProvider } from "#compiled/@opentelemetry/api/index.js"; + +/** + * The `ProxyTracerProvider` surface, duck-typed. + * + * `setGlobalTracerProvider` registers this proxy rather than the provider + * handed to it, so it is the shape eve meets at the global slot. It cannot be + * recognized with `instanceof`: an authored `instrumentation.ts` resolves + * `@opentelemetry/api` from the agent's own dependencies, so its class is a + * different object than the one in eve's vendored copy. + */ +export interface DelegatingTracerProvider extends TracerProvider { + getDelegate: () => TracerProvider; + getDelegateTracer: (name: string, version?: string, options?: unknown) => unknown; + setDelegate: (delegate: TracerProvider) => void; +} + +/** + * Whether `provider` resolves its tracers through a delegate that can be + * replaced. + * + * @internal — not part of the public API. + */ +export function isDelegatingTracerProvider( + provider: TracerProvider, +): provider is DelegatingTracerProvider { + const candidate = provider as Partial; + return ( + typeof candidate.getDelegate === "function" && + typeof candidate.getDelegateTracer === "function" && + typeof candidate.setDelegate === "function" + ); +} + +/** + * Whether a delegate has been set on `provider`. + * + * `getDelegate()` cannot answer this: with nothing set it returns the API's + * no-op provider, and that singleton belongs to whichever copy of + * `@opentelemetry/api` created the proxy, so eve has no object to compare it + * against. `getDelegateTracer` returns `undefined` in exactly that case. + * + * @internal — not part of the public API. + */ +export function hasTracerProviderDelegate(provider: DelegatingTracerProvider): boolean { + return provider.getDelegateTracer("eve.delegate-probe") !== undefined; +} diff --git a/packages/eve/src/harness/instrumentation-config.test.ts b/packages/eve/src/harness/instrumentation-config.test.ts index af254587d..5fcd98d2f 100644 --- a/packages/eve/src/harness/instrumentation-config.test.ts +++ b/packages/eve/src/harness/instrumentation-config.test.ts @@ -25,7 +25,7 @@ describe("instrumentation-config chunk-isolation regression", () => { vi.resetModules(); const moduleA = await import("#harness/instrumentation-config.js"); const config = { functionId: "test.instrumentation.cross-module.alice" }; - moduleA.registerInstrumentationConfig(config, { agentName: "test-agent" }); + await moduleA.registerInstrumentationConfig(config, { agentName: "test-agent" }); vi.resetModules(); const moduleB = await import("#harness/instrumentation-config.js"); @@ -40,7 +40,7 @@ describe("instrumentation-config chunk-isolation regression", () => { const { registerInstrumentationConfig } = await import("#harness/instrumentation-config.js"); const canary = { functionId: "test.instrumentation.global-mount.canary" }; - registerInstrumentationConfig(canary, { agentName: "test-agent" }); + await registerInstrumentationConfig(canary, { agentName: "test-agent" }); expect((globalThis as Record)[globalKey]).toBe(canary); }); @@ -51,7 +51,7 @@ describe("instrumentation-config chunk-isolation regression", () => { vi.resetModules(); const moduleA = await import("#harness/instrumentation-config.js"); const config = { functionId: "test.instrumentation.reimport.canary" }; - moduleA.registerInstrumentationConfig(config, { agentName: "test-agent" }); + await moduleA.registerInstrumentationConfig(config, { agentName: "test-agent" }); const firstRef = (globalThis as Record)[globalKey]; vi.resetModules(); @@ -66,8 +66,33 @@ describe("instrumentation-config chunk-isolation regression", () => { const { registerInstrumentationConfig } = await import("#harness/instrumentation-config.js"); const setup = vi.fn(); - registerInstrumentationConfig({ setup }, { agentName: "weather-agent" }); + await registerInstrumentationConfig({ setup }, { agentName: "weather-agent" }); expect(setup).toHaveBeenCalledExactlyOnceWith({ agentName: "weather-agent" }); }); + + // An `async setup` that registers a tracer provider after an `await` must be + // finished before the next Nitro plugin looks for one. Dropping the promise + // let eve's own telemetry setup win the race and silently starve the + // authored exporter. + it("resolves only after an async setup has finished", async () => { + vi.resetModules(); + const { getInstrumentationConfig, registerInstrumentationConfig } = + await import("#harness/instrumentation-config.js"); + + const registered: string[] = []; + const config = { + setup: async () => { + await Promise.resolve(); + registered.push("provider"); + }, + }; + + const pending = registerInstrumentationConfig(config, { agentName: "async-agent" }); + expect(registered).toEqual([]); + await pending; + + expect(registered).toEqual(["provider"]); + expect(getInstrumentationConfig()).toBe(config); + }); }); diff --git a/packages/eve/src/harness/instrumentation-config.ts b/packages/eve/src/harness/instrumentation-config.ts index 509340fc0..4640475df 100644 --- a/packages/eve/src/harness/instrumentation-config.ts +++ b/packages/eve/src/harness/instrumentation-config.ts @@ -28,20 +28,26 @@ interface InstrumentationConfigGlobal { const globalContainer = globalThis as typeof globalThis & InstrumentationConfigGlobal; /** - * Registers the authored instrumentation config and invokes its `setup` + * Registers the authored instrumentation config and awaits its `setup` * callback with the resolved agent name. * * Called once by the generated instrumentation Nitro plugin at server * startup. Subsequent calls overwrite the previous value. * + * `setup` is awaited so that everything it registers — a tracer provider above + * all — is in place before the next plugin runs and before the first request + * is served. Dropping the promise would let eve's own telemetry setup race an + * `async setup`, and whichever provider lost that race would silently export + * nothing. + * * @internal — not part of the public API. */ -export function registerInstrumentationConfig( +export async function registerInstrumentationConfig( config: InstrumentationDefinition, context: InstrumentationSetupContext, -): void { +): Promise { if (config.setup !== undefined) { - config.setup(context); + await config.setup(context); } globalContainer[INSTRUMENTATION_CONFIG_GLOBAL_KEY] = config; } diff --git a/packages/eve/src/harness/intercept-global-tracer-provider.test.ts b/packages/eve/src/harness/intercept-global-tracer-provider.test.ts new file mode 100644 index 000000000..30e62aad5 --- /dev/null +++ b/packages/eve/src/harness/intercept-global-tracer-provider.test.ts @@ -0,0 +1,285 @@ +import { afterEach, describe, expect, it } from "vitest"; + +import type { + Context, + Span, + SpanOptions, + Tracer, + TracerProvider, +} from "#compiled/@opentelemetry/api/index.js"; +import type { SpanProcessor } from "#compiled/@vercel/otel/index.js"; +import type { DelegatingTracerProvider } from "#harness/delegating-tracer-provider.js"; +import { + attachInterceptedSpanProcessor, + installGlobalTracerProviderInterception, + releaseGlobalTracerProviderInterception, +} from "#harness/intercept-global-tracer-provider.js"; + +const API_REGISTRY_KEY = Symbol.for("opentelemetry.js.api.1"); +const INTERCEPTION_STATE_KEY = Symbol.for("eve.harness-tracer-provider-interception"); + +interface ApiRegistry { + trace?: TracerProvider; + version?: string; +} + +const container = globalThis as typeof globalThis & Record; + +afterEach(() => { + releaseGlobalTracerProviderInterception(); + delete container[API_REGISTRY_KEY]; + delete container[INTERCEPTION_STATE_KEY]; +}); + +describe("installGlobalTracerProviderInterception", () => { + it("does not create the registry, so an author's own API version still registers", () => { + expect(installGlobalTracerProviderInterception()).toBe(true); + + expect(container[API_REGISTRY_KEY]).toBeUndefined(); + + // `registerGlobal` refuses a registry whose `version` is not its own, so the + // object has to be the authored API's. + const registry = registerApiRegistry("9.9.9"); + expect((container[API_REGISTRY_KEY] as ApiRegistry).version).toBe("9.9.9"); + expect(registry.trace).toBeUndefined(); + }); + + // The reason interception exists: a tracer created during authored `setup()` + // holds the concrete tracer, and no later delegate swap can reach it. + it("observes tracers created before the trace writer is attached", () => { + installGlobalTracerProviderInterception(); + const registry = registerApiRegistry("1.9.0"); + const events: string[] = []; + + registry.trace = createInnerProvider(events); + const early = registry.trace.getTracer("authored"); + + const { processor, started } = createRecordingProcessor(); + expect(attachInterceptedSpanProcessor(processor)).toBe(true); + + early.startSpan("authored.work").end(); + + expect(started).toEqual(["authored.work"]); + expect(events).toEqual(["inner-end:authored.work"]); + }); + + // Interception is also where a run's internal spans stop existing: the + // author's provider never gets asked for them, so their exporter never sees + // them. + it("suppresses the Workflow SDK's tracer on the provider it hands back", () => { + installGlobalTracerProviderInterception(); + const registry = registerApiRegistry("1.9.0"); + const events: string[] = []; + + registry.trace = createInnerProvider(events); + const { processor, started } = createRecordingProcessor(); + attachInterceptedSpanProcessor(processor); + + registry.trace.getTracer("workflow").startSpan("step.execute").end(); + registry.trace.getTracer("authored").startSpan("authored.work").end(); + + expect(events).toEqual(["inner-end:authored.work"]); + expect(started).toEqual(["authored.work"]); + }); + + // `setGlobalTracerProvider` registers its proxy first and sets the real + // provider as the delegate only after, so a tracer taken in between is a + // `ProxyTracer` that resolves lazily. Hooking the delegate is what reaches it; + // wrapping the proxy would not. + it("observes tracers taken from a proxy before its delegate is set", () => { + installGlobalTracerProviderInterception(); + const registry = registerApiRegistry("1.9.0"); + const events: string[] = []; + const proxy = createProxyProvider(); + + registry.trace = proxy; + const early = registry.trace.getTracer("authored"); + proxy.setDelegate(createInnerProvider(events)); + + const { processor, started } = createRecordingProcessor(); + expect(attachInterceptedSpanProcessor(processor)).toBe(true); + + early.startSpan("authored.work").end(); + + expect(started).toEqual(["authored.work"]); + expect(events).toEqual(["inner-end:authored.work"]); + }); + + it("observes a proxy that already had a delegate", () => { + const events: string[] = []; + const proxy = createProxyProvider(); + proxy.setDelegate(createInnerProvider(events)); + + installGlobalTracerProviderInterception(); + const registry = registerApiRegistry("1.9.0"); + registry.trace = proxy; + + const { processor, started } = createRecordingProcessor(); + expect(attachInterceptedSpanProcessor(processor)).toBe(true); + + proxy.getTracer("authored").startSpan("authored.work").end(); + + expect(started).toEqual(["authored.work"]); + }); + + // `registerGlobal` assigns the registry slot on every registration it makes — + // context and propagation as well as trace — always with the same object. + // Re-intercepting it would wrap the provider a second time and report every + // span twice. + it("reports each span once when the registry object is reassigned", () => { + installGlobalTracerProviderInterception(); + const registry = registerApiRegistry("1.9.0"); + const events: string[] = []; + + registry.trace = createInnerProvider(events); + // What `registerGlobal` does when the author also registers a context + // manager and a propagator: same object, back into the same slot. + container[API_REGISTRY_KEY] = registry; + container[API_REGISTRY_KEY] = registry; + + const { processor, started } = createRecordingProcessor(); + expect(attachInterceptedSpanProcessor(processor)).toBe(true); + + registry.trace.getTracer("authored").startSpan("authored.work").end(); + + expect(started).toEqual(["authored.work"]); + expect(events).toEqual(["inner-end:authored.work"]); + }); + + it("is idempotent", () => { + expect(installGlobalTracerProviderInterception()).toBe(true); + expect(installGlobalTracerProviderInterception()).toBe(true); + }); +}); + +describe("attachInterceptedSpanProcessor", () => { + it("declines when interception was never installed", () => { + expect(attachInterceptedSpanProcessor(createRecordingProcessor().processor)).toBe(false); + }); + + // An authored `setup` that configures a non-OTel backend registers no + // provider. eve has to register one of its own, so the slot is handed back + // rather than left wrapping nothing. + it("declines and releases the slot when nothing registered a provider", () => { + installGlobalTracerProviderInterception(); + const registry = registerApiRegistry("1.9.0"); + + expect(attachInterceptedSpanProcessor(createRecordingProcessor().processor)).toBe(false); + + const provider = createInnerProvider([]); + registry.trace = provider; + expect(registry.trace).toBe(provider); + }); +}); + +describe("releaseGlobalTracerProviderInterception", () => { + it("restores the provider as it was registered", () => { + installGlobalTracerProviderInterception(); + const registry = registerApiRegistry("1.9.0"); + const provider = createInnerProvider([]); + + registry.trace = provider; + expect(registry.trace).not.toBe(provider); + + releaseGlobalTracerProviderInterception(); + + expect(registry.trace).toBe(provider); + expect(Object.getOwnPropertyDescriptor(registry, "trace")?.get).toBeUndefined(); + }); + + // eve declines rather than degrading the authored path, so a released proxy + // has to be left delegating to exactly what the author registered. + it("restores a proxy's delegate as the author set it", () => { + installGlobalTracerProviderInterception(); + const registry = registerApiRegistry("1.9.0"); + const events: string[] = []; + const proxy = createProxyProvider(); + const delegate = createInnerProvider(events); + + registry.trace = proxy; + proxy.setDelegate(delegate); + expect(proxy.getDelegate()).not.toBe(delegate); + + releaseGlobalTracerProviderInterception(); + + expect(proxy.getDelegate()).toBe(delegate); + // The proxy itself goes back into the slot, not the delegate eve unwrapped + // out of it, so `trace.getTracerProvider()` still answers what it did. + expect(registry.trace).toBe(proxy); + proxy.getTracer("authored").startSpan("authored.work").end(); + expect(events).toEqual(["inner-end:authored.work"]); + }); + + it("is safe to call without an installation", () => { + expect(() => releaseGlobalTracerProviderInterception()).not.toThrow(); + }); +}); + +/** + * `ProxyTracerProvider` as the authored API copy defines it: registered before + * its delegate exists, and handing out tracers that resolve through whatever + * delegate is set by the time a span is started. + */ +function createProxyProvider(): DelegatingTracerProvider { + let delegate: TracerProvider | undefined; + const noopTracer: Tracer = { startSpan: () => ({}) as Span }; + const proxy: DelegatingTracerProvider = { + getDelegate: () => delegate ?? { getTracer: () => noopTracer }, + getDelegateTracer: (name: string, version?: string, options?: unknown) => + delegate?.getTracer(name, version, options), + getTracer: (name: string, version?: string, options?: unknown) => ({ + startSpan: (spanName: string, spanOptions?: SpanOptions, parentContext?: Context) => + (delegate?.getTracer(name, version, options) ?? noopTracer).startSpan( + spanName, + spanOptions, + parentContext, + ), + }), + setDelegate: (next: TracerProvider) => { + delegate = next; + }, + }; + return proxy; +} + +/** What `registerGlobal` does on first use: create the registry, or reuse it. */ +function registerApiRegistry(version: string): ApiRegistry { + const registry: ApiRegistry = { version }; + container[API_REGISTRY_KEY] = registry; + return container[API_REGISTRY_KEY] as ApiRegistry; +} + +function createRecordingProcessor(): { processor: SpanProcessor; started: string[] } { + const started: string[] = []; + return { + processor: { + forceFlush: async () => {}, + onEnd: () => {}, + onStart: (span: unknown) => void started.push((span as { name: string }).name), + shutdown: async () => {}, + }, + started, + }; +} + +function createInnerProvider(events: string[]): TracerProvider { + return { + getTracer(): Tracer { + return { + startSpan(name: string, _options?: SpanOptions, _parentContext?: Context): Span { + const span: Span & { name: string } = { + addEvent: () => span, + end: () => void events.push(`inner-end:${name}`), + isRecording: () => true, + name, + recordException: () => {}, + setAttribute: () => span, + setStatus: () => span, + spanContext: () => ({ spanId: "b".repeat(16), traceFlags: 1, traceId: "a".repeat(32) }), + }; + return span; + }, + }; + }, + }; +} diff --git a/packages/eve/src/harness/intercept-global-tracer-provider.ts b/packages/eve/src/harness/intercept-global-tracer-provider.ts new file mode 100644 index 000000000..0c52524f1 --- /dev/null +++ b/packages/eve/src/harness/intercept-global-tracer-provider.ts @@ -0,0 +1,270 @@ +import type { TracerProvider } from "#compiled/@opentelemetry/api/index.js"; +import type { SpanProcessor } from "#compiled/@vercel/otel/index.js"; + +import { + hasTracerProviderDelegate, + isDelegatingTracerProvider, + type DelegatingTracerProvider, +} from "#harness/delegating-tracer-provider.js"; +import { observeTracerProvider } from "#harness/observe-tracer-provider.js"; +import { suppressWorkflowInstrumentation } from "#harness/workflow-instrumentation.js"; + +// Reaching into another library's global registry is the price of leaving the +// authored API alone: `instrumentation.ts` calls `registerOTel` itself, and a +// single-owner global is the only thing eve can hook. `eve dev` only. When +// `research/provider-neutral-local-observability.md` hands `setup` an eve-owned +// registration instead, this module and its two plugins go away. + +/** + * The slot `@opentelemetry/api` stores its global registry in. + * + * Every copy of the API in the process shares this one object through + * `globalThis`, keyed by the API's major version — the only thing an authored + * `instrumentation.ts` and eve's vendored copy have in common. `1` is the major + * of the vendored API; a registration made by an API with a different major is + * unreadable by eve either way, so there is nothing to intercept there. + */ +const API_REGISTRY_KEY = Symbol.for("opentelemetry.js.api.1"); + +/** + * Held on `globalThis` because eve's interception plugin and its trace-writer + * plugin can resolve to two module instances, and installing in one while + * attaching in the other would silently leave the writer unwired. Same reason + * as `instrumentation-config.ts`. + */ +const INTERCEPTION_STATE_KEY = Symbol.for("eve.harness-tracer-provider-interception"); + +interface ApiRegistry { + trace?: TracerProvider; +} + +interface InterceptionState { + /** Proxy providers already hooked, so a second visit is a no-op. */ + hooked: Set; + installed: boolean; + processor: SpanProcessor | undefined; + /** The provider as registered, before eve wrapped it. */ + provider: TracerProvider | undefined; + /** Undo steps, newest last, run in reverse by the release. */ + undo: Array<() => void>; +} + +type GlobalSlots = Record; + +const container = globalThis as typeof globalThis & GlobalSlots; + +function state(): InterceptionState { + const existing = container[INTERCEPTION_STATE_KEY]; + if (existing !== undefined) return existing as InterceptionState; + const created: InterceptionState = { + hooked: new Set(), + installed: false, + processor: undefined, + provider: undefined, + undo: [], + }; + container[INTERCEPTION_STATE_KEY] = created; + return created; +} + +function processorSource(): SpanProcessor | undefined { + return state().processor; +} + +/** + * Claims the global tracer-provider slot so eve observes every tracer, however + * early it is created. + * + * Must run *before* anything registers a provider. Wrapping one after the fact + * is not equivalent: `ProxyTracerProvider.getTracer` hands out the delegate's + * concrete tracer once a delegate exists, so a tracer created during authored + * `setup()` — by an auto-instrumentation the author enabled, say — keeps a + * direct reference that no later swap can reach. + * + * eve deliberately does not create the registry object. It carries the version + * of whichever API instance registers first, and `registerGlobal` refuses a + * registration whose version does not match, so a registry created by eve's + * vendored copy would break an author on any other patch release. Instead the + * `globalThis` slot itself is intercepted and the author's own object is + * decorated when it arrives. + * + * Returns `false` when the slot cannot be claimed, leaving global state + * untouched. There is no second way in: a provider already handed out concrete + * tracers, and swapping it after the fact would miss them. + * + * @internal — not part of the public API. + */ +export function installGlobalTracerProviderInterception(): boolean { + const current = state(); + if (current.installed) return true; + try { + current.installed = claimRegistrySlot(current); + } catch { + current.installed = false; + } + if (!current.installed) current.undo.length = 0; + return current.installed; +} + +/** + * Routes the spans of every intercepted tracer to `processor`. + * + * Returns `false` when interception is not installed, or when nothing + * registered a provider through it — an authored `setup()` that configures a + * non-OTel backend, for instance. In that case the slot is released first so + * the caller can register its own provider without spans being reported twice. + * + * @internal — not part of the public API. + */ +export function attachInterceptedSpanProcessor(processor: SpanProcessor): boolean { + const current = state(); + if (!current.installed) return false; + if (current.provider === undefined) { + releaseGlobalTracerProviderInterception(); + return false; + } + current.processor = processor; + return true; +} + +/** + * Undoes every intervention, leaving the provider reachable exactly as it was + * registered. + * + * @internal — not part of the public API. + */ +export function releaseGlobalTracerProviderInterception(): void { + const current = state(); + if (!current.installed) return; + current.installed = false; + current.processor = undefined; + current.hooked.clear(); + const undo = current.undo.splice(0, current.undo.length).reverse(); + for (const step of undo) { + try { + step(); + } catch { + // Left uninstalled: with the processor cleared, any wrapper still in + // place reports to nothing and degrades to a pass-through. + } + } + current.provider = undefined; +} + +function claimRegistrySlot(current: InterceptionState): boolean { + const descriptor = Object.getOwnPropertyDescriptor(container, API_REGISTRY_KEY); + if (descriptor?.configurable === false) return false; + + const existing = container[API_REGISTRY_KEY] as ApiRegistry | undefined; + if (existing !== undefined) return interceptTraceSlot(current, existing); + + let registry: ApiRegistry | undefined; + Object.defineProperty(container, API_REGISTRY_KEY, { + configurable: true, + get: () => registry, + // `registerGlobal` reassigns this slot on every registration it makes — + // context, propagation, and metrics as well as trace — always with the + // same object once one exists. Only a new object is worth intercepting; + // repeating the work on the same one would wrap the provider again and + // report every span twice. + set: (value: ApiRegistry | undefined) => { + if (value === registry) return; + registry = value; + if (value !== undefined) interceptTraceSlot(current, value); + }, + }); + current.undo.push(() => { + delete container[API_REGISTRY_KEY]; + if (registry !== undefined) container[API_REGISTRY_KEY] = registry; + }); + return true; +} + +function interceptTraceSlot(current: InterceptionState, registry: ApiRegistry): boolean { + const descriptor = Object.getOwnPropertyDescriptor(registry, "trace"); + if (descriptor?.configurable === false) return false; + + let registered = registry.trace; + let stored = intercept(current, registered); + delete registry.trace; + Object.defineProperty(registry, "trace", { + configurable: true, + enumerable: true, + get: () => stored, + set: (provider: TracerProvider | undefined) => { + registered = provider; + stored = intercept(current, provider); + }, + }); + current.undo.push(() => { + delete registry.trace; + // What the author assigned, which is not what eve stored: a proxy goes back + // as the proxy, a concrete provider goes back unwrapped. + if (registered !== undefined) registry.trace = registered; + }); + return true; +} + +/** + * What the registry holds once eve has had its say. + * + * A proxy provider is stored untouched and hooked at its delegate instead. + * `setGlobalTracerProvider` registers the proxy first and only then sets the + * real provider as its delegate, and a tracer taken before registration + * resolves through that same delegate — so hooking the delegate catches both, + * where wrapping the proxy would catch neither. + */ +function intercept( + current: InterceptionState, + provider: TracerProvider | undefined, +): TracerProvider | undefined { + if (provider === undefined) return undefined; + if (isDelegatingTracerProvider(provider)) { + hookDelegate(current, provider); + return provider; + } + current.provider = provider; + return wrapProvider(provider); +} + +/** + * eve's view of a registered provider: the Workflow SDK's tracer is suppressed + * outermost so a run's spans are never created at all, and every other tracer is + * observed on its way past. + */ +function wrapProvider(provider: TracerProvider): TracerProvider { + return suppressWorkflowInstrumentation(observeTracerProvider(provider, processorSource)); +} + +function hookDelegate(current: InterceptionState, proxy: DelegatingTracerProvider): void { + if (current.hooked.has(proxy)) return; + const descriptor = Object.getOwnPropertyDescriptor(proxy, "setDelegate"); + if (descriptor !== undefined && descriptor.configurable !== true) return; + current.hooked.add(proxy); + + const original = proxy.setDelegate; + // Tracked per proxy rather than read back off the shared state, which holds + // whichever provider registered last and may belong to another proxy. + let delegated: TracerProvider | undefined; + const observe = (delegate: TracerProvider): void => { + current.provider = delegate; + delegated = delegate; + original.call(proxy, wrapProvider(delegate)); + }; + Object.defineProperty(proxy, "setDelegate", { + configurable: true, + value: observe, + writable: true, + }); + current.undo.push(() => { + // `setDelegate` normally lives on the prototype, where deleting the override + // is enough; a proxy carrying it as an own property needs that property put + // back, or the release would leave the provider with no way to be set. + if (descriptor === undefined) delete (proxy as Partial).setDelegate; + else Object.defineProperty(proxy, "setDelegate", descriptor); + if (delegated !== undefined) proxy.setDelegate(delegated); + }); + + // A proxy that already has a delegate was registered before eve got here. + if (hasTracerProviderDelegate(proxy)) observe(proxy.getDelegate()); +} diff --git a/packages/eve/src/harness/local-instrumentation-runtime-conflict.scenario.test.ts b/packages/eve/src/harness/local-instrumentation-runtime-conflict.scenario.test.ts index 359100af2..bb954aaf0 100644 --- a/packages/eve/src/harness/local-instrumentation-runtime-conflict.scenario.test.ts +++ b/packages/eve/src/harness/local-instrumentation-runtime-conflict.scenario.test.ts @@ -1,30 +1,125 @@ -import { mkdtemp, rm } from "node:fs/promises"; +import { mkdtemp, readFile, readdir, rm } from "node:fs/promises"; import { tmpdir } from "node:os"; import { join } from "node:path"; -import { trace } from "@opentelemetry/api"; -import { BasicTracerProvider } from "@opentelemetry/sdk-trace-base"; +import { context, trace } from "@opentelemetry/api"; +import type { ReadableSpan } from "@opentelemetry/sdk-trace-base"; +import { registerOTel } from "@vercel/otel"; import { afterEach, describe, expect, it } from "vitest"; +import { + installGlobalTracerProviderInterception, + releaseGlobalTracerProviderInterception, +} from "#harness/intercept-global-tracer-provider.js"; import { installLocalInstrumentationRuntime } from "#harness/local-instrumentation-runtime.js"; let appRoot: string | undefined; afterEach(async () => { + releaseGlobalTracerProviderInterception(); if (appRoot !== undefined) await rm(appRoot, { force: true, recursive: true }); }); describe("local instrumentation runtime ownership", () => { - it("fails loudly when another global tracer provider already exists", async () => { + // Stands in for an authored `agent/instrumentation.ts`, which registers + // between eve's two dev plugins and resolves `@vercel/otel` and + // `@opentelemetry/api` from the agent's own dependencies rather than eve's + // vendored copies — the interception has to work across those two module + // instances. Only one test may install: the runtime is a process global and + // later calls reuse it. + it("observes an authored tracer provider without displacing it", async () => { appRoot = await mkdtemp(join(tmpdir(), "eve-local-traces-conflict-")); - expect(trace.setGlobalTracerProvider(new BasicTracerProvider())).toBe(true); - - expect(() => - installLocalInstrumentationRuntime({ - appRoot: appRoot!, - frameworkVersion: "test", - serviceName: "test-agent", - }), - ).toThrow(/another runtime already exists/u); + + expect(installGlobalTracerProviderInterception()).toBe(true); + + // Taken before anything registers a provider, which is what an authored + // module that acquires a tracer at import time does. The API hands back a + // proxy tracer bound to its own standby provider, so swapping the global + // provider after the fact could not reach it — only hooking the delegate. + const earlyTracer = trace.getTracer("test-agent"); + + const authoredSpans: string[] = []; + registerOTel({ + serviceName: "authored-agent", + spanProcessors: [ + { + forceFlush: async () => {}, + onEnd: (span: ReadableSpan) => void authoredSpans.push(span.name), + onStart: () => {}, + shutdown: async () => {}, + }, + ], + }); + + const runtime = installLocalInstrumentationRuntime({ + appRoot, + frameworkVersion: "test", + serviceName: "test-agent", + }); + expect(runtime).toBeDefined(); + + const span = earlyTracer.startSpan("agent.session", { + attributes: { "agent.session.id": "session-1" }, + }); + const traceId = span.spanContext().traceId; + + // The Workflow SDK asks the global API for a `workflow` tracer, so a run's + // internal spans arrive by the same route as everything else — and when a + // tool starts a run they are children of the agent's span, inside a trace eve + // owns. Interception declines to create them at all, so neither the local + // store nor the authored exporter receives them, and a span the SDK starts + // underneath one still lands on the agent's span. + const workflowSpan = trace + .getTracer("workflow") + .startSpan("step.execute", {}, trace.setSpan(context.active(), span)); + workflowSpan.end(); + span.end(); + await runtime!.forceFlush(); + + // The authored exporter keeps the agent's spans and no longer receives the + // run's, and eve additionally spools the agent-owned trace to disk. + expect(authoredSpans).toContain("agent.session"); + expect(authoredSpans).not.toContain("step.execute"); + expect(workflowSpan.spanContext()).toEqual(span.spanContext()); + + const stored = await readStoredTrace(appRoot, traceId); + expect(stored.spanNames).toEqual(["agent.session"]); + expect(stored.scopeNames).not.toContain("workflow"); }); }); + +interface StoredTrace { + readonly scopeNames: readonly string[]; + readonly spanNames: readonly string[]; +} + +async function readStoredTrace(appRoot: string, traceId: string): Promise { + const segmentsDirectory = join(appRoot, ".eve", "traces", "v1", traceId, "segments"); + const scopeNames: string[] = []; + const spanNames: string[] = []; + + for (const segment of await readdir(segmentsDirectory)) { + const payload = JSON.parse( + await readFile(join(segmentsDirectory, segment), "utf8"), + ) as OtlpSegment; + for (const resourceSpan of payload.resourceSpans ?? []) { + for (const scopeSpan of resourceSpan.scopeSpans ?? []) { + if (scopeSpan.scope?.name !== undefined) scopeNames.push(scopeSpan.scope.name); + for (const span of scopeSpan.spans ?? []) { + if (span.name !== undefined) spanNames.push(span.name); + } + } + } + } + + return { scopeNames, spanNames }; +} + +interface OtlpSegment { + readonly resourceSpans?: readonly { + readonly scopeSpans?: readonly { + readonly scope?: { readonly name?: string }; + readonly spans?: readonly { readonly name?: string }[]; + }[]; + }[]; +} diff --git a/packages/eve/src/harness/local-instrumentation-runtime-sampling.scenario.test.ts b/packages/eve/src/harness/local-instrumentation-runtime-sampling.scenario.test.ts new file mode 100644 index 000000000..470928279 --- /dev/null +++ b/packages/eve/src/harness/local-instrumentation-runtime-sampling.scenario.test.ts @@ -0,0 +1,43 @@ +import { mkdtemp, rm } from "node:fs/promises"; +import { tmpdir } from "node:os"; +import { join } from "node:path"; + +import { registerOTel } from "@vercel/otel"; +import { afterEach, describe, expect, it } from "vitest"; + +import { + installGlobalTracerProviderInterception, + releaseGlobalTracerProviderInterception, +} from "#harness/intercept-global-tracer-provider.js"; +import { installLocalInstrumentationRuntime } from "#harness/local-instrumentation-runtime.js"; + +let appRoot: string | undefined; + +afterEach(async () => { + releaseGlobalTracerProviderInterception(); + if (appRoot !== undefined) await rm(appRoot, { force: true, recursive: true }); +}); + +describe("local instrumentation runtime under an authored sampler", () => { + // eve used to confirm its own registration by starting a probe span and + // checking that its processor saw it. An authored sampler is free to drop + // that span, which made `eve dev` startup depend on a coin flip. Whether the + // writer installs is now independent of sampling — an `always_off` sampler + // is the extreme case, and the runtime still has to come up so agent context + // propagates and the authored exporter keeps working. + it("installs even when the authored sampler records nothing", async () => { + appRoot = await mkdtemp(join(tmpdir(), "eve-local-traces-sampling-")); + + expect(installGlobalTracerProviderInterception()).toBe(true); + + registerOTel({ serviceName: "authored-agent", traceSampler: "always_off" }); + + const runtime = installLocalInstrumentationRuntime({ + appRoot, + frameworkVersion: "test", + serviceName: "test-agent", + }); + + expect(runtime).toBeDefined(); + }); +}); diff --git a/packages/eve/src/harness/local-instrumentation-runtime.scenario.test.ts b/packages/eve/src/harness/local-instrumentation-runtime.scenario.test.ts index 329fe000b..13c5b970d 100644 --- a/packages/eve/src/harness/local-instrumentation-runtime.scenario.test.ts +++ b/packages/eve/src/harness/local-instrumentation-runtime.scenario.test.ts @@ -29,7 +29,8 @@ describe("local instrumentation runtime", () => { appRoot, frameworkVersion: "test", serviceName: "test-agent", - }); + })!; + expect(runtime).toBeDefined(); const scope: InstrumentationAttemptScope = { attemptId: "session-1:turn-1:0:0", attemptIndex: 0, diff --git a/packages/eve/src/harness/local-instrumentation-runtime.ts b/packages/eve/src/harness/local-instrumentation-runtime.ts index 63d889e26..82e09ba46 100644 --- a/packages/eve/src/harness/local-instrumentation-runtime.ts +++ b/packages/eve/src/harness/local-instrumentation-runtime.ts @@ -1,9 +1,14 @@ import { context, trace } from "#compiled/@opentelemetry/api/index.js"; import { registerOTel } from "#compiled/@vercel/otel/index.js"; -import { ContextAgentTraceStateStore } from "#harness/agent-trace-context-store.js"; import { createAgentOtelInstrumentation } from "#harness/agent-otel-provider.js"; +import { ContextAgentTraceStateStore } from "#harness/agent-trace-context-store.js"; import { AgentTraceSpanProcessor } from "#harness/agent-trace-span-processor.js"; +import { + hasTracerProviderDelegate, + isDelegatingTracerProvider, +} from "#harness/delegating-tracer-provider.js"; +import { attachInterceptedSpanProcessor } from "#harness/intercept-global-tracer-provider.js"; import { createInstrumentationHooks, type InstrumentationProviderDefinition, @@ -18,13 +23,23 @@ import { resolveLocalTraceRetentionSettings, } from "#harness/local-trace-retention.js"; import { LocalTraceSpanProcessor } from "#harness/local-trace-span-processor.js"; +import { createLogger } from "#internal/logging.js"; + +const log = createLogger("harness.local-instrumentation-runtime"); -/** Installs the zero-config local OTel runtime once in an `eve dev` worker. */ +/** + * Installs the zero-config local OTel runtime once in an `eve dev` worker. + * + * Returns `undefined` when eve cannot observe spans — no provider it can reach, + * or no context manager to propagate agent context. Local tracing is a + * development convenience, so it declines rather than taking down a dev server + * whose authored instrumentation is otherwise working. + */ export function installLocalInstrumentationRuntime(input: { readonly appRoot: string; readonly frameworkVersion: string; readonly serviceName: string; -}): InstrumentationRuntime { +}): InstrumentationRuntime | undefined { const existing = getInstrumentationRuntime(); if (existing !== undefined) return existing; @@ -34,19 +49,40 @@ export function installLocalInstrumentationRuntime(input: { const processor = new AgentTraceSpanProcessor( retention.enabled ? [new LocalTraceSpanProcessor(input.appRoot)] : [], ); - registerOTel({ - autoDetectResources: false, - instrumentations: [], - propagators: ["none"], - serviceName: input.serviceName, - spanProcessors: [processor], - }); - const probe = trace.getTracer("eve.registration").startSpan("eve.otel.registration"); - const activeContext = trace.setSpan(context.active(), probe); - const contextAttached = context.with(activeContext, () => trace.getActiveSpan() === probe); - probe.end(); - if (!processor.isAttached() || !contextAttached) { - throw new Error("eve could not register OpenTelemetry because another runtime already exists."); + // A provider an authored `instrumentation.ts` registered is observed rather + // than displaced, so its exporter keeps everything it had. Only an unclaimed + // process gets a provider of eve's own; declining hands the global slot back + // first, so eve's own provider is registered unobserved and reports once. + if (!attachInterceptedSpanProcessor(processor)) { + registerOTel({ + autoDetectResources: false, + instrumentations: [], + propagators: ["none"], + serviceName: input.serviceName, + spanProcessors: [processor], + }); + // Global registration demands an exact API version match, so an agent + // whose own `@opentelemetry/api` is a different patch release than eve's + // vendored copy owns the registry outright and refuses eve's provider. + // `registerOTel` reports that through the diag logger and returns anyway, + // which would leave a runtime here backed by a no-op tracer. + if (!hasRegisteredTracerProvider()) { + log.warn( + "eve could not register an OpenTelemetry tracer provider, so local traces are not being recorded in this dev worker.", + ); + return undefined; + } + } + // Spans reach the processor by construction, so there is nothing to probe + // there — and probing with a real span would make startup depend on the + // authored sampler, which is free to drop it. A context manager is the one + // thing eve cannot arrange itself: without one, agent context does not + // propagate and AI SDK spans would not nest under `agent.step`. + if (!hasContextManager()) { + log.warn( + "eve could not propagate OpenTelemetry context, so local traces are not being recorded in this dev worker.", + ); + return undefined; } const agentOtel = createAgentOtelInstrumentation({ frameworkVersion: input.frameworkVersion, @@ -89,3 +125,34 @@ export function installLocalInstrumentationRuntime(input: { }); } } + +/** + * Whether a context manager is registered, tested without creating a real + * span. + * + * `wrapSpanContext` builds a span the API owns outright, so the answer does not + * depend on any provider's sampler and no probe span reaches an exporter. + */ +function hasContextManager(): boolean { + const probe = trace.wrapSpanContext({ + spanId: "1".repeat(16), + traceFlags: 0, + traceId: "1".repeat(32), + }); + return context.with( + trace.setSpan(context.active(), probe), + () => trace.getActiveSpan() === probe, + ); +} + +/** + * Whether the global tracer provider resolves to something that can make spans. + * + * A provider that delegates says so through its delegate, since the API hands + * back a standby proxy even when nothing is registered. + */ +function hasRegisteredTracerProvider(): boolean { + const provider = trace.getTracerProvider(); + if (!isDelegatingTracerProvider(provider)) return true; + return hasTracerProviderDelegate(provider); +} diff --git a/packages/eve/src/harness/observe-tracer-provider.test.ts b/packages/eve/src/harness/observe-tracer-provider.test.ts new file mode 100644 index 000000000..e9b174403 --- /dev/null +++ b/packages/eve/src/harness/observe-tracer-provider.test.ts @@ -0,0 +1,243 @@ +import { describe, expect, it } from "vitest"; + +import type { + Context, + Span, + SpanOptions, + Tracer, + TracerProvider, +} from "#compiled/@opentelemetry/api/index.js"; +import type { SpanProcessor } from "#compiled/@vercel/otel/index.js"; +import { observeTracerProvider } from "#harness/observe-tracer-provider.js"; + +describe("observeTracerProvider", () => { + it("routes spans from the observed provider through the processor", () => { + const { events, processor } = createRecordingProcessor(); + const provider = observeTracerProvider(createInnerProvider(events), () => processor); + + provider.getTracer("authored").startSpan("authored.work").end(); + + expect(events).toEqual(["start:authored.work", "inner-end:authored.work", "end:authored.work"]); + }); + + it("ends the underlying span exactly once", () => { + const { events, processor } = createRecordingProcessor(); + const provider = observeTracerProvider(createInnerProvider(events), () => processor); + + const span = provider.getTracer("authored").startSpan("authored.work"); + span.end(); + span.end(); + + expect(events.filter((event) => event.startsWith("inner-end"))).toHaveLength(1); + expect(events.filter((event) => event.startsWith("end:"))).toHaveLength(1); + }); + + it("leaves sampled-out spans alone", () => { + const { events, processor } = createRecordingProcessor(); + const provider = observeTracerProvider( + createInnerProvider([], { recording: false }), + () => processor, + ); + + provider.getTracer("authored").startSpan("authored.work").end(); + + expect(events).toEqual([]); + }); + + // Interception is installed before the trace writer exists, so the window + // between them has to be a pass-through rather than a crash. + it("passes spans through while no processor is attached", () => { + const events: string[] = []; + const provider = observeTracerProvider(createInnerProvider(events), () => undefined); + + provider.getTracer("authored").startSpan("authored.work").end(); + + expect(events).toEqual(["inner-end:authored.work"]); + }); + + // Context activation itself needs a registered context manager, so the + // scenario tier proves the nesting; this covers the observation wiring. + it("observes startActiveSpan spans and returns the callback result", () => { + const { events, processor } = createRecordingProcessor(); + const provider = observeTracerProvider(createInnerProvider(events), () => processor); + const tracer = provider.getTracer("authored") as Tracer & { + startActiveSpan: (name: string, callback: (span: Span) => unknown) => unknown; + }; + + const result = tracer.startActiveSpan("authored.work", (span) => { + span.end(); + return "done"; + }); + + expect(result).toBe("done"); + expect(events).toEqual(["start:authored.work", "inner-end:authored.work", "end:authored.work"]); + }); + + // A tracer's identity is (name, version, options) including options.schemaUrl, + // so there is no key eve can cache on without handing back a wrapper over the + // wrong delegate tracer. + it("wraps each requested tracer independently", () => { + const { events, processor } = createRecordingProcessor(); + const provider = observeTracerProvider(createInnerProvider(events), () => processor); + + expect(provider.getTracer("authored", "1")).not.toBe(provider.getTracer("authored", "1")); + + provider + .getTracer("authored", "1", { schemaUrl: "https://example.test/a" }) + .startSpan("a") + .end(); + provider + .getTracer("authored", "1", { schemaUrl: "https://example.test/b" }) + .startSpan("b") + .end(); + + expect(events.filter((event) => event.startsWith("start:"))).toEqual(["start:a", "start:b"]); + }); + + describe("span ownership", () => { + it("does not mutate the span it observes", () => { + const { events, processor } = createRecordingProcessor(); + const raw = createSpan("authored.work", events, true); + const originalEnd = raw.end; + const provider = observeTracerProvider( + { getTracer: () => ({ startSpan: () => raw }) }, + () => processor, + ); + + const observed = provider.getTracer("authored").startSpan("authored.work"); + observed.end(); + + expect(observed).not.toBe(raw); + expect(Object.hasOwn(raw, "end")).toBe(false); + expect(raw.end).toBe(originalEnd); + }); + + // The OTel API contracts nothing about spans being extensible. Assigning + // over `end` used to be how eve observed them, which threw here. + it("observes a frozen span whose end comes from its prototype", () => { + const { events, processor } = createRecordingProcessor(); + const provider = observeTracerProvider(createFrozenSpanProvider(events), () => processor); + + const span = provider.getTracer("authored").startSpan("authored.work"); + span.setAttribute("key", "value").end(); + + expect(events).toEqual([ + "start:authored.work", + "inner-end:authored.work", + "end:authored.work", + ]); + }); + + // A frozen own `end` cannot be substituted by a proxy at all, so eve + // declines the span rather than throwing on the way past. + it("declines a span whose end cannot be intercepted", () => { + const { events, processor } = createRecordingProcessor(); + const provider = observeTracerProvider(createSealedEndProvider(events), () => processor); + + provider.getTracer("authored").startSpan("authored.work").end(); + + // The span still works; eve simply reports neither half of it. + expect(events).toEqual(["inner-end:authored.work"]); + }); + + it("forwards data properties to the observed span", () => { + const { processor } = createRecordingProcessor(); + const provider = observeTracerProvider(createInnerProvider([]), () => processor); + + const span = provider.getTracer("authored").startSpan("authored.work") as Span & { + name: string; + }; + + expect(span.name).toBe("authored.work"); + expect(span.spanContext().traceId).toBe("a".repeat(32)); + }); + }); +}); + +function createRecordingProcessor(): { events: string[]; processor: SpanProcessor } { + const events: string[] = []; + return { + events, + processor: { + forceFlush: async () => {}, + onEnd: (span: unknown) => void events.push(`end:${(span as { name: string }).name}`), + onStart: (span: unknown) => void events.push(`start:${(span as { name: string }).name}`), + shutdown: async () => {}, + }, + }; +} + +function createInnerProvider( + events: string[], + options: { recording?: boolean } = {}, +): TracerProvider { + return { + getTracer(): Tracer { + return { + startSpan(name: string, _options?: SpanOptions, _parentContext?: Context): Span { + return createSpan(name, events, options.recording ?? true); + }, + }; + }, + }; +} + +/** Methods on a prototype, instance frozen: what a hardened SDK span looks like. */ +function createFrozenSpanProvider(events: string[]): TracerProvider { + return { + getTracer(): Tracer { + return { + startSpan(name: string): Span { + return Object.freeze(createSpan(name, events, true)); + }, + }; + }, + }; +} + +/** `end` as a frozen own property, which no proxy is allowed to substitute. */ +function createSealedEndProvider(events: string[]): TracerProvider { + return { + getTracer(): Tracer { + return { + startSpan(name: string): Span { + const span = createSpan(name, events, true); + Object.defineProperty(span, "end", { + configurable: false, + value: () => void events.push(`inner-end:${name}`), + writable: false, + }); + return span; + }, + }; + }, + }; +} + +function createSpan(name: string, events: string[], recording: boolean): Span & { name: string } { + // Prototype-held methods, as every real span implementation has. + const behavior = { + addEvent(this: Span): Span { + return this; + }, + end(): void { + events.push(`inner-end:${name}`); + }, + isRecording(): boolean { + return recording; + }, + recordException(): void {}, + setAttribute(this: Span): Span { + return this; + }, + setStatus(this: Span): Span { + return this; + }, + spanContext() { + return { spanId: "b".repeat(16), traceFlags: 1, traceId: "a".repeat(32) }; + }, + }; + return Object.create(behavior, { name: { enumerable: true, value: name } }) as Span & { + name: string; + }; +} diff --git a/packages/eve/src/harness/observe-tracer-provider.ts b/packages/eve/src/harness/observe-tracer-provider.ts new file mode 100644 index 000000000..036eca15c --- /dev/null +++ b/packages/eve/src/harness/observe-tracer-provider.ts @@ -0,0 +1,143 @@ +import { + context, + trace, + type Context, + type Span, + type SpanOptions, + type Tracer, + type TracerProvider, +} from "#compiled/@opentelemetry/api/index.js"; +import type { SpanProcessor } from "#compiled/@vercel/otel/index.js"; + +/** + * Resolves the processor to report to, at the moment a span is created. + * + * Late-bound because eve wraps tracer providers before it knows whether a + * local trace writer will exist: interception is installed ahead of authored + * `setup()` so no tracer escapes, while the processor is only built once the + * dev worker's trace store settings are known. Returns `undefined` until then, + * and spans created in that window are passed through untouched. + */ +export type SpanProcessorSource = () => SpanProcessor | undefined; + +/** + * Wraps a tracer provider so every span its tracers create is also reported to + * `source()`. + * + * Tracers are wrapped per call rather than memoised: a tracer's identity is + * `(name, version, options)` including `options.schemaUrl`, and a cache keyed + * on anything less hands back a wrapper over the wrong delegate tracer. + * Callers that care about tracer identity hold onto the tracer themselves. + * + * Forwarding only `getTracer` loses nothing a caller could reach: the API hands + * out `ProxyTracerProvider`, whose own surface is `getTracer` and its delegate + * accessors, so `forceFlush` and `shutdown` were never reachable through the + * global. Whoever built the provider still holds it and can flush it directly. + */ +export function observeTracerProvider( + delegate: TracerProvider, + source: SpanProcessorSource, +): TracerProvider { + return { + getTracer(name: string, version?: string, options?: unknown): Tracer { + return observeTracer(delegate.getTracer(name, version, options), source); + }, + }; +} + +/** + * `startActiveSpan` is reimplemented over `startSpan` rather than delegated so + * that every span the tracer hands out passes through {@link observeSpan}; a + * delegated call would create the span inside the wrapped tracer, out of reach. + */ +export function observeTracer(delegate: Tracer, source: SpanProcessorSource): Tracer { + const tracer = { + startSpan(name: string, options?: SpanOptions, parentContext?: Context): Span { + const parent = parentContext ?? context.active(); + return observeSpan(delegate.startSpan(name, options, parent), source, parent); + }, + + startActiveSpan(name: string, ...rest: readonly unknown[]): unknown { + const callback = rest.at(-1); + if (typeof callback !== "function") { + throw new TypeError("startActiveSpan requires a callback as its last argument."); + } + const [options, parentContext] = rest.slice(0, -1) as [SpanOptions?, Context?]; + const parent = parentContext ?? context.active(); + const span = tracer.startSpan(name, options, parent); + return context.with(trace.setSpan(parent, span), () => callback(span)); + }, + }; + + return tracer; +} + +/** + * Reports `span` to the processor without taking ownership of it. + * + * The span belongs to whoever created it, so it is proxied rather than + * mutated: the OpenTelemetry API contracts nothing about a span being + * extensible, and assigning over `end` would throw on a frozen or + * accessor-backed implementation. Everything except `end` forwards to the real + * span, so the provider's own processors and exporters see exactly the object + * they always did. + */ +export function observeSpan(span: Span, source: SpanProcessorSource, parentContext: Context): Span { + const processor = source(); + if (processor === undefined) return span; + // A sampled-out span carries no attributes or timings, so there is nothing + // for a processor to record and no trace for it to belong to. + if (span.isRecording?.() === false) return span; + // Nothing eve can do with a span whose `end` it cannot see: report neither + // half rather than a start with no end. + if (!isSubstitutable(span, "end")) return span; + + processor.onStart(span, parentContext); + + let ended = false; + const end = (endTime?: number): void => { + if (ended) return; + ended = true; + // The real `end` first: it stamps the end time and runs the observed + // provider's own processors, so both sides see a finished span. + span.end(endTime); + processor.onEnd(span); + }; + + const forwarded = new Map(); + const observed: Span = new Proxy(span, { + get(target, property) { + if (property === "end") return end; + const cached = forwarded.get(property); + if (cached !== undefined) return cached; + // Read and call with the real span as the receiver: an implementation + // backed by private fields throws when they are reached through a proxy. + const value = Reflect.get(target, property, target); + if (typeof value !== "function" || !isSubstitutable(target, property)) return value; + const method = (...args: readonly unknown[]): unknown => { + const result = value.apply(target, args); + // Chainable setters return the span itself; hand back the wrapper so a + // chain ending in `.end()` still routes through it. + return result === target ? observed : result; + }; + forwarded.set(property, method); + return method; + }, + }); + + return observed; +} + +/** + * Whether a proxy may return something other than `target[property]`. + * + * A proxy is forbidden from substituting a non-configurable, non-writable own + * data property — reading one through the trap throws instead. Spans normally + * carry their methods on a prototype, where the rule does not apply, so this + * only ever declines for a frozen span. + */ +function isSubstitutable(target: object, property: string | symbol): boolean { + const descriptor = Object.getOwnPropertyDescriptor(target, property); + if (descriptor === undefined) return true; + return descriptor.configurable === true || descriptor.writable === true; +} diff --git a/packages/eve/src/harness/workflow-instrumentation-scope.ts b/packages/eve/src/harness/workflow-instrumentation-scope.ts new file mode 100644 index 000000000..39f258c20 --- /dev/null +++ b/packages/eve/src/harness/workflow-instrumentation-scope.ts @@ -0,0 +1,14 @@ +// Kept in a module of its own, with no imports, because `AgentTraceSpanProcessor` +// reads it and is reachable from the graph eve bundles an authored module out of. +// Importing it from `workflow-instrumentation.ts` would pull the vendored +// `@opentelemetry/api` bundle in behind it, and that bundle's CommonJS shims do +// not survive being nested inside an authored bundle. + +/** + * The instrumentation scope name the Workflow SDK reports its spans under. + * + * `@workflow/core` takes a tracer named `workflow` from the global API, so this + * is the name on every span a run creates — both the ones eve declines to + * create and the ones it filters on the way to the local store. + */ +export const WORKFLOW_INSTRUMENTATION_SCOPE = "workflow"; diff --git a/packages/eve/src/harness/workflow-instrumentation.test.ts b/packages/eve/src/harness/workflow-instrumentation.test.ts new file mode 100644 index 000000000..d8f6e2a8a --- /dev/null +++ b/packages/eve/src/harness/workflow-instrumentation.test.ts @@ -0,0 +1,102 @@ +import { describe, expect, it } from "vitest"; + +import { + ROOT_CONTEXT, + trace, + type Context, + type Span, + type SpanOptions, + type Tracer, + type TracerProvider, +} from "#compiled/@opentelemetry/api/index.js"; +import { suppressWorkflowInstrumentation } from "#harness/workflow-instrumentation.js"; + +const PARENT_SPAN_CONTEXT = { spanId: "b".repeat(16), traceFlags: 1, traceId: "a".repeat(32) }; + +describe("suppressWorkflowInstrumentation", () => { + it("creates no span for the Workflow SDK's tracer", () => { + const started: string[] = []; + const provider = suppressWorkflowInstrumentation(createProvider(started)); + + const span = provider.getTracer("workflow").startSpan("step.execute"); + span.end(); + + expect(started).toEqual([]); + expect(span.isRecording?.()).toBe(false); + }); + + it("passes every other tracer through untouched", () => { + const started: string[] = []; + const inner = createProvider(started); + const provider = suppressWorkflowInstrumentation(inner); + + provider.getTracer("authored").startSpan("authored.work").end(); + provider.getTracer("eve.agent", "1.2.3").startSpan("agent.session").end(); + + expect(started).toEqual(["authored.work", "agent.session"]); + }); + + // A span the SDK starts under a suppressed one has to reach the agent's span, + // not fall out of the trace: `agent.step` stays the parent of the model call + // inside it even when the step ran inside a durable step. + it("hands a suppressed span its parent's context so descendants reparent", () => { + const provider = suppressWorkflowInstrumentation(createProvider([])); + const parent = trace.setSpan(ROOT_CONTEXT, trace.wrapSpanContext(PARENT_SPAN_CONTEXT)); + + const span = provider.getTracer("workflow").startSpan("step.execute", {}, parent); + + expect(span.spanContext()).toEqual(PARENT_SPAN_CONTEXT); + }); + + it("gives a root span no context to inherit", () => { + const provider = suppressWorkflowInstrumentation(createProvider([])); + const parent = trace.setSpan(ROOT_CONTEXT, trace.wrapSpanContext(PARENT_SPAN_CONTEXT)); + + const span = provider + .getTracer("workflow") + .startSpan("workflow.route.flow", { root: true }, parent); + + expect(span.spanContext().traceId).toBe("0".repeat(32)); + }); + + // `@workflow/core` wraps its steps with `startActiveSpan` and depends on the + // callback's return value, so suppression has to implement it rather than + // leave the tracer without it. + it("runs a suppressed startActiveSpan callback and returns its result", () => { + const started: string[] = []; + const provider = suppressWorkflowInstrumentation(createProvider(started)); + const tracer = provider.getTracer("workflow") as Tracer & { + startActiveSpan: (name: string, callback: (span: Span) => unknown) => unknown; + }; + + const result = tracer.startActiveSpan("step.execute", (span) => { + span.end(); + return "done"; + }); + + expect(result).toBe("done"); + expect(started).toEqual([]); + }); + + it("rejects a startActiveSpan call with no callback", () => { + const provider = suppressWorkflowInstrumentation(createProvider([])); + const tracer = provider.getTracer("workflow") as Tracer & { + startActiveSpan: (name: string) => unknown; + }; + + expect(() => tracer.startActiveSpan("step.execute")).toThrow(TypeError); + }); +}); + +function createProvider(started: string[]): TracerProvider { + return { + getTracer(): Tracer { + return { + startSpan(name: string, _options?: SpanOptions, _parentContext?: Context): Span { + started.push(name); + return trace.wrapSpanContext(PARENT_SPAN_CONTEXT); + }, + }; + }, + }; +} diff --git a/packages/eve/src/harness/workflow-instrumentation.ts b/packages/eve/src/harness/workflow-instrumentation.ts new file mode 100644 index 000000000..f19857a66 --- /dev/null +++ b/packages/eve/src/harness/workflow-instrumentation.ts @@ -0,0 +1,70 @@ +import { + INVALID_SPAN_CONTEXT, + context, + trace, + type Context, + type Span, + type SpanOptions, + type Tracer, + type TracerProvider, +} from "#compiled/@opentelemetry/api/index.js"; + +import { WORKFLOW_INSTRUMENTATION_SCOPE } from "#harness/workflow-instrumentation-scope.js"; + +/** + * Wraps a tracer provider so the Workflow SDK's tracer creates no spans. + * + * A durable run's internals — `step.execute`, `step.hydrate`, `queue.publish` — + * describe how eve executes a turn rather than what the agent did, and they land + * in the agent's own trace because a turn runs inside a step. eve keeps them out + * of `.eve/traces/v1` by filtering at its writer, but a writer-side filter can + * do nothing for an authored `instrumentation.ts`: the author's provider creates + * the span, so the only way its exporter never receives one is for the span not + * to exist. Scope is known at `getTracer` time, which is before it does. + * + * `eve dev` only, alongside the interception it composes with; production + * registers no wrapper and is unchanged. + */ +export function suppressWorkflowInstrumentation(delegate: TracerProvider): TracerProvider { + return { + getTracer(name: string, version?: string, options?: unknown): Tracer { + if (name === WORKFLOW_INSTRUMENTATION_SCOPE) return createSuppressedTracer(); + return delegate.getTracer(name, version, options); + }, + }; +} + +/** + * A tracer whose spans record nothing and reach no exporter. + * + * Each span carries its parent's span context instead of an empty one, so a span + * started under a suppressed span becomes a child of the nearest ancestor that + * was not suppressed and inherits the sampling decision already made upstream. + * Suppressed spans drop out of the tree rather than detaching everything below + * them. + */ +export function createSuppressedTracer(): Tracer { + const tracer = { + startSpan(_name: string, options?: SpanOptions, parentContext?: Context): Span { + if (options?.root === true) return trace.wrapSpanContext(INVALID_SPAN_CONTEXT); + const parent = parentContext ?? context.active(); + return trace.wrapSpanContext(trace.getSpanContext(parent) ?? INVALID_SPAN_CONTEXT); + }, + + startActiveSpan(name: string, ...rest: readonly unknown[]): unknown { + const callback = rest.at(-1); + if (typeof callback !== "function") { + throw new TypeError("startActiveSpan requires a callback as its last argument."); + } + const [options, parentContext] = rest.slice(0, -1) as [SpanOptions?, Context?]; + const parent = parentContext ?? context.active(); + const span = tracer.startSpan(name, options, parent); + // Activated even though it records nothing: code inside the callback is + // free to read the active span, and the context it resolves through has to + // be the one the suppressed span carries. + return context.with(trace.setSpan(parent, span), () => callback(span)); + }, + }; + + return tracer; +} diff --git a/packages/eve/src/internal/application/compiled-artifacts.ts b/packages/eve/src/internal/application/compiled-artifacts.ts index 81114d440..e358a659f 100644 --- a/packages/eve/src/internal/application/compiled-artifacts.ts +++ b/packages/eve/src/internal/application/compiled-artifacts.ts @@ -391,7 +391,9 @@ function createInstrumentationPluginSource(input: { `import { registerInstrumentationConfig } from ${stringifyEsmImportSpecifier(input.registerConfigPath)};`, "", "if (instrumentationModule.default != null) {", - ` registerInstrumentationConfig(instrumentationModule.default, { agentName: ${JSON.stringify(input.agentName)} });`, + // Awaited at module scope: an `async setup` must finish registering before + // any later plugin looks for a tracer provider. + ` await registerInstrumentationConfig(instrumentationModule.default, { agentName: ${JSON.stringify(input.agentName)} });`, "}", "", "// Default export satisfies the Nitro plugin contract so this file", diff --git a/packages/eve/src/internal/nitro/host/create-application-nitro.scenario.test.ts b/packages/eve/src/internal/nitro/host/create-application-nitro.scenario.test.ts index 919138520..f247eb1da 100644 --- a/packages/eve/src/internal/nitro/host/create-application-nitro.scenario.test.ts +++ b/packages/eve/src/internal/nitro/host/create-application-nitro.scenario.test.ts @@ -209,7 +209,10 @@ describe("application Nitro creation", () => { ); }); - it("preserves authored instrumentation instead of installing local tracing", async () => { + // Authored instrumentation is bracketed: eve claims the tracer provider + // before it registers one and installs the trace writer after its setup has + // resolved. + it("brackets authored instrumentation with interception and the trace writer", async () => { const nitroStub = createNitroStub(); createNitroMock.mockResolvedValueOnce(nitroStub.nitro); const { createDevelopmentApplicationNitro } = @@ -220,9 +223,34 @@ describe("application Nitro creation", () => { await createDevelopmentApplicationNitro(preparedHost); const plugins = createNitroMock.mock.calls[0]?.[0].plugins as string[]; - expect(plugins).toContain("/app/instrumentation.mjs"); - expect(plugins).not.toEqual( - expect.arrayContaining([expect.stringContaining("local-tracing-runtime-plugin.ts")]), + const interception = plugins.findIndex((plugin) => + plugin.includes("local-tracing-interception-plugin.ts"), + ); + const localTracing = plugins.findIndex((plugin) => + plugin.includes("local-tracing-runtime-plugin.ts"), + ); + const authored = plugins.indexOf("/app/instrumentation.mjs"); + + // First, not merely before the authored plugin: interception runs at module + // scope and has to be in place before any other plugin module body can + // register a provider. + expect(interception).toBe(0); + expect(interception).toBeLessThan(authored); + expect(authored).toBeLessThan(localTracing); + expect(localTracing).toBe(plugins.length - 1); + }); + + it("installs no interception plugin when the agent authors no instrumentation", async () => { + const nitroStub = createNitroStub(); + createNitroMock.mockResolvedValueOnce(nitroStub.nitro); + const { createDevelopmentApplicationNitro } = + await import("#internal/nitro/host/create-application-nitro.js"); + + await createDevelopmentApplicationNitro(createPreparedHost()); + + const plugins = createNitroMock.mock.calls[0]?.[0].plugins as string[]; + expect(plugins.some((plugin) => plugin.includes("local-tracing-interception-plugin.ts"))).toBe( + false, ); }); diff --git a/packages/eve/src/internal/nitro/host/create-application-nitro.ts b/packages/eve/src/internal/nitro/host/create-application-nitro.ts index 89e78ca19..272aa71b8 100644 --- a/packages/eve/src/internal/nitro/host/create-application-nitro.ts +++ b/packages/eve/src/internal/nitro/host/create-application-nitro.ts @@ -739,10 +739,20 @@ export async function createDevelopmentApplicationNitro( const nitroBuildDir = preparedHost.workspace.nitroBuildDir; const bundler = createApplicationNitroBundlerConfiguration(preparedHost, undefined); const plugins = createApplicationNitroPlugins(preparedHost); + const localTracingPlugin = resolvePackageSourceFilePath( + "src/internal/nitro/host/local-tracing-runtime-plugin.ts", + ); + // Local tracing is always on in dev. Authored instrumentation is bracketed: + // eve claims the global tracer-provider slot from the first plugin module, so + // no tracer the authored `setup` creates escapes, and hands the trace writer + // over from the last plugin, so the two never race to be the global provider. if (preparedHost.compiledArtifacts.instrumentationPluginPath === undefined) { + plugins.unshift(localTracingPlugin); + } else { plugins.unshift( - resolvePackageSourceFilePath("src/internal/nitro/host/local-tracing-runtime-plugin.ts"), + resolvePackageSourceFilePath("src/internal/nitro/host/local-tracing-interception-plugin.ts"), ); + plugins.push(localTracingPlugin); } await prepareEveVersionedCacheDirectory(nitroBuildDir); diff --git a/packages/eve/src/internal/nitro/host/local-tracing-interception-plugin.ts b/packages/eve/src/internal/nitro/host/local-tracing-interception-plugin.ts new file mode 100644 index 000000000..b7438bf6e --- /dev/null +++ b/packages/eve/src/internal/nitro/host/local-tracing-interception-plugin.ts @@ -0,0 +1,18 @@ +import { installGlobalTracerProviderInterception } from "#harness/intercept-global-tracer-provider.js"; + +/** + * Claims the global tracer-provider slot before authored `instrumentation.ts` + * runs, so eve observes tracers the authored `setup()` creates as well as ones + * created later. `local-tracing-runtime-plugin.ts` runs after that setup and + * hands the trace writer over. + * + * Deliberately at module scope, and first in the plugin list: this has to be in + * place before any other plugin module body can register a provider. + * + * Only added to the dev host when the agent authors an `instrumentation.ts`; + * with no author to race, the trace-writer plugin registers a provider of its + * own and needs no interception. + */ +installGlobalTracerProviderInterception(); + +export default function installLocalTracingInterceptionPlugin(): void {} diff --git a/packages/eve/src/internal/nitro/host/local-tracing-runtime-plugin.scenario.test.ts b/packages/eve/src/internal/nitro/host/local-tracing-runtime-plugin.scenario.test.ts new file mode 100644 index 000000000..8b7bc1c2c --- /dev/null +++ b/packages/eve/src/internal/nitro/host/local-tracing-runtime-plugin.scenario.test.ts @@ -0,0 +1,35 @@ +import { mkdtemp, rm } from "node:fs/promises"; +import { tmpdir } from "node:os"; +import { join } from "node:path"; + +import { afterEach, describe, expect, it } from "vitest"; + +import { getInstrumentationRuntime } from "#harness/instrumentation-runtime.js"; +import { DEVELOPMENT_WORKER_APP_ROOT_ENV } from "#internal/workflow/development-world-protocol.js"; + +let appRoot: string | undefined; + +afterEach(async () => { + delete process.env[DEVELOPMENT_WORKER_APP_ROOT_ENV]; + if (appRoot !== undefined) await rm(appRoot, { force: true, recursive: true }); +}); + +describe("local tracing runtime plugin", () => { + // The barrier that lets eve run after an authored `instrumentation.ts` whose + // `setup` is async. Nitro imports every plugin as a static sibling, so a + // module body cannot wait on one suspended at a top-level await; plugin bodies + // run only once the whole graph has settled. Installing from module scope + // would put eve's provider in ahead of the authored one. + it("installs the runtime from the plugin body, not on import", async () => { + appRoot = await mkdtemp(join(tmpdir(), "eve-local-tracing-plugin-")); + process.env[DEVELOPMENT_WORKER_APP_ROOT_ENV] = appRoot; + + const { default: installLocalTracingRuntimePlugin } = + await import("#internal/nitro/host/local-tracing-runtime-plugin.js"); + expect(getInstrumentationRuntime()).toBeUndefined(); + + installLocalTracingRuntimePlugin(); + + expect(getInstrumentationRuntime()).toBeDefined(); + }); +}); diff --git a/packages/eve/src/internal/nitro/host/local-tracing-runtime-plugin.ts b/packages/eve/src/internal/nitro/host/local-tracing-runtime-plugin.ts index af0ca6d37..0b58e5116 100644 --- a/packages/eve/src/internal/nitro/host/local-tracing-runtime-plugin.ts +++ b/packages/eve/src/internal/nitro/host/local-tracing-runtime-plugin.ts @@ -4,15 +4,26 @@ import { installLocalInstrumentationRuntime } from "#harness/local-instrumentati import { resolveInstalledPackageInfo } from "#internal/application/package.js"; import { DEVELOPMENT_WORKER_APP_ROOT_ENV } from "#internal/workflow/development-world-protocol.js"; -const appRoot = process.env[DEVELOPMENT_WORKER_APP_ROOT_ENV]; -if (appRoot === undefined) { - throw new Error(`${DEVELOPMENT_WORKER_APP_ROOT_ENV} is required for local tracing.`); -} - -installLocalInstrumentationRuntime({ - appRoot, - frameworkVersion: resolveInstalledPackageInfo().version, - serviceName: basename(appRoot), -}); +/** + * Installs the local trace writer, from the plugin body rather than at module + * scope. + * + * That is what serializes eve behind an authored `instrumentation.ts` whose + * `setup` is `async`. Nitro imports every plugin as a static sibling, so a + * plugin suspended at a top-level `await` does not hold up the next module's + * evaluation — import order alone is no barrier. Plugin bodies run only once + * the whole plugin graph has settled, so by the time this one is called the + * authored provider is registered. + */ +export default function installLocalTracingRuntimePlugin(): void { + const appRoot = process.env[DEVELOPMENT_WORKER_APP_ROOT_ENV]; + if (appRoot === undefined) { + throw new Error(`${DEVELOPMENT_WORKER_APP_ROOT_ENV} is required for local tracing.`); + } -export default function installLocalTracingRuntimePlugin(): void {} + installLocalInstrumentationRuntime({ + appRoot, + frameworkVersion: resolveInstalledPackageInfo().version, + serviceName: basename(appRoot), + }); +} diff --git a/packages/eve/src/public/instrumentation/index.ts b/packages/eve/src/public/instrumentation/index.ts index 0e73ace9e..01c0803c9 100644 --- a/packages/eve/src/public/instrumentation/index.ts +++ b/packages/eve/src/public/instrumentation/index.ts @@ -157,8 +157,11 @@ export interface InstrumentationDefinition { * Setup callback invoked at server startup with the resolved agent name. * Use it to call `registerOTel` or other OTel provider setup; * `context.agentName` comes from `defineAgent`. + * + * May be `async`; eve awaits it before serving any request, so a provider + * registered after an `await` is still in place for the first turn. */ - readonly setup?: (context: InstrumentationSetupContext) => void; + readonly setup?: (context: InstrumentationSetupContext) => void | Promise; } /** diff --git a/packages/eve/test/scenarios/authored-instrumentation-tracing.scenario.test.ts b/packages/eve/test/scenarios/authored-instrumentation-tracing.scenario.test.ts new file mode 100644 index 000000000..4c9a235db --- /dev/null +++ b/packages/eve/test/scenarios/authored-instrumentation-tracing.scenario.test.ts @@ -0,0 +1,388 @@ +import { readdir, readFile } from "node:fs/promises"; +import { join } from "node:path"; + +import { describe, expect, it } from "vitest"; + +import { resolveLocalTraceSchemaDirectory } from "../../src/harness/local-trace-span-processor.js"; +import { WEATHER_AGENT_DESCRIPTOR } from "../../src/internal/testing/scenario-apps/weather-agent.js"; +import { + type ScenarioAppDescriptor, + useScenarioApp, +} from "../../src/internal/testing/scenario-app.js"; +import { sendDevelopmentMessage } from "../dev-client-harness/send-message.js"; +import { createDevelopmentSessionState } from "../dev-client-harness/session.js"; +import { + fetchText, + hasKnownDevServerFailure, + startEveDev, + waitForCondition, +} from "./dev-server-harness.js"; + +const scenarioApp = useScenarioApp(); +const SCENARIO_TIMEOUT_MS = 360_000; +const AUTHORED_SPAN_LOG = ".authored-spans.log"; + +/** + * An `agent/instrumentation.ts` of the shape the docs prescribe: `registerOTel` + * with the author's own span processor, resolving `@vercel/otel` and + * `@opentelemetry/api` from the agent's dependencies rather than eve's vendored + * copies. `setup` is deliberately async — eve has to await it before installing + * its writer, or it would register a provider ahead of this one. + */ +const AUTHORED_INSTRUMENTATION_SOURCE = `import { appendFileSync } from "node:fs"; +import { join } from "node:path"; + +import { defineInstrumentation } from "eve/instrumentation"; +import { registerOTel } from "@vercel/otel"; + +const spanLogPath = join(process.cwd(), ${JSON.stringify(AUTHORED_SPAN_LOG)}); + +export default defineInstrumentation({ + setup: async ({ agentName }) => { + await new Promise((resolve) => setTimeout(resolve, 25)); + registerOTel({ + serviceName: agentName, + spanProcessors: [ + { + forceFlush: async () => {}, + onEnd: (span: { + readonly instrumentationScope?: { readonly name?: string }; + readonly name: string; + }) => { + appendFileSync(spanLogPath, \`\${span.instrumentationScope?.name ?? "unknown"}\\t\${span.name}\\n\`); + }, + onStart: () => {}, + shutdown: async () => {}, + }, + ], + }); + }, +}); +`; + +/** + * A span of the author's own, created inside a turn from a tracer the author + * asks the global API for. It should nest into the agent's trace and reach both + * sinks — eve's writer accepts a whole agent-owned trace, not only the spans it + * created itself. + */ +const AUTHORED_SPAN_TOOL_SOURCE = `import { defineTool } from "eve/tools"; +import { trace } from "@opentelemetry/api"; +import { z } from "zod"; +import { createForecast } from "../lib/weather/client.ts"; + +export default defineTool({ + description: "Get the current weather for a city.", + inputSchema: z.object({ + city: z.string(), + }), + async execute(input) { + return trace.getTracer("weather-agent").startActiveSpan("authored.forecast", (span) => { + try { + return createForecast(input.city); + } finally { + span.end(); + } + }); + }, +}); +`; + +/** + * The same thing outside any session. It belongs to no agent trace, so the + * author's exporter is the only place it can appear: `eve trace` shows sessions, + * and spooling unrelated request traffic to `.eve/traces/v1` would fill the + * store with traces no session ever claims. + */ +const AUTHORED_SPAN_CHANNEL_SOURCE = `import { defineChannel, GET } from "eve/channels"; +import { trace } from "@opentelemetry/api"; + +export default defineChannel({ + routes: [ + GET("/authored-span", () => + trace.getTracer("weather-agent").startActiveSpan("authored.channel", (span) => { + span.end(); + return new Response("ok"); + }), + ), + ], +}); +`; + +const AUTHORED_INSTRUMENTATION_DESCRIPTOR: ScenarioAppDescriptor = { + ...WEATHER_AGENT_DESCRIPTOR, + dependencies: { + ...WEATHER_AGENT_DESCRIPTOR.dependencies, + "@opentelemetry/api": "1.9.1", + "@vercel/otel": "2.1.3", + }, + files: { + ...WEATHER_AGENT_DESCRIPTOR.files, + "agent/channels/authored-span.ts": AUTHORED_SPAN_CHANNEL_SOURCE, + "agent/instrumentation.ts": AUTHORED_INSTRUMENTATION_SOURCE, + "agent/tools/get_weather.ts": AUTHORED_SPAN_TOOL_SOURCE, + }, + name: "authored-instrumentation-agent", +}; + +// The module-level tests cover the interception itself. What only a real +// `eve dev` can prove is the wiring around it: eve's two plugins bracketing the +// authored one in the generated `plugins.mjs`, the authored `setup` awaited +// before the writer is installed, and both sinks fed from one provider. +describe("authored instrumentation in eve dev", () => { + it( + "feeds the authored exporter and the local trace store from the same provider", + async () => { + const app = await scenarioApp(AUTHORED_INSTRUMENTATION_DESCRIPTOR); + const spanLogPath = join(app.appRoot, AUTHORED_SPAN_LOG); + const server = await startEveDev(app.appRoot); + const output = (): string => `stdout:\n${server.stdout()}\n\nstderr:\n${server.stderr()}`; + + try { + const result = await sendDevelopmentMessage({ + message: "What is the weather in Lisbon?", + session: createDevelopmentSessionState(), + serverUrl: server.url, + }); + expect( + result.events.some((event) => event.type === "message.completed"), + `Expected the streamed turn to complete.\n\n${output()}`, + ).toBe(true); + + // The authored processor is still the one the provider reports to, and + // it now also receives eve's own agent spans — which it never saw while + // the local writer stood down in the presence of this file. + let authoredSpans: string[] = []; + await waitForCondition( + async () => { + authoredSpans = await readAuthoredSpanNames(spanLogPath); + return authoredSpans.includes("agent.turn"); + }, + () => + `Authored span processor never received eve's agent spans.\n\nspans: ${JSON.stringify( + authoredSpans, + )}\n\n${output()}`, + ); + + // The author's own span, created from the global API inside the turn, + // arrives there too. + expect( + authoredSpans, + `Authored span processor never received the tool's own span.\n\nspans: ${JSON.stringify( + authoredSpans, + )}\n\n${output()}`, + ).toContain("authored.forecast"); + + // ...and eve spooled the same spans to the local store, so `eve trace` + // keeps working for an agent that authored instrumentation. + let localTraces: LocalTrace[] = []; + await waitForCondition( + async () => { + localTraces = await readLocalTraces(app.appRoot); + return localTraces.some((trace) => trace.spanNames.includes("agent.turn")); + }, + () => + `Local trace store never received eve's agent spans.\n\ntraces: ${JSON.stringify( + localTraces, + )}\n\n${output()}`, + ); + + // One trace, not two: the author's span nests into the agent's trace + // rather than starting a root of its own, which is what makes it show up + // under `agent.step` in `eve trace`. + const agentTrace = localTraces.find((trace) => trace.spanNames.includes("agent.turn")); + await waitForCondition( + async () => { + localTraces = await readLocalTraces(app.appRoot); + return ( + localTraces + .find((trace) => trace.traceId === agentTrace?.traceId) + ?.spanNames.includes("authored.forecast") === true + ); + }, + () => + `Local trace store never received the tool's own span in the agent trace.\n\ntraces: ${JSON.stringify( + localTraces, + )}\n\n${output()}`, + ); + + // The AI SDK bridge reaches both sinks as well. A turn runs several + // steps, so this waits for a snapshot where every model-call span nests + // under one of the trace's own `agent.step` spans — a step's segment is + // written after the model call it contains, so an intermediate snapshot + // can hold a child whose parent has not landed yet. + await waitForCondition( + async () => { + localTraces = await readLocalTraces(app.appRoot); + const spans = + localTraces.find((trace) => trace.traceId === agentTrace?.traceId)?.spans ?? []; + const stepSpanIds = new Set( + spans.filter((span) => span.name === "agent.step").map((span) => span.spanId), + ); + const modelCalls = spans.filter((span) => span.name === "ai.streamText"); + return ( + modelCalls.length > 0 && + modelCalls.every((span) => stepSpanIds.has(span.parentSpanId)) + ); + }, + () => + `Expected every AI SDK model-call span to nest under agent.step.\n\ntraces: ${JSON.stringify( + localTraces, + )}\n\n${output()}`, + ); + + // eve reports a span to its own writer only after the observed provider's + // processors have run, so a span in the local store is already in the + // author's log. + authoredSpans = await readAuthoredSpanNames(spanLogPath); + expect( + authoredSpans, + `Authored span processor never received the AI SDK model-call span.\n\nspans: ${JSON.stringify( + authoredSpans, + )}\n\n${output()}`, + ).toContain("ai.streamText"); + + // A run's internal spans are the one thing eve declines even inside a + // trace it owns, so `eve trace` shows the session's own work rather than + // how the turn was executed. The scope name is the discriminator, so + // assert on it rather than on any particular span name. + expect( + localTraces.flatMap((trace) => trace.scopeNames), + `Expected no Workflow SDK spans in the local store.\n\ntraces: ${JSON.stringify( + localTraces.map((trace) => trace.scopeNames), + )}`, + ).not.toContain("workflow"); + + // Nor does the author's exporter receive them: in `eve dev` eve declines + // to create them at all, so a run's internals exist in neither sink. The + // agent scope is asserted alongside so a scope column that stopped being + // read could not pass this by reporting nothing. + const authoredScopes = (await readAuthoredSpans(spanLogPath)).map((span) => span.scope); + expect( + authoredScopes, + `Authored span processor never reported the agent's instrumentation scope.\n\nscopes: ${JSON.stringify( + authoredScopes, + )}\n\n${output()}`, + ).toContain("eve.agent"); + expect( + authoredScopes, + `Authored span processor received Workflow SDK spans.\n\nscopes: ${JSON.stringify( + authoredScopes, + )}\n\n${output()}`, + ).not.toContain("workflow"); + + // A span outside any session belongs to no agent trace, so it reaches + // the author's exporter and nothing else. Asserted only once the author + // has it: eve's accept decision is made when the span ends, so by then + // the local store has already declined it. + await fetchText(server.url, "/authored-span"); + await waitForCondition( + async () => { + authoredSpans = await readAuthoredSpanNames(spanLogPath); + return authoredSpans.includes("authored.channel"); + }, + () => + `Authored span processor never received the channel's span.\n\nspans: ${JSON.stringify( + authoredSpans, + )}\n\n${output()}`, + ); + localTraces = await readLocalTraces(app.appRoot); + expect(localTraces.flatMap((trace) => trace.spanNames)).not.toContain("authored.channel"); + + expect(output()).not.toContain("could not register an OpenTelemetry tracer provider"); + expect(hasKnownDevServerFailure(output())).toBe(false); + } finally { + await server.stop(); + } + }, + SCENARIO_TIMEOUT_MS, + ); +}); + +interface AuthoredSpan { + readonly name: string; + readonly scope: string; +} + +/** One `\t` line per span the authored processor received. */ +async function readAuthoredSpans(spanLogPath: string): Promise { + let contents = ""; + try { + contents = await readFile(spanLogPath, "utf8"); + } catch { + return []; + } + return contents + .split("\n") + .filter((line) => line.length > 0) + .map((line) => { + const [scope = "", name = ""] = line.split("\t"); + return { name, scope }; + }); +} + +async function readAuthoredSpanNames(spanLogPath: string): Promise { + return (await readAuthoredSpans(spanLogPath)).map((span) => span.name); +} + +interface OtlpSpan { + readonly name?: string; + readonly parentSpanId?: string; + readonly spanId?: string; +} + +interface OtlpSegment { + readonly resourceSpans?: readonly { + readonly scopeSpans?: readonly { + readonly scope?: { readonly name?: string }; + readonly spans?: readonly OtlpSpan[]; + }[]; + }[]; +} + +interface LocalTrace { + readonly scopeNames: readonly string[]; + readonly spanNames: readonly string[]; + readonly spans: readonly OtlpSpan[]; + readonly traceId: string; +} + +async function readLocalTraces(appRoot: string): Promise { + const schemaDirectory = resolveLocalTraceSchemaDirectory(appRoot); + const traces: LocalTrace[] = []; + + for (const traceId of await listDirectory(schemaDirectory)) { + const segmentsDirectory = join(schemaDirectory, traceId, "segments"); + const scopeNames: string[] = []; + const spans: OtlpSpan[] = []; + for (const segment of await listDirectory(segmentsDirectory)) { + const payload = await readSegment(join(segmentsDirectory, segment)); + for (const resourceSpan of payload?.resourceSpans ?? []) { + for (const scopeSpan of resourceSpan.scopeSpans ?? []) { + if (scopeSpan.scope?.name !== undefined) scopeNames.push(scopeSpan.scope.name); + spans.push(...(scopeSpan.spans ?? [])); + } + } + } + const spanNames = spans.flatMap((span) => (span.name === undefined ? [] : [span.name])); + traces.push({ scopeNames, spanNames, spans, traceId }); + } + + return traces; +} + +async function listDirectory(directory: string): Promise { + try { + return await readdir(directory); + } catch { + return []; + } +} + +async function readSegment(path: string): Promise { + try { + return JSON.parse(await readFile(path, "utf8")) as OtlpSegment; + } catch { + return undefined; + } +} diff --git a/packages/eve/test/scenarios/compiled-artifacts-bootstrap.scenario.test.ts b/packages/eve/test/scenarios/compiled-artifacts-bootstrap.scenario.test.ts index d4cc234f3..5e6745497 100644 --- a/packages/eve/test/scenarios/compiled-artifacts-bootstrap.scenario.test.ts +++ b/packages/eve/test/scenarios/compiled-artifacts-bootstrap.scenario.test.ts @@ -100,7 +100,9 @@ describe("writeCompiledArtifactsFiles", () => { expect(instrumentationPluginSource).toContain( `import * as instrumentationModule from ${JSON.stringify(join(agentRoot, "instrumentation.ts").replaceAll("\\", "/"))};`, ); - expect(instrumentationPluginSource).toContain("registerInstrumentationConfig"); + // Awaited at module scope: an `async setup` has to finish registering its + // tracer provider before the next plugin looks for one. + expect(instrumentationPluginSource).toContain("await registerInstrumentationConfig("); const instrumentationPluginModule = (await import( pathToFileURL(instrumentationPluginPath).href