diff --git a/lib/utils/error-handler.js b/lib/utils/error-handler.js index f713bf0212ce0..16abcd67ce303 100644 --- a/lib/utils/error-handler.js +++ b/lib/utils/error-handler.js @@ -90,9 +90,7 @@ const exit = (code, noLog) => { log.verbose('exit', code) if (log.level === 'silent') noLog = true - const reallyExit = (er) => { - if (er && !code) code = typeof er.errno === 'number' ? er.errno : 1 - + const reallyExit = () => { itWorked = !code // Exit directly -- nothing in the CLI should still be running in the @@ -141,9 +139,9 @@ const errorHandler = (er) => { return exit(1, true) } - const m = er.code || er.message.match(/^(?:Error: )?(E[A-Z]+)/) - if (m && !er.code) { - er.code = m + if (!er.code) { + const matchErrorCode = er.message.match(/^(?:Error: )?(E[A-Z]+)/) + er.code = matchErrorCode && matchErrorCode[1] } for (const k of ['type', 'stack', 'statusCode', 'pkgid']) { diff --git a/tap-snapshots/test-lib-utils-error-handler.js-TAP.test.js b/tap-snapshots/test-lib-utils-error-handler.js-TAP.test.js new file mode 100644 index 0000000000000..909051cdab506 --- /dev/null +++ b/tap-snapshots/test-lib-utils-error-handler.js-TAP.test.js @@ -0,0 +1,23 @@ +/* IMPORTANT + * This snapshot file is auto-generated, but designed for humans. + * It should be checked into source control and tracked carefully. + * Re-generate by setting TAP_SNAPSHOT=1 and running tests. + * Make sure to inspect the output below. Do not ignore changes! + */ +'use strict' +exports[`test/lib/utils/error-handler.js TAP handles unknown error > should have expected log contents for unknown error 1`] = ` +0 verbose code 1 +1 error foo A complete log of this run can be found in: +1 error foo {CWD}/cachefolder/_logs/expecteddate-debug.log +2 verbose stack Error: ERROR +3 verbose cwd {CWD} +4 verbose Foo 1.0.0 +5 verbose argv "/node" "{CWD}/test/lib/utils/error-handler.js" +6 verbose node v1.0.0 +7 verbose npm v1.0.0 +8 error foo code ERROR +9 error foo ERR ERROR +10 error foo ERR ERROR +11 verbose exit 1 + +` diff --git a/test/lib/utils/error-handler.js b/test/lib/utils/error-handler.js new file mode 100644 index 0000000000000..840b3a3565031 --- /dev/null +++ b/test/lib/utils/error-handler.js @@ -0,0 +1,522 @@ +/* eslint-disable no-extend-native */ +/* eslint-disable no-global-assign */ +const EventEmitter = require('events') +const requireInject = require('require-inject') +const t = require('tap') + +// NOTE: Although these unit tests may look like the rest on the surface, +// they are in fact very special due to the amount of things hooking directly +// to global process and variables defined in the module scope. That makes +// for tests that are very interdependent and their order are important. + +// generic error to be used in tests +const err = Object.assign(new Error('ERROR'), { code: 'ERROR' }) +err.stack = 'Error: ERROR' + +const redactCwd = (path) => { + const normalizePath = p => p + .replace(/\\+/g, '/') + .replace(/\r\n/g, '\n') + return normalizePath(path) + .replace(new RegExp(normalizePath(process.cwd()), 'g'), '{CWD}') +} + +t.cleanSnapshot = (str) => redactCwd(str) + +// internal modules mocks +const cacheFile = { + append: () => null, + write: () => null +} +const config = { + values: { + cache: 'cachefolder', + timing: true + }, + loaded: true, + updateNotification: null, + get (key) { + return this.values[key] + } +} + +const npm = { + version: '1.0.0', + config +} + +const npmlog = { + disableProgress: () => null, + log (level, ...args) { + this.record.push({ + id: this.record.length, + level, + message: args.reduce((res, i) => `${res} ${i.message ? i.message : i}`, ''), + prefix: level !== 'verbose' ? 'foo' : '' + }) + }, + error (...args) { this.log('error', ...args) }, + info (...args) { this.log('info', ...args) }, + level: 'silly', + levels: { + silly: 0, + verbose: 1, + info: 2, + error: 3, + silent: 4 + }, + notice (...args) { this.log('notice', ...args) }, + record: [], + verbose (...args) { this.log('verbose', ...args) } +} + +const metrics = { + stop: () => null +} + +// overrides OS type/release for cross platform snapshots +const os = require('os') +os.type = () => 'Foo' +os.release = () => '1.0.0' + +// bootstrap tap before cutting off process ref +t.test('ok', (t) => { + t.ok('ok') + t.end() +}) +// cut off process from script so that it won't quit the test runner +// while trying to run through the myriad of cases +const _process = process +process = Object.assign( + new EventEmitter(), + { + argv: ['/node', ..._process.argv.slice(1)], + cwd: _process.cwd, + env: _process.env, + exit () {}, + exitCode: 0, + version: 'v1.0.0', + stdout: { write (_, cb) { cb() } }, + stderr: { write () {} } + } +) +// needs to put process back in its place +// in order for tap to exit properly +t.teardown(() => { + process = _process +}) + +const mocks = { + npmlog, + '../../../lib/npm.js': npm, + '../../../lib/utils/error-message.js': (err) => ({ + ...err, + summary: [['ERR', err.message]], + detail: [['ERR', err.message]] + }), + '../../../lib/utils/metrics.js': metrics, + '../../../lib/utils/cache-file.js': cacheFile +} + +requireInject.installGlobally('../../../lib/utils/error-handler.js', mocks) +let errorHandler = require('../../../lib/utils/error-handler.js') + +t.test('default exit code', (t) => { + t.plan(1) + + // manually simulate timing handlers + process.emit('timing', 'foo', 1) + process.emit('timing', 'foo', 2) + + // generates logfile name with mocked date + const _toISOString = Date.prototype.toISOString + Date.prototype.toISOString = () => 'expecteddate' + + npmlog.level = 'silent' + const _exit = process.exit + process.exit = (code) => { + t.equal(code, 1, 'should default to error code 1') + } + + // skip console.error logs + const _error = console.error + console.error = () => null + + process.emit('exit', 1) + + t.teardown(() => { + npmlog.level = 'silly' + process.exit = _exit + console.error = _error + Date.prototype.toISOString = _toISOString + }) +}) + +t.test('handles unknown error', (t) => { + t.plan(2) + + cacheFile.write = (filename, content) => { + t.equal( + redactCwd(filename), + '{CWD}/cachefolder/_logs/expecteddate-debug.log', + 'should use expected log filename' + ) + t.matchSnapshot( + content, + 'should have expected log contents for unknown error' + ) + } + + errorHandler(err) + + t.teardown(() => { + cacheFile.write = () => null + }) + t.end() +}) + +t.test('npm.config not ready', (t) => { + t.plan(1) + + config.loaded = false + + const _error = console.error + console.error = (msg) => { + t.match( + msg, + /Error: Exit prior to config file resolving./, + 'should exit with config error msg' + ) + } + + errorHandler() + + t.teardown(() => { + console.error = _error + config.loaded = true + }) +}) + +t.test('fail to write logfile', (t) => { + t.plan(1) + + cacheFile.write = () => { + throw err + } + t.teardown(() => { + cacheFile.write = () => null + }) + + t.doesNotThrow( + () => errorHandler(err), + 'should not throw on cache write failure' + ) +}) + +t.test('console.log output using --json', (t) => { + t.plan(1) + + config.values.json = true + + const _log = console.log + console.log = (jsonOutput) => { + t.deepEqual( + JSON.parse(jsonOutput), + { + error: { + code: 'EBADTHING', // should default error code to E[A-Z]+ + summary: 'Error: EBADTHING Something happened', + detail: 'Error: EBADTHING Something happened' + } + }, + 'should output expected json output' + ) + } + + errorHandler(new Error('Error: EBADTHING Something happened')) + + t.teardown(() => { + console.log = _log + delete config.values.json + }) +}) + +t.test('throw a non-error obj', (t) => { + t.plan(3) + + const weirdError = { + code: 'ESOMETHING', + message: 'foo bar' + } + + const _logError = npmlog.error + npmlog.error = (title, err) => { + t.equal(title, 'weird error', 'should name it a weird error') + t.deepEqual(err, weirdError, 'should log given weird error') + } + + const _exit = process.exit + process.exit = (code) => { + t.equal(code, 1, 'should exit with code 1') + } + + errorHandler(weirdError) + + t.teardown(() => { + process.exit = _exit + npmlog.error = _logError + }) +}) + +t.test('throw a string error', (t) => { + t.plan(3) + + const error = 'foo bar' + + const _logError = npmlog.error + npmlog.error = (title, err) => { + t.equal(title, '', 'should have an empty name ref') + t.deepEqual(err, 'foo bar', 'should log string error') + } + + const _exit = process.exit + process.exit = (code) => { + t.equal(code, 1, 'should exit with code 1') + } + + errorHandler(error) + + t.teardown(() => { + process.exit = _exit + npmlog.error = _logError + }) +}) + +t.test('update notification', (t) => { + t.plan(2) + + const updateMsg = 'you should update npm!' + npm.updateNotification = updateMsg + + const _notice = npmlog.notice + npmlog.notice = (prefix, msg) => { + t.equal(prefix, '', 'should have no prefix') + t.equal(msg, updateMsg, 'should show update message') + } + + errorHandler(err) + + t.teardown(() => { + npmlog.notice = _notice + delete npm.updateNotification + }) +}) + +t.test('on exit handler', (t) => { + t.plan(2) + + const _exit = process.exit + process.exit = (code) => { + t.equal(code, 1, 'should default to error code 1') + } + + process.once('timeEnd', (msg) => { + t.equal(msg, 'npm', 'should trigger timeEnd for npm') + }) + + // skip console.error logs + const _error = console.error + console.error = () => null + + process.emit('exit', 1) + + t.teardown(() => { + console.error = _error + process.exit = _exit + }) +}) + +t.test('it worked', (t) => { + t.plan(2) + + config.values.timing = false + + const _exit = process.exit + process.exit = (code) => { + process.exit = _exit + t.equal(code, 0, 'should exit with code 0') + + const _info = npmlog.info + npmlog.info = (msg) => { + npmlog.info = _info + t.equal(msg, 'ok', 'should log ok if "it worked"') + } + + process.emit('exit', 0) + } + + t.teardown(() => { + process.exit = _exit + config.values.timing = true + }) + + errorHandler.exit(0) +}) + +t.test('uses code from errno', (t) => { + t.plan(1) + + // RESET MODULE INTERNAL VARS AND GLOBAL REFS + requireInject.installGlobally.andClearCache('../../../lib/utils/error-handler.js', mocks) + errorHandler = require('../../../lib/utils/error-handler.js') + + npmlog.level = 'silent' + const _exit = process.exit + process.exit = (code) => { + t.equal(code, 127, 'should use set errno') + } + + errorHandler(Object.assign( + new Error('Error with errno'), + { + errno: 127 + } + )) + + t.teardown(() => { + npmlog.level = 'silly' + process.exit = _exit + }) +}) + +t.test('uses exitCode as code if using a number', (t) => { + t.plan(1) + + // RESET MODULE INTERNAL VARS AND GLOBAL REFS + requireInject.installGlobally.andClearCache( + '../../../lib/utils/error-handler.js', + mocks + ) + errorHandler = require('../../../lib/utils/error-handler.js') + + npmlog.level = 'silent' + const _exit = process.exit + process.exit = (code) => { + t.equal(code, 404, 'should use code if a number') + } + + errorHandler(Object.assign( + new Error('Error with code type number'), + { + code: 404 + } + )) + + t.teardown(() => { + npmlog.level = 'silly' + process.exit = _exit + }) +}) + +t.test('call errorHandler with no error', (t) => { + t.plan(1) + + // RESET MODULE INTERNAL VARS AND GLOBAL REFS + requireInject.installGlobally.andClearCache( + '../../../lib/utils/error-handler.js', + mocks + ) + errorHandler = require('../../../lib/utils/error-handler.js') + + const _exit = process.exit + process.exit = (code) => { + t.equal(code, 0, 'should exit with code 0') + } + + t.teardown(() => { + process.exit = _exit + }) + + errorHandler() +}) + +t.test('callback called twice', (t) => { + t.plan(2) + + const _verbose = npmlog.verbose + npmlog.verbose = (key, value) => { + t.equal(key, 'stack', 'should log stack in verbose level') + t.match( + value, + /Error: Callback called more than once./, + 'should have expected error msg' + ) + npmlog.verbose = _verbose + } + + errorHandler() +}) + +t.test('defaults to log error msg if stack is missing', (t) => { + t.plan(1) + + const noStackErr = Object.assign( + new Error('Error with no stack'), + { + code: 'ENOSTACK', + errno: 127 + } + ) + delete noStackErr.stack + + npm.config.loaded = false + + const _error = console.error + console.error = (msg) => { + console.error = _error + npm.config.loaded = true + t.equal(msg, 'Error with no stack', 'should use error msg') + } + + errorHandler(noStackErr) +}) + +t.test('set it worked', (t) => { + t.plan(1) + + // RESET MODULE INTERNAL VARS AND GLOBAL REFS + requireInject.installGlobally.andClearCache( + '../../../lib/utils/error-handler.js', + mocks + ) + errorHandler = require('../../../lib/utils/error-handler.js') + + const _exit = process.exit + process.exit = () => { + t.ok('ok') + } + + t.teardown(() => { + process.exit = _exit + }) + + errorHandler.exit(0, true) +}) + +t.test('use exitCode when emitting exit event', (t) => { + t.plan(1) + + npmlog.level = 'silent' + const _exit = process.exit + process.exit = (code) => { + process.exit = _exit + t.equal(code, 1, 'should exit with code 1') + } + + t.teardown(() => { + process.exit = _exit + npmlog.level = 'silly' + }) + + process.emit('exit') +})