diff --git a/dev-packages/node-integration-tests/suites/public-api/captureException/catched-error/test.ts b/dev-packages/node-integration-tests/suites/public-api/captureException/catched-error/test.ts index 6d04fee01291..1ea1bf3b8569 100644 --- a/dev-packages/node-integration-tests/suites/public-api/captureException/catched-error/test.ts +++ b/dev-packages/node-integration-tests/suites/public-api/captureException/catched-error/test.ts @@ -30,7 +30,7 @@ test('should work inside catch block', done => { '', 'try {', ], - post_context: ['} catch (err) {', ' Sentry.captureException(err);', '}', ''], + post_context: ['} catch (err) {', ' Sentry.captureException(err);', '}'], }), ]), }, diff --git a/packages/node/src/integrations/contextlines.ts b/packages/node/src/integrations/contextlines.ts index 204385144075..dd654fb3a153 100644 --- a/packages/node/src/integrations/contextlines.ts +++ b/packages/node/src/integrations/contextlines.ts @@ -1,22 +1,16 @@ -import { promises } from 'node:fs'; +import { createReadStream } from 'node:fs'; +import { createInterface } from 'node:readline'; import { defineIntegration } from '@sentry/core'; import type { Event, IntegrationFn, StackFrame } from '@sentry/types'; -import { LRUMap, addContextToFrame } from '@sentry/utils'; +import { LRUMap, logger, snipLine } from '@sentry/utils'; -const FILE_CONTENT_CACHE = new LRUMap(100); +import { DEBUG_BUILD } from '../debug-build'; + +const LRU_FILE_CONTENTS_CACHE = new LRUMap>(10); +const LRU_FILE_CONTENTS_FS_READ_FAILED = new LRUMap(20); const DEFAULT_LINES_OF_CONTEXT = 7; const INTEGRATION_NAME = 'ContextLines'; -const readFileAsync = promises.readFile; - -/** - * Resets the file cache. Exists for testing purposes. - * @hidden - */ -export function resetFileContentCache(): void { - FILE_CONTENT_CACHE.clear(); -} - interface ContextLinesOptions { /** * Sets the number of context lines for each frame when loading a file. @@ -27,121 +21,373 @@ interface ContextLinesOptions { frameContextLines?: number; } -/** Exported only for tests, as a type-safe variant. */ -export const _contextLinesIntegration = ((options: ContextLinesOptions = {}) => { - const contextLines = options.frameContextLines !== undefined ? options.frameContextLines : DEFAULT_LINES_OF_CONTEXT; +/** + * Exported for testing purposes. + */ +export function resetFileContentCache(): void { + LRU_FILE_CONTENTS_CACHE.clear(); +} - return { - name: INTEGRATION_NAME, - processEvent(event) { - return addSourceContext(event, contextLines); - }, - }; -}) satisfies IntegrationFn; +/** + * Get or init map value + */ +function emplace, K extends string, V>(map: T, key: K, contents: V): V { + const value = map.get(key); + + if (value === undefined) { + map.set(key, contents); + return contents; + } + + return value; +} /** - * Capture the lines before and after the frame's context. + * Determines if context lines should be skipped for a file. + * - .min.(mjs|cjs|js) files are and not useful since they dont point to the original source + * - node: prefixed modules are part of the runtime and cannot be resolved to a file + * - data: skip json, wasm and inline js https://nodejs.org/api/esm.html#data-imports */ -export const contextLinesIntegration = defineIntegration(_contextLinesIntegration); +function shouldSkipContextLinesForFile(path: string): boolean { + // Test the most common prefix and extension first. These are the ones we + // are most likely to see in user applications and are the ones we can break out of first. + if (path.startsWith('node:')) return true; + if (path.endsWith('.min.js')) return true; + if (path.endsWith('.min.cjs')) return true; + if (path.endsWith('.min.mjs')) return true; + if (path.startsWith('data:')) return true; + return false; +} +/** + * Checks if we have all the contents that we need in the cache. + */ +function rangeExistsInContentCache(file: string, range: ReadlineRange): boolean { + const contents = LRU_FILE_CONTENTS_CACHE.get(file); + if (contents === undefined) return false; + + for (let i = range[0]; i <= range[1]; i++) { + if (contents[i] === undefined) { + return false; + } + } + + return true; +} + +/** + * Creates contiguous ranges of lines to read from a file. In the case where context lines overlap, + * the ranges are merged to create a single range. + */ +function makeLineReaderRanges(lines: number[], linecontext: number): ReadlineRange[] { + if (!lines.length) { + return []; + } + + let i = 0; + const line = lines[0]; + + if (typeof line !== 'number') { + return []; + } + + let current = makeContextRange(line, linecontext); + const out: ReadlineRange[] = []; + // eslint-disable-next-line no-constant-condition + while (true) { + if (i === lines.length - 1) { + out.push(current); + break; + } + + // If the next line falls into the current range, extend the current range to lineno + linecontext. + const next = lines[i + 1]; + if (typeof next !== 'number') { + break; + } + if (next <= current[1]) { + current[1] = next + linecontext; + } else { + out.push(current); + current = makeContextRange(next, linecontext); + } + + i++; + } + + return out; +} +/** + * Extracts lines from a file and stores them in a cache. + */ +function getContextLinesFromFile(path: string, ranges: ReadlineRange[], output: Record): Promise { + return new Promise((resolve, _reject) => { + // It is important *not* to have any async code between createInterface and the 'line' event listener + // as it will cause the 'line' event to + // be emitted before the listener is attached. + const stream = createReadStream(path); + const lineReaded = createInterface({ + input: stream, + }); + + // Init at zero and increment at the start of the loop because lines are 1 indexed. + let lineNumber = 0; + let currentRangeIndex = 0; + const range = ranges[currentRangeIndex]; + if (range === undefined) { + // We should never reach this point, but if we do, we should resolve the promise to prevent it from hanging. + resolve(); + return; + } + let rangeStart = range[0]; + let rangeEnd = range[1]; + + // We use this inside Promise.all, so we need to resolve the promise even if there is an error + // to prevent Promise.all from short circuiting the rest. + function onStreamError(e: Error): void { + // Mark file path as failed to read and prevent multiple read attempts. + LRU_FILE_CONTENTS_FS_READ_FAILED.set(path, 1); + DEBUG_BUILD && logger.error(`Failed to read file: ${path}. Error: ${e}`); + lineReaded.close(); + lineReaded.removeAllListeners(); + resolve(); + } + + // We need to handle the error event to prevent the process from crashing in < Node 16 + // https://github.com/nodejs/node/pull/31603 + stream.on('error', onStreamError); + lineReaded.on('error', onStreamError); + lineReaded.on('close', resolve); + + lineReaded.on('line', line => { + lineNumber++; + if (lineNumber < rangeStart) return; + + // !Warning: This mutates the cache by storing the snipped line into the cache. + output[lineNumber] = snipLine(line, 0); + + if (lineNumber >= rangeEnd) { + if (currentRangeIndex === ranges.length - 1) { + // We need to close the file stream and remove listeners, else the reader will continue to run our listener; + lineReaded.close(); + lineReaded.removeAllListeners(); + return; + } + currentRangeIndex++; + const range = ranges[currentRangeIndex]; + if (range === undefined) { + // This should never happen as it means we have a bug in the context. + lineReaded.close(); + lineReaded.removeAllListeners(); + return; + } + rangeStart = range[0]; + rangeEnd = range[1]; + } + }); + }); +} + +/** + * Adds surrounding (context) lines of the line that an exception occurred on to the event. + * This is done by reading the file line by line and extracting the lines. The extracted lines are stored in + * a cache to prevent multiple reads of the same file. Failures to read a file are similarly cached to prevent multiple + * failing reads from happening. + */ +/* eslint-disable complexity */ async function addSourceContext(event: Event, contextLines: number): Promise { // keep a lookup map of which files we've already enqueued to read, // so we don't enqueue the same file multiple times which would cause multiple i/o reads - const enqueuedReadSourceFileTasks: Record = {}; - const readSourceFileTasks: Promise[] = []; + const filesToLines: Record = {}; if (contextLines > 0 && event.exception?.values) { for (const exception of event.exception.values) { - if (!exception.stacktrace?.frames) { + if (!exception.stacktrace?.frames?.length) { continue; } - // We want to iterate in reverse order as calling cache.get will bump the file in our LRU cache. - // This ends up prioritizes source context for frames at the top of the stack instead of the bottom. + // Maps preserve insertion order, so we iterate in reverse, starting at the + // outermost frame and closer to where the exception has occurred (poor mans priority) for (let i = exception.stacktrace.frames.length - 1; i >= 0; i--) { - // eslint-disable-next-line @typescript-eslint/no-non-null-assertion - const frame = exception.stacktrace.frames[i]!; - // Call cache.get to bump the file to the top of the cache and ensure we have not already - // enqueued a read operation for this filename - if (frame.filename && !enqueuedReadSourceFileTasks[frame.filename] && !FILE_CONTENT_CACHE.get(frame.filename)) { - readSourceFileTasks.push(_readSourceFile(frame.filename)); - enqueuedReadSourceFileTasks[frame.filename] = 1; + const frame: StackFrame | undefined = exception.stacktrace.frames[i]; + const filename = frame?.filename; + + if ( + !frame || + typeof filename !== 'string' || + typeof frame.lineno !== 'number' || + shouldSkipContextLinesForFile(filename) + ) { + continue; } + + const filesToLinesOutput = filesToLines[filename]; + if (!filesToLinesOutput) filesToLines[filename] = []; + // @ts-expect-error this is defined above + filesToLines[filename].push(frame.lineno); } } } - // check if files to read > 0, if so, await all of them to be read before adding source contexts. - // Normally, Promise.all here could be short circuited if one of the promises rejects, but we - // are guarding from that by wrapping the i/o read operation in a try/catch. - if (readSourceFileTasks.length > 0) { - await Promise.all(readSourceFileTasks); + const files = Object.keys(filesToLines); + if (files.length == 0) { + return event; + } + + const readlinePromises: Promise[] = []; + for (const file of files) { + // If we failed to read this before, dont try reading it again. + if (LRU_FILE_CONTENTS_FS_READ_FAILED.get(file)) { + continue; + } + + const filesToLineRanges = filesToLines[file]; + if (!filesToLineRanges) { + continue; + } + + // Sort ranges so that they are sorted by line increasing order and match how the file is read. + filesToLineRanges.sort((a, b) => a - b); + // Check if the contents are already in the cache and if we can avoid reading the file again. + const ranges = makeLineReaderRanges(filesToLineRanges, contextLines); + if (ranges.every(r => rangeExistsInContentCache(file, r))) { + continue; + } + + const cache = emplace(LRU_FILE_CONTENTS_CACHE, file, {}); + readlinePromises.push(getContextLinesFromFile(file, ranges, cache)); } + // The promise rejections are caught in order to prevent them from short circuiting Promise.all + await Promise.all(readlinePromises).catch(() => { + DEBUG_BUILD && logger.log('Failed to read one or more source files and resolve context lines'); + }); + // Perform the same loop as above, but this time we can assume all files are in the cache // and attempt to add source context to frames. if (contextLines > 0 && event.exception?.values) { for (const exception of event.exception.values) { - if (exception.stacktrace && exception.stacktrace.frames) { - await addSourceContextToFrames(exception.stacktrace.frames, contextLines); + if (exception.stacktrace && exception.stacktrace.frames && exception.stacktrace.frames.length > 0) { + addSourceContextToFrames(exception.stacktrace.frames, contextLines, LRU_FILE_CONTENTS_CACHE); } } } return event; } +/* eslint-enable complexity */ /** Adds context lines to frames */ -function addSourceContextToFrames(frames: StackFrame[], contextLines: number): void { +function addSourceContextToFrames( + frames: StackFrame[], + contextLines: number, + cache: LRUMap>, +): void { for (const frame of frames) { // Only add context if we have a filename and it hasn't already been added - if (frame.filename && frame.context_line === undefined) { - const sourceFileLines = FILE_CONTENT_CACHE.get(frame.filename); - - if (sourceFileLines) { - try { - addContextToFrame(sourceFileLines, frame, contextLines); - } catch (e) { - // anomaly, being defensive in case - // unlikely to ever happen in practice but can definitely happen in theory - } + if (frame.filename && frame.context_line === undefined && typeof frame.lineno === 'number') { + const contents = cache.get(frame.filename); + if (contents === undefined) { + continue; } + + addContextToFrame(frame.lineno, frame, contextLines, contents); } } } /** - * Reads file contents and caches them in a global LRU cache. - * If reading fails, mark the file as null in the cache so we don't try again. - * - * @param filename filepath to read content from. + * Clears the context lines from a frame, used to reset a frame to its original state + * if we fail to resolve all context lines for it. + */ +function clearLineContext(frame: StackFrame): void { + delete frame.pre_context; + delete frame.context_line; + delete frame.post_context; +} + +/** + * Resolves context lines before and after the given line number and appends them to the frame; */ -async function _readSourceFile(filename: string): Promise { - const cachedFile = FILE_CONTENT_CACHE.get(filename); +export function addContextToFrame( + lineno: number, + frame: StackFrame, + contextLines: number, + contents: Record | undefined, +): void { + // When there is no line number in the frame, attaching context is nonsensical and will even break grouping. + // We already check for lineno before calling this, but since StackFrame lineno ism optional, we check it again. + if (frame.lineno === undefined || contents === undefined) { + DEBUG_BUILD && logger.error('Cannot resolve context for frame with no lineno or file contents'); + return; + } - // We have already attempted to read this file and failed, do not try again - if (cachedFile === null) { - return null; + frame.pre_context = []; + for (let i = makeRangeStart(lineno, contextLines); i < lineno; i++) { + // We always expect the start context as line numbers cannot be negative. If we dont find a line, then + // something went wrong somewhere. Clear the context and return without adding any linecontext. + const line = contents[i]; + if (line === undefined) { + clearLineContext(frame); + DEBUG_BUILD && logger.error(`Could not find line ${i} in file ${frame.filename}`); + return; + } + + frame.pre_context.push(line); } - // We have a cache hit, return it - if (cachedFile !== undefined) { - return cachedFile; + // We should always have the context line. If we dont, something went wrong, so we clear the context and return + // without adding any linecontext. + if (contents[lineno] === undefined) { + clearLineContext(frame); + DEBUG_BUILD && logger.error(`Could not find line ${lineno} in file ${frame.filename}`); + return; } - // Guard from throwing if readFile fails, this enables us to use Promise.all and - // not have it short circuiting if one of the promises rejects + since context lines are added - // on a best effort basis, we want to throw here anyways. - - // If we made it to here, it means that our file is not cache nor marked as failed, so attempt to read it - let content: string[] | null = null; - try { - const rawFileContents = await readFileAsync(filename, 'utf-8'); - content = rawFileContents.split('\n'); - } catch (_) { - // if we fail, we will mark the file as null in the cache and short circuit next time we try to read it + frame.context_line = contents[lineno]; + + const end = makeRangeEnd(lineno, contextLines); + frame.post_context = []; + for (let i = lineno + 1; i <= end; i++) { + // Since we dont track when the file ends, we cant clear the context if we dont find a line as it could + // just be that we reached the end of the file. + const line = contents[i]; + if (line === undefined) { + break; + } + frame.post_context.push(line); } +} - FILE_CONTENT_CACHE.set(filename, content); - return content; +// Helper functions for generating line context ranges. They take a line number and the number of lines of context to +// include before and after the line and generate an inclusive range of indices. +type ReadlineRange = [start: number, end: number]; +// Compute inclusive end context range +function makeRangeStart(line: number, linecontext: number): number { + return Math.max(1, line - linecontext); +} +// Compute inclusive start context range +function makeRangeEnd(line: number, linecontext: number): number { + return line + linecontext; +} +// Determine start and end indices for context range (inclusive); +function makeContextRange(line: number, linecontext: number): [start: number, end: number] { + return [makeRangeStart(line, linecontext), makeRangeEnd(line, linecontext)]; } + +/** Exported only for tests, as a type-safe variant. */ +export const _contextLinesIntegration = ((options: ContextLinesOptions = {}) => { + const contextLines = options.frameContextLines !== undefined ? options.frameContextLines : DEFAULT_LINES_OF_CONTEXT; + + return { + name: INTEGRATION_NAME, + processEvent(event) { + return addSourceContext(event, contextLines); + }, + }; +}) satisfies IntegrationFn; + +/** + * Capture the lines before and after the frame's context. + */ +export const contextLinesIntegration = defineIntegration(_contextLinesIntegration); diff --git a/packages/node/test/integrations/contextlines.test.ts b/packages/node/test/integrations/contextlines.test.ts index 3c6394f9ac52..14c2992eecad 100644 --- a/packages/node/test/integrations/contextlines.test.ts +++ b/packages/node/test/integrations/contextlines.test.ts @@ -1,4 +1,4 @@ -import { promises } from 'node:fs'; +import * as fs from 'node:fs'; import type { StackFrame } from '@sentry/types'; import { parseStackFrames } from '@sentry/utils'; @@ -6,19 +6,7 @@ import { _contextLinesIntegration, resetFileContentCache } from '../../src/integ import { defaultStackParser } from '../../src/sdk/api'; import { getError } from '../helpers/error'; -jest.mock('node:fs', () => { - const actual = jest.requireActual('node:fs'); - return { - ...actual, - promises: { - ...actual.promises, - readFile: jest.fn(actual.promises), - }, - }; -}); - describe('ContextLines', () => { - const readFileSpy = promises.readFile as unknown as jest.SpyInstance; let contextLines: ReturnType; async function addContext(frames: StackFrame[]): Promise { @@ -35,24 +23,44 @@ describe('ContextLines', () => { }); describe('lru file cache', () => { + test('parseStack when file does not exist', async () => { + expect.assertions(4); + const frames: StackFrame[] = [ + { + colno: 1, + filename: 'file:///var/task/nonexistent.js', + lineno: 1, + function: 'fxn1', + }, + ]; + + const readStreamSpy = jest.spyOn(fs, 'createReadStream'); + await addContext(frames); + + expect(frames[0]!.pre_context).toBeUndefined(); + expect(frames[0]!.post_context).toBeUndefined(); + expect(frames[0]!.context_line).toBeUndefined(); + expect(readStreamSpy).toHaveBeenCalledTimes(1); + }); test('parseStack with same file', async () => { expect.assertions(1); const frames = parseStackFrames(defaultStackParser, new Error('test')); + const readStreamSpy = jest.spyOn(fs, 'createReadStream'); - await addContext(Array.from(frames)); - - const numCalls = readFileSpy.mock.calls.length; + await addContext(frames); + const numCalls = readStreamSpy.mock.calls.length; await addContext(frames); // Calls to `readFile` shouldn't increase if there isn't a new error to // parse whose stacktrace contains a file we haven't yet seen - expect(readFileSpy).toHaveBeenCalledTimes(numCalls); + expect(readStreamSpy).toHaveBeenCalledTimes(numCalls); }); test('parseStack with ESM module names', async () => { expect.assertions(1); + const readStreamSpy = jest.spyOn(fs, 'createReadStream'); const framesWithFilePath: StackFrame[] = [ { colno: 1, @@ -63,25 +71,67 @@ describe('ContextLines', () => { ]; await addContext(framesWithFilePath); - expect(readFileSpy).toHaveBeenCalledTimes(1); + expect(readStreamSpy).toHaveBeenCalledTimes(1); }); test('parseStack with adding different file', async () => { expect.assertions(1); const frames = parseStackFrames(defaultStackParser, new Error('test')); + const readStreamSpy = jest.spyOn(fs, 'createReadStream'); await addContext(frames); - const numCalls = readFileSpy.mock.calls.length; + const numCalls = readStreamSpy.mock.calls.length; const parsedFrames = parseStackFrames(defaultStackParser, getError()); await addContext(parsedFrames); - const newErrorCalls = readFileSpy.mock.calls.length; + const newErrorCalls = readStreamSpy.mock.calls.length; expect(newErrorCalls).toBeGreaterThan(numCalls); }); + test('parseStack with overlapping errors', async () => { + function inner() { + return new Error('inner'); + } + function outer() { + return inner(); + } + + const overlappingContextWithFirstError = parseStackFrames(defaultStackParser, outer()); + + await addContext(overlappingContextWithFirstError); + + const innerFrame = overlappingContextWithFirstError[overlappingContextWithFirstError.length - 1]!; + const outerFrame = overlappingContextWithFirstError[overlappingContextWithFirstError.length - 2]!; + + expect(innerFrame.context_line).toBe(" return new Error('inner');"); + expect(innerFrame.pre_context).toHaveLength(7); + expect(innerFrame.post_context).toHaveLength(7); + + expect(outerFrame.context_line).toBe(' return inner();'); + expect(outerFrame.pre_context).toHaveLength(7); + expect(outerFrame.post_context).toHaveLength(7); + }); + + test('parseStack with error on first line errors', async () => { + const overlappingContextWithFirstError = parseStackFrames(defaultStackParser, getError()); + + await addContext(overlappingContextWithFirstError); + + const errorFrame = overlappingContextWithFirstError.find(f => f.filename?.endsWith('error.ts')); + + if (!errorFrame) { + throw new Error('Could not find error frame'); + } + + expect(errorFrame.context_line).toBe(" return new Error('mock error');"); + expect(errorFrame.pre_context).toHaveLength(2); + expect(errorFrame.post_context).toHaveLength(1); + }); + test('parseStack with duplicate files', async () => { expect.assertions(1); + const readStreamSpy = jest.spyOn(fs, 'createReadStream'); const framesWithDuplicateFiles: StackFrame[] = [ { colno: 1, @@ -104,44 +154,34 @@ describe('ContextLines', () => { ]; await addContext(framesWithDuplicateFiles); - expect(readFileSpy).toHaveBeenCalledTimes(1); + expect(readStreamSpy).toHaveBeenCalledTimes(1); + }); + + test('stack errors without lineno', async () => { + expect.assertions(1); + const readStreamSpy = jest.spyOn(fs, 'createReadStream'); + const framesWithDuplicateFiles: StackFrame[] = [ + { + colno: 1, + filename: '/var/task/index.js', + lineno: undefined, + function: 'fxn1', + }, + ]; + + await addContext(framesWithDuplicateFiles); + expect(readStreamSpy).not.toHaveBeenCalled(); }); test('parseStack with no context', async () => { + expect.assertions(1); contextLines = _contextLinesIntegration({ frameContextLines: 0 }); + const readStreamSpy = jest.spyOn(fs, 'createReadStream'); - expect.assertions(1); const frames = parseStackFrames(defaultStackParser, new Error('test')); await addContext(frames); - expect(readFileSpy).toHaveBeenCalledTimes(0); + expect(readStreamSpy).not.toHaveBeenCalled(); }); }); - - test('does not attempt to readfile multiple times if it fails', async () => { - expect.assertions(1); - - readFileSpy.mockImplementation(() => { - throw new Error("ENOENT: no such file or directory, open '/does/not/exist.js'"); - }); - - await addContext([ - { - colno: 1, - filename: '/does/not/exist.js', - lineno: 1, - function: 'fxn1', - }, - ]); - await addContext([ - { - colno: 1, - filename: '/does/not/exist.js', - lineno: 1, - function: 'fxn1', - }, - ]); - - expect(readFileSpy).toHaveBeenCalledTimes(1); - }); });