diff --git a/dev-packages/e2e-tests/.gitignore b/dev-packages/e2e-tests/.gitignore index 21181cb54143..44206ed6b672 100644 --- a/dev-packages/e2e-tests/.gitignore +++ b/dev-packages/e2e-tests/.gitignore @@ -5,3 +5,9 @@ tmp pnpm-lock.yaml .last-run.json packed + +# Written by Playwright on a failing run, in whichever application failed +test-results + +# Synthesised from the CDK stack on every run of this one application +test-applications/aws-serverless-layer/sam.template.yml diff --git a/dev-packages/e2e-tests/test-applications/aws-serverless-layer/src/lambda-functions-layer/Tunnel/index.js b/dev-packages/e2e-tests/test-applications/aws-serverless-layer/src/lambda-functions-layer/Tunnel/index.js index 5a25387cfe10..ae5bb78d12a9 100644 --- a/dev-packages/e2e-tests/test-applications/aws-serverless-layer/src/lambda-functions-layer/Tunnel/index.js +++ b/dev-packages/e2e-tests/test-applications/aws-serverless-layer/src/lambda-functions-layer/Tunnel/index.js @@ -1,3 +1,5 @@ +const zlib = require('node:zlib'); + function makeHex(length) { return Array.from({ length }, () => Math.floor(Math.random() * 16).toString(16)).join(''); } @@ -15,17 +17,25 @@ exports.handler = async event => { event_id: makeHex(32), message: event?.marker ?? 'lambda-extension-tunnel-test', level: 'info', + // `makeNodeTransport` only gzips past 32KiB, so a compressed envelope smaller than that never + // exercises what the tunnel does with the ones the SDK actually compresses. + ...(event?.padTo ? { padding: 'x'.repeat(Number(event.padTo)) } : {}), }; const envelope = `${JSON.stringify(envelopeHeader)}\n${JSON.stringify(envelopeItemHeader)}\n${JSON.stringify( envelopeItemPayload, )}\n`; + // `makeNodeTransport` gzips any body over 32KiB, so the tunnel has to read a compressed + // envelope header. It could not, and answered 500 — silently dropping every large event. + const compressed = event?.gzip ? zlib.gzipSync(Buffer.from(envelope)) : undefined; + const response = await fetch('http://localhost:9000/envelope', { method: 'POST', headers: { 'Content-Type': 'application/x-sentry-envelope', + ...(compressed ? { 'content-encoding': event.gzip } : {}), }, - body: envelope, + body: compressed ?? envelope, }); const responseBody = await response.text(); diff --git a/dev-packages/e2e-tests/test-applications/aws-serverless-layer/tests/layer.test.ts b/dev-packages/e2e-tests/test-applications/aws-serverless-layer/tests/layer.test.ts index da798f99a9fc..717cf7666ab3 100644 --- a/dev-packages/e2e-tests/test-applications/aws-serverless-layer/tests/layer.test.ts +++ b/dev-packages/e2e-tests/test-applications/aws-serverless-layer/tests/layer.test.ts @@ -395,6 +395,62 @@ test.describe('Lambda layer', () => { expect(missingDsnResult.responseBody).toContain('missing DSN'); }); + test('extension tunnel forwards a gzipped envelope', async ({ lambdaClient }) => { + // The tunnel read the envelope header off the raw bytes, which throws on the gzip magic bytes, + // so every large event was answered 500 and dropped. `makeNodeTransport` only gzips past this + // size — a private const in `@sentry/node`, so it is named rather than imported — and doubling + // it keeps the envelope over the line whatever the header costs. Only the encoding the SDK + // actually sends is exercised: the case and list-valued forms are covered in the extension's + // unit tests, and the event proxy decompresses this exact value only. + const sdkGzipThreshold = 32 * 1024; + const marker = `extension-tunnel-gzip-${Date.now()}`; + const requestPromise = waitForRequest('aws-serverless-layer', requestData => { + return requestData.rawProxyRequestBody.includes(marker); + }); + + const response = await lambdaClient.send( + new InvokeCommand({ + FunctionName: 'LayerTunnel', + Payload: JSON.stringify({ gzip: 'gzip', marker, padTo: sdkGzipThreshold * 2 }), + }), + ); + + expect(parseLambdaPayload(response.Payload).status).toBe(200); + await requestPromise; + }); + + test('extension tunnel rejects a gzipped envelope carrying an unauthorized DSN', async ({ lambdaClient }) => { + // The allowlist has to survive compression, or it is bypassed by setting one header. + const probe = parseLambdaPayload( + ( + await lambdaClient.send( + new InvokeCommand({ + FunctionName: 'LayerTunnel', + Payload: JSON.stringify({ marker: `gzip-dsn-probe-${Date.now()}` }), + }), + ) + ).Payload, + ); + // Asserted, not assumed: without a real DSN to mangle, the tunnel answers 403 `Invalid DSN` + // and this test would pass without the allowlist ever being consulted. + expect(probe.status).toBe(200); + expect(probe.attemptedDsn).toContain('://public@'); + + const response = await lambdaClient.send( + new InvokeCommand({ + FunctionName: 'LayerTunnel', + Payload: JSON.stringify({ + gzip: 'gzip', + dsn: probe.attemptedDsn!.replace('://public@', '://unauthorized@'), + }), + }), + ); + + const result = parseLambdaPayload(response.Payload); + expect(result.status).toBe(403); + expect(result.responseBody).toContain('DSN not allowed'); + }); + test('extension tunnel forwards requests when SENTRY_DSN is missing', async ({ lambdaClient }) => { const marker = `extension-tunnel-no-sentry-dsn-${Date.now()}`; const noDsnRequestPromise = waitForRequest('aws-serverless-layer', requestData => { diff --git a/packages/aws-serverless/src/init.ts b/packages/aws-serverless/src/init.ts index 8c7c238265fa..7eeafe3c2f61 100644 --- a/packages/aws-serverless/src/init.ts +++ b/packages/aws-serverless/src/init.ts @@ -104,6 +104,8 @@ export function init(options: AwsServerlessOptions = {}): NodeClient | undefined } } else { DEBUG_BUILD && debug.log('Proxying Sentry events through the Sentry Lambda extension'); + // Kept literal: importing it from the extension's tree would ship that module in the SDK + // bundle. `test/init.test.ts` asserts the two halves still agree. opts.tunnel = 'http://localhost:9000/envelope'; } } diff --git a/packages/aws-serverless/src/lambda-extension/aws-lambda-extension.ts b/packages/aws-serverless/src/lambda-extension/aws-lambda-extension.ts index 8ecbfe2510ad..30a0d102fe22 100644 --- a/packages/aws-serverless/src/lambda-extension/aws-lambda-extension.ts +++ b/packages/aws-serverless/src/lambda-extension/aws-lambda-extension.ts @@ -1,193 +1,260 @@ -import * as http from 'node:http'; -import { buffer } from 'node:stream/consumers'; +import type * as http from 'node:http'; import { - consoleSandbox, - debug, - type DsnComponents, - dsnToString, - getEnvelopeEndpointWithUrlEncodedAuth, - makeDsn, -} from '@sentry/core'; -import { DEBUG_BUILD } from './debug-build'; + EXTENSION_NAME, + EXTENSIONS_API_PATH, + MAX_REPORTED_FAILURES, + POLL_ESTABLISHED_MS, + POLL_GIVE_UP_MS, + SHUTDOWN_BUDGET_MS, + SHUTDOWN_IDLE_GRACE_MS, + SHUTDOWN_MARGIN_MS, + TERMINAL_POLL_CONFIRMATIONS, + TUNNEL_PORT, +} from './constants'; +import { ExtensionsApiError, isTerminalPollStatus, PermanentRegistrationError } from './errors'; +import { parseEvent, request } from './extensions-api'; +import { SentryTunnel } from './sentry-tunnel'; +import type { ExtensionEvent, PollOutcome } from './types'; +import { logError, retryDelayMs, sleep, truncateBody } from './utils'; + +/** + * AWS's own documented example carries `deadlineMs: 676051`, which is not an epoch value — read as + * one it yields a negative budget and drops whatever is in flight. Anything that is not a plausible + * remaining window falls back to the limit Lambda enforces anyway. + */ +function shutdownBudgetMs(deadlineMs: unknown): number { + const remaining = typeof deadlineMs === 'number' ? deadlineMs - Date.now() : NaN; + const trusted = remaining > 0 && remaining <= SHUTDOWN_BUDGET_MS ? remaining : SHUTDOWN_BUDGET_MS; + + return Math.max(trusted - SHUTDOWN_MARGIN_MS, 0); +} /** * The Extension API Client. */ export class AwsLambdaExtension { private readonly _baseUrl: string; + private readonly _tunnel: SentryTunnel; private _extensionId: string | null; public constructor() { - this._baseUrl = `http://${process.env.AWS_LAMBDA_RUNTIME_API}/2020-01-01/extension`; + this._baseUrl = `http://${process.env.AWS_LAMBDA_RUNTIME_API}${EXTENSIONS_API_PATH}`; + this._tunnel = new SentryTunnel(); this._extensionId = null; } /** - * Register this extension as an external extension with AWS. + * Registers as an external extension, subscribed to SHUTDOWN alone. + * + * An INVOKE subscription joins the gate that holds every invocation until each subscriber has + * asked for the next event, so a poll that dies mid-flight would hold the rest of the + * environment's invocations open until the function timeout. Lambda Managed Instances refuses the + * subscription outright, taking the function's init down with it. + * + * What is retried is the API not answering. Lambda gates the init phase on every registered + * extension, so never registering holds each invocation open with the handler never running, and + * a late registration costs only the first invocation. */ public async register(): Promise { - const res = await fetch(`${this._baseUrl}/register`, { - method: 'POST', - body: JSON.stringify({ - events: ['INVOKE', 'SHUTDOWN'], - }), - headers: { - 'Content-Type': 'application/json', - 'Lambda-Extension-Name': 'sentry-extension', - }, - }); + let failingSince = 0; - if (!res.ok) { - throw new Error(`Failed to register with the extension API: ${await res.text()}`); - } + for (let attempt = 1; ; attempt++) { + try { + this._extensionId = await this._requestRegistration(); + return; + } catch (err) { + if (err instanceof PermanentRegistrationError) { + throw err; + } + + failingSince = failingSince === 0 ? Date.now() : failingSince; + + // The same ceiling the poll loop has, for the same reason: an extension Lambda launched + // that never registers holds the init phase, and with it every invocation, for as long as + // it keeps trying. Past this it is better to crash and let Lambda recycle. + if (Date.now() - failingSince >= POLL_GIVE_UP_MS) { + throw err; + } - this._extensionId = res.headers.get('lambda-extension-identifier'); + if (attempt <= MAX_REPORTED_FAILURES) { + logError('registering with the Extensions API failed, retrying.', err); + } + + await sleep(retryDelayMs(attempt)); + } + } } /** - * Advances the extension to the next event. + * Advances the extension to the next event and returns it. */ - public async next(): Promise { + public async next(): Promise { if (!this._extensionId) { throw new Error('Extension ID is not set'); } - const res = await fetch(`${this._baseUrl}/event/next`, { + const res = await request(`${this._baseUrl}/event/next`, { headers: { 'Lambda-Extension-Identifier': this._extensionId, 'Content-Type': 'application/json', }, }); - if (!res.ok) { - throw new Error(`Failed to advance to next event: ${await res.text()}`); + // Reaching `end` without a status is a transport problem, not a verdict from the API, so it + // must not carry a status into the terminal check. + if (!res.statusCode) { + throw new Error('The Extensions API response carried no status'); } + + if (res.statusCode < 200 || res.statusCode > 299) { + throw new ExtensionsApiError(`Failed to advance to next event: ${truncateBody(res.body)}`, res.statusCode); + } + + const event: unknown = parseEvent(res.body); + + // `run` decides when to stop from `eventType`, and every JSON literal parses — `{}` included — + // so anything without one would read as an event: counters reset, no backoff, immediate re-poll. + if (typeof (event as ExtensionEvent | null)?.eventType !== 'string') { + throw new Error(`The Extensions API returned no event: ${truncateBody(res.body)}`); + } + + return event as ExtensionEvent; } /** - * Reports an error to the extension API. - * @param phase The phase of the extension. - * @param err The error to report. + * Polls the Extensions API until the environment shuts down. + * + * Giving up stops the loop rather than ending the process: subscribed to SHUTDOWN alone, an + * extension that has stopped polling costs the customer nothing but this drain, while exiting + * fails the invocation in flight as `Extension.Crash`. The outcome reports whether the API ever + * took a poll, because that is not true yet during the init phase — see `main`. */ - public async error(phase: 'init' | 'exit', err: Error): Promise { - if (!this._extensionId) { - throw new Error('Extension ID is not set'); - } + public async run(): Promise { + let failures = 0; + let reported = 0; + let terminalStatuses = 0; + let failingSince = 0; + let pollAccepted = false; - const errorType = `Extension.${err.name || 'UnknownError'}`; + for (;;) { + const sentAt = Date.now(); + let event: ExtensionEvent; - const res = await fetch(`${this._baseUrl}/${phase}/error`, { - method: 'POST', - body: JSON.stringify({ - errorMessage: err.message || err.toString(), - errorType, - stackTrace: [err.stack], - }), - headers: { - 'Content-Type': 'application/json', - 'Lambda-Extension-Identifier': this._extensionId, - 'Lambda-Extension-Function-Error': errorType, - }, - }); + try { + event = await this.next(); + // Before the contract check below, and deliberately weaker than the platform's own rule: + // the init phase releases when the poll *reaches* the API, which a client cannot observe + // once the transport dies. A resolved `next()` is the nearest thing it can see, so this + // errs towards reporting the gate closed — see `main` for why that is the cheap direction. + pollAccepted = true; + + // Nothing else was subscribed to, so this is the API answering outside its own contract. + // Falling through would re-poll with no delay, and nothing rate-limits a loop that is no + // longer in the invocation gate. + if (event.eventType !== 'SHUTDOWN') { + throw new Error(`The Extensions API delivered an unsubscribed event: ${event.eventType}`); + } + } catch (err) { + const failedAt = Date.now(); + + // The only health signal available: one poll covers the environment's whole life, so + // "since the last event" would make every counter here a lifetime tally. + if (failedAt - sentAt >= POLL_ESTABLISHED_MS) { + failures = 0; + terminalStatuses = 0; + failingSince = 0; + } + + failures++; + // From the failure rather than `sentAt`, which on a parked poll predates the whole budget. + failingSince = failingSince === 0 ? failedAt : failingSince; - if (!res.ok) { - DEBUG_BUILD && debug.error(`Failed to report error: ${await res.text()}`); + // Deliberately not reset by a non-terminal error: a permanent refusal that flaps with + // transport failures would otherwise never confirm. + if (isTerminalPollStatus(err)) { + terminalStatuses++; + } + + if (terminalStatuses >= TERMINAL_POLL_CONFIRMATIONS || failedAt - failingSince >= POLL_GIVE_UP_MS) { + return { reason: 'unrecoverable', pollAccepted, error: err }; + } + + if (reported++ < MAX_REPORTED_FAILURES) { + logError('polling the Extensions API failed, retrying.', err); + } + + await sleep(retryDelayMs(failures)); + continue; + } + + await this.drainPendingUploads(event.deadlineMs); + return { reason: 'shutdown', pollAccepted }; } + } + + /** + * Waits for envelopes the tunnel is still forwarding, up to the shutdown deadline. + * + * Lambda allows 2,000ms for shutdown and SIGKILLs whatever is left, billed to the function — so + * idling the window costs the customer, and an upload in flight at teardown is simply lost. + */ + public async drainPendingUploads(deadlineMs?: unknown): Promise { + const startedAt = Date.now(); + const until = startedAt + shutdownBudgetMs(deadlineMs); + + for (;;) { + const now = Date.now(); + + if (now >= until) { + return; + } + + // Resolves at once when nothing is in flight, so this doubles as the emptiness check. + if (!(await this._tunnel.uploads.drain(until - now))) { + return; + } + + // Re-armed by each arrival, so a burst of exit flushes extends the wait rather than racing it. + const idleFor = Math.max(startedAt, this._tunnel.lastActivityAt) + SHUTDOWN_IDLE_GRACE_MS - Date.now(); + + if (idleFor <= 0) { + return; + } - throw err; + await sleep(Math.min(idleFor, until - Date.now())); + } } /** * Starts the Sentry tunnel. */ - public startSentryTunnel(): void { - const allowedDsnComponents = getSentryDSNFromEnv(); - - if (!allowedDsnComponents) { - consoleSandbox(() => { - // eslint-disable-next-line no-console - console.warn( - 'Sentry Lambda extension: SENTRY_DSN is not set or is invalid. The /envelope tunnel will forward ' + - 'any DSN in the envelope header without allowlist validation. Set SENTRY_DSN to the same DSN as ' + - 'your SDK to restrict outbound requests.', - ); - }); - } + public startSentryTunnel(port: number = TUNNEL_PORT): http.Server { + return this._tunnel.listen(port); + } - const server = http.createServer(async (req, res) => { - if (req.method === 'POST' && req.url?.startsWith('/envelope')) { - try { - const buf = await buffer(req); - // Extract the actual bytes from the Buffer by slicing its underlying ArrayBuffer - // This ensures we get only the data portion without any padding or offset - const envelopeBytes = buf.buffer.slice(buf.byteOffset, buf.byteOffset + buf.byteLength); - const envelope = new TextDecoder().decode(envelopeBytes); - const piece = envelope.split('\n')[0]; - const header = JSON.parse(piece || '{}') as { dsn?: string }; - const envelopeDsn = header.dsn; - if (!envelopeDsn) { - res.writeHead(400, { 'Content-Type': 'application/json' }); - res.end(JSON.stringify({ error: 'Invalid envelope: missing DSN' })); - return; - } - - // When SENTRY_DSN is set, same allowlist check as handleTunnelRequest in @sentry/core (SSRF protection). - // If not set, we allow any DSN (but warn about this once, above) - if (allowedDsnComponents) { - if (dsnToString(allowedDsnComponents) !== envelopeDsn) { - DEBUG_BUILD && - debug.warn(`Sentry Lambda extension tunnel: rejected request with unauthorized DSN (${envelopeDsn})`); - res.writeHead(403, { 'Content-Type': 'application/json' }); - res.end(JSON.stringify({ error: 'DSN not allowed' })); - return; - } - } - - const dsn = allowedDsnComponents || makeDsn(envelopeDsn); - if (!dsn) { - res.writeHead(403, { 'Content-Type': 'application/json' }); - res.end(JSON.stringify({ error: 'Invalid DSN' })); - return; - } - const upstreamSentryUrl = getEnvelopeEndpointWithUrlEncodedAuth(dsn); - - fetch(upstreamSentryUrl, { - method: 'POST', - body: envelopeBytes as BodyInit, - }).catch(err => { - DEBUG_BUILD && debug.error('Error sending envelope to Sentry', err); - }); - - res.writeHead(200, { 'Content-Type': 'application/json' }); - res.end(JSON.stringify({})); - } catch (e) { - DEBUG_BUILD && debug.error('Error tunneling to Sentry', e); - res.writeHead(500, { 'Content-Type': 'application/json' }); - res.end(JSON.stringify({ error: 'Error tunneling to Sentry' })); - } - } else { - res.writeHead(404, { 'Content-Type': 'application/json' }); - res.end(JSON.stringify({ error: 'Not found' })); - } + /** Resolves to the identifier every later poll carries. */ + private async _requestRegistration(): Promise { + const res = await request(`${this._baseUrl}/register`, { + method: 'POST', + body: JSON.stringify({ events: ['SHUTDOWN'] }), + headers: { + 'Content-Type': 'application/json', + 'Lambda-Extension-Name': EXTENSION_NAME, + }, }); - server.listen(9000, () => { - DEBUG_BUILD && debug.log('Sentry proxy listening on port 9000'); - }); + if (res.statusCode < 200 || res.statusCode > 299) { + throw new PermanentRegistrationError(`Failed to register with the extension API: ${truncateBody(res.body)}`); + } - server.on('error', err => { - DEBUG_BUILD && debug.error('Error starting Sentry proxy', err); - process.exit(1); - }); - } -} + const extensionId = res.headers['lambda-extension-identifier']; -/** - * DSN components allowed for the Lambda extension `/envelope` tunnel, derived from `SENTRY_DSN`. - * - * Exported only for testing purposes. - */ -export function getSentryDSNFromEnv(): DsnComponents | undefined { - const raw = process.env.SENTRY_DSN?.trim(); - return raw ? makeDsn(raw) : undefined; + if (typeof extensionId !== 'string' || !extensionId) { + throw new PermanentRegistrationError( + 'The Extensions API accepted the registration without returning an identifier', + ); + } + + return extensionId; + } } diff --git a/packages/aws-serverless/src/lambda-extension/constants.ts b/packages/aws-serverless/src/lambda-extension/constants.ts new file mode 100644 index 000000000000..f50156b5c3f0 --- /dev/null +++ b/packages/aws-serverless/src/lambda-extension/constants.ts @@ -0,0 +1,87 @@ +/** Extensions API endpoints sit under this path on `AWS_LAMBDA_RUNTIME_API`. */ +export const EXTENSIONS_API_PATH = '/2020-01-01/extension'; + +/** + * "Lambda uses the full file name of the extension to validate that the extension has completed + * the bootstrap sequence", so this has to match the wrapper in `/opt/extensions/`. + * https://docs.aws.amazon.com/lambda/latest/dg/runtimes-extensions-api.html#extensions-registration-api-a + */ +export const EXTENSION_NAME = 'sentry-extension'; + +export const POLL_RETRY_BASE_MS = 100; +export const POLL_RETRY_MAX_MS = 5_000; + +/** A poll that outlasted the longest retry delay is the closest thing to a health signal here. */ +export const POLL_ESTABLISHED_MS = POLL_RETRY_MAX_MS; + +/** + * Clear of the 900s function ceiling, so an outage spanning one whole maximum-length invocation + * cannot trip it on its own. + */ +export const POLL_GIVE_UP_MS = 16 * 60_000; + +/** A lifetime cap: the retry budget restarts on every established poll, so a per-streak one never would. */ +export const MAX_REPORTED_FAILURES = 20; + +/** + * The only statuses the Extensions API documents for `/event/next` besides 200. + * https://docs.aws.amazon.com/lambda/latest/dg/runtimes-extensions-api.html#extensions-api-next + */ +export const TERMINAL_POLL_STATUSES = [403, 500]; + +/** A poll issued while the environment is already tearing down is answered 500, and that clears. */ +export const TERMINAL_POLL_CONFIRMATIONS = 3; + +export const ERROR_BODY_MAX_LENGTH = 200; + +/** + * How far a compressed body is inflated: only the envelope's first line is ever read, and without a + * bound a body expanding 1029:1 drove RSS to 3.1GiB, which on a 128MB function is an OOM the + * platform reports as `Extension.Crash`. + * + * Sized from the header rather than picked: its one unbounded-looking field is `trace`, the + * sampling context, whose source baggage `@sentry/core` caps at `MAX_BAGGAGE_STRING_LENGTH`. A + * header saturating that cap measures 8,085 bytes against 1,273 for a typical one, so this leaves + * roughly double the worst case a well-formed envelope can reach. + */ +export const ENVELOPE_HEADER_MAX_BYTES = 16 * 1024; + +/** Detects a peer that vanished without a FIN/RST — the poll itself may carry no deadline. */ +export const POLL_KEEPALIVE_MS = 30_000; + +/** Where the SDK posts envelopes when the layer extension is in use. */ +export const TUNNEL_PORT = 9000; + +/** What `init` points `tunnel` at, so the two halves of the contract cannot drift apart. */ +export const TUNNEL_URL = `http://localhost:${TUNNEL_PORT}/envelope`; + +/** + * Lambda's shutdown limit for a function with one or more registered external extensions; it + * SIGKILLs whatever is still running at the end of it. + * https://docs.aws.amazon.com/lambda/latest/dg/runtimes-extensions-api.html#runtimes-lifecycle-extensions-shutdown + */ +export const SHUTDOWN_BUDGET_MS = 2_000; + +/** Headroom so the drain returns on its own terms rather than being SIGKILLed mid-upload. */ +export const SHUTDOWN_MARGIN_MS = 200; + +/** The runtime's SIGTERM handlers keep posting envelopes after the shutdown event arrives. */ +export const SHUTDOWN_IDLE_GRACE_MS = 300; + +/** + * A runaway backstop, not a capacity plan. Nothing here caps in-flight uploads today, and no + * measurement says what the right cap would be — the tunnel answers the SDK before its own upstream + * request finishes, so this count is bounded by posting rate times upstream latency rather than by + * anything the SDK holds. The number is therefore chosen, and only its relationship is derived: it + * sits far above the 64 a single `@sentry/node` transport can hold in flight, so a well-behaved SDK + * can never be refused an envelope it could legitimately have outstanding. A refusal is reported + * like any other drop rather than swallowed. + */ +export const MAX_PENDING_UPLOADS = 1_000; + +/** + * Node's largest accepted timer delay; anything above it overflows and fires immediately. Used to + * hold the event loop open with as few wakeups as possible when the extension has stopped polling + * but must not exit. + */ +export const MAX_TIMER_DELAY_MS = 2_147_483_647; diff --git a/packages/aws-serverless/src/lambda-extension/errors.ts b/packages/aws-serverless/src/lambda-extension/errors.ts new file mode 100644 index 000000000000..e17794da2fe3 --- /dev/null +++ b/packages/aws-serverless/src/lambda-extension/errors.ts @@ -0,0 +1,34 @@ +import { TERMINAL_POLL_STATUSES } from './constants'; + +export class ExtensionsApiError extends Error { + public constructor( + message: string, + public readonly statusCode: number, + ) { + super(message); + this.name = 'ExtensionsApiError'; + } +} + +/** + * A registration the Extensions API answered and will not answer differently. It documents 400, + * 403 and 500 for `/register`, the request body is a compile-time constant, and a registration it + * accepted without handing back an identifier leaves nothing to poll with. Retrying any of those + * is worse than failing: the init phase is gated on every extension Lambda launched, so a process + * that never registers holds each invocation to the function timeout with the handler never + * running, where crashing costs one fast invocation and a fresh environment. + * https://docs.aws.amazon.com/lambda/latest/dg/runtimes-extensions-api.html#extensions-registration-api-a + */ +export class PermanentRegistrationError extends Error { + public constructor(message: string) { + super(message); + this.name = 'PermanentRegistrationError'; + } +} + +/** Structural rather than `instanceof`, so it holds for an error that crossed a module boundary. */ +export function isTerminalPollStatus(err: unknown): boolean { + const statusCode = (err as { statusCode?: unknown } | null)?.statusCode; + + return typeof statusCode === 'number' && TERMINAL_POLL_STATUSES.includes(statusCode); +} diff --git a/packages/aws-serverless/src/lambda-extension/extensions-api.ts b/packages/aws-serverless/src/lambda-extension/extensions-api.ts new file mode 100644 index 000000000000..5ed731e9e212 --- /dev/null +++ b/packages/aws-serverless/src/lambda-extension/extensions-api.ts @@ -0,0 +1,52 @@ +import * as http from 'node:http'; +import { POLL_KEEPALIVE_MS } from './constants'; +import type { ExtensionsApiRequest, ExtensionsApiResponse } from './types'; + +/** + * Issues an Extensions API request that carries no deadline at any layer. + * + * "Do not set a timeout on the GET call, as the extension can be suspended for a period of time + * until there is an event to return." + * https://docs.aws.amazon.com/lambda/latest/dg/runtimes-extensions-api.html#extensions-api-next + * + * `fetch` cannot honour that — Node applies undici's 300s `headersTimeout`, which abandons a + * request the API may already have honoured — so registration goes through here too, not only the + * poll. `agent: false` keeps the request out of a pool, the other place a deadline, or a socket + * gone stale across a freeze, can live. + */ +export function request( + url: string, + { method = 'GET', headers, body }: ExtensionsApiRequest, +): Promise { + return new Promise((resolve, reject) => { + const req = http.request(url, { agent: false, method, headers }, res => { + const chunks: Buffer[] = []; + + res.on('data', (chunk: Buffer) => chunks.push(chunk)); + res.on('end', () => + resolve({ + statusCode: res.statusCode ?? 0, + headers: res.headers, + body: Buffer.concat(chunks).toString(), + }), + ); + res.on('error', err => { + req.destroy(); + reject(err); + }); + }); + + req.on('socket', socket => socket.setKeepAlive(true, POLL_KEEPALIVE_MS)); + req.on('error', reject); + req.end(body); + }); +} + +/** `JSON.parse` throws only for a malformed body; every JSON literal parses, including `null`. */ +export function parseEvent(body: string): unknown { + try { + return JSON.parse(body); + } catch { + return undefined; + } +} diff --git a/packages/aws-serverless/src/lambda-extension/index.ts b/packages/aws-serverless/src/lambda-extension/index.ts index f465dae9741d..b7582d596213 100644 --- a/packages/aws-serverless/src/lambda-extension/index.ts +++ b/packages/aws-serverless/src/lambda-extension/index.ts @@ -1,21 +1,5 @@ #!/usr/bin/env node -import { debug } from '@sentry/core'; import { AwsLambdaExtension } from './aws-lambda-extension'; -import { DEBUG_BUILD } from './debug-build'; +import { main } from './main'; -async function main(): Promise { - const extension = new AwsLambdaExtension(); - - await extension.register(); - - extension.startSentryTunnel(); - - // eslint-disable-next-line no-constant-condition - while (true) { - await extension.next(); - } -} - -main().catch(err => { - DEBUG_BUILD && debug.error('Error in Lambda Extension', err); -}); +void main(new AwsLambdaExtension()); diff --git a/packages/aws-serverless/src/lambda-extension/main.ts b/packages/aws-serverless/src/lambda-extension/main.ts new file mode 100644 index 000000000000..fc36e5993953 --- /dev/null +++ b/packages/aws-serverless/src/lambda-extension/main.ts @@ -0,0 +1,64 @@ +import type { AwsLambdaExtension } from './aws-lambda-extension'; +import { MAX_TIMER_DELAY_MS } from './constants'; +import { logError } from './utils'; + +/** + * Runs the extension for the life of the execution environment. + * + * `exit` is a parameter so the three outcomes can be asserted; there is one of each, and which one + * runs is the whole argument of this file. + */ +export async function main( + extension: AwsLambdaExtension, + exit: (code: number) => void = code => process.exit(code), +): Promise { + // Before registering: the listening socket is the referenced handle that keeps this process + // alive, and the tunnel is already serving while registration is still being retried. + extension.startSentryTunnel(); + + try { + await extension.register(); + } catch (err) { + logError('could not register, events will not be tunnelled.', err); + + // The one failure worth exiting for. Lambda gates the init phase on every registered extension + // whatever it subscribed to, so holding a name it cannot poll with holds each invocation to the + // function timeout; crashing lets Lambda recycle into an environment that works. + exit(1); + return; + } + + const outcome = await extension.run(); + + if (outcome.reason === 'shutdown') { + // The drain has returned, so the rest of Lambda's shutdown window — billed to the function, and + // otherwise ended by a SIGKILL — is given back. + exit(0); + return; + } + + // The same hazard registration has. Giving up while the init phase is still waiting on us leaves + // this extension holding every invocation to the function timeout — measured at 30,000ms billed + // per invocation, against under half a second for a crash that lets Lambda recycle. + // + // `pollAccepted` under-reports, because the gate releases when a poll reaches the API rather than + // when one is answered, and only the latter is observable here. Erring this way is deliberate: + // exiting when the gate was already open costs one invocation, while parking when it was not + // costs every invocation for the life of the environment. + if (!outcome.pollAccepted) { + logError('never started polling the Extensions API, events will not be tunnelled.', outcome.error); + exit(1); + return; + } + + logError( + 'stopped polling the Extensions API. Envelopes are still tunnelled, but the shutdown drain is lost, ' + + 'so events captured at teardown may not be sent.', + outcome.error, + ); + + // Deliberately not an exit: a process ending outside the shutdown phase is reported as + // `Extension.Crash` and fails the invocation in flight. Parked explicitly because a tunnel that + // failed to listen leaves no handle, and an empty event loop would exit just the same. + setInterval(() => undefined, MAX_TIMER_DELAY_MS); +} diff --git a/packages/aws-serverless/src/lambda-extension/sentry-tunnel.ts b/packages/aws-serverless/src/lambda-extension/sentry-tunnel.ts new file mode 100644 index 000000000000..6bf5a8e7e0c3 --- /dev/null +++ b/packages/aws-serverless/src/lambda-extension/sentry-tunnel.ts @@ -0,0 +1,227 @@ +import * as http from 'node:http'; +import { buffer } from 'node:stream/consumers'; +import { Readable, type Transform } from 'node:stream'; +import { createBrotliDecompress, createGunzip, createInflate } from 'node:zlib'; +import { + debug, + type DsnComponents, + dsnToString, + getEnvelopeEndpointWithUrlEncodedAuth, + makeDsn, + makePromiseBuffer, + type PromiseBuffer, +} from '@sentry/core'; +import { ENVELOPE_HEADER_MAX_BYTES, MAX_PENDING_UPLOADS, MAX_REPORTED_FAILURES, TUNNEL_PORT } from './constants'; +import { DEBUG_BUILD } from './debug-build'; +import type { EnvelopeHeader } from './types'; +import { logError, logWarn } from './utils'; + +/** What `makeNodeTransport` can put on the wire; it gzips anything over 32 KiB. */ +const DECOMPRESSORS: Record Transform> = { + gzip: createGunzip, + deflate: createInflate, + br: createBrotliDecompress, +}; + +/** + * A header value is the sender's, so it arrives in whatever case and list form they chose. It is + * always one string: Node types this header as such, and joins duplicates with `, ` rather than + * collecting them the way it does `set-cookie`. + */ +function codingOf(contentEncoding: string | undefined): string { + return (contentEncoding ?? '').split(',')[0]?.trim().toLowerCase() ?? ''; +} + +/** + * The envelope header is the first line and it carries the DSN the allowlist needs, so a compressed + * body has to be read before it can be validated — but only that far. + * + * Inflated a chunk at a time and stopped at the newline, rather than in one shot: a one-shot + * `maxOutputLength` bounds the whole body, and since `makeNodeTransport` only compresses past + * 32KiB, every envelope the SDK actually gzips would exceed any bound small enough to protect the + * memory the extension shares with the function. + */ +async function readEnvelopeHeader(body: Buffer, contentEncoding: string | undefined): Promise { + const decompress = DECOMPRESSORS[codingOf(contentEncoding)]; + + // Nullable because every JSON literal parses: `null`, a number and a string all get here, and + // only the caller's optional chaining keeps them from throwing. + return JSON.parse(await readFirstLine(body, decompress)) as EnvelopeHeader | null; +} + +async function readFirstLine(body: Buffer, decompress?: () => Transform): Promise { + if (!decompress) { + return new TextDecoder().decode(body).split('\n')[0] || '{}'; + } + + const stream = Readable.from(body).pipe(decompress()); + let read = ''; + + try { + for await (const chunk of stream) { + read += chunk as string; + + const newline = read.indexOf('\n'); + if (newline >= 0) { + return read.slice(0, newline) || '{}'; + } + + if (read.length > ENVELOPE_HEADER_MAX_BYTES) { + throw new Error('The envelope header is longer than this extension will inflate to read it'); + } + } + } finally { + stream.destroy(); + } + + return read || '{}'; +} + +/** + * `makeDsn` reports a malformed DSN through an ungated `console.error`, so an envelope header is + * caller-controlled text reaching the log verbatim — newlines included, which forges log lines. + */ +function parseEnvelopeDsn(envelopeDsn: string): DsnComponents | undefined { + return URL.canParse(envelopeDsn) ? makeDsn(envelopeDsn) : undefined; +} + +function respond(res: http.ServerResponse, statusCode: number, body: Record): void { + res.writeHead(statusCode, { 'Content-Type': 'application/json' }); + res.end(JSON.stringify(body)); +} + +/** + * DSN components allowed for the Lambda extension `/envelope` tunnel, derived from `SENTRY_DSN`. + * + * Exported only for testing purposes. + */ +export function getSentryDSNFromEnv(): DsnComponents | undefined { + const raw = process.env.SENTRY_DSN?.trim(); + return raw ? makeDsn(raw) : undefined; +} + +/** + * Forwards envelopes the SDK posts locally on to Sentry, so the function never waits on an upload. + * + * Uploads are tracked rather than fired and forgotten, because the shutdown drain has to know what + * is still in flight — untracked, an envelope in flight at teardown dies with the process. + */ +export class SentryTunnel { + /** Tracks what is still in flight, so the shutdown drain knows what it is waiting for. */ + public readonly uploads: PromiseBuffer; + private _lastActivityAt: number; + private _dropsReported: number; + + public constructor() { + this.uploads = makePromiseBuffer(MAX_PENDING_UPLOADS); + this._lastActivityAt = 0; + this._dropsReported = 0; + } + + /** When the tunnel last took a request. The shutdown drain waits for this to go quiet. */ + public get lastActivityAt(): number { + return this._lastActivityAt; + } + + public listen(port: number = TUNNEL_PORT): http.Server { + const allowedDsnComponents = getSentryDSNFromEnv(); + + if (!allowedDsnComponents) { + logWarn( + 'SENTRY_DSN is not set or is invalid. The /envelope tunnel will forward any DSN in the envelope ' + + 'header without allowlist validation. Set SENTRY_DSN to the same DSN as your SDK to restrict ' + + 'outbound requests.', + ); + } + + const server = http.createServer((req, res) => { + this._lastActivityAt = Date.now(); + + if (req.method !== 'POST' || !req.url?.startsWith('/envelope')) { + respond(res, 404, { error: 'Not found' }); + return; + } + + void this._forward(req, res, allowedDsnComponents); + }); + + server.listen(port, () => { + DEBUG_BUILD && debug.log(`Sentry proxy listening on port ${port}`); + }); + + // Surfaced rather than exited on: the extension is registered by this point, and a process that + // ends outside the shutdown phase is reported as `Extension.Crash` against the invocation in + // flight — failing the customer's request over a tunnel only this SDK would have used. + server.on('error', err => { + logError('the envelope tunnel could not listen.', err); + }); + + return server; + } + + private async _forward( + req: http.IncomingMessage, + res: http.ServerResponse, + allowedDsnComponents: DsnComponents | undefined, + ): Promise { + try { + const buf = await buffer(req); + // Slice the underlying ArrayBuffer so only the data portion travels, without padding or offset. + const envelopeBytes = buf.buffer.slice(buf.byteOffset, buf.byteOffset + buf.byteLength); + const contentEncoding = req.headers['content-encoding']; + const envelope = await readEnvelopeHeader(buf, contentEncoding); + const envelopeDsn = envelope?.dsn; + + if (!envelopeDsn) { + respond(res, 400, { error: 'Invalid envelope: missing DSN' }); + return; + } + + // Same allowlist check as `handleTunnelRequest` in @sentry/core (SSRF protection). Without + // SENTRY_DSN any DSN is allowed, which is what the warning above is about. + if (allowedDsnComponents && dsnToString(allowedDsnComponents) !== envelopeDsn) { + // Reported like any other drop: the envelope is discarded, and `debug` cannot say so here. + this._reportDrop('an envelope was rejected because its DSN is not the one this extension was given.'); + respond(res, 403, { error: 'DSN not allowed' }); + return; + } + + const dsn = allowedDsnComponents || parseEnvelopeDsn(envelopeDsn); + + if (!dsn) { + respond(res, 403, { error: 'Invalid DSN' }); + return; + } + + // Forwarded exactly as it arrived, compression included, so the encoding has to travel with + // it — decompressing only ever happened to read the header above. + void this.uploads + .add(() => + fetch(getEnvelopeEndpointWithUrlEncodedAuth(dsn), { + method: 'POST', + body: envelopeBytes as BodyInit, + headers: contentEncoding ? { 'content-encoding': contentEncoding } : undefined, + }), + ) + .then(undefined, err => { + // Also where a full buffer lands, which is a drop like any other rather than a silence. + this._reportDrop('an envelope could not be delivered to Sentry.', err); + }); + + respond(res, 200, {}); + } catch (e) { + this._reportDrop('an envelope could not be read and was dropped.', e); + respond(res, 500, { error: 'Error tunneling to Sentry' }); + } + } + + /** + * A dropped envelope is silent data loss, so it goes to the console rather than to `debug`, which + * is never enabled in this process — capped, so a Sentry outage cannot bill a line per envelope. + */ + private _reportDrop(message: string, err?: unknown): void { + if (this._dropsReported++ < MAX_REPORTED_FAILURES) { + logError(message, ...(err === undefined ? [] : [err])); + } + } +} diff --git a/packages/aws-serverless/src/lambda-extension/types.ts b/packages/aws-serverless/src/lambda-extension/types.ts new file mode 100644 index 000000000000..fc21dd4abd3e --- /dev/null +++ b/packages/aws-serverless/src/lambda-extension/types.ts @@ -0,0 +1,32 @@ +export interface ExtensionEvent { + eventType?: string; + /** Absolute Unix ms. On SHUTDOWN, when Lambda SIGKILLs the process. */ + deadlineMs?: number; +} + +/** Why `run` stopped polling. Only `shutdown` means the environment is going away. */ +export interface PollOutcome { + reason: 'shutdown' | 'unrecoverable'; + /** + * Whether the Extensions API ever took a poll from us. Lambda releases the init phase on the + * first one it accepts, so until then this extension is what every invocation is waiting for. + */ + pollAccepted: boolean; + error?: unknown; +} + +export interface ExtensionsApiRequest { + method?: 'GET' | 'POST'; + headers: Record; + body?: string; +} + +export interface ExtensionsApiResponse { + statusCode: number; + headers: Record; + body: string; +} + +export type EnvelopeHeader = { + dsn?: string; +}; diff --git a/packages/aws-serverless/src/lambda-extension/utils.ts b/packages/aws-serverless/src/lambda-extension/utils.ts new file mode 100644 index 000000000000..b0ece6f3e2e0 --- /dev/null +++ b/packages/aws-serverless/src/lambda-extension/utils.ts @@ -0,0 +1,36 @@ +import { consoleSandbox, truncate } from '@sentry/core'; +import { ERROR_BODY_MAX_LENGTH, POLL_RETRY_BASE_MS, POLL_RETRY_MAX_MS } from './constants'; + +/** + * `debug` is only enabled from `Sentry.init`, which this separate process never calls, so anything + * reported through the logger from the extension is invisible under every option and env var. + */ +export function logError(message: string, ...rest: unknown[]): void { + consoleSandbox(() => { + // eslint-disable-next-line no-console + console.error(`Sentry Lambda extension: ${message}`, ...rest); + }); +} + +/** Configuration advice rather than a failure, so it must not trip an alarm filtering on ERROR. */ +export function logWarn(message: string): void { + consoleSandbox(() => { + // eslint-disable-next-line no-console + console.warn(`Sentry Lambda extension: ${message}`); + }); +} + +/** A response body only ever reaches the console, where the whole of it is nobody's friend. */ +export function truncateBody(body: string): string { + return truncate(body, ERROR_BODY_MAX_LENGTH); +} + +export function retryDelayMs(attempt: number): number { + return Math.min(POLL_RETRY_BASE_MS * 2 ** (attempt - 1), POLL_RETRY_MAX_MS); +} + +export function sleep(ms: number): Promise { + return new Promise(resolve => { + setTimeout(resolve, ms); + }); +} diff --git a/packages/aws-serverless/test/aws-lambda-extension.test.ts b/packages/aws-serverless/test/aws-lambda-extension.test.ts deleted file mode 100644 index 4c3143eea442..000000000000 --- a/packages/aws-serverless/test/aws-lambda-extension.test.ts +++ /dev/null @@ -1,37 +0,0 @@ -import { afterEach, beforeEach, describe, expect, test, vi } from 'vitest'; -import { getSentryDSNFromEnv } from '../src/lambda-extension/aws-lambda-extension'; - -describe('getSentryDSNFromEnv', () => { - afterEach(() => { - delete process.env.SENTRY_DSN; - vi.restoreAllMocks(); - }); - - beforeEach(() => { - vi.spyOn(console, 'error').mockImplementation(() => {}); - }); - - test('returns undefined when SENTRY_DSN is unset', () => { - expect(getSentryDSNFromEnv()).toEqual(undefined); - }); - - test('returns canonical dsn string when SENTRY_DSN is valid', () => { - process.env.SENTRY_DSN = 'https://public@o1.ingest.sentry.io/1'; - - expect(getSentryDSNFromEnv()).toEqual({ - protocol: 'https', - publicKey: 'public', - host: 'o1.ingest.sentry.io', - projectId: '1', - pass: '', - path: '', - port: '', - }); - }); - - test('returns undefined when SENTRY_DSN is invalid', () => { - process.env.SENTRY_DSN = 'not-a-dsn'; - - expect(getSentryDSNFromEnv()).toEqual(undefined); - }); -}); diff --git a/packages/aws-serverless/test/init.test.ts b/packages/aws-serverless/test/init.test.ts index 500338dc7144..4038e6872295 100644 --- a/packages/aws-serverless/test/init.test.ts +++ b/packages/aws-serverless/test/init.test.ts @@ -3,6 +3,7 @@ import { initWithoutDefaultIntegrations } from '@sentry/node'; import { beforeEach, describe, expect, test, vi } from 'vitest'; import type { AwsServerlessOptions } from '../src/init'; import { init } from '../src/init'; +import { TUNNEL_URL } from '../src/lambda-extension/constants'; vi.mock('@sentry/core', async importOriginal => ({ ...(await importOriginal()), @@ -55,7 +56,7 @@ describe('init', () => { expect(mockInitWithoutDefaultIntegrations).toHaveBeenCalledWith( expect.objectContaining({ - tunnel: 'http://localhost:9000/envelope', + tunnel: TUNNEL_URL, }), ); }); diff --git a/packages/aws-serverless/test/lambda-extension/constants.test.ts b/packages/aws-serverless/test/lambda-extension/constants.test.ts new file mode 100644 index 000000000000..5c0baa794e1b --- /dev/null +++ b/packages/aws-serverless/test/lambda-extension/constants.test.ts @@ -0,0 +1,65 @@ +import { MAX_BAGGAGE_STRING_LENGTH } from '@sentry/core'; +import { describe, expect, test } from 'vitest'; +import { + ENVELOPE_HEADER_MAX_BYTES, + POLL_KEEPALIVE_MS, + MAX_TIMER_DELAY_MS, + POLL_ESTABLISHED_MS, + POLL_GIVE_UP_MS, + POLL_RETRY_BASE_MS, + POLL_RETRY_MAX_MS, + SHUTDOWN_BUDGET_MS, + SHUTDOWN_IDLE_GRACE_MS, + SHUTDOWN_MARGIN_MS, + TUNNEL_PORT, + TUNNEL_URL, +} from '../../src/lambda-extension/constants'; + +/** + * Tests import these rather than mirroring them, so retuning a value cannot fail a test that is + * still describing the right behaviour. What that leaves uncovered is a value retuned into a shape + * the code no longer works in, which is what these pin — the relationships, not the numbers. The + * exception is the wire contract, where a change is a break rather than a tuning. + */ +describe('lambda extension constants', () => { + test('treats a poll that outlasted the longest retry as established', () => { + // The whole point of the signal: a poll the API held longer than we would ever have waited + // before retrying is one the API accepted and parked. + expect(POLL_ESTABLISHED_MS).toBe(POLL_RETRY_MAX_MS); + expect(POLL_RETRY_BASE_MS).toBeLessThan(POLL_RETRY_MAX_MS); + }); + + test('probes for a dead peer on a cadence the poll loop can actually use', () => { + // Probing more often than the loop would retry is chatter that buys nothing, and probing less + // often than it gives up means the detection never arrives in time to matter. + expect(POLL_KEEPALIVE_MS).toBeGreaterThan(POLL_RETRY_MAX_MS); + expect(POLL_KEEPALIVE_MS).toBeLessThan(POLL_GIVE_UP_MS); + }); + + test('gives up above the longest invocation Lambda allows', () => { + // Otherwise an outage spanning one maximum-length invocation trips it on its own. + expect(POLL_GIVE_UP_MS).toBeGreaterThan(900_000); + }); + + test('fits the drain and its headroom inside the window Lambda allows', () => { + // Lambda SIGKILLs at the end of the budget, so the grace plus the margin has to leave room for + // an upload to finish rather than consuming the window on its own. + expect(SHUTDOWN_IDLE_GRACE_MS + SHUTDOWN_MARGIN_MS).toBeLessThan(SHUTDOWN_BUDGET_MS); + expect(SHUTDOWN_MARGIN_MS).toBeGreaterThan(0); + }); + + test('parks on the largest delay Node accepts, since anything above it fires at once', () => { + expect(MAX_TIMER_DELAY_MS).toBe(2 ** 31 - 1); + }); + + test('inflates far enough for any envelope header a well-formed SDK can produce', () => { + // The header's only unbounded-looking field is the sampling context, and its source baggage is + // capped by core — so if that cap ever grows past this one, legitimate envelopes start failing + // to parse and are answered 500. + expect(ENVELOPE_HEADER_MAX_BYTES).toBeGreaterThan(MAX_BAGGAGE_STRING_LENGTH); + }); + + test('points the SDK at the port the tunnel listens on', () => { + expect(TUNNEL_URL).toBe(`http://localhost:${TUNNEL_PORT}/envelope`); + }); +}); diff --git a/packages/aws-serverless/test/lambda-extension/drain.test.ts b/packages/aws-serverless/test/lambda-extension/drain.test.ts new file mode 100644 index 000000000000..b75e97a10a52 --- /dev/null +++ b/packages/aws-serverless/test/lambda-extension/drain.test.ts @@ -0,0 +1,84 @@ +import { setTimeout as delay } from 'node:timers/promises'; +import { afterEach, beforeEach, describe, expect, test, vi } from 'vitest'; +import { AwsLambdaExtension } from '../../src/lambda-extension/aws-lambda-extension'; +import { SHUTDOWN_BUDGET_MS, SHUTDOWN_IDLE_GRACE_MS, SHUTDOWN_MARGIN_MS } from '../../src/lambda-extension/constants'; +import { activeTimers, drainedAfter, recordTunnelActivity, trackUpload, waitForQuietTimers } from './helpers'; + +describe('AwsLambdaExtension.drainPendingUploads', () => { + beforeEach(() => { + vi.useFakeTimers(); + }); + + afterEach(() => { + vi.useRealTimers(); + vi.restoreAllMocks(); + }); + + test('waits out a genuine deadline, less the margin that keeps the drain off the SIGKILL', async () => { + const extension = new AwsLambdaExtension(); + trackUpload(extension, new Promise(() => {})); + const startedAt = Date.now(); + + const elapsed = await drainedAfter(extension.drainPendingUploads(startedAt + 700), startedAt); + + expect(elapsed).toBe(700 - SHUTDOWN_MARGIN_MS); + }); + + // AWS's own documented example payload carries `deadlineMs: 676051`, which is not an epoch value. + // Read as one it yields a negative budget and drops whatever is in flight, so anything that is + // not a plausible remaining window has to fall back to the limit Lambda enforces anyway. + test.each([ + ['no deadline at all', () => undefined], + ['a deadline already in the past', () => Date.now() - 5_000], + ["AWS's own documented 676051", () => 676_051], + ['a deadline sent as a string', () => String(Date.now() + 1_000)], + ['an empty object', () => ({})], + ])('falls back to the shutdown budget for %s', async (_shape, deadline) => { + const extension = new AwsLambdaExtension(); + trackUpload(extension, new Promise(() => {})); + const startedAt = Date.now(); + + const elapsed = await drainedAfter(extension.drainPendingUploads(deadline()), startedAt); + + expect(elapsed).toBe(SHUTDOWN_BUDGET_MS - SHUTDOWN_MARGIN_MS); + }); + + test('holds the idle grace open once nothing is left to send', async () => { + // The runtime gets SIGTERM before the extension is released, so envelopes — the SDK's own exit + // flush among them — keep arriving after the shutdown event. Returning the moment the pending + // set is empty drops every one of them. + const extension = new AwsLambdaExtension(); + const startedAt = Date.now(); + + const elapsed = await drainedAfter(extension.drainPendingUploads(undefined), startedAt); + + expect(elapsed).toBe(SHUTDOWN_IDLE_GRACE_MS); + }); + + test('re-arms the idle grace on tunnel activity', async () => { + // A burst of exit flushes should extend the wait rather than race it. + const extension = new AwsLambdaExtension(); + const startedAt = Date.now(); + setTimeout(() => recordTunnelActivity(extension, Date.now()), 200); + + const elapsed = await drainedAfter(extension.drainPendingUploads(undefined), startedAt); + + expect(elapsed).toBe(200 + SHUTDOWN_IDLE_GRACE_MS); + }); +}); + +describe('AwsLambdaExtension.drainPendingUploads on the real clock', () => { + test('leaves no referenced timer behind when an upload beats the deadline', async () => { + // `Promise.race` alone leaves the loser's timer armed, and a referenced timer holds the + // process open past the drain — invisible in elapsed time, which is identical either way. + await waitForQuietTimers(); + expect(activeTimers()).toBe(0); + + const extension = new AwsLambdaExtension(); + trackUpload(extension, delay(20)); + + await extension.drainPendingUploads(Date.now() + SHUTDOWN_BUDGET_MS); + + expect(activeTimers()).toBe(0); + }); +}); diff --git a/packages/aws-serverless/test/lambda-extension/extensions-api.test.ts b/packages/aws-serverless/test/lambda-extension/extensions-api.test.ts new file mode 100644 index 000000000000..49cd0f36efe1 --- /dev/null +++ b/packages/aws-serverless/test/lambda-extension/extensions-api.test.ts @@ -0,0 +1,106 @@ +import * as net from 'node:net'; +import { setTimeout as delay } from 'node:timers/promises'; +import { afterEach, describe, expect, test, vi } from 'vitest'; +import { POLL_KEEPALIVE_MS } from '../../src/lambda-extension/constants'; +import { request } from '../../src/lambda-extension/extensions-api'; +import { collapseEveryDeadline, startServer } from './helpers'; + +const POLL_DEADLINE_GRACE_MS = 50; + +/** + * Rewrites every deadline primitive so that whatever duration is asked for expires at once. A + * request that arms no deadline is untouched; one that arms any is over before the next line runs. + */ + +describe('request', () => { + afterEach(() => { + vi.restoreAllMocks(); + }); + + test('holds the poll open rather than putting a deadline on it', async () => { + // "Do not set a timeout on the GET call, as the extension can be suspended for a period of + // time until there is an event to return." Naming one timeout API and asserting it went + // unused would miss the others — and a socket deadline on its own is harmless anyway, it only + // emits `'timeout'`. So instead every deadline the call arms is made to expire immediately: + // whatever would eventually end the poll ends it here, before the event arrives. + let respond: (() => void) | undefined; + let polling!: () => void; + const reachedServer = new Promise(resolve => (polling = resolve)); + const api = await startServer((_req, res) => { + respond = () => { + res.writeHead(200); + res.end('{}'); + }; + polling(); + }); + + collapseEveryDeadline(); + + let settlement: string | undefined; + const polled = request(api.url, { headers: {} }); + void polled.then( + () => (settlement = 'resolved'), + (err: Error) => (settlement = `rejected with ${err.message}`), + ); + + // The grace only means something once the poll is parked at the server, and a poll that dies + // before it gets there has already lost. + await Promise.race([reachedServer, polled.catch(() => {})]); + // Counted off the real clock: `globalThis.setTimeout` is collapsed for the duration. + await delay(POLL_DEADLINE_GRACE_MS); + + expect(settlement).toBeUndefined(); + + respond?.(); + const answered = await polled; + expect(answered.statusCode).toBe(200); + expect(answered.body).toBe('{}'); + + await api.close(); + }); + + test('rejects when the peer goes away mid-poll', async () => { + // The poll has no deadline on purpose — it spans the environment's frozen idle time, which + // is unbounded — so a peer that disappears has to surface as a socket error instead. + const peer = await startServer(); + peer.server.on('connection', socket => socket.destroy()); + + await expect(request(peer.url, { headers: {} })).rejects.toThrow(); + + await peer.close(); + }); + + test('enables TCP keep-alive so a dead peer is detected without a deadline', async () => { + const api = await startServer((_req, res) => { + res.writeHead(200); + res.end('{}'); + }); + const setKeepAlive = vi.spyOn(net.Socket.prototype, 'setKeepAlive'); + + await request(api.url, { headers: {} }); + + expect(setKeepAlive).toHaveBeenCalledWith(true, POLL_KEEPALIVE_MS); + + await api.close(); + }); + + test('sends a POST body and hands back the response headers, which registration needs', async () => { + let seen: { method?: string; body?: string } = {}; + const api = await startServer((req, res) => { + const chunks: Buffer[] = []; + req.on('data', (chunk: Buffer) => chunks.push(chunk)); + req.on('end', () => { + seen = { method: req.method, body: Buffer.concat(chunks).toString() }; + res.writeHead(200, { 'lambda-extension-identifier': 'an-id' }); + res.end('{}'); + }); + }); + + const res = await request(api.url, { method: 'POST', headers: {}, body: '{"events":["SHUTDOWN"]}' }); + + expect(seen).toEqual({ method: 'POST', body: '{"events":["SHUTDOWN"]}' }); + expect(res.headers['lambda-extension-identifier']).toBe('an-id'); + + await api.close(); + }); +}); diff --git a/packages/aws-serverless/test/lambda-extension/helpers.ts b/packages/aws-serverless/test/lambda-extension/helpers.ts new file mode 100644 index 000000000000..88e48f3d120d --- /dev/null +++ b/packages/aws-serverless/test/lambda-extension/helpers.ts @@ -0,0 +1,209 @@ +import * as http from 'node:http'; +import * as net from 'node:net'; +import { setTimeout as delay } from 'node:timers/promises'; +import type { AddressInfo } from 'node:net'; +import { vi } from 'vitest'; +import type { AwsLambdaExtension } from '../../src/lambda-extension/aws-lambda-extension'; +import type { SentryTunnel } from '../../src/lambda-extension/sentry-tunnel'; +import { SHUTDOWN_BUDGET_MS } from '../../src/lambda-extension/constants'; +import type { PollOutcome } from '../../src/lambda-extension/types'; + +export async function listen(server: http.Server, host?: string): Promise { + await new Promise(resolve => server.listen(0, host, resolve)); + return (server.address() as AddressInfo).port; +} + +export function close(server: http.Server): Promise { + return new Promise(resolve => { + server.closeAllConnections(); + server.close(() => resolve()); + }); +} + +/** A loopback server whose URL and shutdown the caller does not have to assemble each time. */ +export async function startServer( + handler?: http.RequestListener, +): Promise<{ url: string; close: () => Promise; server: http.Server }> { + const server = handler ? http.createServer(handler) : http.createServer(); + const port = await listen(server, '127.0.0.1'); + + return { url: `http://127.0.0.1:${port}/`, close: () => close(server), server }; +} + +export function spyOnExit() { + return vi.spyOn(process, 'exit').mockImplementation((() => undefined) as never); +} + +export interface FakeExtensionsApi { + close: () => Promise; +} + +/** + * Stands in for the Lambda Extensions API. `/register` succeeds by default so tests can reach the + * poll; both endpoints are delegated so each test decides how the API behaves. + */ +export async function startExtensionsApi( + onNext: (req: http.IncomingMessage, res: http.ServerResponse) => void, + onRegister?: (req: http.IncomingMessage, res: http.ServerResponse, attempt: number) => void, +): Promise { + let registrations = 0; + + const server = http.createServer((req, res) => { + if (req.url?.endsWith('/register')) { + if (onRegister) { + onRegister(req, res, ++registrations); + return; + } + + res.writeHead(200, { 'lambda-extension-identifier': 'test-extension-id' }); + res.end('{}'); + return; + } + + onNext(req, res); + }); + + process.env.AWS_LAMBDA_RUNTIME_API = `127.0.0.1:${await listen(server, '127.0.0.1')}`; + + return { close: () => close(server) }; +} + +/** For tests that never get as far as polling; reaching it means the test set itself up wrong. */ +export function pollNotExpected(_req: http.IncomingMessage, res: http.ServerResponse): void { + res.writeHead(500, { 'Content-Type': 'application/json' }); + res.end('the poll should not have been reached'); +} + +export type ScriptedPoll = { eventType?: string } | Error | { heldForMs: number; then: Error }; + +/** + * Drives `run` through a fixed sequence of polls. A step is an event, a rejection, or a rejection + * that only arrives once the poll has been held open — the shape `run` reads as an established + * connection. Anything past the script is a SHUTDOWN, so a loop that fails to stop where the test + * says it should reports the wrong outcome in milliseconds instead of spinning the worker. + */ +export function scriptPolls( + extension: AwsLambdaExtension, + script: ScriptedPoll[], +): { next: ReturnType; startedAt: number[] } { + const startedAt: number[] = []; + let poll = 0; + + const next = vi.spyOn(extension, 'next').mockImplementation(async () => { + startedAt.push(Date.now()); + const step = script[poll++]; + + if (step === undefined) { + return { eventType: 'SHUTDOWN' }; + } + if (step instanceof Error) { + throw step; + } + if ('heldForMs' in step) { + await new Promise(resolve => setTimeout(resolve, step.heldForMs)); + throw step.then; + } + return step; + }); + + return { next, startedAt }; +} + +/** Fake milliseconds to hand the loop; every backoff it can arm is well inside this. */ +export const RUN_DRIVE_MS = 60_000; + +/** + * Runs the poll loop on the fake clock and reports how it ended. A loop that neither returns nor + * rejects reads as `'still polling'` rather than as a suite timeout, so a regression that keeps + * going fails with the outcome it produced. + */ +export async function runToOutcome(extension: AwsLambdaExtension, driveMs: number = RUN_DRIVE_MS): Promise { + let outcome: unknown = 'still polling'; + + void extension.run().then( + (result: PollOutcome) => { + outcome = result; + }, + (err: unknown) => { + outcome = { threw: err }; + }, + ); + + await vi.advanceTimersByTimeAsync(driveMs); + await Promise.resolve(); + + return outcome; +} + +export function trackUpload(extension: AwsLambdaExtension, upload: Promise): void { + (extension as unknown as { _tunnel: SentryTunnel })._tunnel.uploads.add(() => upload); +} + +export function recordTunnelActivity(extension: AwsLambdaExtension, at: number): void { + (extension as unknown as { _tunnel: { _lastActivityAt: number } })._tunnel._lastActivityAt = at; +} + +/** Past every window the drain can legitimately wait out. */ +export const DRAIN_DRIVE_MS = SHUTDOWN_BUDGET_MS + 1_000; + +/** + * How long a drain took on the fake clock, or `'still draining'` when it never returned — a + * deadline read as an epoch can leave the loop running, and awaiting that would surface as a suite + * timeout instead of the budget the drain actually used. + */ +export async function drainedAfter(drain: Promise, startedAt: number): Promise { + let elapsed: number | string = 'still draining'; + + void drain.then(() => { + elapsed = Date.now() - startedAt; + }); + + await vi.advanceTimersByTimeAsync(DRAIN_DRIVE_MS); + await Promise.resolve(); + + return elapsed; +} + +export function activeTimers(): number { + const inspect = (process as NodeJS.Process & { getActiveResourcesInfo?: () => string[] }).getActiveResourcesInfo; + + if (!inspect) { + throw new Error('process.getActiveResourcesInfo is required to detect a leaked timer'); + } + + const resources: string[] = inspect.call(process); + + return resources.filter(resource => resource === 'Timeout').length; +} + +/** + * A timer an earlier test left armed would stand in for the leaked one below, so the measurement + * only means anything from zero. Bounded generously: a keep-alive left by an earlier HTTP test was + * measured clearing in about 1.3s. + */ +export async function waitForQuietTimers(): Promise { + for (let attempt = 0; attempt < 100 && activeTimers() > 0; attempt++) { + await delay(50); + } +} + +export function collapseEveryDeadline(): void { + const timer = globalThis.setTimeout; + const interval = globalThis.setInterval; + const socketDeadline = net.Socket.prototype.setTimeout; + const abortDeadline = AbortSignal.timeout; + + vi.spyOn(globalThis, 'setTimeout').mockImplementation(((handler: () => void, _ms?: number, ...args: unknown[]) => + timer(handler, 0, ...args)) as unknown as typeof globalThis.setTimeout); + vi.spyOn(globalThis, 'setInterval').mockImplementation(((handler: () => void, _ms?: number, ...args: unknown[]) => + interval(handler, 0, ...args)) as unknown as typeof globalThis.setInterval); + vi.spyOn(net.Socket.prototype, 'setTimeout').mockImplementation(function ( + this: net.Socket, + ms: number, + callback?: () => void, + ) { + // Zero already means "no deadline"; arming one here would be the opposite of what was asked. + return socketDeadline.call(this, ms === 0 ? 0 : 1, callback); + }); + vi.spyOn(AbortSignal, 'timeout').mockImplementation(() => abortDeadline.call(AbortSignal, 0)); +} diff --git a/packages/aws-serverless/test/lambda-extension/main.test.ts b/packages/aws-serverless/test/lambda-extension/main.test.ts new file mode 100644 index 000000000000..872d6d716636 --- /dev/null +++ b/packages/aws-serverless/test/lambda-extension/main.test.ts @@ -0,0 +1,98 @@ +import type * as http from 'node:http'; +import { afterEach, beforeEach, describe, expect, test, vi } from 'vitest'; +import { AwsLambdaExtension } from '../../src/lambda-extension/aws-lambda-extension'; +import { ExtensionsApiError } from '../../src/lambda-extension/errors'; +import { main } from '../../src/lambda-extension/main'; + +describe('main', () => { + let errorSpy: ReturnType; + let exit: ReturnType; + let extension: AwsLambdaExtension; + + beforeEach(() => { + errorSpy = vi.spyOn(console, 'error').mockImplementation(() => {}); + exit = vi.fn(); + extension = new AwsLambdaExtension(); + vi.spyOn(extension, 'startSentryTunnel').mockReturnValue(undefined as unknown as http.Server); + vi.useFakeTimers(); + }); + + afterEach(() => { + vi.useRealTimers(); + vi.restoreAllMocks(); + }); + + test('gives back the rest of the shutdown window once the drain has returned', async () => { + vi.spyOn(extension, 'register').mockResolvedValue(undefined); + vi.spyOn(extension, 'run').mockResolvedValue({ reason: 'shutdown', pollAccepted: true }); + + await main(extension, exit); + + expect(exit).toHaveBeenCalledWith(0); + }); + + test('exits when the registration cannot be made, so Lambda recycles the environment', async () => { + // An extension holding a name it cannot poll with holds the init phase, and with it every + // invocation, for the environment's whole life. This is the one failure worth crashing over. + const refused = new Error('Failed to register with the extension API: already registered'); + vi.spyOn(extension, 'register').mockRejectedValue(refused); + const run = vi.spyOn(extension, 'run'); + + await main(extension, exit); + + expect(exit).toHaveBeenCalledWith(1); + expect(run).not.toHaveBeenCalled(); + expect(errorSpy).toHaveBeenCalledWith( + 'Sentry Lambda extension: could not register, events will not be tunnelled.', + refused, + ); + }); + + test('stays up when polling stops, rather than failing the invocation in flight', async () => { + // Out of the invocation gate, an extension that has stopped polling costs the customer + // nothing; a process ending outside the shutdown phase is reported as `Extension.Crash`. + const pollFailure = new ExtensionsApiError('refused', 403); + vi.spyOn(extension, 'register').mockResolvedValue(undefined); + vi.spyOn(extension, 'run').mockResolvedValue({ reason: 'unrecoverable', pollAccepted: true, error: pollFailure }); + + await main(extension, exit); + + expect(exit).not.toHaveBeenCalled(); + // A tunnel that failed to listen leaves no handle, and an empty event loop exits just the same. + expect(vi.getTimerCount()).toBe(1); + vi.clearAllTimers(); + }); + + test('starts the tunnel before registering, so envelopes are served while registration retries', async () => { + const order: string[] = []; + vi.mocked(extension.startSentryTunnel).mockImplementation(() => { + order.push('tunnel'); + return undefined as unknown as http.Server; + }); + vi.spyOn(extension, 'register').mockImplementation(async () => { + order.push('register'); + }); + vi.spyOn(extension, 'run').mockResolvedValue({ reason: 'shutdown', pollAccepted: true }); + + await main(extension, exit); + + expect(order).toEqual(['tunnel', 'register']); + }); + + test('exits when it gave up before the Extensions API ever took a poll', async () => { + // Lambda releases the init phase on the first poll the API accepts, so giving up before then + // leaves this extension holding every invocation to the function timeout — measured at 30,000ms + // billed per invocation, against 1.5s for a crash that lets Lambda recycle. + const pollFailure = new ExtensionsApiError('refused', 403); + vi.spyOn(extension, 'register').mockResolvedValue(undefined); + vi.spyOn(extension, 'run').mockResolvedValue({ reason: 'unrecoverable', pollAccepted: false, error: pollFailure }); + + await main(extension, exit); + + expect(exit).toHaveBeenCalledWith(1); + expect(errorSpy).toHaveBeenCalledWith( + 'Sentry Lambda extension: never started polling the Extensions API, events will not be tunnelled.', + pollFailure, + ); + }); +}); diff --git a/packages/aws-serverless/test/lambda-extension/next.test.ts b/packages/aws-serverless/test/lambda-extension/next.test.ts new file mode 100644 index 000000000000..8825039dae24 --- /dev/null +++ b/packages/aws-serverless/test/lambda-extension/next.test.ts @@ -0,0 +1,89 @@ +import { afterEach, describe, expect, test, vi } from 'vitest'; +import { AwsLambdaExtension } from '../../src/lambda-extension/aws-lambda-extension'; +import { type FakeExtensionsApi, startExtensionsApi } from './helpers'; + +describe('AwsLambdaExtension.next', () => { + let api: FakeExtensionsApi | undefined; + + afterEach(async () => { + await api?.close(); + api = undefined; + delete process.env.AWS_LAMBDA_RUNTIME_API; + vi.restoreAllMocks(); + }); + + test("does not poll through fetch, which would cap the poll at undici's 300s headersTimeout", async () => { + api = await startExtensionsApi((_req, res) => { + res.writeHead(200, { 'Content-Type': 'application/json' }); + res.end(JSON.stringify({ eventType: 'INVOKE' })); + }); + const extension = new AwsLambdaExtension(); + await extension.register(); + + const fetchSpy = vi.spyOn(globalThis, 'fetch'); + await extension.next(); + + expect(fetchSpy).not.toHaveBeenCalled(); + }); + + test('polls the Extensions API path Lambda serves, which is wire contract', async () => { + let polledPath: string | undefined; + api = await startExtensionsApi((req, res) => { + polledPath = req.url; + res.writeHead(200, { 'Content-Type': 'application/json' }); + res.end(JSON.stringify({ eventType: 'INVOKE' })); + }); + const extension = new AwsLambdaExtension(); + await extension.register(); + + await extension.next(); + + expect(polledPath).toBe('/2020-01-01/extension/event/next'); + }); + + test('resolves for an event that arrives long after the request was issued', async () => { + api = await startExtensionsApi((_req, res) => { + setTimeout(() => { + res.writeHead(200, { 'Content-Type': 'application/json' }); + res.end(JSON.stringify({ eventType: 'INVOKE' })); + }, 300); + }); + const extension = new AwsLambdaExtension(); + await extension.register(); + + await expect(extension.next()).resolves.toEqual({ eventType: 'INVOKE' }); + }); + + test('rejects with the response body and status when the Extensions API refuses the poll', async () => { + api = await startExtensionsApi((_req, res) => { + res.writeHead(403, { 'Content-Type': 'application/json' }); + res.end('extension not registered'); + }); + const extension = new AwsLambdaExtension(); + await extension.register(); + + await expect(extension.next()).rejects.toThrow('Failed to advance to next event: extension not registered'); + await expect(extension.next()).rejects.toHaveProperty('statusCode', 403); + }); + + // `run` decides when to stop from `eventType`, so a 200 without one has to count as a failed + // poll. `JSON.parse` succeeds for every JSON literal and `{}` is an object, so anything short of + // an `eventType` string would otherwise read as an INVOKE: counters reset, no backoff, re-poll. + test.each([ + ['an empty object', '{}'], + ['a JSON null', 'null'], + ['a JSON number', '123'], + ['a JSON array', '[]'], + ['a JSON boolean', 'true'], + ['a body that is not JSON at all', 'not json'], + ])('rejects a 200 carrying %s rather than reading it as an event', async (_shape, body) => { + api = await startExtensionsApi((_req, res) => { + res.writeHead(200, { 'Content-Type': 'application/json' }); + res.end(body); + }); + const extension = new AwsLambdaExtension(); + await extension.register(); + + await expect(extension.next()).rejects.toThrow(`The Extensions API returned no event: ${body}`); + }); +}); diff --git a/packages/aws-serverless/test/lambda-extension/register.test.ts b/packages/aws-serverless/test/lambda-extension/register.test.ts new file mode 100644 index 000000000000..b410be346d0e --- /dev/null +++ b/packages/aws-serverless/test/lambda-extension/register.test.ts @@ -0,0 +1,204 @@ +import { text } from 'node:stream/consumers'; +import { setTimeout as delay } from 'node:timers/promises'; +import { afterEach, beforeEach, describe, expect, test, vi } from 'vitest'; +import { AwsLambdaExtension } from '../../src/lambda-extension/aws-lambda-extension'; +import { MAX_REPORTED_FAILURES, POLL_GIVE_UP_MS } from '../../src/lambda-extension/constants'; +import { collapseEveryDeadline, type FakeExtensionsApi, pollNotExpected, startExtensionsApi } from './helpers'; + +/** Long enough for a collapsed deadline to fire; the slowest measured took about 10ms. */ +const REGISTER_DEADLINE_GRACE_MS = 50; + +describe('AwsLambdaExtension.register', () => { + let api: FakeExtensionsApi | undefined; + let errorSpy: ReturnType; + + beforeEach(() => { + errorSpy = vi.spyOn(console, 'error').mockImplementation(() => {}); + }); + + afterEach(async () => { + await api?.close(); + api = undefined; + delete process.env.AWS_LAMBDA_RUNTIME_API; + vi.useRealTimers(); + vi.restoreAllMocks(); + }); + + test('subscribes to SHUTDOWN alone, keeping the extension out of the invocation gate', async () => { + // An INVOKE subscription joins the gate that holds every invocation until each subscriber has + // asked for the next event, so a poll that dies mid-flight would hold the rest of the + // environment's invocations open until the function timeout — and Lambda Managed Instances + // refuses the subscription outright, failing the function's init with it. + let body: unknown; + api = await startExtensionsApi(pollNotExpected, (req, res) => { + void text(req).then(raw => { + body = JSON.parse(raw); + res.writeHead(200, { 'lambda-extension-identifier': 'test-extension-id' }); + res.end('{}'); + }); + }); + + await new AwsLambdaExtension().register(); + + expect(body).toEqual({ events: ['SHUTDOWN'] }); + }); + + test('retries a registration the API never answered, instead of abandoning the extension', async () => { + // Lambda gates the init phase on every extension it launched, so one that never registers holds + // each invocation open until the function timeout without the handler ever running. + let attempts = 0; + api = await startExtensionsApi(pollNotExpected, (_req, res, attempt) => { + attempts = attempt; + + // The first attempt never gets an answer at all, which is the only retryable shape. + if (attempt === 1) { + res.socket?.destroy(); + return; + } + + res.writeHead(200, { 'lambda-extension-identifier': 'late-id' }); + res.end('{}'); + }); + const extension = new AwsLambdaExtension(); + + await extension.register(); + + expect(attempts).toBe(2); + // A transport failure is the one shape worth retrying, and it is what carries a `code`. + expect(errorSpy).toHaveBeenCalledWith( + 'Sentry Lambda extension: registering with the Extensions API failed, retrying.', + expect.objectContaining({ code: 'ECONNRESET' }), + ); + }); + + test('polls with the identifier from the attempt that finally succeeded', async () => { + let polledWith: string | undefined; + api = await startExtensionsApi( + (req, res) => { + polledWith = req.headers['lambda-extension-identifier'] as string | undefined; + res.writeHead(200, { 'Content-Type': 'application/json' }); + res.end(JSON.stringify({ eventType: 'SHUTDOWN' })); + }, + (_req, res, attempt) => { + if (attempt === 1) { + res.socket?.destroy(); + return; + } + + res.writeHead(200, { 'lambda-extension-identifier': 'late-id' }); + res.end('{}'); + }, + ); + const extension = new AwsLambdaExtension(); + await extension.register(); + + await extension.next(); + + expect(polledWith).toBe('late-id'); + }); + + test.each([ + ['a 200 that carries no identifier', 200, '{}', 'without returning an identifier'], + ['a 403', 403, 'already registered', 'Failed to register with the extension API: already registered'], + ['a 400', 400, 'bad request', 'Failed to register with the extension API: bad request'], + ['a 500', 500, 'container error', 'Failed to register with the extension API: container error'], + ])('does not re-register after %s, which the API answered', async (_label, status, body, message) => { + // The body is a compile-time constant, so no answered refusal can start working. Retrying one + // holds the init gate with the handler never running; surfacing costs one fast invocation and + // lets Lambda recycle into an environment that works. + let attempts = 0; + api = await startExtensionsApi(pollNotExpected, (_req, res, attempt) => { + attempts = attempt; + res.writeHead(status, { 'Content-Type': 'application/json' }); + res.end(body); + }); + + await expect(new AwsLambdaExtension().register()).rejects.toThrow(message); + + expect(attempts).toBe(1); + expect(errorSpy).not.toHaveBeenCalled(); + }); + + test('gives up on a registration that never lands, so Lambda can recycle', async () => { + // Retrying forever holds the init phase, and with it every invocation, for as long as it keeps + // trying — the same harm `main` exits on when a poll is never accepted, reached through the + // registration door. Past the ceiling it is better to crash. + const extension = new AwsLambdaExtension(); + const refused = new Error('ECONNREFUSED'); + // The loop is what is under test, so the request is stubbed rather than driven over a socket. + const attempt = vi + .spyOn(extension as unknown as { _requestRegistration: () => Promise }, '_requestRegistration') + .mockRejectedValue(refused); + + vi.useFakeTimers(); + const registering = expect(extension.register()).rejects.toThrow('ECONNREFUSED'); + await vi.advanceTimersByTimeAsync(POLL_GIVE_UP_MS + 60_000); + await registering; + + // It kept trying for the whole window, and stopped reporting long before it stopped trying. + expect(attempt.mock.calls.length).toBeGreaterThan(MAX_REPORTED_FAILURES); + expect(errorSpy).toHaveBeenCalledTimes(MAX_REPORTED_FAILURES); + }); + + test('holds the registration open rather than putting a deadline on it', async () => { + // Measured against the real Extensions API: undici's 300s `headersTimeout` abandoned a POST + // RAPID had already honoured, the retry was refused `Extension.InvalidExtensionState`, and the + // extension exited. Asserting that one timeout API went unused would have missed it, so every + // deadline the call can arm is collapsed instead. + let release: (() => void) | undefined; + let reached!: () => void; + const reachedServer = new Promise(resolve => (reached = resolve)); + api = await startExtensionsApi(pollNotExpected, (_req, res) => { + release = () => { + res.writeHead(200, { 'lambda-extension-identifier': 'test-extension-id' }); + res.end('{}'); + }; + reached(); + }); + + collapseEveryDeadline(); + + let settlement: string | undefined; + const registering = new AwsLambdaExtension().register().then( + () => (settlement = 'registered'), + (err: Error) => (settlement = `rejected with ${err.message}`), + ); + + await reachedServer; + await delay(REGISTER_DEADLINE_GRACE_MS); + + expect(settlement).toBeUndefined(); + + release?.(); + await registering; + // Spelled out rather than "settled": a rejection would satisfy "it stopped waiting" too, and + // this test exists because an abandoned registration is what the API refuses forever after. + expect(settlement).toBe('registered'); + }); + + test('sends the extension name Lambda requires, which is the wrapper filename', async () => { + // Lambda matches the registered name against the file it launched from `/opt/extensions/`, so + // this string is wire contract with `src/lambda-extension/sentry-extension`, not a label. + let name: string | undefined; + api = await startExtensionsApi(pollNotExpected, (req, res) => { + name = req.headers['lambda-extension-name'] as string | undefined; + res.writeHead(200, { 'lambda-extension-identifier': 'test-extension-id' }); + res.end('{}'); + }); + + await new AwsLambdaExtension().register(); + + expect(name).toBe('sentry-extension'); + }); + + test('puts no deadline on the registration, which cannot be made twice', async () => { + // A deadline cannot rescue a wedged API; it can only abandon a POST the API has already + // committed, and every attempt after that is refused for the life of the environment. + const deadline = vi.spyOn(AbortSignal, 'timeout'); + api = await startExtensionsApi(pollNotExpected); + + await new AwsLambdaExtension().register(); + + expect(deadline).not.toHaveBeenCalled(); + }); +}); diff --git a/packages/aws-serverless/test/lambda-extension/run.test.ts b/packages/aws-serverless/test/lambda-extension/run.test.ts new file mode 100644 index 000000000000..58aa94af17ee --- /dev/null +++ b/packages/aws-serverless/test/lambda-extension/run.test.ts @@ -0,0 +1,277 @@ +import { afterEach, beforeEach, describe, expect, test, vi } from 'vitest'; +import { AwsLambdaExtension } from '../../src/lambda-extension/aws-lambda-extension'; +import { + MAX_REPORTED_FAILURES, + TERMINAL_POLL_CONFIRMATIONS, + TERMINAL_POLL_STATUSES, + POLL_ESTABLISHED_MS, + POLL_GIVE_UP_MS, + POLL_RETRY_BASE_MS, +} from '../../src/lambda-extension/constants'; +import { ExtensionsApiError } from '../../src/lambda-extension/errors'; +import { runToOutcome, type ScriptedPoll, scriptPolls, spyOnExit } from './helpers'; + +/** Exactly as many refusals as it takes to confirm one, so the count follows the constant. */ +function refusalsOf(status: number): ExtensionsApiError[] { + return Array.from( + { length: TERMINAL_POLL_CONFIRMATIONS }, + (_, i) => new ExtensionsApiError(`refused #${i + 1}`, status), + ); +} + +describe('AwsLambdaExtension.run', () => { + let errorSpy: ReturnType; + let exitSpy: ReturnType; + + beforeEach(() => { + errorSpy = vi.spyOn(console, 'error').mockImplementation(() => {}); + exitSpy = spyOnExit(); + vi.useFakeTimers(); + }); + + afterEach(() => { + vi.useRealTimers(); + vi.restoreAllMocks(); + }); + + test('keeps polling after a failed poll', async () => { + // Lambda holds an invocation open until every registered extension asks for the next event, so + // a loop that stops on the first rejection leaves later invocations to the function timeout. + const extension = new AwsLambdaExtension(); + const { next } = scriptPolls(extension, [ + new Error('socket hang up'), + { eventType: 'INVOKE' }, + { eventType: 'SHUTDOWN' }, + ]); + + await runToOutcome(extension); + + expect(next).toHaveBeenCalledTimes(3); + }); + + test('reports a failed poll on the console, which the debug logger cannot do here', async () => { + const extension = new AwsLambdaExtension(); + const pollFailure = new Error('socket hang up'); + scriptPolls(extension, [pollFailure, { eventType: 'SHUTDOWN' }]); + + await runToOutcome(extension); + + expect(errorSpy).toHaveBeenCalledWith( + 'Sentry Lambda extension: polling the Extensions API failed, retrying.', + pollFailure, + ); + }); + + test('returns a shutdown outcome instead of throwing or ending the process', async () => { + // Polling after SHUTDOWN only produces failures on the way out, and the caller needs to tell + // that ending apart from a loop that gave up: only this one may exit the process. + const extension = new AwsLambdaExtension(); + const { next } = scriptPolls(extension, [{ eventType: 'SHUTDOWN' }]); + + const outcome = await runToOutcome(extension); + + expect(outcome).toEqual({ reason: 'shutdown', pollAccepted: true }); + expect(next).toHaveBeenCalledTimes(1); + expect(errorSpy).not.toHaveBeenCalled(); + expect(exitSpy).not.toHaveBeenCalled(); + }); + + test.each(TERMINAL_POLL_STATUSES)('stops polling once a %i has been confirmed, without exiting', async status => { + // Nothing exits on a poll failure: with only SHUTDOWN subscribed, an extension that stopped + // polling costs the customer nothing, while a process ending outside the shutdown phase is + // reported as `Extension.Crash` against the invocation in flight. + const extension = new AwsLambdaExtension(); + const refusals = refusalsOf(status); + const { next } = scriptPolls(extension, refusals); + + const outcome = await runToOutcome(extension); + + expect(outcome).toEqual({ reason: 'unrecoverable', pollAccepted: false, error: refusals.at(-1) }); + expect(next).toHaveBeenCalledTimes(TERMINAL_POLL_CONFIRMATIONS); + expect(exitSpy).not.toHaveBeenCalled(); + }); + + test.each(TERMINAL_POLL_STATUSES)( + 'keeps polling after a single %i, which is how a teardown poll is answered', + async status => { + // A 500 is also how the API answers a poll issued while the environment is already being torn + // down, which clears on its own; confirming costs a few hundred ms of backoff. + const extension = new AwsLambdaExtension(); + const { next } = scriptPolls(extension, [ + new ExtensionsApiError('refused once', status), + { eventType: 'INVOKE' }, + { eventType: 'SHUTDOWN' }, + ]); + + const outcome = await runToOutcome(extension); + + expect(outcome).toEqual({ reason: 'shutdown', pollAccepted: true }); + expect(next).toHaveBeenCalledTimes(3); + }, + ); + + test('retries a 408 and a 429 however often they repeat', async () => { + // These are the two 4xx that do start working again; counting them towards the terminal + // confirmations would stop the loop over a hiccup that repeats a few times. + const extension = new AwsLambdaExtension(); + const { next } = scriptPolls(extension, [ + new ExtensionsApiError('request timeout', 408), + new ExtensionsApiError('too many requests', 429), + new ExtensionsApiError('request timeout', 408), + { eventType: 'SHUTDOWN' }, + ]); + + const outcome = await runToOutcome(extension); + + expect(outcome).toEqual({ reason: 'shutdown', pollAccepted: true }); + expect(next).toHaveBeenCalledTimes(4); + }); + + test('confirms a refusal that flaps with transport failures', async () => { + // A permanent refusal rarely arrives cleanly: the API refuses, the socket drops, the API + // refuses again. A count the transport failure resets never confirms, and the loop retries a + // refusal that is never going to clear for the environment's whole life. + const extension = new AwsLambdaExtension(); + const refusals = refusalsOf(403); + const flapping = refusals.flatMap((refusal, i) => + i === refusals.length - 1 ? [refusal] : [refusal, new Error('ECONNRESET')], + ); + const { next } = scriptPolls(extension, flapping); + + const outcome = await runToOutcome(extension); + + expect(outcome).toEqual({ reason: 'unrecoverable', pollAccepted: false, error: refusals.at(-1) }); + expect(next).toHaveBeenCalledTimes(flapping.length); + }); + + test('starts counting over after a poll the API held open', async () => { + // Subscribed to SHUTDOWN alone the extension issues one poll per execution environment, so + // "since the last event" spans the environment's whole life. A poll the API accepted and + // parked is the only health signal left, and it has to clear both counters. + const extension = new AwsLambdaExtension(); + const { next, startedAt } = scriptPolls(extension, [ + new ExtensionsApiError('refused #1', 403), + new ExtensionsApiError('refused #2', 403), + { heldForMs: POLL_ESTABLISHED_MS, then: new ExtensionsApiError('refused #3', 403) }, + new ExtensionsApiError('refused #4', 403), + { eventType: 'SHUTDOWN' }, + ]); + + const outcome = await runToOutcome(extension); + + expect(outcome).toEqual({ reason: 'shutdown', pollAccepted: true }); + expect(next).toHaveBeenCalledTimes(5); + // The backoff starts over too, rather than staying where a long-failing loop had reached. + expect(startedAt[3]! - (startedAt[2]! + POLL_ESTABLISHED_MS)).toBe(POLL_RETRY_BASE_MS); + }); + + test('measures the give-up window from the failure, not from when the parked poll was issued', async () => { + // One poll is parked for the environment's whole life, and warm environments outlive the + // give-up window many times over — so a clock started at `sentAt` would spend the entire budget + // before the first retry, and the first hiccup after a long park would end the loop outright. + const extension = new AwsLambdaExtension(); + const { next } = scriptPolls(extension, [ + { heldForMs: POLL_GIVE_UP_MS + 60_000, then: new Error('ECONNRESET') }, + { eventType: 'SHUTDOWN' }, + ]); + + const outcome = await runToOutcome(extension, POLL_GIVE_UP_MS + 120_000); + + expect(outcome).toEqual({ reason: 'shutdown', pollAccepted: true }); + expect(next).toHaveBeenCalledTimes(2); + }); + + test('keeps the give-up window it restarted, rather than expiring on the failures before it', async () => { + // The restart is the point of the established-poll branch: a poll the API accepted and parked + // is a health signal, so the budget starts over. Clearing the counters without clearing the + // clock would expire the loop shortly after the very signal that was supposed to reprieve it. + const extension = new AwsLambdaExtension(); + const failure = new Error('ECONNREFUSED'); + // Capped backoff makes this about 14 minutes of failing before the API answers once. + const { next } = scriptPolls(extension, [ + ...Array(170).fill(failure), + { heldForMs: POLL_ESTABLISHED_MS, then: failure }, + ...Array(400).fill(failure), + ]); + + // Past the give-up measured from the first failure, well short of it measured from the poll + // the API answered — so a loop still running here is one whose clock restarted. + const outcome = await runToOutcome(extension, POLL_GIVE_UP_MS + 30_000); + + expect(outcome).toBe('still polling'); + expect(next.mock.calls.length).toBeGreaterThan(170); + }); + + test('caps the console over the environment lifetime, not over the latest streak of failures', async () => { + // A peer that accepts the poll and then dies restarts the retry budget every time, which is + // right — the API is still answering. A cap tied to that counter would reset with it and write + // a line every few seconds for as long as the environment lives. + const extension = new AwsLambdaExtension(); + const { next } = scriptPolls( + extension, + Array.from({ length: 200 }, () => ({ heldForMs: POLL_ESTABLISHED_MS, then: new Error('ECONNRESET') })), + ); + + await runToOutcome(extension, 60 * 60_000); + + expect(next.mock.calls.length).toBeGreaterThan(MAX_REPORTED_FAILURES); + expect(errorSpy).toHaveBeenCalledTimes(MAX_REPORTED_FAILURES); + }); + + test('backs off after an event it never subscribed to, rather than re-polling with no delay', async () => { + // Subscribed to SHUTDOWN alone, anything else is the API answering outside its own contract. + // Falling through would re-poll immediately, and nothing rate-limits this loop once the + // extension is out of the invocation gate. + const extension = new AwsLambdaExtension(); + const { next, startedAt } = scriptPolls(extension, [{ eventType: 'INVOKE' }, { eventType: 'SHUTDOWN' }]); + + const outcome = await runToOutcome(extension); + + expect(outcome).toEqual({ reason: 'shutdown', pollAccepted: true }); + expect(next).toHaveBeenCalledTimes(2); + expect(startedAt[1]! - startedAt[0]!).toBe(POLL_RETRY_BASE_MS); + }); + + test('gives up on the wall clock rather than after a fixed number of polls', async () => { + // The give-up sits above the 900s function ceiling, so an outage spanning one whole invocation + // cannot trip it — and a 20-poll cap would, since capped backoff reaches 20 polls in ~80s. + const extension = new AwsLambdaExtension(); + const failure = new Error('ECONNREFUSED'); + let polls = 0; + vi.spyOn(extension, 'next').mockImplementation(async () => { + polls++; + throw failure; + }); + const startedAt = Date.now(); + + const outcome = await runToOutcome(extension, POLL_GIVE_UP_MS + 60_000); + + expect(outcome).toEqual({ reason: 'unrecoverable', pollAccepted: false, error: failure }); + expect(Date.now() - startedAt).toBeGreaterThanOrEqual(POLL_GIVE_UP_MS); + expect(polls).toBeGreaterThan(MAX_REPORTED_FAILURES); + // The loop outlives the console reporting, which is capped so it does not bill the customer + // for one line every 5s until the environment is recycled. + expect(errorSpy).toHaveBeenCalledTimes(MAX_REPORTED_FAILURES); + expect(exitSpy).not.toHaveBeenCalled(); + }); + + test.each([ + ['never answered a poll', [], false], + ['answered one, whatever it answered with', [{ eventType: 'INVOKE' }], true], + // Deliberately false: elapsed time cannot tell a poll the API parked from a connect that hung, + // and the two failures are not symmetric — exiting when we should have parked costs one + // invocation, while parking when we should have exited bills every one of them to the function + // timeout for the life of the environment. + ['only held one open before it failed', [{ heldForMs: POLL_ESTABLISHED_MS, then: new Error('ECONNRESET') }], false], + ])('reports that the Extensions API %s', async (_label, prelude, pollAccepted) => { + // Lambda releases the init phase on the first poll the API answers, and `main` needs to tell + // the two apart: giving up before that holds every invocation, giving up after it is free. + const extension = new AwsLambdaExtension(); + const refusals = refusalsOf(403); + scriptPolls(extension, [...(prelude as ScriptedPoll[]), ...refusals]); + + const outcome = await runToOutcome(extension); + + expect(outcome).toEqual({ reason: 'unrecoverable', pollAccepted, error: refusals.at(-1) }); + }); +}); diff --git a/packages/aws-serverless/test/lambda-extension/sentry-tunnel.test.ts b/packages/aws-serverless/test/lambda-extension/sentry-tunnel.test.ts new file mode 100644 index 000000000000..9e085b06cf32 --- /dev/null +++ b/packages/aws-serverless/test/lambda-extension/sentry-tunnel.test.ts @@ -0,0 +1,454 @@ +import * as http from 'node:http'; +import { promisify } from 'node:util'; +import { gzip } from 'node:zlib'; +import type { AddressInfo } from 'node:net'; +import { afterEach, beforeEach, describe, expect, test, vi } from 'vitest'; +import { AwsLambdaExtension } from '../../src/lambda-extension/aws-lambda-extension'; +import { + ENVELOPE_HEADER_MAX_BYTES, + MAX_REPORTED_FAILURES, + SHUTDOWN_BUDGET_MS, + SHUTDOWN_IDLE_GRACE_MS, +} from '../../src/lambda-extension/constants'; +import { getSentryDSNFromEnv } from '../../src/lambda-extension/sentry-tunnel'; +import { close, listen, spyOnExit } from './helpers'; + +describe('getSentryDSNFromEnv', () => { + afterEach(() => { + vi.unstubAllEnvs(); + vi.restoreAllMocks(); + }); + + beforeEach(() => { + // Arranged rather than assumed: this repo's contributors are the likeliest people on earth to + // have SENTRY_DSN exported, and the value it holds is not this suite's to destroy. + vi.stubEnv('SENTRY_DSN', undefined); + vi.spyOn(console, 'error').mockImplementation(() => {}); + }); + + test('returns undefined when SENTRY_DSN is unset', () => { + expect(getSentryDSNFromEnv()).toEqual(undefined); + }); + + test('returns canonical dsn string when SENTRY_DSN is valid', () => { + vi.stubEnv('SENTRY_DSN', 'https://public@o1.ingest.sentry.io/1'); + + expect(getSentryDSNFromEnv()).toEqual({ + protocol: 'https', + publicKey: 'public', + host: 'o1.ingest.sentry.io', + projectId: '1', + pass: '', + path: '', + port: '', + }); + }); + + test('returns undefined when SENTRY_DSN is invalid', () => { + vi.stubEnv('SENTRY_DSN', 'not-a-dsn'); + + expect(getSentryDSNFromEnv()).toEqual(undefined); + }); +}); + +const UPSTREAM_HOLD_MS = 500; + +/** + * Comfortably past what the header read will inflate to, which is the bound a one-shot inflate + * would have tripped over. Derived from our own constant rather than from `@sentry/node`'s private + * 32KiB gzip threshold: this size clears that too, so the envelope is one the SDK would really + * have compressed, but the test does not silently stop being realistic if that threshold moves. + */ +const REALISTIC_GZIPPED_BYTES = ENVELOPE_HEADER_MAX_BYTES * 4; + +describe('AwsLambdaExtension tunnel', () => { + let servers: http.Server[]; + let errorSpy: ReturnType; + let warnSpy: ReturnType; + + beforeEach(() => { + servers = []; + vi.stubEnv('SENTRY_DSN', undefined); + errorSpy = vi.spyOn(console, 'error').mockImplementation(() => {}); + warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}); + }); + + afterEach(async () => { + await Promise.all(servers.map(close)); + vi.unstubAllEnvs(); + vi.restoreAllMocks(); + }); + + function track(server: http.Server): http.Server { + servers.push(server); + return server; + } + + /** Starts a tunnel on an ephemeral port and hands back the base URL the SDK would post to. */ + async function startTunnel(extension = new AwsLambdaExtension()): Promise { + const tunnel = track(extension.startSentryTunnel(0)); + await new Promise(resolve => tunnel.once('listening', resolve)); + + return `http://127.0.0.1:${(tunnel.address() as AddressInfo).port}`; + } + + /** Counts what actually left the extension, which is the only thing SSRF protection is about. */ + async function startUpstream(): Promise<{ dsn: string; received: string[]; encodings: (string | undefined)[] }> { + const received: string[] = []; + const encodings: (string | undefined)[] = []; + const port = await listen( + track( + http.createServer((req, res) => { + received.push(req.url ?? ''); + encodings.push(req.headers['content-encoding']); + res.writeHead(200, { 'Content-Type': 'application/json' }); + res.end('{}'); + }), + ), + '127.0.0.1', + ); + + return { dsn: `http://public@127.0.0.1:${port}/1`, received, encodings }; + } + + function envelope(dsn: string): string { + return `{"dsn":"${dsn}"}\n{"type":"event"}\n{}`; + } + + test('forwards an envelope whose DSN matches the one the extension was given', async () => { + const upstream = await startUpstream(); + vi.stubEnv('SENTRY_DSN', upstream.dsn); + const extension = new AwsLambdaExtension(); + const url = await startTunnel(extension); + + const res = await fetch(`${url}/envelope`, { method: 'POST', body: envelope(upstream.dsn) }); + await extension.drainPendingUploads(Date.now() + SHUTDOWN_BUDGET_MS); + + expect(res.status).toBe(200); + expect(await res.json()).toEqual({}); + expect(upstream.received).toHaveLength(1); + }); + + test.each([['gzip', promisify(gzip)]])( + 'reads the header of a %s envelope, which is how the SDK sends anything over 32 KiB', + async (encoding, compress) => { + // `makeNodeTransport` gzips a body past GZIP_THRESHOLD and sets `content-encoding`. Parsing the + // raw bytes as the envelope header throws on the magic bytes, which answered 500 and dropped + // every large event — measured end to end with the real layer and the real SDK. + const upstream = await startUpstream(); + vi.stubEnv('SENTRY_DSN', upstream.dsn); + const extension = new AwsLambdaExtension(); + const url = await startTunnel(extension); + const body = new Uint8Array(await compress(Buffer.from(envelope(upstream.dsn)))); + + const res = await fetch(`${url}/envelope`, { + method: 'POST', + body, + headers: { 'content-encoding': encoding }, + }); + await extension.drainPendingUploads(Date.now() + SHUTDOWN_BUDGET_MS); + + expect(res.status).toBe(200); + expect(upstream.received).toHaveLength(1); + // Forwarded as it arrived, so Sentry has to be told it is still compressed. + expect(upstream.encodings).toEqual([encoding]); + }, + ); + + test('rejects a compressed envelope whose DSN is not the one the extension was given', async () => { + // The allowlist has to survive compression, or it is bypassed by setting one header. + const upstream = await startUpstream(); + vi.stubEnv('SENTRY_DSN', upstream.dsn); + const extension = new AwsLambdaExtension(); + const url = await startTunnel(extension); + const body = new Uint8Array(await promisify(gzip)(Buffer.from(envelope('https://attacker@evil.example.com/1')))); + + const res = await fetch(`${url}/envelope`, { + method: 'POST', + body, + headers: { 'content-encoding': 'gzip' }, + }); + await extension.drainPendingUploads(Date.now() + SHUTDOWN_BUDGET_MS); + + expect(res.status).toBe(403); + expect(upstream.received).toHaveLength(0); + }); + + test.each([['GZIP'], ['gzip, identity'], [' gzip ']])( + 'reads a body whose content-encoding arrives as %s', + async encoding => { + // The value is the sender's, so it comes in whatever case and list form they chose; a strict + // match drops the envelope with a 500. + const upstream = await startUpstream(); + vi.stubEnv('SENTRY_DSN', upstream.dsn); + const extension = new AwsLambdaExtension(); + const url = await startTunnel(extension); + const body = new Uint8Array(await promisify(gzip)(Buffer.from(envelope(upstream.dsn)))); + + const res = await fetch(`${url}/envelope`, { + method: 'POST', + body, + headers: { 'content-encoding': encoding }, + }); + await extension.drainPendingUploads(Date.now() + SHUTDOWN_BUDGET_MS); + + expect(res.status).toBe(200); + expect(upstream.received).toHaveLength(1); + }, + ); + + test.each([REALISTIC_GZIPPED_BYTES, REALISTIC_GZIPPED_BYTES * 10])( + 'forwards a gzipped envelope of %i bytes, the size at which the SDK actually compresses', + async size => { + // `makeNodeTransport` only gzips past 32KiB, so every envelope that arrives compressed is + // larger than any bound small enough to protect the sandbox. Inflating the whole body to read + // one line therefore fails on exactly the envelopes this path exists for. + const upstream = await startUpstream(); + vi.stubEnv('SENTRY_DSN', upstream.dsn); + const extension = new AwsLambdaExtension(); + const url = await startTunnel(extension); + const envelope = `{"dsn":"${upstream.dsn}"}\n{"type":"event"}\n${'x'.repeat(size)}\n`; + const body = new Uint8Array(await promisify(gzip)(Buffer.from(envelope))); + + const res = await fetch(`${url}/envelope`, { + method: 'POST', + body, + headers: { 'content-encoding': 'gzip' }, + }); + await extension.drainPendingUploads(Date.now() + SHUTDOWN_BUDGET_MS); + + expect(res.status).toBe(200); + expect(upstream.received).toHaveLength(1); + expect(upstream.encodings).toEqual(['gzip']); + }, + ); + + test('refuses to inflate a body far past the envelope header, rather than exhausting the sandbox', async () => { + // The extension shares the function's memory limit, so an unbounded inflate is an OOM the + // platform reports as `Extension.Crash` against the invocation in flight. Measured without the + // bound: a 611KiB body expanding 1029:1 drove RSS to 3.1GiB. + const upstream = await startUpstream(); + vi.stubEnv('SENTRY_DSN', upstream.dsn); + const extension = new AwsLambdaExtension(); + const url = await startTunnel(extension); + // The bound applies to the header, which is all this ever inflates — so the body that trips it + // is one with no newline in reach, not one that is merely large. + const bomb = new Uint8Array(await promisify(gzip)(Buffer.alloc(ENVELOPE_HEADER_MAX_BYTES * 64, 0x20))); + + const res = await fetch(`${url}/envelope`, { + method: 'POST', + body: bomb, + headers: { 'content-encoding': 'gzip' }, + }); + + expect(res.status).toBe(500); + expect(upstream.received).toHaveLength(0); + // Silent loss is what this whole change is about, so a dropped envelope has to be visible — + // and it has to be the bound that rejected it, not the parse failing on whatever inflated. + // `objectContaining` earns its exception here: the error is Node's, and only its `code` is + // ours to assert — it proves the bound rejected the body rather than the parse failing later. + expect(errorSpy).toHaveBeenCalledWith( + 'Sentry Lambda extension: an envelope could not be read and was dropped.', + new Error('The envelope header is longer than this extension will inflate to read it'), + ); + }); + + test('stops reporting dropped envelopes long before it stops dropping them', async () => { + // A Sentry outage or a malformed producer must not bill the customer one CloudWatch line per + // envelope for the life of the environment. + const url = await startTunnel(); + const drops = MAX_REPORTED_FAILURES + 5; + + for (let i = 0; i < drops; i++) { + const res = await fetch(`${url}/envelope`, { method: 'POST', body: 'not json\n{}' }); + expect(res.status).toBe(500); + } + + expect(errorSpy).toHaveBeenCalledTimes(MAX_REPORTED_FAILURES); + }); + + test('does not put an unparseable envelope DSN into the log', async () => { + // `makeDsn` reports a bad DSN through an ungated `console.error`, so the header's text reaches + // stderr verbatim — and a newline in it forges a CloudWatch line. + const url = await startTunnel(); + const forged = 'bad\nFORGED LINE\nstill-bad'; + + const res = await fetch(`${url}/envelope`, { + method: 'POST', + body: `{"dsn":"${forged.replace(/\n/g, '\\n')}"}\n{"type":"event"}\n{}`, + }); + + expect(res.status).toBe(403); + expect(await res.json()).toEqual({ error: 'Invalid DSN' }); + expect(errorSpy).not.toHaveBeenCalled(); + }); + + test('rejects an envelope carrying a DSN the extension was not given, and forwards nothing', async () => { + // The allowlist is this tunnel's SSRF protection: it listens on a port inside the customer's + // execution environment, so a DSN it accepts is a host it will make an outbound request to. + const upstream = await startUpstream(); + vi.stubEnv('SENTRY_DSN', upstream.dsn); + const extension = new AwsLambdaExtension(); + const url = await startTunnel(extension); + + const res = await fetch(`${url}/envelope`, { + method: 'POST', + body: envelope('https://attacker@evil.example.com/1'), + }); + await extension.drainPendingUploads(Date.now() + SHUTDOWN_BUDGET_MS); + + expect(res.status).toBe(403); + expect(await res.json()).toEqual({ error: 'DSN not allowed' }); + expect(upstream.received).toHaveLength(0); + }); + + test.each([ + ['a path that is not /envelope', 'GET', '/', undefined, 404, { error: 'Not found' }], + ['a method that is not POST', 'GET', '/envelope', undefined, 404, { error: 'Not found' }], + [ + 'an envelope header with no dsn', + 'POST', + '/envelope', + '{}\n{"type":"event"}', + 400, + { + error: 'Invalid envelope: missing DSN', + }, + ], + // `JSON.parse` succeeds for every JSON literal, so the header can be any of these at runtime + // however it is typed. + [ + 'an envelope header that is a JSON null', + 'POST', + '/envelope', + 'null\n{}', + 400, + { + error: 'Invalid envelope: missing DSN', + }, + ], + [ + 'an envelope header that is a JSON number', + 'POST', + '/envelope', + '123\n{}', + 400, + { + error: 'Invalid envelope: missing DSN', + }, + ], + [ + 'an envelope header that is not JSON', + 'POST', + '/envelope', + 'not json\n{}', + 500, + { + error: 'Error tunneling to Sentry', + }, + ], + [ + 'an envelope carrying an unparseable DSN', + 'POST', + '/envelope', + '{"dsn":"nonsense"}\n{}', + 403, + { + error: 'Invalid DSN', + }, + ], + ])('answers %s with the documented status', async (_label, method, path, body, status, payload) => { + const url = await startTunnel(); + + const res = await fetch(`${url}${path}`, { method, body }); + + expect(res.status).toBe(status); + expect(await res.json()).toEqual(payload); + }); + + test('re-arms the shutdown drain from a request it actually took', async () => { + // `_lastActivityAt` is written by the request handler and read by the drain. A test that sets + // the field itself leaves the only production writer uncovered, and without it the drain + // returns on the bare grace and drops whatever the runtime posts during its SIGTERM window. + const extension = new AwsLambdaExtension(); + const url = await startTunnel(extension); + const startedAt = Date.now(); + + setTimeout(() => void fetch(`${url}/not-an-envelope`).catch(() => undefined), SHUTDOWN_IDLE_GRACE_MS / 2); + await extension.drainPendingUploads(startedAt + SHUTDOWN_BUDGET_MS); + + expect(Date.now() - startedAt).toBeGreaterThan(SHUTDOWN_IDLE_GRACE_MS + 50); + }); + + test('warns rather than errors when SENTRY_DSN is unset, and says so in one argument', async () => { + // Advice, not a failure: an alarm filtering on ERROR must not fire, and a second argument + // would be rendered into the line as a trailing `undefined`. + await startTunnel(); + + expect(warnSpy).toHaveBeenCalledWith( + 'Sentry Lambda extension: SENTRY_DSN is not set or is invalid. The /envelope tunnel will forward ' + + 'any DSN in the envelope header without allowlist validation. Set SENTRY_DSN to the same DSN as ' + + 'your SDK to restrict outbound requests.', + ); + expect(errorSpy).not.toHaveBeenCalled(); + }); + + test('waits for an envelope the tunnel is still forwarding', async () => { + // An upload in flight when the environment is torn down is simply lost, so the drain has to + // outlast it rather than return the moment the tunnel has answered the SDK. + let upstreamRespondedAt = 0; + const upstreamPort = await listen( + track( + http.createServer((_req, res) => { + setTimeout(() => { + upstreamRespondedAt = Date.now(); + res.writeHead(200, { 'Content-Type': 'application/json' }); + res.end('{}'); + }, UPSTREAM_HOLD_MS); + }), + ), + '127.0.0.1', + ); + const dsn = `http://public@127.0.0.1:${upstreamPort}/1`; + vi.stubEnv('SENTRY_DSN', dsn); + + const extension = new AwsLambdaExtension(); + const tunnel = track(extension.startSentryTunnel(0)); + await new Promise(resolve => tunnel.once('listening', resolve)); + const tunnelPort = (tunnel.address() as AddressInfo).port; + + const tunnelled = await fetch(`http://127.0.0.1:${tunnelPort}/envelope`, { + method: 'POST', + body: `{"dsn":"${dsn}"}\n{"type":"event"}\n{}`, + }); + expect(tunnelled.status).toBe(200); + + await extension.drainPendingUploads(Date.now() + SHUTDOWN_BUDGET_MS); + + // Read at the instant the drain returned: still zero means it walked away from the upload. + expect(upstreamRespondedAt).toBeGreaterThan(0); + }); + + test('reports a tunnel that cannot listen instead of ending the process', async () => { + // The extension is already registered by this point, and a process that ends outside the + // shutdown phase is reported as `Extension.Crash` against the invocation in flight — failing + // the customer's request over a tunnel only this SDK would have used. + // Bound the way the tunnel binds — every interface — so the port really is taken from it. + const takenPort = await listen(track(http.createServer())); + const exitSpy = spyOnExit(); + + const tunnel = track(new AwsLambdaExtension().startSentryTunnel(takenPort)); + const listenError = await new Promise(resolve => tunnel.once('error', resolve)); + + expect(exitSpy).not.toHaveBeenCalled(); + expect(errorSpy).toHaveBeenCalledWith( + 'Sentry Lambda extension: the envelope tunnel could not listen.', + listenError, + ); + }); +}); + +/** + * Long enough for a collapsed deadline to fire — the slowest measured took about 10ms — and + * short enough that the test costs roughly the round trip it already pays for. + */