diff --git a/doc/api/debugger.md b/doc/api/debugger.md index 5eeffd43e57f5f..31da549458a476 100644 --- a/doc/api/debugger.md +++ b/doc/api/debugger.md @@ -236,6 +236,10 @@ debug> added: - v26.1.0 changes: + - version: REPLACEME + pr-url: https://github.com/nodejs/node/pull/63437 + description: Add `probe_failure` terminal `error` event for inspector-side mid-session + failures, and `error.details` for additional context on per-hit and terminal errors. - version: v26.2.0 pr-url: https://github.com/nodejs/node/pull/63286 description: JSON report schema bumped to v2. Probe `target` is now @@ -382,7 +386,10 @@ $ node inspect --json --probe cli.js:5 --expr 'rss' cli.js "value": 55443456, "description": "55443456" } - // If the expression throws, "error" is present instead of "result". + // If the probe expression throws, fails, or never completes, the entry + // carries an `error` field instead of `result` with the shape + // `{ message: string, details?: object }`. The `message` and `details` + // content is informational only and may change between releases. }, { "probe": 0, @@ -414,24 +421,40 @@ $ node inspect --json --probe cli.js:5 --expr 'rss' cli.js // "error": { // "code": "probe_target_exit", // "exitCode": 1, - // "stderr": "[Error: boom]", + // "stderr": "Error: boom", // "message": "Target exited with code 1 before probes: app.js:10" // } // } + // 5. { + // "event": "error", + // "pending": [1], + // "error": { + // "code": "probe_failure", + // "probe": 0, + // "stderr": "...", + // "message": "Target process exited during probe evaluation before probes: app.js:12. If the failure repeats, review the probe expression.", + // "details": { "lastCdpMethod": "Debugger.evaluateOnCallFrame" } + // } + // } } ] } ``` -### Output and exit codes from the probed process +### Output and exit codes Probe mode only prints the final probe report to stdout, and otherwise silences stdout/stderr from the child process. When the probing session ends, -`node inspect` typically exits with code `0` and prints a final report to -stdout. If the child process exits with a non-zero code before the -probe session ends, the final report records a terminal `error` event along -with the exit code and captured child stderr. The probing process itself -still exits with code `0` in this case. +the probing process typically exits with code `0` and prints a final report to +stdout. If the child process exits with a non-zero code before the probe +session ends, or the probe session cannot complete for another reason, the +final report records a terminal `error` event. + +When `error.code` is `'probe_failure'` or `'probe_timeout'`, the probing process +exits with a non-zero code, indicating recorded hits may be incomplete. +In this case, `error.message` will contain recovery hints, and `error.probe`, +when present, is an index into the report's `probes` array that identifies +the possible culprit probe on a best-effort basis to help guide debugging. Invalid arguments and fatal launch or connect failures may cause the probing process to exit with a non-zero code and print an error message diff --git a/lib/internal/debugger/inspect_probe.js b/lib/internal/debugger/inspect_probe.js index 4600d8eb10ee3b..14f7413fea8ef1 100644 --- a/lib/internal/debugger/inspect_probe.js +++ b/lib/internal/debugger/inspect_probe.js @@ -12,7 +12,7 @@ const { NumberIsNaN, NumberParseInt, ObjectEntries, - Promise, + PromiseWithResolvers, RegExpPrototypeExec, RegExpPrototypeSymbolSplit, SafeMap, @@ -20,6 +20,7 @@ const { StringPrototypeIncludes, StringPrototypeSlice, StringPrototypeStartsWith, + Symbol, } = primordials; const { clearTimeout, setTimeout } = require('timers'); @@ -42,6 +43,18 @@ const { const kProbeDefaultTimeout = 30000; const kProbeVersion = 2; const kProbeDisconnectSentinel = 'Waiting for the debugger to disconnect...'; +const kProbeAttachedSentinel = 'Debugger attached.'; +const kProbeListeningPrefix = 'Debugger listening on ws://'; +const kProbeEndingPrefix = 'Debugger ending on ws://'; +const kProbeHelpLine = + 'For help, see: https://nodejs.org/learn/getting-started/debugging'; +// Thrown by `callCdp` after `recordInspectorFailure` has handled the failure, +// so callers can short-circuit without recording duplicate events. +const kInspectorFailedSentinel = Symbol('probe.inspectorFailed'); +const kStartupTeardownAdvice = + 'The target startup may have torn down the inspector. If startup does ' + + 'not touch the inspector, this is likely a Node.js bug. Please file an issue.'; +const kReviewProbeExprAdvice = 'If the failure repeats, review the probe expression.'; const kDigitsRegex = /^\d+$/; const kInspectPortRegex = /^--inspect-port=(\d+)$/; @@ -56,7 +69,7 @@ const kInspectPortRegex = /^--inspect-port=(\d+)$/; /** * Location where the probe was evaluated, serialized into the public report. * @typedef {object} Location - * @property {string} url V8-reported script URL. + * @property {string} [url] V8-reported script URL, if known. * @property {number} line 1-based line number. * @property {number} column 1-based column number. */ @@ -118,17 +131,7 @@ function formatPendingProbeLocations(probes, pending) { return ArrayPrototypeJoin(ArrayFrom(seen), ', '); } -function formatTargetExitMessage(probes, pending, exitCode, signal) { - const status = signal === null ? - `Target exited with code ${exitCode}` : - `Target exited with signal ${signal}`; - if (pending.length === 0) { - return `${status} before target completion`; - } - return `${status} before probes: ${formatPendingProbeLocations(probes, pending)}`; -} - -// Trim the "Waiting for the debugger to disconnect..." message from stderr for reporting child errors. +// Trim inspector-side noise lines from stderr for reporting child errors. function trimProbeChildStderr(stderr) { const lines = RegExpPrototypeSymbolSplit(/\r\n|\r|\n/g, stderr); const kept = []; @@ -136,6 +139,10 @@ function trimProbeChildStderr(stderr) { const line = lines[i]; if (line === '' && i === lines.length - 1) { continue; } if (line === kProbeDisconnectSentinel) { continue; } + if (line === kProbeAttachedSentinel) { continue; } + if (line === kProbeHelpLine) { continue; } + if (StringPrototypeStartsWith(line, kProbeListeningPrefix)) { continue; } + if (StringPrototypeStartsWith(line, kProbeEndingPrefix)) { continue; } ArrayPrototypePush(kept, line); } return ArrayPrototypeJoin(kept, '\n'); @@ -251,9 +258,7 @@ function buildProbeTextReport(report) { formatHitLocation(result.location) : formatTargetText(probe.target); ArrayPrototypePush(lines, `Hit ${result.hit} at ${locText}`); if (result.error !== undefined) { - ArrayPrototypePush(lines, - ` [error] ${probe.expr} = ` + - `${formatRemoteObject(result.error)}`); + ArrayPrototypePush(lines, ` [error] ${probe.expr} = ${result.error.message}`); } else { ArrayPrototypePush(lines, ` ${probe.expr} = ` + @@ -428,18 +433,29 @@ class ProbeInspectorSession { this.childStderr = ''; this.disconnectRequested = false; this.finished = false; + // True once the inspector WebSocket connects. Event handlers ignore + // pre-connect exits/closes so launch/connect failures report through run(). + this.connected = false; + // True once breakpoints are bound and the target is released from --inspect-brk + // via `Runtime.runIfWaitingForDebugger`. + // Distinguishes "exited before user code ran" from "exited during the live session". this.started = false; - this.stderrBuffer = ''; + // A sliding buffer of at most kProbeDisconnectSentinel.length to detect disconnect. + this.disconnectSentinelBuffer = ''; /** @type {Map} keyed by V8 breakpointId. */ this.breakpointDefinitions = new SafeMap(); /** @type {Map} scriptId -> URL. */ this.scriptIdToUrl = new SafeMap(); this.results = []; this.timeout = null; - this.resolveCompletion = null; - this.completionPromise = new Promise((resolve) => { - this.resolveCompletion = resolve; - }); + // The currently-awaited CDP request, or null when no request is in flight. + /** @type {{ method: string, probe: { index: number, location: Location } | null } | null} */ + this.inFlight = null; + // Most recently completed probe, used for `error.probe` when a non-evaluate CDP call rejects. + this.lastProbeIndex = null; + const { promise, resolve } = PromiseWithResolvers(); + this.completionPromise = promise; + this.resolveCompletion = resolve; /** @type {Probe[]} */ this.probes = ArrayPrototypeMap(options.probes, ({ expr, target }) => ({ expr, target, hits: 0 })); this.onChildOutput = FunctionPrototypeBind(this.onChildOutput, this); @@ -449,81 +465,129 @@ class ProbeInspectorSession { this.onScriptParsed = FunctionPrototypeBind(this.onScriptParsed, this); } - finish(state) { + // Marking the probing process to exit with 0, recorded hits are trustworthy. + finishWithTrustedResult(terminal) { + this.finish(kNoFailure, terminal); + } + + // Marking the probing process to exit with 1, recorded hits are best-effort. + finishWithUnreliableResult(terminal) { + this.finish(kGenericUserError, terminal); + } + + finish(exitCode, terminal) { if (this.finished) { return; } this.finished = true; if (this.timeout !== null) { clearTimeout(this.timeout); this.timeout = null; } - this.resolveCompletion(state); + this.resolveCompletion({ exitCode, terminal }); + } + + getProbeTargetExitEvent(exitCode, signal) { + const pending = this.getPendingProbeIndices(); + const how = signal !== null ? `with signal ${signal}` : `with code ${exitCode}`; + const status = pending.length === 0 ? + 'target completion' : `probes: ${formatPendingProbeLocations(this.probes, pending)}`; + const error = { + __proto__: null, + code: 'probe_target_exit', + message: `Target exited ${how} before ${status}`, + }; + if (exitCode !== null) { error.exitCode = exitCode; } + if (signal !== null) { error.signal = signal; } + error.stderr = trimProbeChildStderr(this.childStderr); + return { event: 'error', pending, error }; } onChildOutput(text, which) { if (which !== 'stderr') { return; } - if (this.started) { - this.childStderr += text; - } + this.childStderr += text; - const combined = this.stderrBuffer + text; - if (this.started && + const combined = this.disconnectSentinelBuffer + text; + // Detect the disconnect sentinel. + if (this.connected && StringPrototypeIncludes(combined, kProbeDisconnectSentinel)) { this.disconnectRequested = true; this.client.reset(); } - if (combined.length > kProbeDisconnectSentinel.length) { - this.stderrBuffer = StringPrototypeSlice(combined, - combined.length - - kProbeDisconnectSentinel.length); + if (combined.length > kProbeDisconnectSentinel.length) { // Slide the buffer. + this.disconnectSentinelBuffer = StringPrototypeSlice(combined, + combined.length - kProbeDisconnectSentinel.length); } else { - this.stderrBuffer = combined; + this.disconnectSentinelBuffer = combined; } } onChildExit(code, signal) { - if (this.started) { - if (code !== 0 || signal !== null) { - this.finish({ - __proto__: null, - event: 'error', - exitCode: code, - signal, - stderr: trimProbeChildStderr(this.childStderr), - }); - } else { - this.finish('complete'); - } + // Pre-connect exits are deliberately silent: the target never reached + // a state where probes could be set, so any report would be empty. + if (!this.connected) { return; } + if (this.finished) { return; } + if (this.inFlight !== null && this.inFlight.probe !== null) { + this.recordInspectorFailure({ + reason: 'Target process exited during probe evaluation', + advice: kReviewProbeExprAdvice, + }); + return; + } + if (this.started && code === 0 && signal === null) { + const pending = this.getPendingProbeIndices(); + this.finishWithTrustedResult(pending.length === 0 ? { event: 'completed' } : { event: 'miss', pending }); + return; } + this.finishWithTrustedResult(this.getProbeTargetExitEvent(code, signal)); } onClientClose() { - if (!this.started || this.child === null) { return; } - - // TODO(joyeecheung): Surface mid-probe inspector disconnects as terminal probe errors - // instead of deferring to timeout or miss classification. + if (!this.connected) { return; } if (this.disconnectRequested) { return; } + if (this.finished) { return; } if (this.child.exitCode !== null || this.child.signalCode !== null) { this.onChildExit(this.child.exitCode, this.child.signalCode); + return; } + if (!this.started) { + this.recordInspectorFailure({ + reason: 'Inspector connection lost before probes started', + advice: kStartupTeardownAdvice, + }); + return; + } + if (this.inFlight !== null) { + if (this.inFlight.probe !== null || this.lastProbeIndex !== null) { + this.recordInspectorFailure({ + reason: 'Inspector connection lost during probe activity', + advice: 'A probe expression may have caused the disconnection. ' + + 'If the failure repeats, review the probe expressions.', + }); + } else { + this.recordInspectorFailure({ + reason: 'Inspector connection lost during inspector activity', + advice: 'This is likely a Node.js bug. Please file an issue.', + }); + } + return; + } + this.recordInspectorFailure({ + reason: 'Inspector connection lost', + advice: 'The target was likely terminated externally. If the failure ' + + 'persists, check the target\'s process environment.', + }); } onPaused(params) { - // TODO(joyeecheung): Preserve evaluation and resume failures as terminal probe errors - // instead of collapsing them into a synthetic completion. this.handlePaused(params).catch((error) => { - if (!this.finished) { - if (error?.code === 'ERR_DEBUGGER_ERROR') { - if (this.child !== null && - (this.child.exitCode !== null || this.child.signalCode !== null)) { - this.onChildExit(this.child.exitCode, this.child.signalCode); - } - return; - } - this.finish('complete'); - } + if (error === kInspectorFailedSentinel) { return; } + this.recordInspectorFailure({ + reason: 'Probe mode encountered an unexpected internal failure', + advice: 'This is likely a Node.js bug. Please file an issue.', + internalError: error, + }); }); } @@ -561,6 +625,7 @@ class ProbeInspectorSession { // Evaluate the expressions in the order they appear on the command line. for (const probeIndex of definition.probeIndices) { await this.evaluateProbe(callFrameId, probeIndex, location); + if (this.finished) { break; } } } @@ -568,35 +633,181 @@ class ProbeInspectorSession { } async evaluateProbe(callFrameId, probeIndex, location) { + if (this.finished) { return; } const probe = this.probes[probeIndex]; - const evaluation = await this.client.callMethod('Debugger.evaluateOnCallFrame', { - callFrameId, - expression: probe.expr, - generatePreview: true, - }); + const evaluation = await this.callCdp( + 'Debugger.evaluateOnCallFrame', + { callFrameId, expression: probe.expr, generatePreview: true }, + { __proto__: null, index: probeIndex, location }, + ); + this.lastProbeIndex = probeIndex; probe.hits++; const result = { probe: probeIndex, event: 'hit', hit: probe.hits, location }; if (evaluation.exceptionDetails !== undefined) { - result.error = evaluation.result === undefined ? { - type: 'object', - subtype: 'error', - description: 'Probe expression failed', - } : trimRemoteObject(evaluation.result); + result.error = { + __proto__: null, + message: evaluation.result?.description ?? 'Probe expression failed', + details: { __proto__: null, exception: trimRemoteObject(evaluation.exceptionDetails) }, + }; } else { result.result = trimRemoteObject(evaluation.result); } - ArrayPrototypePush(this.results, result); } async resume() { if (this.finished) { return; } - await this.client.callMethod('Debugger.resume'); + await this.callCdp('Debugger.resume'); + } + + async callCdp(method, params, probe = null) { + if (this.finished) { throw kInspectorFailedSentinel; } + this.inFlight = { __proto__: null, method, probe }; + try { + const result = await this.client.callMethod(method, params); + // A timeout or process exit can finish the report while the CDP request + // is still outstanding. Ignore the late reply in that case. + if (this.finished) { throw kInspectorFailedSentinel; } + return result; + } catch (err) { + if (this.disconnectRequested) { + // Only the in-flight evaluation gets attribution. Other rejections + // under disconnect are downstream noise. + if (probe !== null) { + this.recordInspectorFailure({ + reason: 'Target process exited during probe evaluation', + advice: kReviewProbeExprAdvice, + }); + } + throw kInspectorFailedSentinel; + } + // Another event handler already recorded the terminal event. + if (this.finished) { throw kInspectorFailedSentinel; } + if (!this.started) { + this.recordInspectorFailure({ + reason: 'Probe mode failed before user code ran', + advice: kStartupTeardownAdvice, + cdpError: err, + }); + } else if (method === 'Debugger.evaluateOnCallFrame') { + this.recordInspectorFailure({ + reason: 'The inspector could not evaluate a probe expression', + advice: `The rejection details are recorded on the probe hit. ${kReviewProbeExprAdvice}`, + cdpError: err, + }); + } else if (this.lastProbeIndex !== null) { + this.recordInspectorFailure({ + reason: 'Probe session failed after a probe evaluation', + advice: 'If the failure repeats, review the most-recently-evaluated probe expression.', + cdpError: err, + }); + } else { + this.recordInspectorFailure({ + reason: 'Probe session failed during inspector activity', + advice: 'This is likely a Node.js bug. Please file an issue.', + cdpError: err, + }); + } + throw kInspectorFailedSentinel; + } finally { + this.inFlight = null; + } + } + + // Records the first inspector-side terminal for the session, later callers are ignored. + recordInspectorFailure({ reason, advice, cdpError, internalError }) { + if (this.finished) { return; } + const child = this.child; + const exitedAbnormally = child !== null && + (child.signalCode !== null || (child.exitCode !== null && child.exitCode !== 0)); + const inFlightProbe = this.inFlight === null ? null : this.inFlight.probe; + // This normally emits `probe_failure`, but yields to `probe_target_exit` when the child + // has already exited abnormally and there is no in-flight probe to attribute to. + if (exitedAbnormally && inFlightProbe === null) { + this.finishWithTrustedResult(this.getProbeTargetExitEvent(child.exitCode, child.signalCode)); + return; + } + + const failedCdpMethod = this.inFlight === null ? null : this.inFlight.method; + let protocolError = null; + // // `ERR_DEBUGGER_ERROR` is a Node-internal code, not a CDP-level protocol code + if (cdpError !== undefined && cdpError.code !== 'ERR_DEBUGGER_ERROR') { + protocolError = { __proto__: null, message: cdpError.message, code: cdpError.code }; + } + const protocolErrorGoesOnHit = (protocolError !== null) && (failedCdpMethod === 'Debugger.evaluateOnCallFrame'); + + let attribution = null; + if (inFlightProbe !== null) { + const { index, location } = inFlightProbe; + const error = { __proto__: null }; + if (protocolErrorGoesOnHit) { + error.message = 'Probe evaluation failed at the protocol layer'; + error.details = { __proto__: null, protocolError }; + } else { + error.message = 'Probe evaluation did not complete'; + } + this.probes[index].hits++; + ArrayPrototypePush(this.results, { + probe: index, event: 'hit', hit: this.probes[index].hits, location, error, + }); + attribution = index; + } else if (failedCdpMethod !== null && this.lastProbeIndex !== null) { + attribution = this.lastProbeIndex; + } + // When there is no in-flight CDP call (e.g. `onClientClose` after all probes hit), ignore + // `lastProbeIndex` since it can't be attributed to a specific probe. + + const pending = this.getPendingProbeIndices(); + const suffix = pending.length === 0 ? + '' : ` before probes: ${formatPendingProbeLocations(this.probes, pending)}`; + const error = { + __proto__: null, + code: 'probe_failure', + message: `${reason}${suffix}. ${advice}`, + }; + if (attribution !== null) { error.probe = attribution; } + error.stderr = trimProbeChildStderr(this.childStderr); + + let details; + if (failedCdpMethod !== null) { + details = { __proto__: null, lastCdpMethod: failedCdpMethod }; + if (protocolError !== null && !protocolErrorGoesOnHit) { details.protocolError = protocolError; } + } + if (internalError !== undefined) { + details ??= { __proto__: null }; + details.internalError = { __proto__: null, message: internalError?.message, stack: internalError?.stack }; + } + if (details !== undefined) { error.details = details; } + + this.finishWithUnreliableResult({ event: 'error', pending, error }); } startTimeout() { - this.timeout = setTimeout(() => { this.finish('timeout'); }, this.options.timeout); + this.timeout = setTimeout(() => { + if (this.finished) { return; } + if (this.inFlight !== null) { + const hasProbeAttribution = + this.inFlight.probe !== null || this.lastProbeIndex !== null; + this.recordInspectorFailure({ + reason: 'Probe session timed out', + advice: hasProbeAttribution ? + ('The probe expression may be slow, hanging, or interfering with the inspector connection. ' + + 'Try increasing `--timeout`; if the failure persists, review the probe expressions.') : + 'Try increasing `--timeout`; if the failure persists, please file an issue.', + }); + return; + } + const pending = this.getPendingProbeIndices(); + const message = `Timed out after ${this.options.timeout}ms waiting for ` + + (pending.length === 0 ? 'target completion' : + `probes: ${formatPendingProbeLocations(this.probes, pending)}`); + this.finishWithUnreliableResult({ + event: 'timeout', + pending, + error: { code: 'probe_timeout', message }, + }); + }, this.options.timeout); this.timeout.unref(); } @@ -649,7 +860,7 @@ class ProbeInspectorSession { params.columnNumber = target.column - 1; } - const result = await this.client.callMethod('Debugger.setBreakpointByUrl', params); + const result = await this.callCdp('Debugger.setBreakpointByUrl', params); this.breakpointDefinitions.set(result.breakpointId, { probeIndices }); } } @@ -664,53 +875,17 @@ class ProbeInspectorSession { return pending; } - buildReport(state) { - const pending = this.getPendingProbeIndices(); - const report = { - v: kProbeVersion, - probes: ArrayPrototypeMap(this.probes, ({ expr, target }) => ({ expr, target })), - results: ArrayPrototypeSlice(this.results), + buildReport({ exitCode, terminal }) { + const results = ArrayPrototypeSlice(this.results); + ArrayPrototypePush(results, terminal); + return { + code: exitCode, + report: { + v: kProbeVersion, + probes: ArrayPrototypeMap(this.probes, ({ expr, target }) => ({ expr, target })), + results, + }, }; - - if (state === 'timeout') { - ArrayPrototypePush(report.results, { - event: 'timeout', - pending, - error: { - code: 'probe_timeout', - message: pending.length === 0 ? - `Timed out after ${this.options.timeout}ms waiting for target completion` : - `Timed out after ${this.options.timeout}ms waiting for probes: ` + - `${formatPendingProbeLocations(this.probes, pending)}`, - }, - }); - return { code: kGenericUserError, report }; - } - - if (state?.event === 'error') { - const error = { - __proto__: null, - code: 'probe_target_exit', - message: formatTargetExitMessage(this.probes, pending, state.exitCode, state.signal), - }; - if (state.exitCode !== null) { - error.exitCode = state.exitCode; - } - if (state.signal !== null) { - error.signal = state.signal; - } - error.stderr = state.stderr; - ArrayPrototypePush(report.results, { event: 'error', pending, error }); - return { code: kNoFailure, report }; - } - - if (pending.length === 0) { - ArrayPrototypePush(report.results, { event: 'completed' }); - } else { - ArrayPrototypePush(report.results, { event: 'miss', pending }); - } - - return { code: kNoFailure, report }; } async cleanup() { @@ -746,13 +921,18 @@ class ProbeInspectorSession { this.attachListeners(); await this.client.connect(actualPort, actualHost); - await this.client.callMethod('Runtime.enable'); - await this.client.callMethod('Debugger.enable'); - await this.bindBreakpoints(); - this.started = true; - this.startTimeout(); - - await this.client.callMethod('Runtime.runIfWaitingForDebugger'); + this.connected = true; + + try { + await this.callCdp('Runtime.enable'); + await this.callCdp('Debugger.enable'); + await this.bindBreakpoints(); + this.started = true; + this.startTimeout(); + await this.callCdp('Runtime.runIfWaitingForDebugger'); + } catch (err) { + if (err !== kInspectorFailedSentinel) { throw err; } + } const state = await this.completionPromise; return this.buildReport(state); diff --git a/test/common/debugger-probe.js b/test/common/debugger-probe.js index c9e67931ee4573..bc5c206bb78926 100644 --- a/test/common/debugger-probe.js +++ b/test/common/debugger-probe.js @@ -10,30 +10,69 @@ const assert = require('assert'); // https://github.com/nodejs/node/issues/58245 const probeTargetExitSignal = 'SIGSEGV'; +function isProbeSegvTeardown(result) { + if (result?.event !== 'error') { return false; } + const error = result.error; + if (error?.signal !== probeTargetExitSignal) { return false; } + return error.code === 'probe_target_exit' || error.code === 'probe_failure'; +} + +function findProbeSegvTeardownLine(output) { + const signalPrefix = `Target exited with signal ${probeTargetExitSignal}`; + if (output.startsWith(signalPrefix)) { return 0; } + const idx = output.indexOf(`\n${signalPrefix}`); + return idx === -1 ? -1 : idx + 1; +} + +// Replace volatile fields in a probe report (stack frames, Node.js version, +// scriptId, callFrames) with stable placeholders for deepStrictEqual. +function normalizeProbeReport(value) { + if (typeof value === 'string') { + return value + .replace(/(?:\n[ \t]+at\s[^\n]*)+/g, '\n') + .replace(/\nNode\.js v[^\n]+/g, '\nNode.js '); + } + if (Array.isArray(value)) { + return value.map(normalizeProbeReport); + } + if (value !== null && typeof value === 'object') { + const result = {}; + for (const key of Object.keys(value)) { + if (key === 'scriptId') { + result[key] = ''; + } else if (key === 'callFrames') { + result[key] = ''; + } else { + result[key] = normalizeProbeReport(value[key]); + } + } + return result; + } + return value; +} + function assertProbeJson(output, expected) { const normalized = JSON.parse(output); const lastResult = normalized.results?.[normalized.results.length - 1]; - if (lastResult?.event === 'error' && - lastResult.error?.code === 'probe_target_exit' && - lastResult.error?.signal === probeTargetExitSignal) { + if (isProbeSegvTeardown(lastResult)) { // Log to facilitate debugging if this normalization is occurring. console.log('Normalizing trailing SIGSEGV in JSON probe output'); normalized.results[normalized.results.length - 1] = expected.results.at(-1); } - assert.deepStrictEqual(normalized, expected); + assert.deepStrictEqual(normalizeProbeReport(normalized), normalizeProbeReport(expected)); } function assertProbeText(output, expected) { - const signalPrefix = `Target exited with signal ${probeTargetExitSignal}`; - const idx = output.indexOf(signalPrefix); + const lineStart = findProbeSegvTeardownLine(output); let normalized; - if (idx !== -1) { + if (lineStart !== -1) { // Log to facilitate debugging if this normalization is occurring. console.log('Normalizing trailing SIGSEGV in text probe output'); - const lineStart = output.lastIndexOf('\n', idx); - normalized = (lineStart === -1 ? '' : output.slice(0, lineStart)) + '\nCompleted'; + const expectedLineStart = expected.lastIndexOf('\n'); + const terminalLine = expectedLineStart === -1 ? expected : expected.slice(expectedLineStart + 1); + normalized = lineStart === 0 ? terminalLine : `${output.slice(0, lineStart - 1)}\n${terminalLine}`; } else { normalized = output; } diff --git a/test/fixtures/debugger/probe-exits-during-probe.js b/test/fixtures/debugger/probe-exits-during-probe.js new file mode 100644 index 00000000000000..7bed0703f90570 --- /dev/null +++ b/test/fixtures/debugger/probe-exits-during-probe.js @@ -0,0 +1,8 @@ +'use strict'; + +function exitDuringProbe() { + process.exit(0); +} + +module.exports = { exitDuringProbe }; +globalThis.probeLine = 1; diff --git a/test/fixtures/debugger/probe-inspector-close-two-probes.js b/test/fixtures/debugger/probe-inspector-close-two-probes.js new file mode 100644 index 00000000000000..43bf438e899547 --- /dev/null +++ b/test/fixtures/debugger/probe-inspector-close-two-probes.js @@ -0,0 +1,13 @@ +'use strict'; + +const fs = require('fs'); +const inspector = require('inspector'); + +fs.writeSync(2, 'probe-inspector-close-marker\n'); + +const closeInspector = () => { inspector.close(); }; + +const firstProbeLine = 1; +const secondProbeLine = 2; + +setInterval(() => {}, 1000); diff --git a/test/fixtures/debugger/probe-inspector-resume.js b/test/fixtures/debugger/probe-inspector-resume.js new file mode 100644 index 00000000000000..f8025c53e7191c --- /dev/null +++ b/test/fixtures/debugger/probe-inspector-resume.js @@ -0,0 +1,14 @@ +'use strict'; +const { Session } = require('inspector'); + +function callInspectorResume() { + const session = new Session(); + session.connect(); + // Use a callback to ensure the probing resume happens after this one is delivered. + session.post('Debugger.resume', () => {}); + return 1; +} + +const probeLine = 1; +module.exports = { callInspectorResume }; +setInterval(() => {}, 1000); // Keep it alive to prevent early exit. diff --git a/test/fixtures/debugger/probe-script-throws.js b/test/fixtures/debugger/probe-script-throws.js new file mode 100644 index 00000000000000..c253eaf163a193 --- /dev/null +++ b/test/fixtures/debugger/probe-script-throws.js @@ -0,0 +1,9 @@ +'use strict'; + +function neverCalled() { + return 1; +} + +const reached = 1; +throw new Error('boom'); +neverCalled(); diff --git a/test/fixtures/debugger/probe-target-syntax-error.js b/test/fixtures/debugger/probe-target-syntax-error.js new file mode 100644 index 00000000000000..a72137f7fe1346 --- /dev/null +++ b/test/fixtures/debugger/probe-target-syntax-error.js @@ -0,0 +1,3 @@ +'use strict'; + +const x = ; diff --git a/test/fixtures/debugger/probe-throwing-getter.js b/test/fixtures/debugger/probe-throwing-getter.js new file mode 100644 index 00000000000000..906e464f98dd87 --- /dev/null +++ b/test/fixtures/debugger/probe-throwing-getter.js @@ -0,0 +1,21 @@ +'use strict'; + +const holder = { + get throwingGetter() { + throw new Error('boom'); + }, +}; + +let probesDone = false; +function markProbesDone() { + probesDone = true; +} + +module.exports = { holder, markProbesDone }; + +globalThis.probeLine1 = 1; +globalThis.probeLine2 = 2; + +const interval = setInterval(() => { + if (probesDone) clearInterval(interval); +}, 50); diff --git a/test/fixtures/debugger/probe-types.js b/test/fixtures/debugger/probe-types.js index d5d676a6b8dfa4..9ca45b69684b37 100644 --- a/test/fixtures/debugger/probe-types.js +++ b/test/fixtures/debugger/probe-types.js @@ -15,12 +15,3 @@ errorValue.stack = 'Error: boom'; function consume() {} consume(); - -// TODO(joyeecheung): add a test for evaluation errors. This can be -// somewhat flaky on slow CI machines. -// const holder = new class Foo { -// get throwingGetter() { -// throw new Error('foo'); -// } -// } -// probe holder.throwingGetter diff --git a/test/parallel/test-debugger-probe-expression-throws.js b/test/parallel/test-debugger-probe-expression-throws.js new file mode 100644 index 00000000000000..a5447fe0a0f590 --- /dev/null +++ b/test/parallel/test-debugger-probe-expression-throws.js @@ -0,0 +1,64 @@ +// This tests that a probe expression throwing an exception is recorded as +// a per-hit error and does not fail the session. +'use strict'; + +const common = require('../common'); +common.skipIfInspectorDisabled(); + +const fixtures = require('../common/fixtures'); +const { spawnSyncAndExit } = require('../common/child_process'); +const { assertProbeJson } = require('../common/debugger-probe'); + +const cwd = fixtures.path('debugger'); +const fixture = 'probe-throwing-getter.js'; +const probes = [ + { expr: 'holder.throwingGetter', target: { suffix: fixture, line: 16 } }, + // This clears the interval so the process will exit naturally. + { expr: 'markProbesDone()', target: { suffix: fixture, line: 17 } }, +]; +const url = fixtures.fileURL('debugger', fixture).href; + +spawnSyncAndExit(process.execPath, [ + 'inspect', '--json', + '--probe', `${fixture}:16`, '--expr', probes[0].expr, + '--probe', `${fixture}:17`, '--expr', probes[1].expr, + fixture, +], { cwd }, { + status: 0, + signal: null, + stdout(output) { + assertProbeJson(output, { + v: 2, + probes, + results: [{ + probe: 0, + event: 'hit', + hit: 1, + location: { url, line: 16, column: 1 }, + error: { + message: 'Error: boom\n', + details: { + exception: { + exceptionId: 1, + text: 'Uncaught', + lineNumber: 4, + columnNumber: 4, + scriptId: '', + stackTrace: { callFrames: '' }, + exception: { type: 'object', subtype: 'error', description: 'Error: boom\n' }, + }, + }, + }, + }, { + probe: 1, + event: 'hit', + hit: 1, + location: { url, line: 17, column: 1 }, + result: { type: 'undefined' }, + }, { + event: 'completed', + }], + }); + }, + trim: true, +}); diff --git a/test/parallel/test-debugger-probe-failure-hang-during-evaluate.js b/test/parallel/test-debugger-probe-failure-hang-during-evaluate.js new file mode 100644 index 00000000000000..332b519d393fcd --- /dev/null +++ b/test/parallel/test-debugger-probe-failure-hang-during-evaluate.js @@ -0,0 +1,58 @@ +// This tests that when a probe expression closes the inspector mid-session, +// session failure surfaces as probe_failure with downstream probes left pending. +'use strict'; + +const common = require('../common'); +common.skipIfInspectorDisabled(); + +const fixtures = require('../common/fixtures'); +const { spawnSyncAndExit } = require('../common/child_process'); +const { assertProbeJson } = require('../common/debugger-probe'); + +const cwd = fixtures.path('debugger'); +const fixture = 'probe-inspector-close-two-probes.js'; +const marker = 'probe-inspector-close-marker'; +const timeoutMs = common.platformTimeout(1000); +const probes = [ + { expr: 'closeInspector()', target: { suffix: fixture, line: 10 } }, + { expr: 'firstProbeLine', target: { suffix: fixture, line: 11 } }, +]; +const location = { url: fixtures.fileURL('debugger', fixture).href, line: 10, column: 24 }; + +spawnSyncAndExit(process.execPath, [ + 'inspect', '--json', `--timeout=${timeoutMs}`, + '--probe', `${fixture}:10`, '--expr', probes[0].expr, + '--probe', `${fixture}:11`, '--expr', probes[1].expr, + fixture, +], { cwd }, { + status: 1, + signal: null, + stdout(output) { + assertProbeJson(output, { + v: 2, + probes, + results: [{ + probe: 0, + event: 'hit', + hit: 1, + location, + error: { message: 'Probe evaluation did not complete' }, + }, { + event: 'error', + pending: [1], + error: { + code: 'probe_failure', + message: + `Probe session timed out before probes: ${fixture}:11. ` + + 'The probe expression may be slow, hanging, or interfering ' + + 'with the inspector connection. Try increasing `--timeout`; ' + + 'if the failure persists, review the probe expressions.', + probe: 0, + stderr: marker, + details: { lastCdpMethod: 'Debugger.evaluateOnCallFrame' }, + }, + }], + }); + }, + trim: true, +}); diff --git a/test/parallel/test-debugger-probe-failure-process-exit.js b/test/parallel/test-debugger-probe-failure-process-exit.js new file mode 100644 index 00000000000000..1e14c8b2b81842 --- /dev/null +++ b/test/parallel/test-debugger-probe-failure-process-exit.js @@ -0,0 +1,50 @@ +// This tests that a clean process.exit(0) from inside a probe expression +// surfaces as probe_failure, not probe_target_exit. +'use strict'; + +const common = require('../common'); +common.skipIfInspectorDisabled(); + +const fixtures = require('../common/fixtures'); +const { spawnSyncAndExit } = require('../common/child_process'); +const { assertProbeJson } = require('../common/debugger-probe'); + +const cwd = fixtures.path('debugger'); +const fixture = 'probe-exits-during-probe.js'; +const probes = [{ expr: 'exitDuringProbe()', target: { suffix: fixture, line: 8 } }]; +const location = { url: fixtures.fileURL('debugger', fixture).href, line: 8, column: 1 }; + +spawnSyncAndExit(process.execPath, [ + 'inspect', '--json', + '--probe', `${fixture}:8`, '--expr', probes[0].expr, + fixture, +], { cwd }, { + status: 1, + signal: null, + stdout(output) { + assertProbeJson(output, { + v: 2, + probes, + results: [{ + probe: 0, + event: 'hit', + hit: 1, + location, + error: { message: 'Probe evaluation did not complete' }, + }, { + event: 'error', + pending: [], + error: { + code: 'probe_failure', + message: + 'Target process exited during probe evaluation. ' + + 'If the failure repeats, review the probe expression.', + probe: 0, + stderr: '', + details: { lastCdpMethod: 'Debugger.evaluateOnCallFrame' }, + }, + }], + }); + }, + trim: true, +}); diff --git a/test/parallel/test-debugger-probe-failure-resume.js b/test/parallel/test-debugger-probe-failure-resume.js new file mode 100644 index 00000000000000..e5578ec452e1e7 --- /dev/null +++ b/test/parallel/test-debugger-probe-failure-resume.js @@ -0,0 +1,57 @@ +// This tests that a probe expression resuming the target through its own +// inspector.Session surfaces as probe_failure. +'use strict'; + +const common = require('../common'); +common.skipIfInspectorDisabled(); + +const fixtures = require('../common/fixtures'); +const { spawnSyncAndExit } = require('../common/child_process'); +const { assertProbeJson } = require('../common/debugger-probe'); + +const cwd = fixtures.path('debugger'); +const fixture = 'probe-inspector-resume.js'; +const probes = [{ + expr: 'callInspectorResume()', + target: { suffix: fixture, line: 12 }, +}]; +const location = { url: fixtures.fileURL('debugger', fixture).href, line: 12, column: 19 }; + +spawnSyncAndExit(process.execPath, [ + 'inspect', '--json', + '--probe', `${fixture}:12`, '--expr', probes[0].expr, + fixture, +], { cwd }, { + status: 1, + signal: null, + stdout(output) { + assertProbeJson(output, { + v: 2, + probes, + results: [{ + probe: 0, + event: 'hit', + hit: 1, + location, + result: { type: 'number', value: 1, description: '1' }, + }, { + event: 'error', + pending: [], + error: { + code: 'probe_failure', + message: + 'Probe session failed after a probe evaluation. If the ' + + 'failure repeats, review the most-recently-evaluated probe ' + + 'expression.', + probe: 0, + stderr: '', + details: { + lastCdpMethod: 'Debugger.resume', + protocolError: { message: 'Can only perform operation while paused.', code: -32000 }, + }, + }, + }], + }); + }, + trim: true, +}); diff --git a/test/parallel/test-debugger-probe-script-throws.js b/test/parallel/test-debugger-probe-script-throws.js new file mode 100644 index 00000000000000..0df67adb6a862a --- /dev/null +++ b/test/parallel/test-debugger-probe-script-throws.js @@ -0,0 +1,63 @@ +// This tests that an uncaught throw in the target between probe hits is +// surfaced as probe_target_exit, with hits before the throw preserved. +'use strict'; + +const common = require('../common'); +common.skipIfInspectorDisabled(); + +const path = require('path'); +const fixtures = require('../common/fixtures'); +const { spawnSyncAndExit } = require('../common/child_process'); +const { assertProbeJson } = require('../common/debugger-probe'); + +const cwd = fixtures.path('debugger'); +const fixture = 'probe-script-throws.js'; +const fixturePath = path.join(cwd, fixture); +const probes = [ + { expr: '\'before-throw\'', target: { suffix: fixture, line: 7 } }, + { expr: '99', target: { suffix: fixture, line: 4 } }, +]; +const location = { url: fixtures.fileURL('debugger', fixture).href, line: 7, column: 17 }; +const stderr = + `${fixturePath}:8\n` + + 'throw new Error(\'boom\');\n' + + '^\n' + + '\n' + + 'Error: boom\n' + + '\n' + + '\n' + + 'Node.js '; + +spawnSyncAndExit(process.execPath, [ + 'inspect', '--json', + '--probe', `${fixture}:7`, '--expr', probes[0].expr, + '--probe', `${fixture}:4`, '--expr', probes[1].expr, + fixture, +], { cwd }, { + // probe_target_exit: probing process exits 0 (hits trustworthy). + status: 0, + signal: null, + stdout(output) { + assertProbeJson(output, { + v: 2, + probes, + results: [{ + probe: 0, + event: 'hit', + hit: 1, + location, + result: { type: 'string', value: 'before-throw' }, + }, { + event: 'error', + pending: [1], + error: { + code: 'probe_target_exit', + message: `Target exited with code 1 before probes: ${fixture}:4`, + exitCode: 1, + stderr, + }, + }], + }); + }, + trim: true, +}); diff --git a/test/parallel/test-debugger-probe-target-syntax-error.js b/test/parallel/test-debugger-probe-target-syntax-error.js new file mode 100644 index 00000000000000..905bcd0b6ce3e3 --- /dev/null +++ b/test/parallel/test-debugger-probe-target-syntax-error.js @@ -0,0 +1,51 @@ +// This tests that a target script that fails to parse is surfaced as probe_target_exit. +'use strict'; + +const common = require('../common'); +common.skipIfInspectorDisabled(); + +const path = require('path'); +const fixtures = require('../common/fixtures'); +const { spawnSyncAndExit } = require('../common/child_process'); +const { assertProbeJson } = require('../common/debugger-probe'); + +const cwd = fixtures.path('debugger'); +const fixture = 'probe-target-syntax-error.js'; +const fixturePath = path.join(cwd, fixture); +const probes = [{ expr: 'x', target: { suffix: fixture, line: 3 } }]; +const stderr = + `${fixturePath}:3\n` + + 'const x = ;\n' + + ' ^\n' + + '\n' + + 'SyntaxError: Unexpected token \';\'\n' + + '\n' + + '\n' + + 'Node.js '; + +spawnSyncAndExit(process.execPath, [ + 'inspect', '--json', + '--probe', `${fixture}:3`, '--expr', probes[0].expr, + fixture, +], { cwd }, { + // probe_target_exit: probing process exits 0. + status: 0, + signal: null, + stdout(output) { + assertProbeJson(output, { + v: 2, + probes, + results: [{ + event: 'error', + pending: [0], + error: { + code: 'probe_target_exit', + message: `Target exited with code 1 before probes: ${fixture}:3`, + exitCode: 1, + stderr, + }, + }], + }); + }, + trim: true, +});