diff --git a/dev-packages/node-integration-tests/suites/tracing/httpIntegration/instrument-throwing-callbacks.mjs b/dev-packages/node-integration-tests/suites/tracing/httpIntegration/instrument-throwing-callbacks.mjs new file mode 100644 index 000000000000..6f320edfab45 --- /dev/null +++ b/dev-packages/node-integration-tests/suites/tracing/httpIntegration/instrument-throwing-callbacks.mjs @@ -0,0 +1,31 @@ +import * as Sentry from '@sentry/node'; +import { loggingTransport } from '@sentry-internal/node-integration-tests'; + +Sentry.init({ + dsn: 'https://public@dsn.ingest.sentry.io/1337', + release: '1.0', + tracesSampleRate: 1.0, + transport: loggingTransport, + + integrations: [ + Sentry.httpIntegration({ + instrumentation: { + requestHook: () => { + throw new Error('requestHook error'); + }, + responseHook: () => { + throw new Error('responseHook error'); + }, + applyCustomAttributesOnSpan: () => { + throw new Error('applyCustomAttributesOnSpan error'); + }, + }, + ignoreIncomingRequests: () => { + throw new Error('ignoreIncomingRequests error'); + }, + onSpanCreated: () => { + throw new Error('onSpanCreated error'); + }, + }), + ], +}); diff --git a/dev-packages/node-integration-tests/suites/tracing/httpIntegration/test.ts b/dev-packages/node-integration-tests/suites/tracing/httpIntegration/test.ts index 69740b8bdaf4..af5579bef0da 100644 --- a/dev-packages/node-integration-tests/suites/tracing/httpIntegration/test.ts +++ b/dev-packages/node-integration-tests/suites/tracing/httpIntegration/test.ts @@ -581,4 +581,28 @@ describe('httpIntegration', () => { await runner.completed(); }); + describe('user callbacks that throw', () => { + createEsmAndCjsTests(__dirname, 'server.mjs', 'instrument-throwing-callbacks.mjs', (createRunner, test) => { + test('still handles requests and sends the span when `onSpanCreated` and `ignoreIncomingRequests` throw', async () => { + const expectedTransaction = { + contexts: { + trace: { + op: 'http.server', + status: 'ok', + data: { url: expect.stringMatching(/\/test$/), 'http.response.status_code': 200 }, + }, + }, + }; + const runner = createRunner() + .unordered() + .expect({ transaction: expectedTransaction }) + .expect({ transaction: expectedTransaction }) + .start(); + + expect(await runner.makeRequest('get', '/test')).toEqual({ response: 'response 1' }); + expect(await runner.makeRequest('post', '/test')).toEqual({ response: 'response 2' }); + await runner.completed(); + }); + }); + }); }); diff --git a/packages/core/src/integrations/http/server-subscription.ts b/packages/core/src/integrations/http/server-subscription.ts index 85c047909256..dca89aaeb399 100644 --- a/packages/core/src/integrations/http/server-subscription.ts +++ b/packages/core/src/integrations/http/server-subscription.ts @@ -23,6 +23,7 @@ import { HTTP_ON_SERVER_REQUEST } from './constants'; import type { HttpIncomingMessage, HttpInstrumentationOptions, HttpServer, HttpServerResponse } from './types'; import { DEBUG_BUILD } from '../../debug-build'; import { debug } from '../../utils/debug-logger'; +import { safeCallback } from '../../utils/safeCallback'; import { getClient, getCurrentScope, getIsolationScope, withIsolationScope } from '../../currentScopes'; import { hasSpansEnabled } from '../../utils/hasSpansEnabled'; import { headersToDict, httpHeadersToSpanAttributes, httpRequestToRequestData } from '../../utils/request'; @@ -116,7 +117,14 @@ export function instrumentServer(options: HttpInstrumentationOptions, server: Ht sessionFlushingDelayMS = 60_000, } = options; - if (maxRequestBodySize !== 'none' && !ignoreRequestBody?.(url, request)) { + if ( + maxRequestBodySize !== 'none' && + !safeCallback( + DEBUG_BUILD ? 'The `ignoreRequestBody` callback threw an error, ignoring the request body:' : '', + () => !!ignoreRequestBody?.(url, request), + () => true, + ) + ) { patchRequestToCaptureBody(request, isolationScope, maxRequestBodySize, INTEGRATION_NAME); } @@ -322,7 +330,11 @@ function buildServerSpanWrap( }, }, span => { - onSpanCreated?.(span, request, response); + safeCallback( + DEBUG_BUILD ? 'The `onSpanCreated` callback threw an error:' : '', + () => onSpanCreated?.(span, request, response), + () => undefined, + ); // Ensure we only end the span once // E.g. error can be emitted before close is emitted let isEnded = false; @@ -345,7 +357,11 @@ function buildServerSpanWrap( ), }); span.setStatus(status); - onSpanEnd?.(span, request, response); + safeCallback( + DEBUG_BUILD ? 'The `onSpanEnd` callback threw an error:' : '', + () => onSpanEnd?.(span, request, response), + () => undefined, + ); span.end(); } @@ -392,7 +408,13 @@ function shouldIgnoreSpansForIncomingRequest( return true; } - if (ignoreIncomingRequests?.(urlPath, request)) { + if ( + safeCallback( + DEBUG_BUILD ? 'The `ignoreIncomingRequests` callback threw an error, not ignoring the request:' : '', + () => !!ignoreIncomingRequests?.(urlPath, request), + () => false, + ) + ) { return true; } diff --git a/packages/core/src/shared-exports.ts b/packages/core/src/shared-exports.ts index 4a6a1a4accd0..c94304177273 100644 --- a/packages/core/src/shared-exports.ts +++ b/packages/core/src/shared-exports.ts @@ -91,6 +91,7 @@ export { isStreamedBeforeSendSpanCallback } from './tracing/spans/beforeSendSpan export { safeSetSpanJSONAttributes } from './tracing/spans/captureSpan'; export { isSentryRequestUrl } from './utils/isSentryRequestUrl'; export { handleCallbackErrors } from './utils/handleCallbackErrors'; +export { safeCallback } from './utils/safeCallback'; export { parameterize, fmt } from './utils/parameterize'; export type { HandleTunnelRequestOptions } from './utils/tunnel'; export { handleTunnelRequest } from './utils/tunnel'; diff --git a/packages/core/src/utils/safeCallback.ts b/packages/core/src/utils/safeCallback.ts new file mode 100644 index 000000000000..5b9079ca7c5d --- /dev/null +++ b/packages/core/src/utils/safeCallback.ts @@ -0,0 +1,35 @@ +import { DEBUG_BUILD } from '../debug-build'; +import { debug } from './debug-logger'; +import { isThenable } from './is'; + +/** + * Invokes a user-provided callback (e.g. `beforeSend`, `tracesSampler`, an integration hook) so that + * neither a synchronous throw nor a rejected promise escapes into the caller. On failure the error is + * logged and `fallback(error)` supplies the result instead. + * + * Not for `startSpan` bodies: those must re-throw and are handled by `handleCallbackErrors`. + * + * @param message - Logged via `debug.error` together with the error. Pass it as `DEBUG_BUILD ? '...' : ''` + * so the string is tree-shaken from non-debug bundles. + * @param fn - Invokes the callback. + * @param fallback - Produces the result to use when the callback throws or rejects. + */ +export function safeCallback(message: string, fn: () => T, fallback: (error: unknown) => T): T { + let result: T; + try { + result = fn(); + } catch (error) { + return recover(message, error, fallback); + } + + if (isThenable(result)) { + return result.then(undefined, (error: unknown) => recover(message, error, fallback)) as T; + } + + return result; +} + +function recover(message: string, error: unknown, fallback: (error: unknown) => T): T { + DEBUG_BUILD && debug.error(message, error); + return fallback(error); +} diff --git a/packages/core/test/lib/integrations/http/server-subscription.test.ts b/packages/core/test/lib/integrations/http/server-subscription.test.ts index 136e06312905..468c028eb8e5 100644 --- a/packages/core/test/lib/integrations/http/server-subscription.test.ts +++ b/packages/core/test/lib/integrations/http/server-subscription.test.ts @@ -8,6 +8,7 @@ import { getIsolationScope } from '../../../../src/currentScopes'; import { setCurrentClient } from '../../../../src/sdk'; import { HTTP_ON_SERVER_REQUEST } from '../../../../src/integrations/http/constants'; import { getHttpServerSubscriptions } from '../../../../src/integrations/http/server-subscription'; +import type { HttpInstrumentationOptions } from '../../../../src/integrations/http/types'; import type { Event } from '../../../../src/types/event'; import { getDefaultTestClientOptions, TestClient } from '../../../mocks/client'; @@ -42,7 +43,12 @@ describe('getHttpServerSubscriptions', () => { await new Promise(resolve => server.close(() => resolve())); }); - async function makeRequest(path: string, method: 'GET' | 'HEAD' = 'GET'): Promise { + async function makeRequest( + path: string, + method: 'GET' | 'HEAD' | 'OPTIONS' | 'POST' = 'GET', + extraHeaders: Record = {}, + body?: string, + ): Promise { const { port } = server.address() as AddressInfo; return new Promise((resolve, reject) => { // Connection: close so the server-side `response.once('close', ...)` @@ -54,7 +60,7 @@ describe('getHttpServerSubscriptions', () => { port, path, method, - headers: { Connection: 'close' }, + headers: { Connection: 'close', ...extraHeaders }, }, res => { // throw away response body @@ -65,7 +71,7 @@ describe('getHttpServerSubscriptions', () => { }, ); req.on('error', reject); - req.end(); + req.end(body); }); } @@ -81,7 +87,7 @@ describe('getHttpServerSubscriptions', () => { }); } - function instrument(spans: boolean, extra: { ignoreStaticAssets?: boolean } = {}): void { + function instrument(spans: boolean, extra: Omit = {}): void { const { [HTTP_ON_SERVER_REQUEST]: onServerRequest } = getHttpServerSubscriptions({ spans, ...extra }); // Fire the channel listener manually with the server we're about to use. // This avoids depending on Node's diagnostics_channel firing (only @@ -223,6 +229,76 @@ describe('getHttpServerSubscriptions', () => { expect(transaction.transaction).toBe('GET /favicon.ico'); }); + describe('with user callbacks that throw', () => { + const throwingCallback = (): never => { + throw new Error('callback error'); + }; + + async function expectRequestHandledTwice(): Promise { + await makeRequest('/first'); + await makeRequest('/second'); + } + + it('still handles the request and ends the span when `onSpanCreated` throws', async () => { + const handler = vi.fn((_req: http.IncomingMessage, res: http.ServerResponse) => res.end('ok')); + server = http.createServer(handler); + await new Promise(resolve => server.listen(0, '127.0.0.1', () => resolve())); + instrument(true, { onSpanCreated: throwingCallback }); + + await expectRequestHandledTwice(); + const transaction = await waitForTransaction(); + + expect(handler).toHaveBeenCalledTimes(2); + expect(transaction.transaction).toBe('GET /first'); + }); + + it('still handles the request and ends the span when `onSpanEnd` throws', async () => { + const handler = vi.fn((_req: http.IncomingMessage, res: http.ServerResponse) => res.end('ok')); + server = http.createServer(handler); + await new Promise(resolve => server.listen(0, '127.0.0.1', () => resolve())); + instrument(true, { onSpanEnd: throwingCallback }); + + await expectRequestHandledTwice(); + const transaction = await waitForTransaction(); + + expect(handler).toHaveBeenCalledTimes(2); + expect(transaction.transaction).toBe('GET /first'); + }); + + it('creates the span when `ignoreIncomingRequests` throws', async () => { + const handler = vi.fn((_req: http.IncomingMessage, res: http.ServerResponse) => res.end('ok')); + server = http.createServer(handler); + await new Promise(resolve => server.listen(0, '127.0.0.1', () => resolve())); + instrument(true, { ignoreIncomingRequests: throwingCallback }); + + await expectRequestHandledTwice(); + const transaction = await waitForTransaction(); + + expect(handler).toHaveBeenCalledTimes(2); + expect(transaction.transaction).toBe('GET /first'); + }); + + it('skips the request body when `ignoreRequestBody` throws', async () => { + const receivedBodies: string[] = []; + server = http.createServer((req, res) => { + let body = ''; + req.on('data', chunk => (body += chunk)); + req.on('end', () => { + receivedBodies.push(body); + res.end('ok'); + }); + }); + await new Promise(resolve => server.listen(0, '127.0.0.1', () => resolve())); + instrument(true, { maxRequestBodySize: 'always', ignoreRequestBody: throwingCallback }); + + await makeRequest('/body', 'POST', { 'Content-Type': 'text/plain' }, 'secret'); + const transaction = await waitForTransaction(); + + expect(receivedBodies).toEqual(['secret']); + expect(transaction.request?.data).toBeUndefined(); + }); + }); + it('re-evaluates the spans default per request based on the current client', async () => { // Swap in a no-tracing client. The default-from-client decision must be // reactive: instrumentation registered before this swap should still diff --git a/packages/core/test/lib/utils/safeCallback.test.ts b/packages/core/test/lib/utils/safeCallback.test.ts new file mode 100644 index 000000000000..dc5c4552d6ae --- /dev/null +++ b/packages/core/test/lib/utils/safeCallback.test.ts @@ -0,0 +1,70 @@ +import { afterEach, describe, expect, it, vi } from 'vitest'; +import { debug } from '../../../src/utils/debug-logger'; +import { safeCallback } from '../../../src/utils/safeCallback'; + +describe('safeCallback', () => { + const debugErrorSpy = vi.spyOn(debug, 'error').mockImplementation(() => undefined); + + afterEach(() => { + debugErrorSpy.mockClear(); + }); + + it('returns the result of a sync callback', () => { + const fallback = vi.fn(() => 'fallback'); + + expect(safeCallback('callback threw:', () => 'value', fallback)).toBe('value'); + expect(fallback).not.toHaveBeenCalled(); + expect(debugErrorSpy).not.toHaveBeenCalled(); + }); + + it('returns the fallback and logs when a sync callback throws', () => { + const error = new Error('boom'); + const fallback = vi.fn(() => 'fallback'); + + expect( + safeCallback( + 'callback threw:', + () => { + throw error; + }, + fallback, + ), + ).toBe('fallback'); + expect(fallback).toHaveBeenCalledWith(error); + expect(debugErrorSpy).toHaveBeenCalledWith('callback threw:', error); + }); + + it('resolves to the result of an async callback', async () => { + const fallback = vi.fn(async () => 'fallback'); + + const result = safeCallback('callback threw:', async () => 'value', fallback); + + expect(result).toBeInstanceOf(Promise); + await expect(result).resolves.toBe('value'); + expect(fallback).not.toHaveBeenCalled(); + expect(debugErrorSpy).not.toHaveBeenCalled(); + }); + + it('resolves to the fallback and logs when an async callback rejects', async () => { + const error = new Error('boom'); + const fallback = vi.fn(async () => 'fallback'); + + const result = safeCallback('callback threw:', () => Promise.reject(error), fallback); + + await expect(result).resolves.toBe('fallback'); + expect(fallback).toHaveBeenCalledWith(error); + expect(debugErrorSpy).toHaveBeenCalledWith('callback threw:', error); + }); + + it('does not treat non-thenable objects as promises', () => { + const value = { then: 'not a function' }; + + expect( + safeCallback( + 'callback threw:', + () => value, + () => ({ then: 'fallback' }), + ), + ).toBe(value); + }); +}); diff --git a/packages/deno/test/deno-http.test.ts b/packages/deno/test/deno-http.test.ts index a67be1fc5d71..3ae3306bd810 100644 --- a/packages/deno/test/deno-http.test.ts +++ b/packages/deno/test/deno-http.test.ts @@ -6,7 +6,14 @@ import { assert } from 'https://deno.land/std@0.212.0/assert/assert.ts'; import { assertEquals } from 'https://deno.land/std@0.212.0/assert/assert_equals.ts'; import { assertExists } from 'https://deno.land/std@0.212.0/assert/assert_exists.ts'; import type { DenoClient } from '../build/esm/index.js'; -import { getCurrentScope, getGlobalScope, getIsolationScope, init, startSpan } from '../build/esm/index.js'; +import { + denoHttpIntegration, + getCurrentScope, + getGlobalScope, + getIsolationScope, + init, + startSpan, +} from '../build/esm/index.js'; import { DENO_VERSION, HTTP_CLIENT_DIAGNOSTICS_CHANNEL_SUPPORTED, @@ -196,3 +203,45 @@ Deno.test({ assertEquals(httpClientSpan!.data?.['http.response.status_code'], 200); }, }); + +Deno.test({ + name: 'denoHttpIntegration: a throwing onSpanEnd still ends the span and serves later requests', + async fn() { + resetGlobals(); + const sink = transactionSink(); + init({ + dsn: 'https://username@domain/123', + tracesSampleRate: 1, + beforeSendTransaction: sink.beforeSendTransaction, + integrations: [ + denoHttpIntegration({ + onSpanEnd: () => { + throw new Error('onSpanEnd error'); + }, + }), + ], + }); + + const server = http.createServer((_req, res) => { + res.end('ok'); + }); + const port: number = await new Promise(resolve => { + server.listen(0, '127.0.0.1', () => { + resolve((server.address() as { port: number }).port); + }); + }); + + assertEquals(await (await fetch(`http://127.0.0.1:${port}/first`)).text(), 'ok'); + assertEquals(await (await fetch(`http://127.0.0.1:${port}/second`)).text(), 'ok'); + + const txn = await withTimeout( + sink.waitFor(t => t.transaction === 'GET /first'), + 5000, + 'http.server transaction for the first request', + ); + + await new Promise(resolve => server.close(() => resolve())); + + assertEquals(txn.contexts?.trace?.op, 'http.server'); + }, +}); diff --git a/packages/node-core/src/integrations/http/httpServerSpansIntegration.ts b/packages/node-core/src/integrations/http/httpServerSpansIntegration.ts index 34fc2e4cfd6c..802fa6bf7138 100644 --- a/packages/node-core/src/integrations/http/httpServerSpansIntegration.ts +++ b/packages/node-core/src/integrations/http/httpServerSpansIntegration.ts @@ -54,6 +54,7 @@ import { withActiveSpan, SPAN_KIND, filterCollectedUrl, + safeCallback, } from '@sentry/core'; import { DEBUG_BUILD } from '../../debug-build'; import type { NodeClient } from '../../sdk/client'; @@ -199,11 +200,26 @@ const _httpServerSpansIntegration = ((options: HttpServerSpansIntegrationOptions }, }); - // TODO v11: Remove the following three hooks, only onSpanCreated should remain - requestHook?.(span, request); - responseHook?.(span, response); - applyCustomAttributesOnSpan?.(span, request, response); - onSpanCreated?.(span, request, response); + safeCallback( + DEBUG_BUILD ? 'The `requestHook` callback threw an error:' : '', + () => requestHook?.(span, request), + () => undefined, + ); + safeCallback( + DEBUG_BUILD ? 'The `responseHook` callback threw an error:' : '', + () => responseHook?.(span, response), + () => undefined, + ); + safeCallback( + DEBUG_BUILD ? 'The `applyCustomAttributesOnSpan` callback threw an error:' : '', + () => applyCustomAttributesOnSpan?.(span, request, response), + () => undefined, + ); + safeCallback( + DEBUG_BUILD ? 'The `onSpanCreated` callback threw an error:' : '', + () => onSpanCreated?.(span, request, response), + () => undefined, + ); const rpcMetadata: RPCMetadata = { type: RPCType.HTTP, span }; @@ -363,7 +379,13 @@ function shouldIgnoreSpansForIncomingRequest( return true; } - if (ignoreIncomingRequests?.(urlPath, request)) { + if ( + safeCallback( + DEBUG_BUILD ? 'The `ignoreIncomingRequests` callback threw an error, not ignoring the request:' : '', + () => !!ignoreIncomingRequests?.(urlPath, request), + () => false, + ) + ) { return true; }