Skip to content

Commit 8dae3f0

Browse files
committed
feat(server-utils): Enrich invoke_agent on streamed v6 orchestrion calls
Defer the orchestrion streamText operation span (via the deferSpanEnd hook the binding already supports) and await the StreamTextResult's completion promises (totalUsage/text/finishReason/toolCalls, resolved on drain) to enrich the invoke_agent span. This closes the earlier gap where that span ended synchronously before the stream drained, so v6 orchestrion now matches v7 and the v6 OTel path for streamed usage and output.
1 parent 2e53d4f commit 8dae3f0

2 files changed

Lines changed: 61 additions & 24 deletions

File tree

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

Lines changed: 12 additions & 24 deletions
Original file line numberDiff line numberDiff line change
@@ -44,12 +44,6 @@ describe.each([
4444
// else, we use the OTel processor
4545
const expectedOrigin = usesChannels ? 'auto.vercelai.channel' : 'auto.vercelai.otel';
4646

47-
// Streamed model-call spans get usage/finish/output on every path. The parent invoke_agent span only
48-
// gets the streamed aggregate where the operation span outlives the stream: the OTel path (v6, native
49-
// spans) and the v7 channel (asyncEnd deferred on total usage). In v6 orchestrion the operation span
50-
// ends synchronously when `streamText` returns, before the stream drains, so it can't be enriched.
51-
const enrichesInvokeAgentForStream = !(version === '6' && isOrchestrionEnabled());
52-
5347
// We only run this in ESM and CJS to verify full support
5448
// Other suites we only run in ESM to simplify the test setup
5549
createEsmAndCjsTests(
@@ -628,16 +622,14 @@ describe.each([
628622
'[{"role":"assistant","parts":[{"type":"text","content":"Stream response!"}],"finish_reason":"stop"}]',
629623
);
630624

631-
// The summed usage and output also land on the parent invoke_agent span, except where its
632-
// span ends before the stream drains (see `enrichesInvokeAgentForStream`).
633-
if (enrichesInvokeAgentForStream) {
634-
expect(invokeAgent.attributes?.[GEN_AI_USAGE_INPUT_TOKENS_ATTRIBUTE]?.value).toBe(10);
635-
expect(invokeAgent.attributes?.[GEN_AI_USAGE_OUTPUT_TOKENS_ATTRIBUTE]?.value).toBe(20);
636-
expect(invokeAgent.attributes?.[GEN_AI_USAGE_TOTAL_TOKENS_ATTRIBUTE]?.value).toBe(30);
637-
expect(invokeAgent.attributes?.[GEN_AI_OUTPUT_MESSAGES_ATTRIBUTE]?.value).toBe(
638-
'[{"role":"assistant","parts":[{"type":"text","content":"Stream response!"}],"finish_reason":"stop"}]',
639-
);
640-
}
625+
// The summed usage and output also land on the parent invoke_agent span, whose own
626+
// channel result is otherwise undefined for a stream.
627+
expect(invokeAgent.attributes?.[GEN_AI_USAGE_INPUT_TOKENS_ATTRIBUTE]?.value).toBe(10);
628+
expect(invokeAgent.attributes?.[GEN_AI_USAGE_OUTPUT_TOKENS_ATTRIBUTE]?.value).toBe(20);
629+
expect(invokeAgent.attributes?.[GEN_AI_USAGE_TOTAL_TOKENS_ATTRIBUTE]?.value).toBe(30);
630+
expect(invokeAgent.attributes?.[GEN_AI_OUTPUT_MESSAGES_ATTRIBUTE]?.value).toBe(
631+
'[{"role":"assistant","parts":[{"type":"text","content":"Stream response!"}],"finish_reason":"stop"}]',
632+
);
641633
},
642634
})
643635
.start()
@@ -672,11 +664,9 @@ describe.each([
672664
expect(invokeAgent.status).toBe('ok');
673665
expect(invokeAgent.attributes?.['vercel.ai.operationId']?.value).toBe('ai.streamText');
674666
// Usage is summed across the two streamed model calls (10+15, 20+25, 30+40).
675-
if (enrichesInvokeAgentForStream) {
676-
expect(invokeAgent.attributes?.[GEN_AI_USAGE_INPUT_TOKENS_ATTRIBUTE]?.value).toBe(25);
677-
expect(invokeAgent.attributes?.[GEN_AI_USAGE_OUTPUT_TOKENS_ATTRIBUTE]?.value).toBe(45);
678-
expect(invokeAgent.attributes?.[GEN_AI_USAGE_TOTAL_TOKENS_ATTRIBUTE]?.value).toBe(70);
679-
}
667+
expect(invokeAgent.attributes?.[GEN_AI_USAGE_INPUT_TOKENS_ATTRIBUTE]?.value).toBe(25);
668+
expect(invokeAgent.attributes?.[GEN_AI_USAGE_OUTPUT_TOKENS_ATTRIBUTE]?.value).toBe(45);
669+
expect(invokeAgent.attributes?.[GEN_AI_USAGE_TOTAL_TOKENS_ATTRIBUTE]?.value).toBe(70);
680670

681671
const generateContents = container.items.filter(
682672
span => span.attributes?.['sentry.op']?.value === 'gen_ai.generate_content',
@@ -743,9 +733,7 @@ describe.each([
743733
expect(invokeAgent).toBeDefined();
744734
expect(invokeAgent.status).toBe('ok');
745735
expect(invokeAgent.attributes?.['vercel.ai.operationId']?.value).toBe('ai.streamText');
746-
if (enrichesInvokeAgentForStream) {
747-
expect(invokeAgent.attributes?.[GEN_AI_USAGE_TOTAL_TOKENS_ATTRIBUTE]?.value).toBe(30);
748-
}
736+
expect(invokeAgent.attributes?.[GEN_AI_USAGE_TOTAL_TOKENS_ATTRIBUTE]?.value).toBe(30);
749737

750738
const generateContent = container.items.find(
751739
span => span.attributes?.['sentry.op']?.value === 'gen_ai.generate_content',

packages/server-utils/src/vercel-ai/vercel-ai-orchestrion-v6-subscriber.ts

Lines changed: 49 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,3 +1,4 @@
1+
/* eslint-disable max-lines */
12
import type { Span } from '@sentry/core';
23
import { debug, getActiveSpan, SPAN_STATUS_ERROR, withActiveSpan } from '@sentry/core';
34
import { DEBUG_BUILD } from '../debug-build';
@@ -233,10 +234,58 @@ function bindOperation(
233234
}
234235
messages.delete(data);
235236
},
237+
// `streamText` returns synchronously, so its operation span would otherwise end before the stream
238+
// drains — losing the aggregate usage/output. Defer the end and await the result's completion
239+
// promises (`totalUsage`/`text`/…, which resolve on drain), mirroring how v7's channel defers the
240+
// operation span on the SDK's total-usage promise.
241+
deferSpanEnd: ({ data, end }) => deferStreamTextOperationEnd(data, end),
236242
},
237243
);
238244
}
239245

246+
/**
247+
* Keep a streamed `streamText` operation span open until the stream drains, then enrich it from the
248+
* `StreamTextResult`'s completion promises (usage/output/finish reason) and end it. Returns `false` for
249+
* anything that isn't a streamed `streamText` result, so the helper ends the span as usual.
250+
*/
251+
function deferStreamTextOperationEnd(
252+
data: TracingChannelPayloadWithSpan<OrchestrionContext>,
253+
end: (error?: unknown) => void,
254+
): boolean {
255+
if (messages.get(data)?.type !== 'streamText' || 'error' in data || !isStreamingResult(data.result)) {
256+
return false;
257+
}
258+
259+
const streamResult = data.result;
260+
void (async () => {
261+
try {
262+
const [usage, text, toolCalls, finishReason, response] = await Promise.all([
263+
streamResult.totalUsage ?? streamResult.usage,
264+
streamResult.text,
265+
streamResult.toolCalls,
266+
streamResult.finishReason,
267+
streamResult.response,
268+
]);
269+
// Feed the resolved values back through the shared enrichment: `beforeSpanEnd` reads `data.result`.
270+
data.result = { usage, text, toolCalls, finishReason, response };
271+
end();
272+
} catch (error) {
273+
end(error);
274+
}
275+
})();
276+
277+
return true;
278+
}
279+
280+
/** A `StreamTextResult` exposes its aggregates as promises (`totalUsage`/`usage`); a settled result does not. */
281+
function isStreamingResult(result: unknown): result is Record<string, PromiseLike<unknown> | undefined> {
282+
return isRecord(result) && (isThenable(result.totalUsage) || isThenable(result.usage));
283+
}
284+
285+
function isThenable(value: unknown): boolean {
286+
return isRecord(value) && typeof value.then === 'function';
287+
}
288+
240289
/**
241290
* Neutralize `ai`'s native OpenTelemetry instrumentation for this call by pointing
242291
* `experimental_telemetry` at a copy with `isEnabled: false`. `ai`'s `getTracer` then returns its

0 commit comments

Comments
 (0)