From 3183eee5d44c6aad3fffec5688c85d583ca17426 Mon Sep 17 00:00:00 2001 From: Luke Karrys Date: Thu, 2 May 2024 09:48:28 -0700 Subject: [PATCH] feat: create exit handler class --- lib/base-cmd.js | 29 +- lib/cli/entry.js | 22 +- lib/cli/exit-handler.js | 263 +++++++------- lib/npm.js | 282 +++++++++++---- lib/utils/error-message.js | 42 +-- .../tap-snapshots/test/index.js.test.cjs | 1 - smoke-tests/test/npm-replace-global.js | 6 +- .../test/lib/cli/exit-handler.js.test.cjs | 24 +- .../test/lib/commands/doctor.js.test.cjs | 57 +++- test/fixtures/mock-npm.js | 17 - test/lib/cli/entry.js | 33 +- test/lib/cli/exit-handler.js | 320 +++++++++++------- test/lib/npm.js | 8 + test/lib/utils/error-message.js | 2 +- 14 files changed, 655 insertions(+), 451 deletions(-) diff --git a/lib/base-cmd.js b/lib/base-cmd.js index 9c30ef8a4b44e..99ae6d7f43c70 100644 --- a/lib/base-cmd.js +++ b/lib/base-cmd.js @@ -1,4 +1,4 @@ -const { log, output } = require('proc-log') +const { log } = require('proc-log') class BaseCommand { static workspaces = false @@ -111,33 +111,6 @@ class BaseCommand { }) } - async cmdExec (args) { - const { config } = this.npm - - if (config.get('usage')) { - return output.standard(this.usage) - } - - const hasWsConfig = config.get('workspaces') || config.get('workspace').length - // if cwd is a workspace, the default is set to [that workspace] - const implicitWs = config.get('workspace', 'default').length - - // (-ws || -w foo) && (cwd is not a workspace || command is not ignoring implicit workspaces) - if (hasWsConfig && (!implicitWs || !this.constructor.ignoreImplicitWorkspace)) { - if (this.npm.global) { - throw new Error('Workspaces not supported for global packages') - } - if (!this.constructor.workspaces) { - throw Object.assign(new Error('This command does not support workspaces.'), { - code: 'ENOWORKSPACES', - }) - } - return this.execWorkspaces(args) - } - - return this.exec(args) - } - // Compare the number of entries with what was expected checkExpected (entries) { if (!this.npm.config.isDefault('expect-results')) { diff --git a/lib/cli/entry.js b/lib/cli/entry.js index 5d676c3f0a8a1..49b13eb0234cd 100644 --- a/lib/cli/entry.js +++ b/lib/cli/entry.js @@ -15,7 +15,8 @@ module.exports = async (process, validateEngines) => { require('graceful-fs').gracefulify(require('fs')) const satisfies = require('semver/functions/satisfies') - const exitHandler = require('./exit-handler.js') + const ExitHandler = require('./exit-handler.js') + const exitHandler = new ExitHandler({ process }) const Npm = require('../npm.js') const npm = new Npm() exitHandler.setNpm(npm) @@ -28,8 +29,7 @@ module.exports = async (process, validateEngines) => { // At this point we've required a few files and can be pretty sure we dont contain invalid syntax for this version of node. It's possible a lazy require would, but that's unlikely enough that it's not worth catching anymore and we attach the more important exit handlers. validateEngines.off() - process.on('uncaughtException', exitHandler) - process.on('unhandledRejection', exitHandler) + exitHandler.registerUncaughtHandlers() // It is now safe to log a warning if they are using a version of node that is not going to fail on syntax errors but is still unsupported and untested and might not work reliably. This is safe to use the logger now which we want since this will show up in the error log too. if (!satisfies(validateEngines.node, validateEngines.engines)) { @@ -42,13 +42,13 @@ module.exports = async (process, validateEngines) => { const { exec, command, args } = await npm.load() if (!exec) { - return exitHandler() + return exitHandler.exit() } if (!command) { output.standard(npm.usage) process.exitCode = 1 - return exitHandler() + return exitHandler.exit() } // Options are prefixed by a hyphen-minus (-, \u2d). @@ -72,16 +72,8 @@ module.exports = async (process, validateEngines) => { updateNotifier(npm).then((msg) => (npm.updateNotification = msg)) await execPromise - return exitHandler() + return exitHandler.exit() } catch (err) { - if (err.code === 'EUNKNOWNCOMMAND') { - const didYouMean = require('../utils/did-you-mean.js') - const suggestions = await didYouMean(npm.localPrefix, err.command) - output.standard(`Unknown command: "${err.command}"${suggestions}\n`) - output.standard('To see a list of supported npm commands, run:\n npm help') - process.exitCode = 1 - return exitHandler() - } - return exitHandler(err) + return exitHandler.exit(err) } } diff --git a/lib/cli/exit-handler.js b/lib/cli/exit-handler.js index 5866c46b57c5f..fff95165a18de 100644 --- a/lib/cli/exit-handler.js +++ b/lib/cli/exit-handler.js @@ -1,160 +1,173 @@ const { log, output, META } = require('proc-log') -const errorMessage = require('../utils/error-message.js') -const { redactLog: replaceInfo } = require('@npmcli/redact') +const { errorMessage, getExitCodeFromError } = require('../utils/error-message.js') -let npm = null // set by the cli -let exitHandlerCalled = false -let showLogFileError = false +class ExitHandler { + #npm = null + #process = null + #exited = false + #exitErrorMessage = false -process.on('exit', code => { - const hasLoadedNpm = npm?.config.loaded + #noNpmError = false - if (!code) { - log.info('ok') - } else { - log.verbose('code', code) + get #hasNpm () { + return !!this.#npm } - if (!exitHandlerCalled) { - process.exitCode = code || 1 - log.error('', 'Exit handler never called!') - log.error('', 'This is an error with npm itself. Please report this error at:') - log.error('', ' ') - // eslint-disable-next-line no-console - console.error('') - showLogFileError = true + get #loaded () { + return !!this.#npm?.loaded } - // npm must be loaded to know where the log file was written - if (hasLoadedNpm) { - npm.finish({ showLogFileError }) - // This removes any listeners npm setup, mostly for tests to avoid max listener warnings - npm.unload() + get #showExitErrorMessage () { + if (!this.#loaded) { + return false + } + if (!this.#exited) { + return true + } + return this.#exitErrorMessage } - // these are needed for the tests to have a clean slate in each test case - exitHandlerCalled = false - showLogFileError = false -}) + get #notLoadedOrExited () { + return !this.#loaded && !this.#exited + } -const exitHandler = err => { - exitHandlerCalled = true + setNpm (npm) { + this.#npm = npm + } - const hasLoadedNpm = npm?.config.loaded + constructor ({ process }) { + this.#process = process + this.#process.on('exit', this.#handleProcesExitAndReset) + } - if (!npm) { - err = err || new Error('Exit prior to setting npm in exit handler') - // Don't use proc-log here since npm was never set - // eslint-disable-next-line no-console - console.error(err.stack || err.message) - return process.exit(1) + registerUncaughtHandlers () { + this.#process.on('uncaughtException', this.#handleExit) + this.#process.on('unhandledRejection', this.#handleExit) } - if (!hasLoadedNpm) { - err = err || new Error('Exit prior to config file resolving.') - // Don't use proc-log here since npm was never loaded - // eslint-disable-next-line no-console - console.error(err.stack || err.message) + exit (err) { + this.#handleExit(err) } - // only show the notification if it finished. - if (typeof npm.updateNotification === 'string') { - log.notice('', npm.updateNotification, { [META]: true, force: true }) + #handleProcesExitAndReset = (code) => { + this.#handleProcessExit(code) + + // Reset all the state. This is only relevant for tests since + // in reality the process fully exits here. + this.#process.off('exit', this.#handleProcesExitAndReset) + this.#process.off('uncaughtException', this.#handleExit) + this.#process.off('unhandledRejection', this.#handleExit) + if (this.#loaded) { + this.#npm.unload() + } + this.#npm = null + this.#exited = false + this.#exitErrorMessage = false } - let exitCode = process.exitCode || 0 - let noLogMessage = exitCode !== 0 - let jsonError - - if (err) { - exitCode = 1 - // if we got a command that just shells out to something else, then it - // will presumably print its own errors and exit with a proper status - // code if there's a problem. If we got an error with a code=0, then... - // something else went wrong along the way, so maybe an npm problem? - const isShellout = npm.isShellout - const quietShellout = isShellout && typeof err.code === 'number' && err.code - if (quietShellout) { - exitCode = err.code - noLogMessage = true - } else if (typeof err === 'string') { - // XXX: we should stop throwing strings - log.error('', err) - noLogMessage = true - } else if (!(err instanceof Error)) { - log.error('weird error', err) - noLogMessage = true - } else { - const os = require('node:os') - const fs = require('node:fs') - if (!err.code) { - const matchErrorCode = err.message.match(/^(?:Error: )?(E[A-Z]+)/) - err.code = matchErrorCode && matchErrorCode[1] - } + #handleProcessExit (code) { + // Force exit code to a number if it has not been set + const exitCode = typeof code === 'number' ? code : (this.#exited ? 0 : 1) + this.#process.exitCode = exitCode - for (const k of ['type', 'stack', 'statusCode', 'pkgid']) { - const v = err[k] - if (v) { - log.verbose(k, replaceInfo(v)) - } - } + if (this.#notLoadedOrExited) { + // Exit handler was not called and npm was not loaded so we have to log something + this.#logConsoleError(new Error(`Process exited unexpectedly with code: ${exitCode}`)) + return + } - log.verbose('cwd', process.cwd()) - log.verbose('', os.type() + ' ' + os.release()) - log.verbose('node', process.version) - log.verbose('npm ', 'v' + npm.version) + if (this.#logNoNpmError()) { + return + } - for (const k of ['code', 'syscall', 'file', 'path', 'dest', 'errno']) { - const v = err[k] - if (v) { - log.error(k, v) - } - } + const os = require('node:os') + log.verbose('cwd', this.#process.cwd()) + log.verbose('os', `${os.type()} ${os.release()}`) + log.verbose('node', this.#process.version) + log.verbose('npm ', `v${this.#npm.version}`) - const { summary, detail, json, files = [] } = errorMessage(err, npm) - jsonError = json - - for (let [file, content] of files) { - file = `${npm.logPath}${file}` - content = `'Log files:\n${npm.logFiles.join('\n')}\n\n${content.trim()}\n` - try { - fs.writeFileSync(file, content) - detail.push(['', `\n\nFor a full report see:\n${file}`]) - } catch (logFileErr) { - log.warn('', `Could not write error message to ${file} due to ${logFileErr}`) - } - } + // only show the notification if it finished + if (typeof this.#npm.updateNotification === 'string') { + log.notice('', this.#npm.updateNotification, { [META]: true, force: true }) + } - for (const errline of [...summary, ...detail]) { - log.error(...errline) + if (!this.#exited) { + log.error('', 'Exit handler never called!') + log.error('', 'This is an error with npm itself. Please report this error at:') + log.error('', ' ') + if (this.#npm.silent) { + output.error('') } + } - if (typeof err.errno === 'number') { - exitCode = err.errno - } else if (typeof err.code === 'number') { - exitCode = err.code - } + log.verbose('exit', exitCode) + + if (exitCode) { + log.verbose('code', exitCode) + } else { + log.info('ok') + } + + if (this.#showExitErrorMessage) { + log.error('', this.#npm.exitErrorMessage()) } } - if (hasLoadedNpm) { - output.flush({ [META]: true, jsonError }) + #logConsoleError (err) { + // Run our error message formatters on all errors even if we + // have no npm or an unloaded npm. This will clean the error + // and possible return a formatted message about EACCESS or something. + const { summary, detail } = errorMessage(err, this.#npm) + const formatted = [...new Set([...summary, ...detail].flat().filter(Boolean))].join('\n') + // If we didn't get anything from the formatted message then just display the full stack + // eslint-disable-next-line no-console + console.error(formatted === err.message ? err.stack : formatted) } - log.verbose('exit', exitCode || 0) + #logNoNpmError (err) { + if (this.#hasNpm) { + return false + } + // Make sure we only log this error once + if (!this.#noNpmError) { + this.#noNpmError = true + this.#logConsoleError( + new Error(`Exit prior to setting npm in exit handler`, err ? { cause: err } : {}) + ) + } + return true + } + + #handleExit = (err) => { + this.#exited = true + + // No npm at all + if (this.#logNoNpmError(err)) { + return this.#process.exit(this.#process.exitCode || getExitCodeFromError(err) || 1) + } - showLogFileError = (hasLoadedNpm && npm.silent) || noLogMessage - ? false - : !!exitCode + // npm was never loaded but we still might have a config loading error or + // something similar that we can run through the error message formatter + // to give the user a clue as to what happened.s + if (!this.#loaded) { + this.#logConsoleError(new Error('Exit prior to config file resolving', { cause: err })) + return this.#process.exit(this.#process.exitCode || getExitCodeFromError(err) || 1) + } + + this.#exitErrorMessage = err?.suppressError === true ? false : !!err - // explicitly call process.exit now so we don't hang on things like the - // update notifier, also flush stdout/err beforehand because process.exit doesn't - // wait for that to happen. - let flushed = 0 - const flush = [process.stderr, process.stdout] - const exit = () => ++flushed === flush.length && process.exit(exitCode) - flush.forEach((f) => f.write('', exit)) + // Prefer the exit code of the error, then the current process exit code, + // then set it to 1 if we still have an error. Otherwise we call process.exit + // with undefined so that it can determine the final exit code + const exitCode = err?.exitCode ?? this.#process.exitCode ?? (err ? 1 : undefined) + + // explicitly call process.exit now so we don't hang on things like the + // update notifier, also flush stdout/err beforehand because process.exit doesn't + // wait for that to happen. + this.#process.stderr.write('', () => this.#process.stdout.write('', () => { + this.#process.exit(exitCode) + })) + } } -module.exports = exitHandler -module.exports.setNpm = n => (npm = n) +module.exports = ExitHandler diff --git a/lib/npm.js b/lib/npm.js index df2297b215da7..c22b10b973bdf 100644 --- a/lib/npm.js +++ b/lib/npm.js @@ -7,7 +7,7 @@ const usage = require('./utils/npm-usage.js') const LogFile = require('./utils/log-file.js') const Timers = require('./utils/timers.js') const Display = require('./utils/display.js') -const { log, time, output } = require('proc-log') +const { log, time, output, META } = require('proc-log') const { redactLog: replaceInfo } = require('@npmcli/redact') const pkg = require('../package.json') const { deref } = require('./utils/cmd-list.js') @@ -73,76 +73,14 @@ class Npm { }) } - get version () { - return this.constructor.version - } - - // Call an npm command - async exec (cmd, args = this.argv) { - const Command = Npm.cmd(cmd) - const command = new Command(this) - - // since 'test', 'start', 'stop', etc. commands re-enter this function - // to call the run-script command, we need to only set it one time. - if (!this.#command) { - this.#command = command - process.env.npm_command = this.command - } - - return time.start(`command:${cmd}`, () => command.cmdExec(args)) - } - async load () { - return time.start('npm:load', () => this.#load()) - } - - get loaded () { - return this.config.loaded - } - - // This gets called at the end of the exit handler and - // during any tests to cleanup all of our listeners - // Everything in here should be synchronous - unload () { - this.#timers.off() - this.#display.off() - this.#logFile.off() - } - - finish ({ showLogFileError } = {}) { - this.#timers.finish({ - id: this.#runId, - command: this.#argvClean, - logfiles: this.logFiles, - version: this.version, - }) - - if (showLogFileError) { - if (!this.silent) { - // just a line break if not in silent mode - output.error('') - } - - if (this.logFiles.length) { - return log.error('', `A complete log of this run can be found in: ${this.logFiles}`) - } - - const logsMax = this.config.get('logs-max') - if (logsMax <= 0) { - // user specified no log file - log.error('', `Log files were not written due to the config logs-max=${logsMax}`) - } else { - // could be an error writing to the directory - log.error('', - `Log files were not written due to an error writing to the directory: ${this.#logsDir}` + - '\nYou can rerun the command with `--loglevel=verbose` to see the logs in your terminal' - ) - } + let err + try { + return await time.start('npm:load', () => this.#load()) + } catch (e) { + err = e } - } - - get title () { - return this.#title + return this.#handleError(err) } async #load () { @@ -260,8 +198,210 @@ class Npm { return { exec: true, command: commandArg, args: this.argv } } - get isShellout () { - return this.#command?.constructor?.isShellout + async exec (cmd, args = this.argv) { + if (!this.#command) { + let err + try { + await this.#exec(cmd, args) + } catch (e) { + err = e + } + return this.#handleError(err) + } else { + return this.#exec(cmd, args) + } + } + + // Call an npm command + async #exec (cmd, args) { + const Command = this.constructor.cmd(cmd) + const command = new Command(this) + + // since 'test', 'start', 'stop', etc. commands re-enter this function + // to call the run-script command, we need to only set it one time. + if (!this.#command) { + this.#command = command + process.env.npm_command = this.command + } + + if (this.config.get('usage')) { + return output.standard(command.usage) + } + + let execWorkspaces = false + const hasWsConfig = this.config.get('workspaces') || this.config.get('workspace').length + // if cwd is a workspace, the default is set to [that workspace] + const implicitWs = this.config.get('workspace', 'default').length + // (-ws || -w foo) && (cwd is not a workspace || command is not ignoring implicit workspaces) + if (hasWsConfig && (!implicitWs || !Command.ignoreImplicitWorkspace)) { + if (this.global) { + throw new Error('Workspaces not supported for global packages') + } + if (!Command.workspaces) { + throw Object.assign(new Error('This command does not support workspaces.'), { + code: 'ENOWORKSPACES', + }) + } + execWorkspaces = true + } + + return time.start(`command:${cmd}`, () => + execWorkspaces ? command.execWorkspaces(args) : command.exec(args)) + } + + // This gets called at the end of the exit handler and + // during any tests to cleanup all of our listeners + // Everything in here should be synchronous + unload () { + this.#timers.off() + this.#display.off() + this.#logFile.off() + } + + finish () { + // Finish all our timer work, this will write the file if requested, end timers, etc + this.#timers.finish({ + id: this.#runId, + command: this.#argvClean, + logfiles: this.logFiles, + version: this.version, + }) + } + + exitErrorMessage () { + if (this.logFiles.length) { + return `A complete log of this run can be found in: ${this.logFiles}` + } + + const logsMax = this.config.get('logs-max') + if (logsMax <= 0) { + // user specified no log file + return `Log files were not written due to the config logs-max=${logsMax}` + } + + // could be an error writing to the directory + return `Log files were not written due to an error writing to the directory: ${this.#logsDir}` + + '\nYou can rerun the command with `--loglevel=verbose` to see the logs in your terminal' + } + + async #handleError (err) { + if (err) { + Object.assign(err, await this.#getError(err)) + } + + // TODO: make this not need to be public + this.finish() + + output.flush({ + [META]: true, + jsonError: err && this.loaded && this.config.get('json') ? { + code: err.code, + summary: (err.summary || []).map(l => l.slice(1).join(' ')).join('\n'), + detail: (err.detail || []).map(l => l.slice(1).join(' ')).join('\n'), + } : null, + }) + + if (err) { + throw err + } + } + + async #getError (err) { + const { errorMessage, getExitCodeFromError } = require('./utils/error-message.js') + + // if we got a command that just shells out to something else, then it + // will presumably print its own errors and exit with a proper status + // code if there's a problem. If we got an error with a code=0, then... + // something else went wrong along the way, so maybe an npm problem? + if (this.#command?.constructor?.isShellout && typeof err.code === 'number' && err.code) { + return { + exitCode: err.code, + suppressError: true, + } + } + + // XXX: we should stop throwing strings + if (typeof err === 'string') { + log.error('', err) + return { + exitCode: 1, + suppressError: true, + } + } + + // XXX: we should stop throwing other non-errors + if (!(err instanceof Error)) { + log.error('weird error', err) + return { + exitCode: 1, + suppressError: true, + } + } + + if (err.code === 'EUNKNOWNCOMMAND') { + const didYouMean = require('./utils/did-you-mean.js') + const suggestions = await didYouMean(this.localPrefix, err.command) + output.standard(`Unknown command: "${err.command}"${suggestions}\n`) + output.standard('To see a list of supported npm commands, run:\n npm help') + return { + exitCode: 1, + suppressError: true, + } + } + + err.code ??= err.message.match(/^(?:Error: )?(E[A-Z]+)/)?.[1] + + for (const k of ['type', 'stack', 'statusCode', 'pkgid']) { + const v = err[k] + if (v) { + log.verbose(k, replaceInfo(v)) + } + } + + const exitCode = getExitCodeFromError(err) || 1 + const { summary, detail, files } = errorMessage(err, this) + + const { writeFileSync } = require('node:fs') + for (const [file, content] of files) { + const filePath = `${this.logPath}${file}` + const fileContent = `'Log files:\n${this.logFiles.join('\n')}\n\n${content.trim()}\n` + try { + writeFileSync(filePath, fileContent) + detail.push(['', `\n\nFor a full report see:\n${filePath}`]) + } catch (fileErr) { + log.warn('', `Could not write error message to ${file} due to ${fileErr}`) + } + } + + for (const k of ['code', 'syscall', 'file', 'path', 'dest', 'errno']) { + const v = err[k] + if (v) { + log.error(k, v) + } + } + + for (const errline of [...summary, ...detail]) { + log.error(...errline) + } + + return { + exitCode, + summary, + detail, + suppressError: false, + } + } + + get title () { + return this.#title + } + + get loaded () { + return this.config.loaded + } + + get version () { + return this.constructor.version } get command () { diff --git a/lib/utils/error-message.js b/lib/utils/error-message.js index 969e56636dfe8..3d1b18f29dab6 100644 --- a/lib/utils/error-message.js +++ b/lib/utils/error-message.js @@ -3,18 +3,6 @@ const { resolve } = require('node:path') const { redactLog: replaceInfo } = require('@npmcli/redact') const { log } = require('proc-log') -const messageText = msg => msg.map(line => line.slice(1).join(' ')).join('\n') - -const jsonError = (er, npm, { summary, detail }) => { - if (npm?.config.loaded && npm.config.get('json')) { - return { - code: er.code, - summary: messageText(summary), - detail: messageText(detail), - } - } -} - const errorMessage = (er, npm) => { const short = [] const detail = [] @@ -67,13 +55,9 @@ const errorMessage = (er, npm) => { case 'EACCES': case 'EPERM': { const isCachePath = - typeof er.path === 'string' && - npm.config.loaded && - er.path.startsWith(npm.config.get('cache')) + typeof er.path === 'string' && npm.loaded && er.path.startsWith(npm.config.get('cache')) const isCacheDest = - typeof er.dest === 'string' && - npm.config.loaded && - er.dest.startsWith(npm.config.get('cache')) + typeof er.dest === 'string' && npm.loaded && er.dest.startsWith(npm.config.get('cache')) if (process.platform !== 'win32' && (isCachePath || isCacheDest)) { // user probably doesn't need this, but still add it to the debug log @@ -407,25 +391,35 @@ const errorMessage = (er, npm) => { default: short.push(['', er.message || er]) + if (er.cause) { + detail.push(['cause', er.cause.message]) + } if (er.signal) { detail.push(['signal', er.signal]) } - if (er.cmd && Array.isArray(er.args)) { detail.push(['command', ...[er.cmd, ...er.args.map(replaceInfo)]]) } - if (er.stdout) { detail.push(['', er.stdout.trim()]) } - if (er.stderr) { detail.push(['', er.stderr.trim()]) } - break } - return { summary: short, detail, files, json: jsonError(er, npm, { summary: short, detail }) } + return { summary: short, detail, files } +} + +const getExitCodeFromError = (err) => { + if (typeof err?.errno === 'number') { + return err.errno + } else if (typeof err?.code === 'number') { + return err.code + } } -module.exports = errorMessage +module.exports = { + getExitCodeFromError, + errorMessage, +} diff --git a/smoke-tests/tap-snapshots/test/index.js.test.cjs b/smoke-tests/tap-snapshots/test/index.js.test.cjs index c889c830e845a..69c9ceab87fd0 100644 --- a/smoke-tests/tap-snapshots/test/index.js.test.cjs +++ b/smoke-tests/tap-snapshots/test/index.js.test.cjs @@ -66,7 +66,6 @@ npm error npm error aliases: clean-install, ic, install-clean, isntall-clean npm error npm error Run "npm help ci" for more info - npm error A complete log of this run can be found in: {NPM}/{TESTDIR}/cache/_logs/{LOG} ` diff --git a/smoke-tests/test/npm-replace-global.js b/smoke-tests/test/npm-replace-global.js index c0accf6ba53b5..03a976ab6ccf3 100644 --- a/smoke-tests/test/npm-replace-global.js +++ b/smoke-tests/test/npm-replace-global.js @@ -191,7 +191,11 @@ t.test('fail when updating with lazy require', async t => { // so an uncached lazy require within the exit handler will always throw await fs.writeFile( join(paths.globalNodeModules, 'npm/lib/cli/exit-handler.js'), - `module.exports = () => require('./LAZY_REQUIRE_CANARY');module.exports.setNpm = () => {}`, + `module.exports = class { + setNpm(){} + registerUncaughtHandlers(){} + exit() { require('./LAZY_REQUIRE_CANARY') } + }`, 'utf-8' ) diff --git a/tap-snapshots/test/lib/cli/exit-handler.js.test.cjs b/tap-snapshots/test/lib/cli/exit-handler.js.test.cjs index cedb56642f26d..0a2eb41278261 100644 --- a/tap-snapshots/test/lib/cli/exit-handler.js.test.cjs +++ b/tap-snapshots/test/lib/cli/exit-handler.js.test.cjs @@ -20,18 +20,18 @@ XX timing npm:load:setTitle Completed in {TIME}ms XX verbose logfile logs-max:10 dir:{CWD}/cache/_logs/{DATE}- XX verbose logfile {CWD}/cache/_logs/{DATE}-debug-0.log XX timing npm:load Completed in {TIME}ms +XX timing command:root Completed in {TIME}ms XX verbose stack Error: Unknown error +XX error code ECODE +XX error Unknown error +XX timing npm Completed in {TIME}ms +XX info timing Timing info written to: {CWD}/cache/_logs/{DATE}-timing.json XX verbose cwd {CWD}/prefix -XX verbose {OS} +XX verbose os {OS} XX verbose {NODE-VERSION} XX verbose npm {NPM-VERSION} -XX error code ECODE -XX error ERR SUMMARY Unknown error -XX error ERR DETAIL Unknown error XX verbose exit 1 XX verbose code 1 -XX timing npm Completed in {TIME}ms -XX info timing Timing info written to: {CWD}/cache/_logs/{DATE}-timing.json XX error A complete log of this run can be found in: {CWD}/cache/_logs/{DATE}-debug-0.log ` @@ -50,17 +50,17 @@ timing npm:load:setTitle Completed in {TIME}ms verbose logfile logs-max:10 dir:{CWD}/cache/_logs/{DATE}- verbose logfile {CWD}/cache/_logs/{DATE}-debug-0.log timing npm:load Completed in {TIME}ms +timing command:root Completed in {TIME}ms verbose stack Error: Unknown error +error code ECODE +error Unknown error +timing npm Completed in {TIME}ms +info timing Timing info written to: {CWD}/cache/_logs/{DATE}-timing.json verbose cwd {CWD}/prefix -verbose {OS} +verbose os {OS} verbose {NODE-VERSION} verbose npm {NPM-VERSION} -error code ECODE -error ERR SUMMARY Unknown error -error ERR DETAIL Unknown error verbose exit 1 verbose code 1 -timing npm Completed in {TIME}ms -info timing Timing info written to: {CWD}/cache/_logs/{DATE}-timing.json error A complete log of this run can be found in: {CWD}/cache/_logs/{DATE}-debug-0.log ` diff --git a/tap-snapshots/test/lib/commands/doctor.js.test.cjs b/tap-snapshots/test/lib/commands/doctor.js.test.cjs index dbcad22ac0a51..0f5b9520516f2 100644 --- a/tap-snapshots/test/lib/commands/doctor.js.test.cjs +++ b/tap-snapshots/test/lib/commands/doctor.js.test.cjs @@ -121,7 +121,9 @@ Object { exports[`test/lib/commands/doctor.js TAP bad proxy > logs 1`] = ` Object { - "error": Array [], + "error": Array [ + "Some problems found. See above for recommendations.", + ], "info": Array [ "doctor Running checkup", "doctor Pinging registry", @@ -400,7 +402,9 @@ exports[`test/lib/commands/doctor.js TAP discrete checks git > output 1`] = ` exports[`test/lib/commands/doctor.js TAP discrete checks invalid environment > logs 1`] = ` Object { - "error": Array [], + "error": Array [ + "Some problems found. See above for recommendations.", + ], "info": Array [ "doctor Running checkup", "doctor Finding git in your PATH", @@ -514,7 +518,9 @@ current: v1.0.0, recommended: v1.0.0 exports[`test/lib/commands/doctor.js TAP error reading directory > logs 1`] = ` Object { - "error": Array [], + "error": Array [ + "Some problems found. See above for recommendations.", + ], "info": Array [ "doctor Running checkup", "doctor Pinging registry", @@ -616,7 +622,9 @@ verified 0 tarballs exports[`test/lib/commands/doctor.js TAP incorrect owner > logs 1`] = ` Object { - "error": Array [], + "error": Array [ + "Some problems found. See above for recommendations.", + ], "info": Array [ "doctor Running checkup", "doctor Pinging registry", @@ -686,6 +694,7 @@ Object { "doctor checkFilesPermission Missing permissions on {CWD}/global/node_modules (expect: readable)", "doctor checkFilesPermission Missing permissions on {CWD}/prefix/node_modules/.bin (expect: readable, writable, executable)", "doctor checkFilesPermission Missing permissions on {CWD}/global/bin (expect: executable)", + "Some problems found. See above for recommendations.", ], "info": Array [ "doctor Running checkup", @@ -710,7 +719,9 @@ Object { exports[`test/lib/commands/doctor.js TAP missing git > logs 1`] = ` Object { - "error": Array [], + "error": Array [ + "Some problems found. See above for recommendations.", + ], "info": Array [ "doctor Running checkup", "doctor Pinging registry", @@ -771,7 +782,9 @@ verified 0 tarballs exports[`test/lib/commands/doctor.js TAP missing global directories > logs 1`] = ` Object { - "error": Array [], + "error": Array [ + "Some problems found. See above for recommendations.", + ], "info": Array [ "doctor Running checkup", "doctor Pinging registry", @@ -890,7 +903,9 @@ verified 0 tarballs exports[`test/lib/commands/doctor.js TAP node out of date - current > logs 1`] = ` Object { - "error": Array [], + "error": Array [ + "Some problems found. See above for recommendations.", + ], "info": Array [ "doctor Running checkup", "doctor Pinging registry", @@ -947,7 +962,9 @@ verified 0 tarballs exports[`test/lib/commands/doctor.js TAP node out of date - lts > logs 1`] = ` Object { - "error": Array [], + "error": Array [ + "Some problems found. See above for recommendations.", + ], "info": Array [ "doctor Running checkup", "doctor Pinging registry", @@ -1004,7 +1021,9 @@ verified 0 tarballs exports[`test/lib/commands/doctor.js TAP non-default registry > logs 1`] = ` Object { - "error": Array [], + "error": Array [ + "Some problems found. See above for recommendations.", + ], "info": Array [ "doctor Running checkup", "doctor Pinging registry", @@ -1061,7 +1080,9 @@ verified 0 tarballs exports[`test/lib/commands/doctor.js TAP npm out of date > logs 1`] = ` Object { - "error": Array [], + "error": Array [ + "Some problems found. See above for recommendations.", + ], "info": Array [ "doctor Running checkup", "doctor Pinging registry", @@ -1118,7 +1139,9 @@ verified 0 tarballs exports[`test/lib/commands/doctor.js TAP ping 404 > logs 1`] = ` Object { - "error": Array [], + "error": Array [ + "Some problems found. See above for recommendations.", + ], "info": Array [ "doctor Running checkup", "doctor Pinging registry", @@ -1176,7 +1199,9 @@ verified 0 tarballs exports[`test/lib/commands/doctor.js TAP ping 404 in color > logs 1`] = ` Object { - "error": Array [], + "error": Array [ + "Some problems found. See above for recommendations.", + ], "info": Array [ "/u001b[94mdoctor/u001b[39m Running checkup", "/u001b[94mdoctor/u001b[39m Pinging registry", @@ -1234,7 +1259,9 @@ verified 0 tarballs exports[`test/lib/commands/doctor.js TAP ping exception with code > logs 1`] = ` Object { - "error": Array [], + "error": Array [ + "Some problems found. See above for recommendations.", + ], "info": Array [ "doctor Running checkup", "doctor Pinging registry", @@ -1292,7 +1319,9 @@ verified 0 tarballs exports[`test/lib/commands/doctor.js TAP ping exception without code > logs 1`] = ` Object { - "error": Array [], + "error": Array [ + "Some problems found. See above for recommendations.", + ], "info": Array [ "doctor Running checkup", "doctor Pinging registry", diff --git a/test/fixtures/mock-npm.js b/test/fixtures/mock-npm.js index d8a4834a9abff..674147781af4c 100644 --- a/test/fixtures/mock-npm.js +++ b/test/fixtures/mock-npm.js @@ -2,8 +2,6 @@ const os = require('os') const fs = require('fs').promises const path = require('path') const tap = require('tap') -const { output, META } = require('proc-log') -const errorMessage = require('../../lib/utils/error-message') const mockLogs = require('./mock-logs.js') const mockGlobals = require('@npmcli/mock-globals') const tmock = require('./tmock') @@ -83,21 +81,6 @@ const getMockNpm = async (t, { mocks, init, load, npm: npmOpts }) => { await Promise.all(this.unrefPromises) return res } - - async exec (...args) { - const [res, err] = await super.exec(...args).then((r) => [r]).catch(e => [null, e]) - // This mimics how the exit handler flushes output for commands that have - // buffered output. It also uses the same json error processing from the - // error message fn. This is necessary for commands with buffered output - // to read the output after exec is called. This is not *exactly* how it - // works in practice, but it is close enough for now. - const jsonError = err && errorMessage(err, this).json - output.flush({ [META]: true, jsonError }) - if (err) { - throw err - } - return res - } } const npm = init ? new MockNpm() : null diff --git a/test/lib/cli/entry.js b/test/lib/cli/entry.js index 60a38b70abf89..87563fab59902 100644 --- a/test/lib/cli/entry.js +++ b/test/lib/cli/entry.js @@ -8,16 +8,22 @@ const validateEngines = require('../../../lib/cli/validate-engines.js') const cliMock = async (t, opts) => { let exitHandlerArgs = null let npm = null - const exitHandlerMock = (...args) => { - exitHandlerArgs = args - npm.unload() - } - exitHandlerMock.setNpm = _npm => npm = _npm const { Npm, ...mock } = await loadMockNpm(t, { ...opts, init: false }) const cli = tmock(t, '{LIB}/cli/entry.js', { '{LIB}/npm.js': Npm, - '{LIB}/cli/exit-handler.js': exitHandlerMock, + '{LIB}/cli/exit-handler.js': class MockExitHandler { + exit (...args) { + exitHandlerArgs = args + npm.unload() + } + + registerUncaughtHandlers () {} + + setNpm (_npm) { + npm = _npm + } + }, }) return { @@ -113,21 +119,6 @@ t.test('print usage if no params provided', async t => { t.match(process.exitCode, 1) }) -t.test('print usage if non-command param provided', async t => { - const { cli, outputs, exitHandlerCalled, exitHandlerNpm } = await cliMock(t, { - globals: { - 'process.argv': ['node', 'npm', 'tset'], - }, - }) - await cli(process) - - t.match(outputs[0], 'Unknown command: "tset"') - t.match(outputs[0], 'Did you mean this?') - t.match(exitHandlerCalled(), [], 'should call exitHandler with no args') - t.ok(exitHandlerNpm(), 'exitHandler npm is set') - t.match(process.exitCode, 1) -}) - t.test('load error calls error handler', async t => { const err = new Error('test load error') const { cli, exitHandlerCalled } = await cliMock(t, { diff --git a/test/lib/cli/exit-handler.js b/test/lib/cli/exit-handler.js index 7b465643504c7..73cc57cb9a676 100644 --- a/test/lib/cli/exit-handler.js +++ b/test/lib/cli/exit-handler.js @@ -5,6 +5,8 @@ const os = require('node:os') const t = require('tap') const fsMiniPass = require('fs-minipass') const { output, time } = require('proc-log') +const errorMessage = require('../../../lib/utils/error-message.js') +const ExecCommand = require('../../../lib/commands/exec.js') const { load: loadMockNpm } = require('../../fixtures/mock-npm') const mockGlobals = require('@npmcli/mock-globals') const { cleanCwd, cleanDate } = require('../../fixtures/clean-snapshot') @@ -46,20 +48,48 @@ mockGlobals(t, { // these are process properties that are needed in the running code and tests // eslint-disable-next-line max-len ...pick(process, 'version', 'execPath', 'stdout', 'stderr', 'stdin', 'cwd', 'chdir', 'env', 'umask'), + pid: 123456, argv: ['/node', ...process.argv.slice(1)], kill: () => {}, reallyExit: (code) => process.exit(code), - pid: 123456, - exit: (code) => { - process.exitCode = code || process.exitCode || 0 - process.emit('exit', process.exitCode) + exit (code) { + this.emit('exit', code) }, }), }, { replace: true }) -const mockExitHandler = async (t, { config, mocks, files, ...opts } = {}) => { +const mockExitHandler = async (t, { + config, + mocks = {}, + files, + error, + command, + ...opts +} = {}) => { const errors = [] + mocks['{LIB}/utils/error-message.js'] = { + ...errorMessage, + errorMessage: (err) => ({ + ...errorMessage.errorMessage(err), + ...(files ? { files } : {}), + }), + } + + if (error) { + mocks[`{LIB}/commands/root.js`] = class { + async exec () { + throw error + } + } + mocks[`{LIB}/commands/exec.js`] = class extends ExecCommand { + async exec (...args) { + await super.exec(...args) + throw error + } + } + } + const { npm, ...rest } = await loadMockNpm(t, { ...opts, mocks, @@ -72,19 +102,10 @@ const mockExitHandler = async (t, { config, mocks, files, ...opts } = {}) => { }, }) - const exitHandler = tmock(t, '{LIB}/cli/exit-handler.js', { - '{LIB}/utils/error-message.js': (err) => ({ - summary: [['ERR SUMMARY', err.message]], - detail: [['ERR DETAIL', err.message]], - ...(files ? { files } : {}), - json: { - code: err.code, - summary: err.message, - detail: err.message, - }, - }), - ...mocks, - }) + const ExitHandler = tmock(t, '{LIB}/cli/exit-handler.js', mocks) + + const exitHandler = new ExitHandler({ process }) + exitHandler.registerUncaughtHandlers() if (npm) { exitHandler.setNpm(npm) @@ -103,9 +124,15 @@ const mockExitHandler = async (t, { config, mocks, files, ...opts } = {}) => { npm, // Make it async to make testing ergonomics a little easier so we dont need // to t.plan() every test to make sure we get process.exit called. - exitHandler: (...args) => new Promise(res => { + exitHandler: (argErr) => new Promise(res => { process.once('exit', res) - exitHandler(...args) + if (npm) { + npm.exec(command || 'root') + .then(() => exitHandler.exit()) + .catch((err) => exitHandler.exit(err)) + } else { + exitHandler.exit(argErr || error) + } }), } } @@ -126,9 +153,10 @@ const err = (message = '', options = {}, noStack = false) => { t.test('handles unknown error with logs and debug file', async (t) => { const { exitHandler, debugFile, logs } = await mockExitHandler(t, { config: { loglevel: 'silly', timing: true }, + error: err('Unknown error', 'ECODE'), }) - await exitHandler(err('Unknown error', 'ECODE')) + await exitHandler() const fileLogs = await debugFile() const fileLines = fileLogs.split('\n') @@ -148,74 +176,80 @@ t.test('handles unknown error with logs and debug file', async (t) => { t.equal(logs.length, parseInt(lastLog) + 1) t.match(logs.error, [ 'code ECODE', - 'ERR SUMMARY Unknown error', - 'ERR DETAIL Unknown error', + 'Unknown error', + 'A complete log of this run can be found in:', ]) t.match(fileLogs, /\d+ error code ECODE/) - t.match(fileLogs, /\d+ error ERR SUMMARY Unknown error/) - t.match(fileLogs, /\d+ error ERR DETAIL Unknown error/) + t.match(fileLogs, /\d+ error Unknown error/) t.matchSnapshot(logs, 'logs') t.matchSnapshot(fileLines.map(l => l.replace(lineNumber, 'XX ')), 'debug file contents') }) -t.test('exit handler never called - loglevel silent', async (t) => { - const { logs, errors } = await mockExitHandler(t, { - config: { loglevel: 'silent' }, +t.test('exit handler never called', async t => { + t.test('loglevel silent', async (t) => { + const { logs, errors } = await mockExitHandler(t, { + config: { loglevel: 'silent' }, + }) + process.emit('exit', 1) + t.strictSame(logs, []) + t.strictSame(errors(), [''], 'one empty string') }) - process.emit('exit', 1) - t.strictSame(logs.error, []) - t.strictSame(errors(), [''], 'one empty string') -}) -t.test('exit handler never called - loglevel notice', async (t) => { - const { logs, errors } = await mockExitHandler(t) - process.emit('exit', 1) - t.equal(process.exitCode, 1) - t.match(logs.error, [ - 'Exit handler never called!', - /error with npm itself/, - ]) - t.strictSame(errors(), ['', ''], 'two empty string on output') -}) + t.test('loglevel notice', async (t) => { + const { logs, errors } = await mockExitHandler(t) + process.emit('exit', 1) + t.equal(process.exitCode, 1) + t.match(logs.error, [ + 'Exit handler never called!', + /error with npm itself/, + ]) + t.strictSame(errors(), []) + }) -t.test('exit handler never called - no npm', async (t) => { - const { logs, errors } = await mockExitHandler(t, { init: false }) - process.emit('exit', 1) - t.equal(process.exitCode, 1) - t.strictSame(logs.error, []) - t.strictSame(errors(), [''], 'one empty string') + t.test('no npm', async (t) => { + const { logs, errors } = await mockExitHandler(t, { init: false }) + process.emit('exit', 1) + t.equal(process.exitCode, 1) + t.strictSame(logs.error, []) + t.match(errors(), [`Error: Process exited unexpectedly with code: 1`]) + }) }) -t.test('exit handler called - no npm', async (t) => { - const { exitHandler, errors } = await mockExitHandler(t, { init: false }) - await exitHandler() - t.equal(process.exitCode, 1) - t.equal(errors().length, 1) - t.match(errors(), [/Error: Exit prior to setting npm in exit handler/]) -}) +t.test('exit handler called and no npm', async t => { + t.test('no npm', async (t) => { + const { exitHandler, errors } = await mockExitHandler(t, { init: false }) + await exitHandler() + t.equal(process.exitCode, 1) + t.equal(errors().length, 1) + t.match(errors(), [/Exit prior to setting npm in exit handler/]) + }) -t.test('exit handler called - no npm with error', async (t) => { - const { exitHandler, errors } = await mockExitHandler(t, { init: false }) - await exitHandler(err('something happened')) - t.equal(process.exitCode, 1) - t.equal(errors().length, 1) - t.match(errors(), [/Error: something happened/]) -}) + t.test('with error', async (t) => { + const { exitHandler, errors } = await mockExitHandler(t, { init: false }) + await exitHandler(err('something happened')) + t.equal(process.exitCode, 1) + t.equal(errors().length, 1) + t.match(errors(), [/Exit prior to setting npm in exit handler/]) + t.match(errors(), [/something happened/]) + }) -t.test('exit handler called - no npm with error without stack', async (t) => { - const { exitHandler, errors } = await mockExitHandler(t, { init: false }) - await exitHandler(err('something happened', {}, true)) - t.equal(process.exitCode, 1) - t.equal(errors().length, 1) - t.match(errors(), [/something happened/]) + t.test('with error without stack', async (t) => { + const { exitHandler, errors } = await mockExitHandler(t, { init: false }) + await exitHandler(err('something happened', {}, true)) + t.equal(process.exitCode, 1) + t.equal(errors().length, 1) + t.match(errors(), [/Exit prior to setting npm in exit handler/]) + t.match(errors(), [/something happened/]) + }) }) t.test('standard output using --json', async (t) => { const { exitHandler, outputs } = await mockExitHandler(t, { config: { json: true }, + error: err('Error: EBADTHING Something happened'), }) - await exitHandler(err('Error: EBADTHING Something happened')) + await exitHandler() t.equal(process.exitCode, 1) t.same( @@ -224,7 +258,7 @@ t.test('standard output using --json', async (t) => { error: { code: 'EBADTHING', // should default error code to E[A-Z]+ summary: 'Error: EBADTHING Something happened', - detail: 'Error: EBADTHING Something happened', + detail: '', }, }, 'should output expected json output' @@ -234,13 +268,14 @@ t.test('standard output using --json', async (t) => { t.test('merges output buffers errors with --json', async (t) => { const { exitHandler, outputs } = await mockExitHandler(t, { config: { json: true }, + error: err('Error: EBADTHING Something happened'), }) output.buffer({ output_data: 1 }) output.buffer(JSON.stringify({ more_data: 2 })) output.buffer('not json, will be ignored') - await exitHandler(err('Error: EBADTHING Something happened')) + await exitHandler() t.equal(process.exitCode, 1) t.same( @@ -251,7 +286,7 @@ t.test('merges output buffers errors with --json', async (t) => { error: { code: 'EBADTHING', // should default error code to E[A-Z]+ summary: 'Error: EBADTHING Something happened', - detail: 'Error: EBADTHING Something happened', + detail: '', }, }, 'should output expected json output' @@ -259,12 +294,14 @@ t.test('merges output buffers errors with --json', async (t) => { }) t.test('output buffer without json', async (t) => { - const { exitHandler, outputs, logs } = await mockExitHandler(t) + const { exitHandler, outputs, logs } = await mockExitHandler(t, { + error: err('Error: EBADTHING Something happened'), + }) output.buffer('output_data') output.buffer('more_data') - await exitHandler(err('Error: EBADTHING Something happened')) + await exitHandler() t.equal(process.exitCode, 1) t.same( @@ -276,13 +313,15 @@ t.test('output buffer without json', async (t) => { }) t.test('throw a non-error obj', async (t) => { - const { exitHandler, logs } = await mockExitHandler(t) - - await exitHandler({ - code: 'ESOMETHING', - message: 'foo bar', + const { exitHandler, logs } = await mockExitHandler(t, { + error: { + code: 'ESOMETHING', + message: 'foo bar', + }, }) + await exitHandler() + t.equal(process.exitCode, 1) t.match(logs.error, [ "weird error { code: 'ESOMETHING', message: 'foo bar' }", @@ -290,9 +329,11 @@ t.test('throw a non-error obj', async (t) => { }) t.test('throw a string error', async (t) => { - const { exitHandler, logs } = await mockExitHandler(t) + const { exitHandler, logs } = await mockExitHandler(t, { + error: 'foo bar', + }) - await exitHandler('foo bar') + await exitHandler() t.equal(process.exitCode, 1) t.match(logs.error, [ @@ -308,9 +349,7 @@ t.test('update notification - shows even with loglevel error', async (t) => { await exitHandler() - t.match(logs.notice, [ - 'you should update npm!', - ]) + t.match(logs.notice, ['you should update npm!']) }) t.test('update notification - hidden with silent', async (t) => { @@ -333,25 +372,32 @@ t.test('npm.config not ready', async (t) => { t.equal(process.exitCode, 1) t.equal(errors().length, 1) + t.match(errors(), [ - /Error: Exit prior to config file resolving./, + /Exit prior to config file resolving/, ], 'should exit with config error msg') + t.match(errors(), [ + /call config.load\(\) before reading values/, + ], 'should exit with cause error msg') t.strictSame(logs, [], 'no logs if it doesnt load') }) t.test('no logs dir', async (t) => { const { exitHandler, logs } = await mockExitHandler(t, { config: { 'logs-max': 0 }, + error: new Error('an error'), }) - await exitHandler(new Error()) - - t.match(logs.error[2], - 'Log files were not written due to the config logs-max=0') + await exitHandler() + t.match(logs.error, [ + 'an error', + 'Log files were not written due to the config logs-max=0', + ]) t.match(logs.filter((l) => l.includes('npm.load.mkdirplogs')), []) }) t.test('timers fail to write', async (t) => { const { exitHandler, logs } = await mockExitHandler(t, { + error: new Error('an error'), config: (dirs) => ({ 'logs-dir': resolve(dirs.prefix, 'LOGS_DIR'), timing: true, @@ -373,13 +419,14 @@ t.test('timers fail to write', async (t) => { }, }) - await exitHandler(new Error()) + await exitHandler() t.match(logs.warn[0], `timing could not write timing file: Error: err`) }) t.test('log files fail to write', async (t) => { const { exitHandler, logs } = await mockExitHandler(t, { + error: new Error('an error'), config: (dirs) => ({ 'logs-dir': resolve(dirs.prefix, 'LOGS_DIR'), }), @@ -398,31 +445,32 @@ t.test('log files fail to write', async (t) => { }, }) - await exitHandler(new Error()) + await exitHandler() - t.match(logs.error[2], `error writing to the directory`) + t.match(logs.error, ['an error', `error writing to the directory`]) }) t.test('files from error message', async (t) => { const { exitHandler, logs, cache } = await mockExitHandler(t, { + error: err('Error message'), files: [ ['error-file.txt', '# error file content'], ], }) - await exitHandler(err('Error message')) + await exitHandler() const logFiles = fs.readdirSync(join(cache, '_logs')) const errorFileName = logFiles.find(f => f.endsWith('error-file.txt')) const errorFile = fs.readFileSync(join(cache, '_logs', errorFileName)).toString() - - t.match(logs[2], /For a full report see:\n.*-error-file\.txt/) + t.match(logs, ['Error message', /For a full report see:\n.*-error-file\.txt/]) t.match(errorFile, '# error file content') t.match(errorFile, 'Log files:') }) t.test('files from error message with error', async (t) => { const { exitHandler, logs } = await mockExitHandler(t, { + error: err('Error message'), config: (dirs) => ({ 'logs-dir': resolve(dirs.prefix, 'LOGS_DIR'), }), @@ -441,7 +489,7 @@ t.test('files from error message with error', async (t) => { }, }) - await exitHandler(err('Error message')) + await exitHandler() t.match(logs.warn[0], /Could not write error message to.*error-file\.txt.*err/) }) @@ -513,47 +561,54 @@ t.test('unfinished timers', async (t) => { }) t.test('uses code from errno', async (t) => { - const { exitHandler, logs } = await mockExitHandler(t) + const { exitHandler, logs } = await mockExitHandler(t, { + error: err('Error with errno', { errno: 127 }), + }) - await exitHandler(err('Error with errno', { errno: 127 })) + await exitHandler() t.equal(process.exitCode, 127) t.match(logs.error, ['errno 127']) }) t.test('uses code from number', async (t) => { - const { exitHandler, logs } = await mockExitHandler(t) + const { exitHandler, logs } = await mockExitHandler(t, { + error: err('Error with code type number', 404), + }) - await exitHandler(err('Error with code type number', 404)) + await exitHandler() t.equal(process.exitCode, 404) t.match(logs.error, ['code 404']) }) t.test('uses all err special properties', async t => { - const { exitHandler, logs } = await mockExitHandler(t) - const keys = ['code', 'syscall', 'file', 'path', 'dest', 'errno'] const properties = keys.reduce((acc, k) => { acc[k] = `${k}-hey` return acc }, {}) - await exitHandler(err('Error with code type number', properties)) + const { exitHandler, logs } = await mockExitHandler(t, { + error: err('Error with code type number', properties), + }) + + await exitHandler() t.equal(process.exitCode, 1) t.match(logs.error, keys.map((k) => `${k} ${k}-hey`), 'all special keys get logged') }) t.test('verbose logs replace info on err props', async t => { - const { exitHandler, logs } = await mockExitHandler(t, { - config: { loglevel: 'verbose' }, - }) - const keys = ['type', 'stack', 'pkgid'] const properties = keys.reduce((acc, k) => { acc[k] = `${k}-https://user:pass@registry.npmjs.org/` return acc }, {}) - await exitHandler(err('Error with code type number', properties)) + const { exitHandler, logs } = await mockExitHandler(t, { + error: err('Error with code type number', properties), + config: { loglevel: 'verbose' }, + }) + + await exitHandler() t.equal(process.exitCode, 1) t.match( logs.verbose.filter(l => !/^(logfile|title|argv)/.test(l)), @@ -571,12 +626,14 @@ t.test('call exitHandler with no error', async (t) => { t.match(logs.error, []) }) -t.test('defaults to log error msg if stack is missing when unloaded', async (t) => { - const { exitHandler, logs, errors } = await mockExitHandler(t, { load: false }) +t.test('defaults to log error msg if stack is missing when no npm', async (t) => { + const { exitHandler, logs, errors } = await mockExitHandler(t, { + init: false, + }) await exitHandler(err('Error with no stack', { code: 'ENOSTACK', errno: 127 }, true)) t.equal(process.exitCode, 127) - t.strictSame(errors(), ['Error with no stack'], 'should use error msg') + t.match(errors(), ['Error with no stack'], 'should use error msg') t.strictSame(logs.error, []) }) @@ -590,18 +647,21 @@ t.test('exits uncleanly when only emitting exit event', async (t) => { }) t.test('do no fancy handling for shellouts', async t => { - const mockShelloutExit = (t) => mockExitHandler(t, { + const mockShelloutExit = (t, opts) => mockExitHandler(t, { command: 'exec', - exec: true, argv: ['-c', 'exit'], config: { timing: false, + ...opts.config, }, + ...opts, }) t.test('shellout with a numeric error code', async t => { - const { exitHandler, logs, errors } = await mockShelloutExit(t) - await exitHandler(err('', 5)) + const { exitHandler, logs, errors } = await mockShelloutExit(t, { + error: err('', 5), + }) + await exitHandler() t.equal(process.exitCode, 5, 'got expected exit code') t.strictSame(logs.error, [], 'no noisy warnings') t.strictSame(logs.warn, [], 'no noisy warnings') @@ -609,19 +669,37 @@ t.test('do no fancy handling for shellouts', async t => { }) t.test('shellout without a numeric error code (something in npm)', async t => { - const { exitHandler, logs, errors } = await mockShelloutExit(t) - await exitHandler(err('', 'banana stand')) + const { exitHandler, logs, errors } = await mockShelloutExit(t, { + error: err('', 'banana stand'), + }) + await exitHandler() t.equal(process.exitCode, 1, 'got expected exit code') // should log some warnings and errors, because something weird happened t.strictNotSame(logs.error, [], 'bring the noise') - t.strictSame(errors(), ['']) + t.strictSame(errors(), []) }) t.test('shellout with code=0 (extra weird?)', async t => { - const { exitHandler, logs, errors } = await mockShelloutExit(t) - await exitHandler(Object.assign(new Error(), { code: 0 })) + const { exitHandler, logs, errors } = await mockShelloutExit(t, { + error: Object.assign(new Error(), { code: 0 }), + }) + await exitHandler() t.equal(process.exitCode, 1, 'got expected exit code') t.strictNotSame(logs.error, [], 'bring the noise') - t.strictSame(errors(), ['']) + t.strictSame(errors(), []) + }) + + t.test('shellout with json', async t => { + const { exitHandler, logs, outputs } = await mockShelloutExit(t, { + error: err('', 5), + config: { json: true }, + }) + await exitHandler() + t.equal(process.exitCode, 5, 'got expected exit code') + t.strictSame(logs.error, [], 'no noisy warnings') + t.strictSame(logs.warn, [], 'no noisy warnings') + t.match(JSON.parse(outputs), { + error: { code: 5, summary: '', detail: '' }, + }) }) }) diff --git a/test/lib/npm.js b/test/lib/npm.js index a965a79a3f528..6525708dc5795 100644 --- a/test/lib/npm.js +++ b/test/lib/npm.js @@ -559,3 +559,11 @@ t.test('usage', async t => { } }) }) + +t.test('print usage if non-command param provided', async t => { + const { npm, outputs } = await loadMockNpm(t) + + await t.rejects(npm.exec('tset'), { command: 'tset', exitCode: 1 }) + t.match(outputs[0], 'Unknown command: "tset"') + t.match(outputs[0], 'Did you mean this?') +}) diff --git a/test/lib/utils/error-message.js b/test/lib/utils/error-message.js index 1ba5865592edb..55b6053985a8c 100644 --- a/test/lib/utils/error-message.js +++ b/test/lib/utils/error-message.js @@ -40,7 +40,7 @@ const loadMockNpm = async (t, { errorMocks, ...opts } = {}) => { }) return { ...res, - errorMessage: (er) => mockError(er, res.npm), + errorMessage: (er) => mockError.errorMessage(er, res.npm), } }