Skip to content

Commit f34c2fe

Browse files
committed
feat(server-utils): Capture usage/output on streamed Vercel AI spans (v7 + orchestrion)
1 parent 3d3328e commit f34c2fe

6 files changed

Lines changed: 657 additions & 46 deletions

File tree

Lines changed: 48 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,48 @@
1+
import * as Sentry from '@sentry/node';
2+
import { Output, streamText } from 'ai';
3+
import { MockLanguageModelV3, simulateReadableStream } from 'ai/test';
4+
import { z } from 'zod';
5+
6+
// `streamObject` is deprecated in `ai` v7 (it publishes no telemetry channel events); structured
7+
// output now flows through the `streamText` primitive with an `experimental_output`, which does. So a
8+
// streamed structured-output call must still produce the usual streamText/doStream spans, with the
9+
// streamed JSON captured as the output.
10+
async function run() {
11+
await Sentry.startSpan({ op: 'function', name: 'main' }, async () => {
12+
const result = streamText({
13+
experimental_telemetry: { isEnabled: true, recordInputs: true, recordOutputs: true },
14+
experimental_output: Output.object({
15+
schema: z.object({ city: z.string(), weather: z.string() }),
16+
}),
17+
model: new MockLanguageModelV3({
18+
doStream: async () => ({
19+
stream: simulateReadableStream({
20+
chunks: [
21+
{ type: 'stream-start', warnings: [] },
22+
{ type: 'text-start', id: '0' },
23+
{ type: 'text-delta', id: '0', delta: '{"city":"San Francisco",' },
24+
{ type: 'text-delta', id: '0', delta: '"weather":"sunny"}' },
25+
{ type: 'text-end', id: '0' },
26+
{
27+
type: 'finish',
28+
finishReason: { unified: 'stop', raw: 'stop' },
29+
usage: {
30+
inputTokens: { total: 12, noCache: 12, cached: 0 },
31+
outputTokens: { total: 18, noCache: 18, cached: 0 },
32+
totalTokens: { total: 30, noCache: 30, cached: 0 },
33+
},
34+
},
35+
],
36+
}),
37+
}),
38+
}),
39+
prompt: 'What is the weather in San Francisco?',
40+
});
41+
42+
for await (const _part of result.fullStream) {
43+
void _part;
44+
}
45+
});
46+
}
47+
48+
run();
Lines changed: 78 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,78 @@
1+
import * as Sentry from '@sentry/node';
2+
import { stepCountIs, streamText, tool } from 'ai';
3+
import { MockLanguageModelV3, simulateReadableStream } from 'ai/test';
4+
import { z } from 'zod';
5+
6+
async function run() {
7+
await Sentry.startSpan({ op: 'function', name: 'main' }, async () => {
8+
let callCount = 0;
9+
10+
const result = streamText({
11+
experimental_telemetry: { isEnabled: true, recordInputs: true, recordOutputs: true },
12+
model: new MockLanguageModelV3({
13+
doStream: async () => {
14+
// First step streams a tool call; after the tool runs, the second step streams the answer.
15+
if (callCount++ === 0) {
16+
return {
17+
stream: simulateReadableStream({
18+
chunks: [
19+
{ type: 'stream-start', warnings: [] },
20+
{
21+
type: 'tool-call',
22+
toolCallId: 'call-1',
23+
toolName: 'getWeather',
24+
input: JSON.stringify({ location: 'San Francisco' }),
25+
},
26+
{
27+
type: 'finish',
28+
finishReason: { unified: 'tool-calls', raw: 'tool_calls' },
29+
usage: {
30+
inputTokens: { total: 10, noCache: 10, cached: 0 },
31+
outputTokens: { total: 20, noCache: 20, cached: 0 },
32+
totalTokens: { total: 30, noCache: 30, cached: 0 },
33+
},
34+
},
35+
],
36+
}),
37+
};
38+
}
39+
return {
40+
stream: simulateReadableStream({
41+
chunks: [
42+
{ type: 'stream-start', warnings: [] },
43+
{ type: 'text-start', id: '0' },
44+
{ type: 'text-delta', id: '0', delta: 'Sunny, ' },
45+
{ type: 'text-delta', id: '0', delta: '72°F.' },
46+
{ type: 'text-end', id: '0' },
47+
{
48+
type: 'finish',
49+
finishReason: { unified: 'stop', raw: 'stop' },
50+
usage: {
51+
inputTokens: { total: 15, noCache: 15, cached: 0 },
52+
outputTokens: { total: 25, noCache: 25, cached: 0 },
53+
totalTokens: { total: 40, noCache: 40, cached: 0 },
54+
},
55+
},
56+
],
57+
}),
58+
};
59+
},
60+
}),
61+
tools: {
62+
getWeather: tool({
63+
description: 'Get the current weather for a location',
64+
inputSchema: z.object({ location: z.string() }),
65+
execute: async ({ location }) => `Weather in ${location}: Sunny, 72°F`,
66+
}),
67+
},
68+
stopWhen: stepCountIs(5),
69+
prompt: 'What is the weather in San Francisco?',
70+
});
71+
72+
for await (const _part of result.fullStream) {
73+
void _part;
74+
}
75+
});
76+
}
77+
78+
run();

dev-packages/node-integration-tests/suites/tracing/vercelai/v6_v7/test.ts

Lines changed: 130 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -595,6 +595,136 @@ describe.each(matrix)('Vercel AI integration (version %s)', (version, vercelAiVe
595595
expect(generateContent).toBeDefined();
596596
expect(generateContent.parent_span_id).toBe(invokeAgent.span_id);
597597
expect(generateContent.attributes['vercel.ai.operationId']?.value).toBe('ai.streamText.doStream');
598+
599+
// The stream's final usage/finish/output arrive only as the stream drains, after the
600+
// channel already resolved the model call. Tapping the stream recovers them onto the
601+
// model-call span on every path (v7 channel, v6 OTel, v6 orchestrion).
602+
expect(generateContent.attributes[GEN_AI_USAGE_INPUT_TOKENS_ATTRIBUTE]?.value).toBe(10);
603+
expect(generateContent.attributes[GEN_AI_USAGE_OUTPUT_TOKENS_ATTRIBUTE]?.value).toBe(20);
604+
expect(generateContent.attributes[GEN_AI_USAGE_TOTAL_TOKENS_ATTRIBUTE]?.value).toBe(30);
605+
expect(generateContent.attributes[GEN_AI_RESPONSE_FINISH_REASONS_ATTRIBUTE]?.value).toBe('["stop"]');
606+
expect(generateContent.attributes[GEN_AI_OUTPUT_MESSAGES_ATTRIBUTE]?.value).toBe(
607+
'[{"role":"assistant","parts":[{"type":"text","content":"Stream response!"}],"finish_reason":"stop"}]',
608+
);
609+
610+
// The summed usage and output also land on the parent invoke_agent span, whose own
611+
// channel result is otherwise undefined for a stream.
612+
expect(invokeAgent.attributes[GEN_AI_USAGE_INPUT_TOKENS_ATTRIBUTE]?.value).toBe(10);
613+
expect(invokeAgent.attributes[GEN_AI_USAGE_OUTPUT_TOKENS_ATTRIBUTE]?.value).toBe(20);
614+
expect(invokeAgent.attributes[GEN_AI_USAGE_TOTAL_TOKENS_ATTRIBUTE]?.value).toBe(30);
615+
expect(invokeAgent.attributes[GEN_AI_OUTPUT_MESSAGES_ATTRIBUTE]?.value).toBe(
616+
'[{"role":"assistant","parts":[{"type":"text","content":"Stream response!"}],"finish_reason":"stop"}]',
617+
);
618+
},
619+
})
620+
.start()
621+
.completed();
622+
});
623+
},
624+
{
625+
additionalDependencies: {
626+
ai: vercelAiVersion,
627+
},
628+
},
629+
);
630+
631+
createEsmTests(
632+
__dirname,
633+
'scenario-stream-tools.mjs',
634+
'instrument.mjs',
635+
(createRunner, test) => {
636+
test('captures usage, tool calls and output across a multi-step streamText', async () => {
637+
await createRunner()
638+
.expect({ transaction: { transaction: 'main' } })
639+
.expect({
640+
span: container => {
641+
const invokeAgent = container.items.find(
642+
span => span.attributes['sentry.op']?.value === 'gen_ai.invoke_agent',
643+
)!;
644+
expect(invokeAgent).toBeDefined();
645+
expect(invokeAgent.status).toBe('ok');
646+
expect(invokeAgent.attributes['vercel.ai.operationId']?.value).toBe('ai.streamText');
647+
// Usage is summed across the two streamed model calls (10+15, 20+25, 30+40).
648+
expect(invokeAgent.attributes[GEN_AI_USAGE_INPUT_TOKENS_ATTRIBUTE]?.value).toBe(25);
649+
expect(invokeAgent.attributes[GEN_AI_USAGE_OUTPUT_TOKENS_ATTRIBUTE]?.value).toBe(45);
650+
expect(invokeAgent.attributes[GEN_AI_USAGE_TOTAL_TOKENS_ATTRIBUTE]?.value).toBe(70);
651+
652+
const generateContents = container.items.filter(
653+
span => span.attributes['sentry.op']?.value === 'gen_ai.generate_content',
654+
);
655+
expect(generateContents).toHaveLength(2);
656+
generateContents.forEach(span => expect(span.parent_span_id).toBe(invokeAgent.span_id));
657+
658+
// The step that streamed a tool call: tool-call output part + tool-calls finish reason.
659+
const toolStep = generateContents.find(
660+
span => span.attributes[GEN_AI_RESPONSE_FINISH_REASONS_ATTRIBUTE]?.value === '["tool-calls"]',
661+
)!;
662+
expect(toolStep).toBeDefined();
663+
expect(toolStep.attributes[GEN_AI_USAGE_INPUT_TOKENS_ATTRIBUTE]?.value).toBe(10);
664+
expect(toolStep.attributes[GEN_AI_USAGE_OUTPUT_TOKENS_ATTRIBUTE]?.value).toBe(20);
665+
const toolStepOutput = toolStep.attributes[GEN_AI_OUTPUT_MESSAGES_ATTRIBUTE]?.value as string;
666+
expect(toolStepOutput).toContain('"type":"tool_call"');
667+
expect(toolStepOutput).toContain('getWeather');
668+
669+
// The step that streamed the final answer text.
670+
const textStep = generateContents.find(
671+
span => span.attributes[GEN_AI_RESPONSE_FINISH_REASONS_ATTRIBUTE]?.value === '["stop"]',
672+
)!;
673+
expect(textStep).toBeDefined();
674+
expect(textStep.attributes[GEN_AI_USAGE_INPUT_TOKENS_ATTRIBUTE]?.value).toBe(15);
675+
expect(textStep.attributes[GEN_AI_OUTPUT_MESSAGES_ATTRIBUTE]?.value).toContain('Sunny, 72°F.');
676+
677+
// A tool span is emitted for the streamed tool call. Its parent and recorded input/output
678+
// vary by path during stream consumption (tool i/o is covered by the non-stream scenario
679+
// and the v7 path), so here we just assert the span exists with the right name/status.
680+
const executeTool = container.items.find(span => span.name === 'execute_tool getWeather')!;
681+
expect(executeTool).toBeDefined();
682+
expect(executeTool.status).toBe('ok');
683+
expect(executeTool.attributes[GEN_AI_TOOL_NAME_ATTRIBUTE]?.value).toBe('getWeather');
684+
},
685+
})
686+
.start()
687+
.completed();
688+
});
689+
},
690+
{
691+
additionalDependencies: {
692+
ai: vercelAiVersion,
693+
},
694+
},
695+
);
696+
697+
createEsmTests(
698+
__dirname,
699+
'scenario-stream-structured-output.mjs',
700+
'instrument.mjs',
701+
(createRunner, test) => {
702+
test('captures streamed structured output (streamText with experimental_output)', async () => {
703+
await createRunner()
704+
.expect({ transaction: { transaction: 'main' } })
705+
.expect({
706+
span: container => {
707+
const invokeAgent = container.items.find(
708+
span => span.attributes['sentry.op']?.value === 'gen_ai.invoke_agent',
709+
)!;
710+
expect(invokeAgent).toBeDefined();
711+
expect(invokeAgent.status).toBe('ok');
712+
expect(invokeAgent.attributes['vercel.ai.operationId']?.value).toBe('ai.streamText');
713+
expect(invokeAgent.attributes[GEN_AI_USAGE_TOTAL_TOKENS_ATTRIBUTE]?.value).toBe(30);
714+
715+
const generateContent = container.items.find(
716+
span => span.attributes['sentry.op']?.value === 'gen_ai.generate_content',
717+
)!;
718+
expect(generateContent).toBeDefined();
719+
expect(generateContent.parent_span_id).toBe(invokeAgent.span_id);
720+
expect(generateContent.attributes[GEN_AI_USAGE_INPUT_TOKENS_ATTRIBUTE]?.value).toBe(12);
721+
expect(generateContent.attributes[GEN_AI_USAGE_OUTPUT_TOKENS_ATTRIBUTE]?.value).toBe(18);
722+
expect(generateContent.attributes[GEN_AI_RESPONSE_FINISH_REASONS_ATTRIBUTE]?.value).toBe('["stop"]');
723+
// The streamed JSON object is accumulated from the text deltas and captured as the
724+
// model's output text (embedded as an escaped JSON string in the output message).
725+
const output = generateContent.attributes[GEN_AI_OUTPUT_MESSAGES_ATTRIBUTE]?.value as string;
726+
expect(output).toContain('San Francisco');
727+
expect(output).toContain('sunny');
598728
},
599729
})
600730
.start()

0 commit comments

Comments
 (0)