Skip to content

Commit 38d0d7b

Browse files
mydeaclaude
andauthored
fix(vercelai): Avoid double-capturing v4 tool errors in orchestrion mode (#22293)
In orchestrion mode, a v4 Vercel AI tool error was reported to Sentry **twice**: once by the channel subscriber (`captureToolError`, which captured the raw error mid-execution) and again when the SDK's wrapped `AI_ToolExecutionError` bubbled up to the app's error handling (express handler, or the global unhandled-rejection handler). The two events are different objects (raw error vs. wrapper), so Sentry's already-captured dedup didn't collapse them. This also caused a flaky test: `captures error in tool in express server` used `.unordered()` with a single `event` expect and matched whichever of the two error envelopes arrived first — when the express-handler envelope won the race, the tool-tag assertions failed. _Root cause_ The channel subscriber's tool-`execute` wrapper always captured the thrown error and re-threw. That capture is required on **v5**, where `executeTools` swallows the rejection into `tool-error` content so it never surfaces otherwise. On **v4** the rejection instead bubbles out of the `ai` call, so it is already captured by the app's error handling — making the channel capture a duplicate. The OTel integration never had this problem because it doesn't self-capture v4 thrown tool errors; it lets them bubble. Changes: - The orchestrion subscriber now only self-captures tool errors when the enclosing operation swallows them (v5+, detected via the `'v1'` model spec version already used elsewhere in the file). On v4 it marks the tool span as errored and lets the error bubble, matching the OTel path — so a single error event is reported. - To preserve trace correlation for bubbled errors, the subscriber stamps the operation's call-site span onto the error via `_sentry_active_span`, reusing the exact mechanism the OTel integration already uses (`onunhandledrejection` restores it at capture time). Without this, an unhandled rejection in a non-OTel (orchestrion) process would start its own trace instead of correlating to the transaction. - Both of the above are per-operation facts keyed by the operation span, so they're stored together in a single `WeakMap<Span, OperationErrorInfo>` (`{ callSiteSpan, toolErrorsBubbleToCaller }`) written once at operation start, rather than two parallel collections. - Tests updated: both v4 error-in-tool scenarios now assert a single `AI_ToolExecutionError` event correlated to the transaction, in both orchestrion and OTel modes. Fixes the flaky `suites/tracing/vercelai/test.ts > ... > captures error in tool in express server [cjs]`. --------- Co-authored-by: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
1 parent 27b350f commit 38d0d7b

2 files changed

Lines changed: 84 additions & 53 deletions

File tree

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

Lines changed: 28 additions & 40 deletions
Original file line numberDiff line numberDiff line change
@@ -321,28 +321,22 @@ describe('Vercel AI integration (v4)', () => {
321321

322322
expect(errorEvent).toBeDefined();
323323
expect(errorEvent!.tags).toMatchObject({ 'test-tag': 'test-value' });
324-
// Trace id is shared between the transaction and the tool error.
325-
expect(errorEvent!.contexts!.trace!.trace_id).toBe(transactionEvent!.contexts!.trace!.trace_id);
326324

327-
if (orchestrion) {
328-
// The channel subscriber captures the raw tool error and tags it with the tool identity.
329-
expect(errorEvent!.level).toBe('error');
330-
expect(errorEvent!.tags).toMatchObject({
331-
'vercel.ai.tool.name': 'getWeather',
332-
'vercel.ai.tool.callId': 'call-1',
333-
});
334-
} else {
335-
// The OTel processor surfaces the SDK's wrapped `AI_ToolExecutionError`.
336-
expect(errorEvent!.exception?.values).toEqual(
337-
expect.arrayContaining([
338-
expect.objectContaining({
339-
type: 'AI_ToolExecutionError',
340-
value: 'Error executing tool getWeather: Error in tool',
341-
}),
342-
]),
343-
);
344-
expect(errorEvent!.contexts!.trace!.span_id).toBe(transactionEvent!.contexts!.trace!.span_id);
345-
}
325+
// The tool error bubbles out of the `ai` call as the SDK's wrapped `AI_ToolExecutionError`. The
326+
// channel subscriber deliberately doesn't self-capture v4 tool errors (that would double-report
327+
// alongside the bubbled error), so a single error event is produced in both modes.
328+
expect(errorEvent!.exception?.values).toEqual(
329+
expect.arrayContaining([
330+
expect.objectContaining({
331+
type: 'AI_ToolExecutionError',
332+
value: 'Error executing tool getWeather: Error in tool',
333+
}),
334+
]),
335+
);
336+
// Both paths stamp the operation's call-site span onto the bubbled error, so the global
337+
// unhandled-rejection handler restores it and correlates the report to the transaction's root span.
338+
expect(errorEvent!.contexts!.trace!.trace_id).toBe(transactionEvent!.contexts!.trace!.trace_id);
339+
expect(errorEvent!.contexts!.trace!.span_id).toBe(transactionEvent!.contexts!.trace!.span_id);
346340
});
347341
});
348342

@@ -352,7 +346,7 @@ describe('Vercel AI integration (v4)', () => {
352346
let errorEvent: Event | undefined;
353347

354348
const runner = createRunner()
355-
// In orchestrion mode the tool error is captured mid-request, so envelopes can arrive in any order.
349+
// The error and transaction/span envelopes can arrive in either order, so assert content, not order.
356350
.unordered()
357351
.expect({
358352
transaction: transaction => {
@@ -403,24 +397,18 @@ describe('Vercel AI integration (v4)', () => {
403397
expect(errorEvent!.tags).toMatchObject({ 'test-tag': 'test-value' });
404398
expect(errorEvent!.contexts!.trace!.trace_id).toBe(transactionEvent!.contexts!.trace!.trace_id);
405399

406-
if (orchestrion) {
407-
// The channel subscriber captures the raw tool error and tags it with the tool identity.
408-
expect(errorEvent!.tags).toMatchObject({
409-
'vercel.ai.tool.name': 'getWeather',
410-
'vercel.ai.tool.callId': 'call-1',
411-
});
412-
} else {
413-
// The OTel processor surfaces the SDK's wrapped `AI_ToolExecutionError`.
414-
expect(errorEvent!.exception?.values).toEqual(
415-
expect.arrayContaining([
416-
expect.objectContaining({
417-
type: 'AI_ToolExecutionError',
418-
value: 'Error executing tool getWeather: Error in tool',
419-
}),
420-
]),
421-
);
422-
expect(errorEvent!.contexts!.trace!.span_id).toBe(transactionEvent!.contexts!.trace!.span_id);
423-
}
400+
// The tool error bubbles out of the `ai` call as the SDK's wrapped `AI_ToolExecutionError` and is
401+
// captured once by the express error handler — the channel subscriber deliberately doesn't
402+
// self-capture v4 tool errors, so orchestrion and OTel produce the same single error event.
403+
expect(errorEvent!.exception?.values).toEqual(
404+
expect.arrayContaining([
405+
expect.objectContaining({
406+
type: 'AI_ToolExecutionError',
407+
value: 'Error executing tool getWeather: Error in tool',
408+
}),
409+
]),
410+
);
411+
expect(errorEvent!.contexts!.trace!.span_id).toBe(transactionEvent!.contexts!.trace!.span_id);
424412
});
425413
});
426414

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

Lines changed: 56 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,13 @@
11
/* eslint-disable max-lines */
22
import type { Span } from '@sentry/core';
3-
import { debug, getActiveSpan, isObjectLike, SPAN_STATUS_ERROR, withActiveSpan } from '@sentry/core';
3+
import {
4+
addNonEnumerableProperty,
5+
debug,
6+
getActiveSpan,
7+
isObjectLike,
8+
SPAN_STATUS_ERROR,
9+
withActiveSpan,
10+
} from '@sentry/core';
411
import { DEBUG_BUILD } from '../debug-build';
512
import { CHANNELS } from '../orchestrion/channels';
613
import { bindTracingChannelToSpan, type TracingChannelPayloadWithSpan } from '../tracing-channel';
@@ -100,6 +107,21 @@ const callIdBySpan = new WeakMap<Span, string>();
100107
// child `generate_content` span (whose event would fall back to the global default). v7's channel forwards
101108
// these flags on every event, so this keeps v6 identical.
102109
const recordingBySpan = new WeakMap<Span, ReturnType<typeof recording>>();
110+
interface OperationErrorInfo {
111+
// The span active when the operation was invoked (its call site, e.g. the enclosing request/`main` span).
112+
// When an operation's error bubbles out unhandled it reaches the global handler outside any span, so — as
113+
// the OTel path does — we stamp this span onto the error (in `beforeSpanEnd`) so the unhandled-rejection
114+
// handler can restore it and correlate the captured error to the operation's trace.
115+
callSiteSpan: Span | undefined;
116+
// Whether a thrown tool error bubbles out of the `ai` call (v4). On v4 a tool-`execute` rejection is
117+
// wrapped in `AI_ToolExecutionError` and re-thrown, so it reaches the user's own error handling (or our
118+
// global handlers) — capturing it at the tool span too would double-report it, matching how the OTel path
119+
// leaves v4 tool errors to bubble. On v5 `executeTools` swallows the rejection into `tool-error` content,
120+
// so it never surfaces and we must capture it ourselves (see `failSpan`).
121+
toolErrorsBubbleToCaller: boolean;
122+
}
123+
// Per-operation error-handling info, keyed by the operation span (see `OperationErrorInfo`).
124+
const operationErrorInfoBySpan = new WeakMap<Span, OperationErrorInfo>();
103125

104126
// The `experimental_telemetry` objects we swapped in to suppress `ai`'s native OTel spans (see
105127
// `suppressNativeTelemetry`). Our skip logic treats `isEnabled === false` as "user disabled telemetry,
@@ -220,10 +242,17 @@ function bindOperation(
220242
// from the channels, so the SDK's would be duplicates. Reads above have already captured everything
221243
// we need off `telemetry`.
222244
suppressNativeTelemetry(callOptions, telemetry);
245+
// The span active here is the operation's call site — `bindTracingChannelToSpan` only makes the
246+
// operation span active *after* this returns — so this is the span we later restore for a bubbled error.
247+
const callSiteSpan = getActiveSpan();
223248
const span = createSpanFromMessage(message, options);
224249
if (span) {
225250
messages.set(data, message);
226251
operationSpans.add(span);
252+
// `'v1'` models are v4 (v5/v6 are `'v2'`), where a thrown tool error bubbles out of the call rather
253+
// than being swallowed into `tool-error` content — so its tool spans must not self-capture the error.
254+
const isV4 = isObjectLike(callOptions.model) && callOptions.model.specificationVersion === 'v1';
255+
operationErrorInfoBySpan.set(span, { callSiteSpan, toolErrorsBubbleToCaller: isV4 });
227256
// v6's `executeToolCall` span: tracked so the v5 tool-`execute` patch can recognize (and skip)
228257
// tool calls it runs, since that patch sees this span as its active parent (see `patchToolExecute`).
229258
if (message.type === 'executeTool') {
@@ -239,13 +268,12 @@ function bindOperation(
239268
if (isObjectLike(callOptions.tools)) {
240269
patchOperationTools(callOptions.tools, options);
241270
}
242-
// v4 has no `resolveLanguageModel` chokepoint — the passed `LanguageModelV1`
243-
// (`specificationVersion: 'v1'`) is called directly — so patch its `doGenerate`/`doStream`
244-
// here, at the operation start, instead. v5/v6 models are `'v2'` and are patched via
245-
// `resolveLanguageModel`, so restricting to `'v1'` keeps this strictly additive and avoids
246-
// double-patching. Embedding models are also `'v1'` but expose no `doGenerate`/`doStream`, so
247-
// the patch is a no-op for `embed`/`embedMany`.
248-
if (isObjectLike(callOptions.model) && callOptions.model.specificationVersion === 'v1') {
271+
// v4 has no `resolveLanguageModel` chokepoint — the passed `LanguageModelV1` is called directly — so
272+
// patch its `doGenerate`/`doStream` here, at the operation start, instead. v5/v6 models are patched via
273+
// `resolveLanguageModel`, so restricting to v4 keeps this strictly additive and avoids double-patching.
274+
// Embedding models are also `'v1'` but expose no `doGenerate`/`doStream`, so the patch is a no-op for
275+
// `embed`/`embedMany`.
276+
if (isV4) {
249277
patchModelMethods(callOptions.model as PatchableModel, options);
250278
}
251279
}
@@ -262,7 +290,16 @@ function bindOperation(
262290
return;
263291
}
264292
// The helper's `error` handler already set the span status; only enrich from a successful result.
265-
if (!('error' in data)) {
293+
if ('error' in data) {
294+
// The error bubbles out of the `ai` call. If nothing handles it before our global handler, that
295+
// handler runs outside any span — so stamp the operation's call-site span onto the error, letting
296+
// the unhandled-rejection handler restore it and correlate the report to this trace. This mirrors
297+
// the OTel path; it's a no-op when the error is handled earlier (e.g. a framework error handler).
298+
const callSiteSpan = operationErrorInfoBySpan.get(span)?.callSiteSpan;
299+
if (callSiteSpan && isObjectLike(data.error)) {
300+
addNonEnumerableProperty(data.error, '_sentry_active_span', callSiteSpan);
301+
}
302+
} else {
266303
// v6's `executeToolCall` returns the tool result/error object directly, whereas the shared core
267304
// (matching v7) expects it nested under `output`; wrap it so tool-error detection works.
268305
message.result = message.type === 'executeTool' ? { output: data.result } : data.result;
@@ -586,11 +623,17 @@ function patchToolExecute(
586623
return original.apply(this, [input, ...rest]);
587624
}
588625

589-
// v5's `executeTools` catches a thrown tool error and turns it into `tool-error` content rather
590-
// than rejecting, so the user never sees a rejection — we must capture it here. Rethrow so
591-
// `executeTools` still produces its `tool-error` result and the operation continues normally.
626+
// v5's `executeTools` catches a thrown tool error and turns it into `tool-error` content rather than
627+
// rejecting, so the user never sees a rejection — we must capture it here. On v4 the rejection bubbles
628+
// out of the call and reaches the user's error handling (or our global handlers), so we only mark the
629+
// span and leave the capture to them, avoiding a duplicate report. Rethrow either way so `executeTools`
630+
// still produces its `tool-error` result (v5) and the rejection propagates (v4).
592631
const failSpan = (error: unknown): never => {
593-
captureToolError(span, message, error);
632+
if (operationErrorInfoBySpan.get(parent)?.toolErrorsBubbleToCaller) {
633+
span.setStatus({ code: SPAN_STATUS_ERROR, message: error instanceof Error ? error.message : 'tool_error' });
634+
} else {
635+
captureToolError(span, message, error);
636+
}
594637
span.end();
595638
throw error;
596639
};

0 commit comments

Comments
 (0)