From 14824e26c9193db22b4306a388b13877a194e571 Mon Sep 17 00:00:00 2001 From: Samuel Newman Date: Wed, 2 Sep 2026 18:19:22 +0300 Subject: [PATCH] scope sentry network filtering to error values and exception events Co-Authored-By: Claude Fable 5.1 --- src/logger/__tests__/logger.test.ts | 57 +++++++++ src/logger/sentry/network-errors.test.ts | 142 +++++++++++++++++------ src/logger/sentry/network-errors.ts | 66 ++++++++--- src/logger/sentry/setup/index.ts | 4 - src/logger/transports/sentry.ts | 67 +++++++---- 5 files changed, 260 insertions(+), 76 deletions(-) diff --git a/src/logger/__tests__/logger.test.ts b/src/logger/__tests__/logger.test.ts index 3b11283a6f..c16db2ffb2 100644 --- a/src/logger/__tests__/logger.test.ts +++ b/src/logger/__tests__/logger.test.ts @@ -301,6 +301,15 @@ describe('general functionality', () => { timestamp, ) + // a named key can carry the failure as a plain string too + sentryTransport( + LogLevel.Error, + Logger.Context.Default, + 'poll failed', + {safeMessage: 'Network request failed'}, + timestamp, + ) + // call sites do not consistently use the same metadata key sentryTransport( LogLevel.Error, @@ -312,6 +321,8 @@ describe('general functionality', () => { jest.runAllTimers() expect(Sentry.captureMessage).not.toHaveBeenCalled() + // suppressing the event must not suppress the breadcrumb + expect(Sentry.addBreadcrumb).toHaveBeenCalledTimes(4) // network Error object sentryTransport( @@ -333,6 +344,52 @@ describe('general functionality', () => { expect(Sentry.captureException).not.toHaveBeenCalled() }) + test('sentryTransport reports errors with unrelated metadata', () => { + jest.clearAllMocks() + const timestamp = Date.now() + + sentryTransport( + LogLevel.Error, + Logger.Context.Default, + 'thumbnail upload failed', + {url: 'https://twitch.tv/abort', reason: 'aborted'}, + timestamp, + ) + + jest.runAllTimers() + expect(Sentry.captureMessage).toHaveBeenCalledTimes(1) + expect(Sentry.captureMessage).toHaveBeenCalledWith( + 'thumbnail upload failed', + expect.anything(), + ) + + sentryTransport( + LogLevel.Error, + Logger.Context.Default, + new Error('thumbnail upload failed'), + {url: 'https://twitch.tv/abort'}, + timestamp, + ) + expect(Sentry.captureException).toHaveBeenCalledTimes(1) + }) + + test('sentryTransport keeps breadcrumbs below error level', () => { + jest.clearAllMocks() + const timestamp = Date.now() + + sentryTransport( + LogLevel.Info, + Logger.Context.Default, + 'polling', + {safeMessage: new Error('Network request failed')}, + timestamp, + ) + + expect(Sentry.addBreadcrumb).toHaveBeenCalledTimes(1) + jest.runAllTimers() + expect(Sentry.captureMessage).not.toHaveBeenCalled() + }) + test('add/remove transport', () => { const timestamp = Date.now() const logger = new Logger({}) diff --git a/src/logger/sentry/network-errors.test.ts b/src/logger/sentry/network-errors.test.ts index 173af6ae21..0ed754910d 100644 --- a/src/logger/sentry/network-errors.test.ts +++ b/src/logger/sentry/network-errors.test.ts @@ -1,4 +1,4 @@ -import {type Procedure, XrpcFetchError, XrpcResponseError} from '@atproto/lex' +import {getMain, XrpcInternalError, XrpcResponseError} from '@atproto/lex' import {describe, expect, test} from '@jest/globals' import {type ErrorEvent} from '@sentry/react-native' @@ -6,52 +6,106 @@ import { dropExpectedNetworkErrors, isExpectedSentryNetworkError, } from '#/logger/sentry/network-errors' +import {com} from '#/lexicons' -const method = { - nsid: 'app.bsky.test.getTest', - type: 'query', -} as unknown as Procedure +const method = getMain(com.atproto.server.describeServer) -function xrpcResponseError(status: number) { +/** An `XrpcResponseError` for a response that carried no JSON error payload. */ +function statusOnlyError(status: number) { return new XrpcResponseError(method, new Response(null, {status}), undefined) } +/** + * An `XrpcResponseError` as the PDS pipethrough produces it: the status is + * rewritten while the upstream lexicon code is forwarded verbatim. + */ +function payloadError(status: number, error: string, message: string) { + const body = {error, message} + return new XrpcResponseError( + method, + new Response(JSON.stringify(body), { + status, + headers: {'content-type': 'application/json'}, + }), + {encoding: 'application/json', body}, + ) +} + +function exceptionEvent(type: string, value: string): ErrorEvent { + return {type: undefined, exception: {values: [{type, value}]}} +} + describe('isExpectedSentryNetworkError', () => { test.each([502, 503, 504])('detects transient upstream status %s', status => { - expect(isExpectedSentryNetworkError(xrpcResponseError(status))).toBe(true) + expect(isExpectedSentryNetworkError(statusOnlyError(status))).toBe(true) }) test.each([429, 500])('keeps actionable HTTP status %s', status => { - expect(isExpectedSentryNetworkError(xrpcResponseError(status))).toBe(false) + expect(isExpectedSentryNetworkError(statusOnlyError(status))).toBe(false) }) - test('checks an XRPC fetch error cause', () => { + test('detects a pipethrough 502 forwarding an upstream error code', () => { + const error = payloadError( + 502, + 'InternalServerError', + 'Internal Server Error', + ) + + expect(error.error).toBe('InternalServerError') + expect(isExpectedSentryNetworkError(error)).toBe(true) + }) + + test('checks the cause of a wrapper that does not embed it', () => { expect( isExpectedSentryNetworkError( - new XrpcFetchError(method, new Error('fetch failed: connection reset')), + new XrpcInternalError(method, undefined, { + cause: new Error('fetch failed: connection reset'), + }), ), ).toBe(true) }) - test('keeps implementation errors wrapped by XRPC fetch errors', () => { + test('keeps implementation errors wrapped by XRPC errors', () => { expect( isExpectedSentryNetworkError( - new XrpcFetchError( - method, - new TypeError('URL.canParse is not a function'), - ), + new XrpcInternalError(method, undefined, { + cause: new TypeError('URL.canParse is not a function'), + }), ), ).toBe(false) }) + + test.each(['UpstreamFailure', 'Upstream Failure', '[UpstreamFailure]'])( + 'detects the transient upstream message %s', + message => { + expect(isExpectedSentryNetworkError(message)).toBe(true) + }, + ) + + test.each(['upstreamTimeoutV2', 'handleUpstreamFailureRetry'])( + 'keeps the camelCase identifier %s', + message => { + expect(isExpectedSentryNetworkError(message)).toBe(false) + }, + ) }) describe('dropExpectedNetworkErrors', () => { test('drops automatic captures using the original exception', () => { - const event = {type: undefined} satisfies ErrorEvent + /* + * The serialized values do not carry the cause chain, so the hint is the + * only place the transport failure is visible. + */ + const event = exceptionEvent( + 'XrpcInternalError', + 'Unable to fulfill XRPC request', + ) expect( dropExpectedNetworkErrors(event, { - originalException: new Error('fetch failed: connection closed'), + originalException: new XrpcInternalError(method, undefined, { + cause: new Error('fetch failed: connection closed'), + }), }), ).toBeNull() }) @@ -73,29 +127,47 @@ describe('dropExpectedNetworkErrors', () => { expect(dropExpectedNetworkErrors(event, {})).toBeNull() }) - test('drops serialized transient upstream errors', () => { - const event = { - type: undefined, - exception: { - values: [{type: 'XrpcResponseError', value: 'Upstream Timeout'}], - }, - } satisfies ErrorEvent + test('drops a serialized transient upstream error carrying a payload', () => { + const event = exceptionEvent('XrpcResponseError', 'Upstream Timeout') expect(dropExpectedNetworkErrors(event, {})).toBeNull() }) + test('drops a serialized transient upstream error with no payload', () => { + const {message} = statusOnlyError(504) + + // Locks the text lex builds from the status alone, which the filter matches + expect(message).toBe('Upstream server responded with a 504 error') + expect( + dropExpectedNetworkErrors( + exceptionEvent('XrpcResponseError', message), + {}, + ), + ).toBeNull() + }) + + test.each([ + '[USER REPORT] alice.bsky.social video-upload-aborted', + '[USER REPORT] alice.bsky.social Network request failed', + ])('keeps the message event %s', message => { + const event = {type: undefined, message} satisfies ErrorEvent + + expect(dropExpectedNetworkErrors(event, {originalException: message})).toBe( + event, + ) + }) + test('keeps non-network events', () => { - const event = { - type: undefined, - exception: { - values: [ - { - type: 'XrpcFetchError', - value: 'URL.canParse is not a function', - }, - ], - }, - } satisfies ErrorEvent + const event = exceptionEvent( + 'XrpcFetchError', + 'Unexpected fetchHandler() error: URL.canParse is not a function', + ) + + expect(dropExpectedNetworkErrors(event, {})).toBe(event) + }) + + test('keeps a camelCase identifier that merely contains an upstream word', () => { + const event = exceptionEvent('Error', 'checkout failed: upstreamTimeoutV2') expect(dropExpectedNetworkErrors(event, {})).toBe(event) }) diff --git a/src/logger/sentry/network-errors.ts b/src/logger/sentry/network-errors.ts index 21a22f1a60..aefc1ae07f 100644 --- a/src/logger/sentry/network-errors.ts +++ b/src/logger/sentry/network-errors.ts @@ -1,19 +1,39 @@ import {XrpcResponseError} from '@atproto/lex' import {type ErrorEvent} from '@sentry/react-native' -import {isNetworkError} from '#/lib/network-error' +import {isNetworkError, safeStringify} from '#/lib/network-error' -const TRANSIENT_UPSTREAM_ERRORS = new Set([ - 'UpstreamFailure', - 'NotEnoughResources', - 'UpstreamTimeout', -]) +/** + * HTTP statuses that mean an upstream service was unavailable. + * + * Matched on the status rather than the lexicon code because the code is not + * reliable here: the PDS pipethrough rewrites the status to 502 while + * forwarding the upstream error code verbatim, so an upstream 500 arrives as a + * 502 still named `InternalServerError`. The status is authoritative. + * + * `#/lib/xrpc-error` is deliberately not used for the `instanceof` check - it + * imports `#/lexicons`, which would pull the whole lexicon graph into the + * module evaluated before `Sentry.init()`. + */ +const TRANSIENT_UPSTREAM_STATUSES = new Set([502, 503, 504]) +/** + * Sentry serializes an exception as `{type: error.name, value: error.message}`, + * so these match the message text rather than the `toString()`. Lex builds that + * message from the server's error payload ("Upstream Timeout") or, when the + * response carries no JSON payload, from the status alone ("Upstream server + * responded with a 504 error"). + * + * The optional space matches the spaced prose and the space-free lexicon code + * ("UpstreamFailure") alike, and the word boundaries keep camelCase + * identifiers such as `upstreamTimeoutV2` from matching. + */ const TRANSIENT_UPSTREAM_MESSAGES = [ - /upstream\s*failure/i, - /not\s*enough\s*resources/i, - /upstream\s*timeout/i, + /\bupstream\s?failure\b/i, + /\bnot\s?enough\s?resources\b/i, + /\bupstream\s?timeout\b/i, /operation timed out, please try again/i, + /\bupstream server responded with a 50[234] error\b/i, ] /** @@ -29,23 +49,39 @@ export function isExpectedSentryNetworkError(value: unknown): boolean { if ( value instanceof XrpcResponseError && - TRANSIENT_UPSTREAM_ERRORS.has(value.error) + TRANSIENT_UPSTREAM_STATUSES.has(value.status) ) { return true } - const message = String(value) - return TRANSIENT_UPSTREAM_MESSAGES.some(pattern => pattern.test(message)) + const message = safeStringify(value) + return ( + message !== undefined && + TRANSIENT_UPSTREAM_MESSAGES.some(pattern => pattern.test(message)) + ) } -/** Global backstop for automatic captures that bypass the logger transport. */ +/** + * Global backstop for automatic captures that bypass the logger transport. + * + * Only exception events are inspected. Sentry sets `hint.originalException` to + * the message *string* for a `captureMessage`, and message events reach Sentry + * from exactly two places: the logger transport, which has already run this + * check before capturing, and user bug reports, which must never be dropped + * for happening to contain a word like "aborted" in the report slug. + */ export function dropExpectedNetworkErrors( event: ErrorEvent, hint: {originalException?: unknown}, ): ErrorEvent | null { - const candidates: unknown[] = [hint.originalException, event.message] + const exceptions = event.exception?.values + if (!exceptions?.length) { + return event + } - for (const exception of event.exception?.values ?? []) { + const candidates: unknown[] = [hint.originalException] + + for (const exception of exceptions) { candidates.push(exception.value) if (exception.type && exception.value) { candidates.push(`${exception.type}: ${exception.value}`) diff --git a/src/logger/sentry/setup/index.ts b/src/logger/sentry/setup/index.ts index 1d0d6a936d..60bece9c92 100644 --- a/src/logger/sentry/setup/index.ts +++ b/src/logger/sentry/setup/index.ts @@ -18,10 +18,6 @@ init({ */ `t is not defined`, `Can't find variable: t`, - /* - * Un-useful errors - */ - `Network request failed`, ], /** * Does not affect traces of error events or other logs, just disables diff --git a/src/logger/transports/sentry.ts b/src/logger/transports/sentry.ts index 9b5fd6d8ac..026de76a40 100644 --- a/src/logger/transports/sentry.ts +++ b/src/logger/transports/sentry.ts @@ -1,21 +1,58 @@ import {Sentry} from '#/logger/sentry/lib' import {isExpectedSentryNetworkError} from '#/logger/sentry/network-errors' -import {LogLevel, type Transport} from '#/logger/types' +import {LogLevel, type Metadata, type Transport} from '#/logger/types' import {prepareMetadata} from '#/logger/util' +/** + * Metadata keys that have historically carried the underlying failure as a + * plain string. + */ +const CHECKED_METADATA_KEYS = ['safeMessage', 'message', 'error'] + +/** + * Whether this log records a network failure Sentry should not be told about. + * + * The failure is often passed in metadata rather than as the message, and call + * sites do not consistently use the same key, so any `Error` value counts no + * matter which key holds it. Values of other types only count under the keys + * above: metadata is arbitrary, and scanning all of it lets an unrelated string + * - a stream URL containing "abort", say - suppress a real error. + */ +function isExpectedNetworkFailure( + message: string | Error, + metadata: Metadata, +): boolean { + if (isExpectedSentryNetworkError(message)) { + return true + } + for (const value of Object.values(metadata)) { + if (value instanceof Error && isExpectedSentryNetworkError(value)) { + return true + } + } + return CHECKED_METADATA_KEYS.some( + key => key in metadata && isExpectedSentryNetworkError(metadata[key]), + ) +} + export const sentryTransport: Transport = ( level, context, message, - {type, tags, fingerprint, ...metadata}, + {type, tags, fingerprint, __metadata__, ...metadata}, timestamp, ) => { // Skip debug messages entirely for now - esb if (level === LogLevel.Debug) return + /* + * `__metadata__` is ambient context rather than something the call site + * passed, so it is destructured out of the scanned metadata and folded back + * in here to keep the attached data unchanged. + */ const meta = { __context__: context, - ...prepareMetadata(metadata), + ...prepareMetadata(__metadata__ ? {__metadata__, ...metadata} : metadata), } let _tags = tags || {} _tags = { @@ -47,24 +84,15 @@ export const sentryTransport: Transport = ( timestamp: timestamp / 1000, // Sentry expects seconds }) - /* - * Keep the breadcrumb, but don't send expected network failures as events. - * The underlying cause is often passed in metadata rather than the message - * itself, and call sites do not consistently use the same metadata key. - */ - if ( - isExpectedSentryNetworkError(message) || - Object.values(metadata).some(isExpectedSentryNetworkError) - ) { - return - } - /** * Only error-level strings are reported to Sentry as events. Lower levels * are captured as breadcrumbs above and attached to the next event, if - * any. + * any - so the network check only has to run here. */ if (level === LogLevel.Error) { + // Keep the breadcrumb, but don't send expected network failures as events + if (isExpectedNetworkFailure(message, metadata)) return + // Defer non-critical messages so they're sent in a batch queueMessageForSentry(message, { level: severity, @@ -74,12 +102,7 @@ export const sentryTransport: Transport = ( }) } } else { - if ( - isExpectedSentryNetworkError(message) || - Object.values(metadata).some(isExpectedSentryNetworkError) - ) { - return - } + if (isExpectedNetworkFailure(message, metadata)) return /** * It's otherwise an Error and should be reported with captureException