diff --git a/CHANGELOG.md b/CHANGELOG.md index b6b8060bce4e..6d8f555ae436 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -27,6 +27,10 @@ Work in this release was contributed by @adityareddy-dev, @jpdefo, @Jxxunnn, @ph `ignoreStaticAssets` defaults to `true`, so `Deno.serve` no longer creates spans for `GET` requests to common static assets such as `favicon.ico`, `robots.txt` or `*.js` files. To keep these spans, set `denoServeIntegration({ ignoreStaticAssets: false })`. `Deno.serve` spans also follow the client's tracing configuration by default, so the integration does not start spans when tracing is disabled. +- **feat(deno): Record request sessions for `Deno.serve`** + + `denoServeIntegration` now records a request session for each incoming request, as `denoHttpIntegration` does for `node:http`. This gives release health and crash-free rates for `Deno.serve` apps. Sessions are sent only when a `release` is set. To turn them off, set `denoServeIntegration({ sessions: false })`. `sessionFlushingDelayMS` sets how long the SDK waits before it sends the session aggregate. + ## 11.8.0 ### Important Changes diff --git a/packages/core/src/integrations/http/record-request-session.ts b/packages/core/src/integrations/http/record-request-session.ts index 4ab0eccb88dd..fa608118a5a2 100644 --- a/packages/core/src/integrations/http/record-request-session.ts +++ b/packages/core/src/integrations/http/record-request-session.ts @@ -33,6 +33,29 @@ export function recordRequestSession( sessionFlushingDelayMS?: number; }, ): void { + response.once('close', startRequestSession(client, { requestIsolationScope, sessionFlushingDelayMS })); +} + +/** + * Starts a session and tracks it in the context of a given isolation scope. + * Returns a function to call when the request ends. It puts the session into + * a task, which aggregates it with other sessions in a certain time window + * (sessionFlushingDelayMs, 60 seconds by default). Calls after the first + * one do nothing. + * + * Use this when the server has no `node:http` response to pass to + * {@link recordRequestSession}. + */ +export function startRequestSession( + client: Client, + { + requestIsolationScope, + sessionFlushingDelayMS = 60_000, + }: { + requestIsolationScope: Scope; + sessionFlushingDelayMS?: number; + }, +): () => void { // Errors in this request are counted by the request session aggregate, so they must not also // update a process session inherited from the parent isolation scope. requestIsolationScope.setSession(); @@ -41,7 +64,12 @@ export function recordRequestSession( }); client.emit('startRequestSession'); - response.once('close', () => { + let ended = false; + return () => { + if (ended) { + return; + } + ended = true; const requestSession = requestIsolationScope.getScopeData().sdkProcessingMetadata.requestSession; if (client && requestSession) { @@ -89,5 +117,5 @@ export function recordRequestSession( safeUnref(timeout); } } - }); + }; } diff --git a/packages/core/src/server.ts b/packages/core/src/server.ts index e44bb9c2df8b..73f0c08e174f 100644 --- a/packages/core/src/server.ts +++ b/packages/core/src/server.ts @@ -22,7 +22,7 @@ export { DEFAULT_IGNORE_STATUS_CODES, processHttpServerTransactionEvent, } from './integrations/http/server-transaction-event'; -export { recordRequestSession } from './integrations/http/record-request-session'; +export { recordRequestSession, startRequestSession } from './integrations/http/record-request-session'; export { getClientIPAddress } from './utils/clientIPAddress'; export { addOutgoingRequestBreadcrumb } from './integrations/http/add-outgoing-request-breadcrumb'; export { diff --git a/packages/core/test/lib/integrations/http/record-request-session.test.ts b/packages/core/test/lib/integrations/http/record-request-session.test.ts new file mode 100644 index 000000000000..2aef541fa81f --- /dev/null +++ b/packages/core/test/lib/integrations/http/record-request-session.test.ts @@ -0,0 +1,129 @@ +import { EventEmitter } from 'node:events'; +import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest'; +import { recordRequestSession, startRequestSession } from '../../../../src/integrations/http/record-request-session'; +import { Scope } from '../../../../src/scope'; +import { getDefaultTestClientOptions, TestClient } from '../../../mocks/client'; + +function createTestClient(): TestClient { + return new TestClient(getDefaultTestClientOptions({ release: '1.0.0' })); +} + +describe('startRequestSession()', () => { + beforeEach(() => { + vi.useFakeTimers(); + vi.setSystemTime(new Date('March 19, 1999 06:12:34 UTC')); + }); + + afterEach(() => { + vi.useRealTimers(); + }); + + it('counts the session when end() is called', () => { + const client = createTestClient(); + const sendSessionSpy = vi.spyOn(client, 'sendSession'); + const requestIsolationScope = new Scope(); + + const end = startRequestSession(client, { requestIsolationScope }); + vi.runAllTimers(); + expect(sendSessionSpy).not.toHaveBeenCalled(); + + end(); + vi.runAllTimers(); + + expect(sendSessionSpy).toHaveBeenCalledWith({ + aggregates: [{ crashed: 0, errored: 0, exited: 1, started: '1999-03-19T06:12:00.000Z' }], + }); + }); + + it('counts the status set on the request isolation scope before end()', () => { + const client = createTestClient(); + const sendSessionSpy = vi.spyOn(client, 'sendSession'); + const requestIsolationScope = new Scope(); + + const end = startRequestSession(client, { requestIsolationScope }); + requestIsolationScope.getScopeData().sdkProcessingMetadata.requestSession!.status = 'crashed'; + end(); + vi.runAllTimers(); + + expect(sendSessionSpy).toHaveBeenCalledWith({ + aggregates: [{ crashed: 1, errored: 0, exited: 0, started: '1999-03-19T06:12:00.000Z' }], + }); + }); + + it('counts a session once when end() is called more than once', () => { + const client = createTestClient(); + const sendSessionSpy = vi.spyOn(client, 'sendSession'); + const requestIsolationScope = new Scope(); + + const end = startRequestSession(client, { requestIsolationScope }); + end(); + end(); + vi.runAllTimers(); + + expect(sendSessionSpy).toHaveBeenCalledTimes(1); + expect(sendSessionSpy).toHaveBeenCalledWith({ + aggregates: [{ crashed: 0, errored: 0, exited: 1, started: '1999-03-19T06:12:00.000Z' }], + }); + }); + + it('emits the "startRequestSession" hook when the session starts', () => { + const client = createTestClient(); + const onStartRequestSession = vi.fn(); + client.on('startRequestSession', onStartRequestSession); + + startRequestSession(client, { requestIsolationScope: new Scope() }); + + expect(onStartRequestSession).toHaveBeenCalledTimes(1); + }); + + it('uses sessionFlushingDelayMS to schedule the aggregate', () => { + const client = createTestClient(); + const sendSessionSpy = vi.spyOn(client, 'sendSession'); + + startRequestSession(client, { requestIsolationScope: new Scope(), sessionFlushingDelayMS: 1_000 })(); + + vi.advanceTimersByTime(999); + expect(sendSessionSpy).not.toHaveBeenCalled(); + vi.advanceTimersByTime(1); + expect(sendSessionSpy).toHaveBeenCalledTimes(1); + }); + it('sends the aggregate after 60 seconds by default', () => { + const client = createTestClient(); + const sendSessionSpy = vi.spyOn(client, 'sendSession'); + + startRequestSession(client, { requestIsolationScope: new Scope() })(); + + vi.advanceTimersByTime(59_999); + expect(sendSessionSpy).not.toHaveBeenCalled(); + vi.advanceTimersByTime(1); + expect(sendSessionSpy).toHaveBeenCalledTimes(1); + }); +}); + +describe('recordRequestSession()', () => { + beforeEach(() => { + vi.useFakeTimers(); + vi.setSystemTime(new Date('March 19, 1999 06:12:34 UTC')); + }); + + afterEach(() => { + vi.useRealTimers(); + }); + + it('counts the session when the response emits close', () => { + const client = createTestClient(); + const sendSessionSpy = vi.spyOn(client, 'sendSession'); + const response = Object.assign(new EventEmitter(), { statusCode: 200, headers: {} }); + + recordRequestSession(client, { requestIsolationScope: new Scope(), response }); + vi.runAllTimers(); + expect(sendSessionSpy).not.toHaveBeenCalled(); + + response.emit('close'); + vi.runAllTimers(); + + expect(sendSessionSpy).toHaveBeenCalledWith({ + aggregates: [{ crashed: 0, errored: 0, exited: 1, started: '1999-03-19T06:12:00.000Z' }], + }); + }); +}); diff --git a/packages/deno/src/integrations/deno-serve.ts b/packages/deno/src/integrations/deno-serve.ts index 16d061cbd1f7..9d20e9084848 100644 --- a/packages/deno/src/integrations/deno-serve.ts +++ b/packages/deno/src/integrations/deno-serve.ts @@ -61,6 +61,23 @@ export type DenoServeIntegrationOptions = { */ onSpanEnd?: (span: Span, request: Request, response: Response) => void; + /** + * Whether the integration should create [Sessions](https://docs.sentry.io/product/releases/health/#sessions) for + * incoming requests to track the health and crash-free rate of your releases in Sentry. + * + * For a streamed response, the session ends when the stream finishes. + * + * @default `true` + */ + sessions?: boolean; + + /** + * Number of milliseconds until sessions are flushed as a session aggregate. + * + * @default `60000` (60s) + */ + sessionFlushingDelayMS?: number; + /** * Do not capture spans for incoming `Deno.serve` requests with the given status codes. * By default, some 3xx and 4xx status codes are dropped (see @default). @@ -149,6 +166,8 @@ const _denoServeIntegration = ((options: DenoServeIntegrationOptions = {}) => { spans: options.spans, onSpanCreated: options.onSpanCreated, onSpanEnd: options.onSpanEnd, + sessions: options.sessions ?? true, + sessionFlushingDelayMS: options.sessionFlushingDelayMS, processEvent(event: Event): Event | null { // Gated on this integration's own span origin so it does not filter `node:http` // transactions, which `denoHttpIntegration` owns via its own `ignoreStatusCodes`. diff --git a/packages/deno/src/utils/streaming.ts b/packages/deno/src/utils/streaming.ts index 276d2455af3a..0b82c16e4a47 100644 --- a/packages/deno/src/utils/streaming.ts +++ b/packages/deno/src/utils/streaming.ts @@ -2,17 +2,17 @@ import type { Span } from '@sentry/core'; import { classifyResponseStreaming } from '@sentry/core/server'; /** - * Tee a stream, and end the provided span when the stream ends. + * Tee a stream, and end the provided span (if any) when the stream ends. * Returns the other side of the tee, which can be used to send the * response to a client. * * `onEnd` runs right before the span ends. */ -export async function streamResponse(span: Span, res: Response, onEnd?: () => void): Promise { +export async function streamResponse(span: Span | undefined, res: Response, onEnd?: () => void): Promise { const classification = classifyResponseStreaming(res); const endSpan = (): void => { onEnd?.(); - span.end(); + span?.end(); }; // not streaming, just end the span and return the response diff --git a/packages/deno/src/wrap-deno-request-handler.ts b/packages/deno/src/wrap-deno-request-handler.ts index 465adeb1ed44..ed8d6ae2b77e 100644 --- a/packages/deno/src/wrap-deno-request-handler.ts +++ b/packages/deno/src/wrap-deno-request-handler.ts @@ -25,7 +25,7 @@ import { winterCGRequestToRequestData, withIsolationScope, } from '@sentry/core'; -import { getClientIPAddress, isStaticAssetRequest } from '@sentry/core/server'; +import { getClientIPAddress, isStaticAssetRequest, startRequestSession } from '@sentry/core/server'; import type { DenoServeIntegrationOptions } from './integrations/deno-serve'; import { streamResponse } from './utils/streaming'; @@ -100,17 +100,25 @@ export const wrapDenoRequestHandler = ( } isolationScope.setClient(client); + const integration = client.getIntegrationByName('DenoServe'); + const endSession = integration?.sessions + ? startRequestSession(client, { + requestIsolationScope: isolationScope, + sessionFlushingDelayMS: integration.sessionFlushingDelayMS, + }) + : undefined; + if (request.method === 'OPTIONS' || request.method === 'HEAD') { try { return await handler(); } catch (e) { captureServeError(e); throw e; + } finally { + endSession?.(); } } - const integration = client.getIntegrationByName('DenoServe'); - const urlObject = parseStringToURLObject(request.url); const [rawName, attributes] = getHttpSpanDetailsFromUrlObject( urlObject, @@ -181,16 +189,18 @@ export const wrapDenoRequestHandler = ( }, async () => { if (!createSpan) { + let res: Response; try { - const res = await handler(); + res = await handler(); isolationScope.setContext('response', { status_code: res.status, }); - return res; } catch (e) { captureServeError(e); + endSession?.(); throw e; } + return endSession ? streamResponse(undefined, res, endSession) : res; } return startSpanManual({ name, attributes }, async span => { @@ -212,14 +222,16 @@ export const wrapDenoRequestHandler = ( } catch (e) { span.end(); captureServeError(e); + endSession?.(); throw e; } - return streamResponse( - span, - res, - onSpanEnd && (() => callUserCallback('onSpanEnd', () => onSpanEnd(span, request, res), undefined)), - ); + return streamResponse(span, res, () => { + if (onSpanEnd) { + callUserCallback('onSpanEnd', () => onSpanEnd(span, request, res), undefined); + } + endSession?.(); + }); }); }, ); diff --git a/packages/deno/test/deno-serve.test.ts b/packages/deno/test/deno-serve.test.ts index f30318f0fbcd..90719660ea43 100644 --- a/packages/deno/test/deno-serve.test.ts +++ b/packages/deno/test/deno-serve.test.ts @@ -1,11 +1,13 @@ // -import type { ErrorEvent, Span, TransactionEvent } from '@sentry/core'; -import { getMainCarrier } from '@sentry/core'; +import type { AggregationCounts, Envelope, ErrorEvent, Span, TransactionEvent } from '@sentry/core'; +import { forEachEnvelopeItem, getMainCarrier } from '@sentry/core'; import { assertEquals, assertExists, assertMatch, assertNotEquals } from 'https://deno.land/std@0.212.0/assert/mod.ts'; -import type { DenoClient } from '../build/esm/index.js'; +import type { DenoClient, DenoOptions } from '../build/esm/index.js'; import { captureException, captureMessage, init, denoServeIntegration, setTag, setUser } from '../build/esm/index.js'; +import { makeTestTransport } from './transport.ts'; + const LOOPBACK_ADDRESS = /^(127\.0\.0\.1|::1|::ffff:127\.0\.0\.1)$/; function resetGlobals(): void { @@ -1410,3 +1412,180 @@ Deno.test('Deno.serve should create the span and still respond when ignoreIncomi ['GET /page'], ); }); + +type SessionCounts = Omit; + +function initWithSessionTransport(options: DenoOptions = {}): { + client: DenoClient; + sessions: SessionCounts[]; + firstSession: Promise; +} { + const sessions: SessionCounts[] = []; + let resolveFirstSession: () => void; + const firstSession = new Promise(resolve => (resolveFirstSession = resolve)); + const client = init({ + dsn: 'https://username@domain/123', + release: '1.0.0', + transport: makeTestTransport((envelope: Envelope) => { + forEachEnvelopeItem(envelope, (item, type) => { + if (type === 'sessions') { + for (const { started: _started, ...counts } of (item[1] as { aggregates: AggregationCounts[] }).aggregates) { + sessions.push(counts); + } + resolveFirstSession(); + } + }); + }), + ...options, + }) as DenoClient; + return { client, sessions, firstSession }; +} + +Deno.test('Deno.serve should record an exited session for a successful request', async () => { + resetGlobals(); + const { client, sessions } = initWithSessionTransport(); + + const server = await serveForTest(() => new Response('OK')); + await (await fetch(`${server.url}/ok`)).text(); + await server.close(); + await client.flush(); + + assertEquals(sessions, [{ exited: 1, errored: 0, crashed: 0 }]); +}); + +Deno.test('Deno.serve should record an errored session for a handled exception', async () => { + resetGlobals(); + const { client, sessions } = initWithSessionTransport(); + + const server = await serveForTest(() => { + captureException(new Error('handled')); + return new Response('OK'); + }); + await (await fetch(`${server.url}/handled`)).text(); + await server.close(); + await client.flush(); + + assertEquals(sessions, [{ exited: 0, errored: 1, crashed: 0 }]); +}); + +Deno.test('Deno.serve should record a crashed session when the handler throws', async () => { + resetGlobals(); + const { client, sessions } = initWithSessionTransport(); + + const server = await serveForTest(() => { + throw new Error('unhandled'); + }); + await (await fetch(`${server.url}/throws`)).text(); + await server.close(); + await client.flush(); + + assertEquals(sessions, [{ exited: 0, errored: 0, crashed: 1 }]); +}); + +Deno.test('Deno.serve should record sessions for OPTIONS and HEAD requests', async () => { + resetGlobals(); + const { client, sessions } = initWithSessionTransport(); + + const server = await serveForTest(() => new Response('OK')); + await (await fetch(`${server.url}/cors`, { method: 'OPTIONS' })).text(); + await (await fetch(`${server.url}/cors`, { method: 'HEAD' })).text(); + await server.close(); + await client.flush(); + + assertEquals(sessions, [{ exited: 2, errored: 0, crashed: 0 }]); +}); + +Deno.test('Deno.serve should not record sessions when sessions is false', async () => { + resetGlobals(); + const { client, sessions } = initWithSessionTransport({ + integrations: integrations => [ + ...integrations.filter(integration => integration.name !== 'DenoServe'), + denoServeIntegration({ sessions: false }), + ], + }); + + const server = await serveForTest(() => new Response('OK')); + await (await fetch(`${server.url}/ok`)).text(); + await server.close(); + await client.flush(); + + assertEquals(sessions, []); +}); + +Deno.test('Deno.serve should send the session aggregate after sessionFlushingDelayMS', async () => { + resetGlobals(); + const { sessions, firstSession } = initWithSessionTransport({ + integrations: integrations => [ + ...integrations.filter(integration => integration.name !== 'DenoServe'), + denoServeIntegration({ sessionFlushingDelayMS: 50 }), + ], + }); + + const server = await serveForTest(() => new Response('OK')); + await (await fetch(`${server.url}/ok`)).text(); + await server.close(); + + // The timeout only bounds a failure. With the default 60s delay, no + // session arrives within it. + let timeoutId: ReturnType | undefined; + const timedOut = new Promise<'timed out'>(resolve => { + timeoutId = setTimeout(() => resolve('timed out'), 10_000); + }); + const result = await Promise.race([firstSession.then(() => 'sent' as const), timedOut]); + clearTimeout(timeoutId); + + assertEquals(result, 'sent'); + assertEquals(sessions, [{ exited: 1, errored: 0, crashed: 0 }]); +}); + +for (const [label, options] of [ + ['when tracing is enabled', { tracesSampleRate: 1, traceLifecycle: 'static' }], + ['when tracing is disabled', {}], +] as const) { + Deno.test(`Deno.serve should record a streamed response session when the stream finishes ${label}`, async () => { + resetGlobals(); + const { client, sessions } = initWithSessionTransport(options); + + let streamController: ReadableStreamDefaultController | undefined; + const server = await serveForTest(() => { + const stream = new ReadableStream({ + start(controller) { + streamController = controller; + controller.enqueue(new TextEncoder().encode('chunk\n')); + }, + }); + return new Response(stream, { headers: { 'content-type': 'text/event-stream' } }); + }); + + const response = await fetch(`${server.url}/stream`); + await client.flush(); + assertEquals(sessions, []); + + streamController!.close(); + assertEquals(await response.text(), 'chunk\n'); + await server.close(); + await client.flush(); + + assertEquals(sessions, [{ exited: 1, errored: 0, crashed: 0 }]); + }); +} + +Deno.test('Deno.serve should record sessions for requests without a span', async () => { + resetGlobals(); + const { client, sessions } = initWithSessionTransport({ + tracesSampleRate: 1, + traceLifecycle: 'static', + integrations: integrations => [ + ...integrations.filter(integration => integration.name !== 'DenoServe'), + denoServeIntegration({ ignoreIncomingRequests: urlPath => urlPath === '/health' }), + ], + }); + + const server = await serveForTest(() => new Response('OK')); + await (await fetch(`${server.url}/health`)).text(); + await (await fetch(`${server.url}/favicon.ico`)).text(); + await server.close(); + await client.flush(); + + assertEquals(sessions, [{ exited: 2, errored: 0, crashed: 0 }]); +});