From e6a1eafb7b641cb3ff4577e3936e5e9b1d6b389c Mon Sep 17 00:00:00 2001 From: Charly Gomez Date: Mon, 7 Sep 2026 09:59:25 +0200 Subject: [PATCH] fix(core): Stop supabaseIntegration from ending spans twice The Supabase auth and PostgREST wrappers end their spans by hand once the wrapped promise settles, but they ran inside a startSpan callback that also ends the span when the callback's promise resolves. Every instrumented call therefore ended its span twice, and OTel diag loggers reported "You can only call end() on a span once" for each one. Switch both wrappers to startSpanManual so the manual end is the only one. Dropping the manual end instead would have extended each span to include the caller's own then handlers, which the wrapper chains onto the promise it returns. Fixes #24116 Co-Authored-By: Claude Fable 5.1 --- packages/core/src/integrations/supabase.ts | 9 +- .../test/lib/integrations/supabase.test.ts | 141 +++++++++++++++--- 2 files changed, 124 insertions(+), 26 deletions(-) diff --git a/packages/core/src/integrations/supabase.ts b/packages/core/src/integrations/supabase.ts index a97dd0e0f9f3..843f8e02ef2c 100644 --- a/packages/core/src/integrations/supabase.ts +++ b/packages/core/src/integrations/supabase.ts @@ -13,7 +13,7 @@ import { defineIntegration } from '../integration'; import { SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN } from '../semanticAttributes'; import { setHttpStatus, SPAN_STATUS_ERROR, SPAN_STATUS_OK } from '../tracing'; import { hasSpanStreamingEnabled } from '../tracing/spans/hasSpanStreamingEnabled'; -import { startSpan } from '../tracing/trace'; +import { startSpanManual } from '../tracing/trace'; import type { IntegrationFn } from '../types/integration'; import type { WebFetchHeaders } from '../types/webfetchapi'; import { debug } from '../utils/debug-logger'; @@ -291,7 +291,9 @@ function instrumentAuthOperation(operation: AuthOperationFn, isAdmin = false): A // transactions. `auth ${isAdmin ? '(admin) ' : ''}${operation.name}`; - return startSpan( + // The span is ended by hand once the wrapped promise settles, so `startSpanManual` is used to keep + // `startSpan`'s automatic end from ending it a second time. + return startSpanManual( { name, attributes: { @@ -474,7 +476,8 @@ function instrumentPostgRESTFilterBuilder( attributes['db.body'] = bodyPayload; } - return startSpan( + // Same as the auth wrapper above: the span is ended by hand, so avoid the automatic second end. + return startSpanManual( { name, attributes, diff --git a/packages/core/test/lib/integrations/supabase.test.ts b/packages/core/test/lib/integrations/supabase.test.ts index 175e6caee6d8..961f232e21d3 100644 --- a/packages/core/test/lib/integrations/supabase.test.ts +++ b/packages/core/test/lib/integrations/supabase.test.ts @@ -14,15 +14,43 @@ import type { } from '../../../src/integrations/supabase'; import { resolveDataCollectionOptions } from '../../../src/utils/data-collection/resolveDataCollectionOptions'; -const tracingMocks = vi.hoisted(() => ({ - startSpan: vi.fn((_opts: unknown, cb: (span: unknown) => unknown) => { - const mockSpan = { - setStatus: vi.fn(), - end: vi.fn(), - }; - return cb(mockSpan); - }), -})); +const tracingMocks = vi.hoisted(() => { + const createMockSpan = () => ({ + setStatus: vi.fn(), + end: vi.fn(), + }); + + const startedSpans: Array> = []; + + return { + startedSpans, + // Mirrors the real `startSpan`, which ends the span itself once the callback's promise settles. + startSpan: vi.fn((_opts: unknown, cb: (span: unknown) => unknown) => { + const mockSpan = createMockSpan(); + startedSpans.push(mockSpan); + const result = cb(mockSpan); + if (result && typeof (result as PromiseLike).then === 'function') { + return (result as Promise).then( + value => { + mockSpan.end(); + return value; + }, + err => { + mockSpan.end(); + throw err; + }, + ); + } + mockSpan.end(); + return result; + }), + startSpanManual: vi.fn((_opts: unknown, cb: (span: unknown, finish: () => void) => unknown) => { + const mockSpan = createMockSpan(); + startedSpans.push(mockSpan); + return cb(mockSpan, () => mockSpan.end()); + }), + }; +}); const currentScopesMocks = vi.hoisted(() => ({ getClient: vi.fn(), @@ -37,6 +65,7 @@ vi.mock('../../../src/tracing', () => ({ vi.mock('../../../src/tracing/trace', () => ({ startSpan: tracingMocks.startSpan, + startSpanManual: tracingMocks.startSpanManual, })); vi.mock('../../../src/currentScopes', () => ({ @@ -53,10 +82,14 @@ type CreateMockSupabaseClientOptions = { dataCollectionDatabaseQueryData?: boolean; /** Defaults to `'static'`, so span names keep the full description. */ traceLifecycle?: 'static' | 'stream'; + /** When set, the builder's `then` rejects with this value instead of resolving with `resolveWith`. */ + rejectWith?: unknown; }; const DEFAULT_MOCK_SUPABASE_REST_URL = 'https://example.supabase.co/rest/v1/todos'; +const flushPromises = (): Promise => new Promise(resolve => setTimeout(resolve, 0)); + /** Shared PATCH + query string + body shape for operation data tests. */ const MOCK_SUPABASE_PII_SCENARIO: Pick = { method: 'PATCH', @@ -90,7 +123,9 @@ function createMockSupabaseClient(resolveWith: unknown, options?: CreateMockSupa body = body; then(onfulfilled?: (value: any) => any, onrejected?: (reason: any) => any): Promise { - return Promise.resolve(resolveWith).then(onfulfilled, onrejected); + const promise = + options?.rejectWith !== undefined ? Promise.reject(options.rejectWith) : Promise.resolve(resolveWith); + return promise.then(onfulfilled, onrejected); } } @@ -128,6 +163,7 @@ function createMockSupabaseClient(resolveWith: unknown, options?: CreateMockSupa describe('Supabase Integration', () => { beforeEach(() => { currentScopesMocks.getClient.mockReturnValue(undefined); + tracingMocks.startedSpans.length = 0; }); describe('getHeader', () => { @@ -264,6 +300,65 @@ describe('Supabase Integration', () => { }); }); + describe('span lifecycle', () => { + beforeEach(() => { + vi.spyOn(exportsModule, 'captureException').mockImplementation(() => ''); + vi.spyOn(breadcrumbModule, 'addBreadcrumb').mockImplementation(() => {}); + }); + + afterEach(() => { + vi.restoreAllMocks(); + }); + + it('ends the PostgREST span exactly once when the query resolves', async () => { + const client = createMockSupabaseClient({ status: 200, data: [] }); + instrumentSupabaseClient(client); + + await (client as any).from('todos').select('*'); + // Awaiting the builder settles through the `resolve` passed to `then`, before the wrapped promise chain + // has fully unwound. Yield once so any trailing `end()` call has had a chance to run. + await flushPromises(); + + expect(tracingMocks.startedSpans).toHaveLength(1); + expect(tracingMocks.startedSpans[0]!.end).toHaveBeenCalledTimes(1); + }); + + it('ends the PostgREST span exactly once when the query rejects', async () => { + const rejection = new Error('network down'); + const client = createMockSupabaseClient(undefined, { rejectWith: rejection }); + instrumentSupabaseClient(client); + + await expect((client as any).from('todos').select('*')).rejects.toBe(rejection); + await flushPromises(); + + expect(tracingMocks.startedSpans).toHaveLength(1); + expect(tracingMocks.startedSpans[0]!.end).toHaveBeenCalledTimes(1); + }); + + it('ends the auth span exactly once', async () => { + const client = createMockSupabaseClient(undefined) as any; + client.auth.signInWithPassword = vi.fn(() => Promise.resolve({ data: { user: {} }, error: null })); + instrumentSupabaseClient(client); + + await client.auth.signInWithPassword({ email: 'a@b.c', password: 'pw' }); + + expect(tracingMocks.startedSpans).toHaveLength(1); + expect(tracingMocks.startedSpans[0]!.end).toHaveBeenCalledTimes(1); + }); + + it('ends the auth span exactly once when the operation rejects', async () => { + const client = createMockSupabaseClient(undefined) as any; + const rejection = new Error('auth down'); + client.auth.signInWithPassword = vi.fn(() => Promise.reject(rejection)); + instrumentSupabaseClient(client); + + await expect(client.auth.signInWithPassword({ email: 'a@b.c', password: 'pw' })).rejects.toBe(rejection); + + expect(tracingMocks.startedSpans).toHaveLength(1); + expect(tracingMocks.startedSpans[0]!.end).toHaveBeenCalledTimes(1); + }); + }); + describe('operation data collection', () => { let captureExceptionSpy: ReturnType; let addBreadcrumbSpy: ReturnType; @@ -286,7 +381,7 @@ describe('Supabase Integration', () => { await (client as any).from('users').update({}).then(); - const spanOptions = tracingMocks.startSpan.mock.calls[0]![0] as { + const spanOptions = tracingMocks.startSpanManual.mock.calls[0]![0] as { name: string; attributes: Record; }; @@ -308,7 +403,7 @@ describe('Supabase Integration', () => { await (client as any).from('users').update({}).then(); - const spanOptions = tracingMocks.startSpan.mock.calls[0]![0] as { + const spanOptions = tracingMocks.startSpanManual.mock.calls[0]![0] as { name: string; attributes: Record; }; @@ -339,7 +434,7 @@ describe('Supabase Integration', () => { await (client as any).from('users').update({}).then(); - const spanOptions = tracingMocks.startSpan.mock.calls[0]![0] as { + const spanOptions = tracingMocks.startSpanManual.mock.calls[0]![0] as { name: string; attributes: Record; }; @@ -361,7 +456,7 @@ describe('Supabase Integration', () => { await (client as any).from('users').update({}).then(); - const spanOptions = tracingMocks.startSpan.mock.calls[0]![0] as { + const spanOptions = tracingMocks.startSpanManual.mock.calls[0]![0] as { name: string; attributes: Record; }; @@ -382,7 +477,7 @@ describe('Supabase Integration', () => { await (client as any).from('users').update({}).then(); - const spanOptions = tracingMocks.startSpan.mock.calls[0]![0] as { + const spanOptions = tracingMocks.startSpanManual.mock.calls[0]![0] as { name: string; attributes: Record; }; @@ -407,7 +502,7 @@ describe('Supabase Integration', () => { await (client as any).from('users').update({}).then(); - const spanOptions = tracingMocks.startSpan.mock.calls[0]![0] as { + const spanOptions = tracingMocks.startSpanManual.mock.calls[0]![0] as { name: string; attributes: Record; }; @@ -432,7 +527,7 @@ describe('Supabase Integration', () => { await (client as any).from('users').update({}).then(); - const spanOptions = tracingMocks.startSpan.mock.calls[0]![0] as { + const spanOptions = tracingMocks.startSpanManual.mock.calls[0]![0] as { name: string; attributes: Record; }; @@ -477,7 +572,7 @@ describe('Supabase Integration', () => { }); it('includes insert(...) in span description and db.body when payload is a non-empty array', async () => { - tracingMocks.startSpan.mockClear(); + tracingMocks.startSpanManual.mockClear(); const client = createMockSupabaseClient( { status: 200 }, { @@ -491,7 +586,7 @@ describe('Supabase Integration', () => { await (client as any).from('todos').insert({}).then(); - const spanOptions = tracingMocks.startSpan.mock.calls[0]![0] as { + const spanOptions = tracingMocks.startSpanManual.mock.calls[0]![0] as { name: string; attributes: Record; }; @@ -514,7 +609,7 @@ describe('Supabase Integration', () => { }); it('sets db.sdk from X-Client-Info', async () => { - tracingMocks.startSpan.mockClear(); + tracingMocks.startSpanManual.mockClear(); const client = createMockSupabaseClient( { status: 200 }, { headers: createHeaders({ 'X-Client-Info': 'supabase-js/2.112.0' }) }, @@ -523,12 +618,12 @@ describe('Supabase Integration', () => { await (client as any).from('todos').select().then(); - const spanOptions = tracingMocks.startSpan.mock.calls[0]![0] as { attributes: Record }; + const spanOptions = tracingMocks.startSpanManual.mock.calls[0]![0] as { attributes: Record }; expect(spanOptions.attributes['db.sdk']).toBe('supabase-js/2.112.0'); }); it('detects upsert from the Prefer header', async () => { - tracingMocks.startSpan.mockClear(); + tracingMocks.startSpanManual.mockClear(); const client = createMockSupabaseClient( { status: 200 }, { @@ -541,7 +636,7 @@ describe('Supabase Integration', () => { await (client as any).from('todos').upsert({}).then(); - const spanOptions = tracingMocks.startSpan.mock.calls[0]![0] as { + const spanOptions = tracingMocks.startSpanManual.mock.calls[0]![0] as { name: string; attributes: Record; };