diff --git a/packages/ai/tests/integration.test.ts b/packages/ai/tests/integration.test.ts index 491744f..a6745a9 100644 --- a/packages/ai/tests/integration.test.ts +++ b/packages/ai/tests/integration.test.ts @@ -10,7 +10,10 @@ import { TraceIdRatioBasedSampler, } from "@opentelemetry/sdk-trace-base"; import { sessionSpanContext } from "@telemetry-dev/otel"; +import { generateText, tool } from "ai-v6"; +import { MockLanguageModelV3 } from "ai-v6/test"; import { expect, test, vi } from "vitest"; +import { z } from "zod"; import { telemetryDev } from "../src/v6.ts"; @@ -1014,3 +1017,106 @@ test("v6 exports session spans only when the configured sampler selects them", a expect(errors).toEqual([]); } }); + +// The other ai@6 tests send hand-built events; this one runs generateText through the real ai@6 +// dispatcher and checks the fields the integration reads from its events: the model, the prompt, +// and the tool's arguments and result. +test("a real ai@6 generateText run with a tool call records the root, both steps, and the tool", async () => { + const { spanBatches, metrics, overrides } = makeCapture(); + let calls = 0; + + const mockModel = new MockLanguageModelV3({ + provider: "openai", + modelId: "gpt-4o", + doGenerate: async () => { + calls += 1; + + const usage = { + inputTokens: { total: 4, noCache: 4, cacheRead: undefined, cacheWrite: undefined }, + outputTokens: { total: 2, text: 2, reasoning: undefined }, + }; + + return calls === 1 + ? { + content: [ + { + type: "tool-call" as const, + toolCallId: "call-1", + toolName: "lookup", + input: JSON.stringify({ q: "otel" }), + }, + ], + finishReason: { unified: "tool-calls" as const, raw: "tool_calls" }, + usage, + warnings: [], + } + : { + content: [{ type: "text" as const, text: "found it" }], + finishReason: { unified: "stop" as const, raw: "stop" }, + usage, + warnings: [], + }; + }, + }); + + const result = await generateText({ + model: mockModel, + prompt: "find otel", + tools: { + lookup: tool({ + inputSchema: z.object({ q: z.string() }), + execute: async ({ q }) => ({ hits: [q] }), + }), + }, + stopWhen: () => calls >= 2, + experimental_telemetry: { + isEnabled: true, + integrations: [ + telemetryDev( + { apiKey: "td_live_test", environment: "test", serviceName: "svc" }, + overrides, + ), + ], + }, + }); + + expect(result.text).toBe("found it"); + await vi.waitFor(() => expect(spanBatches).toHaveLength(1)); + + const spans = spanBatches[0]!; + const root = spans.find( + (s) => s.kind === SpanKind.INTERNAL && s.attributes["gen_ai.operation.name"] !== "execute_tool", + )!; + const steps = spans.filter((s) => s.kind === SpanKind.CLIENT); + const tools = spans.filter((s) => s.attributes["gen_ai.operation.name"] === "execute_tool"); + + expect(root.attributes["gen_ai.operation.name"]).toBe("invoke_agent"); + expect(root.attributes["gen_ai.provider.name"]).toBe("openai"); + expect(root.attributes["gen_ai.request.model"]).toBe("gpt-4o"); + expect(String(root.attributes["gen_ai.input.messages"])).toContain("find otel"); + + expect(steps).toHaveLength(2); + expect(tools).toHaveLength(1); + expect(tools[0]!.attributes["gen_ai.tool.name"]).toBe("lookup"); + expect(tools[0]!.attributes["gen_ai.tool.call.arguments"]).toBe(JSON.stringify({ q: "otel" })); + expect(tools[0]!.attributes["gen_ai.tool.call.result"]).toBe(JSON.stringify({ hits: ["otel"] })); + expect(tools[0]!.parentSpanContext?.spanId).toBe(spanId(steps[0]!)); + + for (const step of steps) { + expect(step.parentSpanContext?.spanId).toBe(spanId(root)); + expect(step.attributes["gen_ai.usage.input_tokens"]).toBe(4); + } + + expect(steps.map((s) => s.attributes["gen_ai.response.finish_reasons"])).toEqual([ + ["tool-calls"], + ["stop"], + ]); + + // A duration per step and per tool, as with hand-built events. + const durations = metrics.filter((m) => m.metric === "duration"); + expect(durations.map((m) => String(m.attributes["gen_ai.operation.name"])).sort()).toEqual([ + "chat", + "chat", + "execute_tool", + ]); +}); diff --git a/packages/ai/tests/integration_v7.test.ts b/packages/ai/tests/integration_v7.test.ts index 0a4079f..bafa89e 100644 --- a/packages/ai/tests/integration_v7.test.ts +++ b/packages/ai/tests/integration_v7.test.ts @@ -1,4 +1,12 @@ -import { type Attributes, ROOT_CONTEXT, SpanKind, SpanStatusCode } from "@opentelemetry/api"; +import { + type Attributes, + type Context, + context, + ROOT_CONTEXT, + SpanKind, + SpanStatusCode, + trace, +} from "@opentelemetry/api"; import { AlwaysOffSampler, AlwaysOnSampler, @@ -8,7 +16,8 @@ import { SamplingDecision, TraceIdRatioBasedSampler, } from "@opentelemetry/sdk-trace-base"; -import { sessionSpanContext } from "@telemetry-dev/otel"; +import { AlsContextManager, sessionSpanContext } from "@telemetry-dev/otel"; +import { AsyncLocalStorage } from "node:async_hooks"; import { expect, test, vi } from "vitest"; import { telemetryDev } from "../src/index.ts"; @@ -4012,3 +4021,295 @@ test("overlapping evaluations stay isolated and errors clean up their call state expect(new Set(spanBatches[1]!.map(traceId)).size).toBe(1); expect(traceId(spanBatches[0]![0]!)).not.toBe(traceId(spanBatches[1]![0]!)); }); + +test("executeTool runs the tool inside its span and the tool end finishes that span", async () => { + context.setGlobalContextManager(new AlsContextManager(new AsyncLocalStorage())); + // The tool end runs at 2s and the step end at 3s, so the tool span's end time shows which one + // ended it. + vi.useFakeTimers({ toFake: ["Date"], now: 1_000 }); + + try { + const { spanBatches, overrides } = makeCapture(); + const integ = telemetryDev(baseOptions, overrides); + const callId = "call-execute-tool"; + const toolCall = { toolCallId: "t-exec", toolName: "lookup", input: { q: "x" } }; + let activeSpanId: string | undefined; + + integ.onStart?.({ + callId, + operationId: "ai.generateText", + provider: "openai", + modelId: "gpt-4o", + messages: [{ role: "user", content: "go" }], + }); + integ.onStepStart?.({ callId, stepNumber: 0 }); + integ.onToolExecutionStart?.({ callId, toolCall }); + + const result = await integ.executeTool?.({ + callId, + toolCallId: "t-exec", + execute: async () => { + activeSpanId = trace.getActiveSpan()?.spanContext().spanId; + + return "tool output"; + }, + }); + + vi.setSystemTime(2_000); + integ.onToolExecutionEnd?.({ + callId, + toolCall, + toolExecutionMs: 5, + toolOutput: { type: "tool-result", output: { ok: true } }, + }); + vi.setSystemTime(3_000); + integ.onStepEnd?.({ + callId, + stepNumber: 0, + model, + text: "", + finishReason: "tool-calls", + response: { id: "r-exec", modelId: "gpt-4o" }, + usage: { inputTokens: 3, outputTokens: 1 }, + }); + await integ.onEnd?.({ + callId, + text: "done", + finishReason: "stop", + usage: { inputTokens: 3, outputTokens: 1 }, + }); + + expect(result).toBe("tool output"); + const spans = spanBatches[0]!; + const step = byOperation(spans, "chat").find((s) => s.kind === SpanKind.CLIENT)!; + const tools = byOperation(spans, "execute_tool"); + expect(tools).toHaveLength(1); + expect(spanId(tools[0]!)).toBe(activeSpanId); + expect(tools[0]!.parentSpanContext?.spanId).toBe(spanId(step)); + expect(tools[0]!.attributes["gen_ai.tool.name"]).toBe("lookup"); + expect(tools[0]!.endTime).toEqual([2, 0]); + } finally { + vi.useRealTimers(); + context.disable(); + } +}); + +test("a step that ends without onStepStart gets a span that starts with the trace", async () => { + const { spanBatches, overrides } = makeCapture(); + const integ = telemetryDev(baseOptions, overrides); + const callId = "call-no-step-start"; + + // The step ends a second after the trace starts, so a step that started at its own end + // would not share the trace's start time. + vi.useFakeTimers({ toFake: ["Date"], now: 1_000 }); + + try { + integ.onStart?.({ + callId, + operationId: "ai.generateText", + provider: "openai", + modelId: "gpt-4o", + messages: [{ role: "user", content: "hi" }], + }); + vi.setSystemTime(2_000); + integ.onStepEnd?.({ + callId, + stepNumber: 0, + model, + text: "hello", + finishReason: "stop", + response: { id: "r-no-start", modelId: "gpt-4o" }, + usage: { inputTokens: 2, outputTokens: 1 }, + }); + await integ.onEnd?.({ + callId, + text: "hello", + finishReason: "stop", + usage: { inputTokens: 2, outputTokens: 1 }, + }); + } finally { + vi.useRealTimers(); + } + + const spans = spanBatches[0]!; + const root = spans.find((s) => s.kind === SpanKind.INTERNAL)!; + const steps = spans.filter((s) => s.kind === SpanKind.CLIENT); + expect(steps).toHaveLength(1); + expect(steps[0]!.parentSpanContext?.spanId).toBe(spanId(root)); + expect(steps[0]!.startTime).toEqual(root.startTime); + expect(steps[0]!.attributes["gen_ai.usage.input_tokens"]).toBe(2); +}); + +type V7Integration = ReturnType; + +const gateway = (modelId: string) => ({ provider: "gateway", modelId }); + +const evaluateInput = { + ...gateway("openai/gpt-4o"), + state: { response: "Paris" }, + questions: { correct: { type: "boolean", question: "Is this correct?" } }, +}; + +const evaluateOutput = { + answers: { correct: { type: "boolean", probability: 1 } }, + usage: { inputTokens: 1, outputTokens: 1 }, +}; + +// Each run starts the call and its step with the gateway provider. `finish` ends both, and the +// error table fails the call while the step is still open instead. +const gatewayRuns = [ + { + operation: "generateText", + start: (integ: V7Integration, callId: string) => { + integ.onStart?.({ + callId, + operationId: "ai.generateText", + ...gateway("openai/gpt-4o"), + prompt: "hi", + }); + integ.onStepStart?.({ callId, stepNumber: 0, ...gateway("openai/gpt-4o") }); + }, + finish: async (integ: V7Integration, callId: string) => { + integ.onStepEnd?.({ + callId, + stepNumber: 0, + model: gateway("openai/gpt-4o"), + text: "hello", + finishReason: "stop", + response: { id: "r-gateway-text", modelId: "openai/gpt-4o" }, + usage: { inputTokens: 1, outputTokens: 1 }, + }); + await integ.onEnd?.({ + callId, + text: "hello", + finishReason: "stop", + usage: { inputTokens: 1, outputTokens: 1 }, + }); + }, + }, + { + operation: "generateObject", + start: (integ: V7Integration, callId: string) => { + integ.onStart?.({ + callId, + operationId: "ai.generateObject", + ...gateway("openai/gpt-4o"), + prompt: "name?", + }); + integ.onObjectStepStart?.({ callId, ...gateway("openai/gpt-4o") }); + }, + finish: async (integ: V7Integration, callId: string) => { + integ.onObjectStepEnd?.({ + callId, + finishReason: "stop", + response: { id: "r-gateway-object", modelId: "openai/gpt-4o" }, + usage: { inputTokens: 1, outputTokens: 1 }, + objectText: "{}", + }); + await integ.onEnd?.({ + callId, + object: {}, + finishReason: "stop", + usage: { inputTokens: 1, outputTokens: 1 }, + }); + }, + }, + { + operation: "embed", + start: (integ: V7Integration, callId: string) => { + const embedModel = gateway("openai/text-embedding-3-small"); + integ.onStart?.({ callId, operationId: "ai.embed", ...embedModel, value: "a" }); + integ.onEmbedStart?.({ callId, embedCallId: "e-gateway", ...embedModel }); + }, + finish: async (integ: V7Integration, callId: string) => { + integ.onEmbedEnd?.({ callId, embedCallId: "e-gateway", usage: { tokens: 1 } }); + await integ.onEnd?.({ callId, usage: { tokens: 1 } }); + }, + }, + { + operation: "rerank", + start: (integ: V7Integration, callId: string) => { + const rerankModel = gateway("cohere/rerank-v3.5"); + integ.onStart?.({ + callId, + operationId: "ai.rerank", + ...rerankModel, + documents: ["a", "b"], + query: "q", + }); + integ.onRerankStart?.({ callId, ...rerankModel }); + }, + finish: async (integ: V7Integration, callId: string) => { + integ.onRerankEnd?.({ callId }); + await integ.onEnd?.({ callId, ranking: [{ index: 0, score: 1 }] }); + }, + }, + { + operation: "evaluate", + start: (integ: V7Integration, callId: string) => { + integ.experimental_onEvaluateStart?.({ + callId, + operationId: "ai.evaluate", + ...evaluateInput, + }); + integ.experimental_onEvaluationModelCallStart?.({ + callId, + operationId: "ai.evaluate.doEvaluate", + ...evaluateInput, + }); + }, + finish: async (integ: V7Integration, callId: string) => { + integ.experimental_onEvaluationModelCallEnd?.({ + callId, + operationId: "ai.evaluate.doEvaluate", + ...evaluateInput, + ...evaluateOutput, + }); + await integ.experimental_onEvaluateEnd?.({ + callId, + operationId: "ai.evaluate", + ...evaluateInput, + ...evaluateOutput, + }); + }, + }, +]; + +const expectGatewayRootAndStep = (spans: readonly ReadableSpan[]) => { + const roots = spans.filter((s) => s.kind === SpanKind.INTERNAL); + const steps = spans.filter((s) => s.kind === SpanKind.CLIENT); + expect(roots).toHaveLength(1); + expect(steps).toHaveLength(1); + expect(roots[0]!.attributes["gen_ai.provider.name"]).toBe("Vercel AI Gateway"); + expect(steps[0]!.attributes["gen_ai.provider.name"]).toBe("Vercel AI Gateway"); +}; + +test.each(gatewayRuns)( + "ai@7 $operation relabels the gateway provider on the root and step spans", + async ({ operation, start, finish }) => { + const { spanBatches, overrides } = makeCapture(); + const integ = telemetryDev(baseOptions, overrides); + const callId = `gateway-${operation}`; + + start(integ, callId); + await finish(integ, callId); + + expectGatewayRootAndStep(spanBatches[0]!); + }, +); + +// A step that ends takes the root's provider, so only a step an error leaves open shows the label +// from its own start event. +test.each(gatewayRuns)( + "ai@7 $operation relabels the gateway provider on a step an error leaves open", + async ({ operation, start }) => { + const { spanBatches, overrides } = makeCapture(); + const integ = telemetryDev(baseOptions, overrides); + const callId = `gateway-${operation}-error`; + + start(integ, callId); + await integ.onError?.({ callId, error: new Error("provider down") }); + + expectGatewayRootAndStep(spanBatches[0]!); + }, +); diff --git a/packages/ai/tests/wrappers.test.ts b/packages/ai/tests/wrappers.test.ts index 7510ec4..ff7c371 100644 --- a/packages/ai/tests/wrappers.test.ts +++ b/packages/ai/tests/wrappers.test.ts @@ -1,11 +1,14 @@ import { type Attributes, SpanStatusCode } from "@opentelemetry/api"; import type { ReadableSpan } from "@opentelemetry/sdk-trace-base"; -import { expect, test } from "vitest"; +import { expect, test, vi } from "vitest"; import { + wrapCancelBatch, wrapGenerateImage, wrapGenerateSpeech, + wrapGenerateVideo, wrapGetBatchResults, + wrapGetBatchStatus, wrapStartBatch, wrapTranscribe, } from "../src/index.ts"; @@ -651,3 +654,102 @@ test("thrown values that cannot be stringified still reach onError", async () => "A value that cannot be converted to a string was thrown", ); }); + +test.each([ + ["a videos list", { videos: [{}, {}] }, 2], + ["a single video", { video: {} }, 1], + ["no video", {}, undefined], +])("video wrapper counts the videos from %s", async (_case, result, count) => { + const { spans, overrides } = capture(); + + await wrapGenerateVideo( + async (_options: { model: { provider: string; modelId: string }; prompt: string }) => result, + config, + overrides, + )({ model: { provider: "google", modelId: "veo-3" }, prompt: "x" }); + + expect(spans).toHaveLength(1); + expect(spans[0]!.attributes["gen_ai.output.type"]).toBe("video"); + expect(spans[0]!.attributes["td.ai.output.video_count"]).toBe(count); +}); + +test.each([ + ["durationInSeconds", { text: "hi", durationInSeconds: 3.5 }, 3.5], + ["duration without durationInSeconds", { text: "hi", duration: 2 }, 2], + ["durationInSeconds over duration", { text: "hi", durationInSeconds: 3.5, duration: 9 }, 3.5], + ["a duration that is not finite", { text: "hi", durationInSeconds: Number.NaN }, undefined], +])("transcription records its duration from %s", async (_case, result, seconds) => { + const { spans, overrides } = capture(); + + await wrapTranscribe( + async (_options: { audio: Uint8Array }) => result, + config, + overrides, + )({ + audio: new Uint8Array([1]), + }); + + expect(spans).toHaveLength(1); + expect(spans[0]!.attributes["td.ai.transcription.duration_seconds"]).toBe(seconds); +}); + +test("media wrappers relabel the gateway provider", async () => { + const { spans, overrides } = capture(); + + await wrapGenerateImage( + async (_options: { model: { provider: string; modelId: string }; prompt: string }) => ({ + images: [], + }), + config, + overrides, + )({ model: { provider: "gateway", modelId: "openai/gpt-image-1" }, prompt: "x" }); + + expect(spans[0]!.attributes["gen_ai.provider.name"]).toBe("Vercel AI Gateway"); +}); + +test.each([ + ["status", wrapGetBatchStatus, "batch.status", "in_progress"], + ["cancel", wrapCancelBatch, "batch.cancel", "cancelled"], +] as const)( + "batch %s wrapper records its operation, batch id, and status", + async (_name, wrap, operation, status) => { + const { spans, overrides } = capture(); + + const result = await wrap( + async (_input: { batch: { id: string } }) => ({ id: "batch-1", status }), + config, + overrides, + )({ batch: { id: "batch-1" } }); + + expect(result).toEqual({ id: "batch-1", status }); + expect(spans).toHaveLength(1); + expect(spans[0]!.name).toBe(operation); + expect(spans[0]!.attributes["gen_ai.operation.name"]).toBe(operation); + expect(spans[0]!.attributes["td.ai.batch.id"]).toBe("batch-1"); + expect(spans[0]!.attributes["td.ai.batch.status"]).toBe(status); + }, +); + +test("media and batch wrappers return the provider function itself without an api key", () => { + vi.stubEnv("TELEMETRY_DEV_API_KEY", undefined); + + try { + const options = { environment: "test", serviceName: "test" }; + const fn = async () => ({}); + + for (const wrap of [ + wrapGenerateImage, + wrapGenerateSpeech, + wrapTranscribe, + wrapGenerateVideo, + wrapStartBatch, + wrapGetBatchStatus, + wrapCancelBatch, + wrapGetBatchResults, + ]) { + expect(wrap(fn, options)).toBe(fn); + } + } finally { + vi.unstubAllEnvs(); + } +});