diff options
Diffstat (limited to 'test/lib/utils/exit-handler.js')
-rw-r--r-- | test/lib/utils/exit-handler.js | 618 |
1 files changed, 332 insertions, 286 deletions
diff --git a/test/lib/utils/exit-handler.js b/test/lib/utils/exit-handler.js index adc7c3f4e..54bf48f89 100644 --- a/test/lib/utils/exit-handler.js +++ b/test/lib/utils/exit-handler.js @@ -1,177 +1,213 @@ -/* eslint-disable no-extend-native */ -/* eslint-disable no-global-assign */ const t = require('tap') -const EventEmitter = require('events') const os = require('os') -const fs = require('fs') -const path = require('path') - -const { real: mockNpm } = require('../../fixtures/mock-npm') - -// 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}') +const EventEmitter = require('events') +const { format } = require('../../../lib/utils/log-file') +const { load: loadMockNpm } = require('../../fixtures/mock-npm') +const mockGlobals = require('../../fixtures/mock-globals') +const { cleanCwd, cleanDate } = require('../../fixtures/clean-snapshot') + +const pick = (obj, ...keys) => keys.reduce((acc, key) => { + acc[key] = obj[key] + return acc +}, {}) + +t.formatSnapshot = (obj) => { + if (Array.isArray(obj)) { + return obj + .map((i) => Array.isArray(i) ? i.join(' ') : i) + .join('\n') + } + return obj } -t.cleanSnapshot = (str) => redactCwd(str) - -const cacheFolder = t.testdir({}) -const logFile = path.resolve(cacheFolder, '_logs', 'expecteddate-debug.log') -const timingFile = path.resolve(cacheFolder, '_timing.json') - -const { Npm } = mockNpm(t, { - '../../package.json': { - version: '1.0.0', - }, -}) -const npm = new Npm() - -t.before(async () => { - await npm.load() - npm.config.set('cache', cacheFolder) -}) +t.cleanSnapshot = (path) => cleanDate(cleanCwd(path)) +// Config loading is dependent on env so strip those from snapshots + .replace(/.*timing config:load:.*\n/gm, '') + .replace(/(Completed in )\d+(ms)/g, '$1{TIME}$2') // cut off process from script so that it won't quit the test runner // while trying to run through the myriad of cases. need to make it // have all the functions signal-exit relies on so that it doesn't // nerf itself, thinking global.process is broken or gone. -const _process = process -process = Object.assign( - new EventEmitter(), - { - argv: ['/node', ..._process.argv.slice(1)], - cwd: _process.cwd, - env: _process.env, +mockGlobals(t, { + process: Object.assign(new EventEmitter(), { + ...pick(process, 'execPath', 'stdout', 'stderr', 'cwd', 'env'), + argv: ['/node', ...process.argv.slice(1)], version: 'v1.0.0', + kill: () => {}, + reallyExit: (code) => process.exit(code), + pid: 123456, exit: (code) => { process.exitCode = code || process.exitCode || 0 process.emit('exit', process.exitCode) }, - stdout: { write (_, cb) { - cb() - } }, - stderr: { write () {} }, - hrtime: _process.hrtime, - kill: () => {}, - reallyExit: (code) => process.exit(code), - pid: 123456, + }), +}, { replace: true }) + +const mockExitHandler = async (t, { init, load, testdir, config } = {}) => { + const errors = [] + mockGlobals(t, { 'console.error': (err) => errors.push(err) }) + + const { npm, logMocks, ...rest } = await loadMockNpm(t, { + init, + load, + testdir, + mocks: { + '../../package.json': { + version: '1.0.0', + }, + }, + config: { + loglevel: 'notice', + ...config, + }, + }) + + const exitHandler = t.mock('../../../lib/utils/exit-handler.js', { + '../../../lib/utils/error-message.js': (err) => ({ + ...err, + summary: [['ERR SUMMARY', err.message]], + detail: [['ERR DETAIL', err.message]], + }), + os: { + type: () => 'Foo', + release: () => '1.0.0', + }, + ...logMocks, + }) + + if (npm) { + exitHandler.setNpm(npm) } -) - -const osType = os.type -const osRelease = os.release -// overrides OS type/release for cross platform snapshots -os.type = () => 'Foo' -os.release = () => '1.0.0' - -// generates logfile name with mocked date -const _toISOString = Date.prototype.toISOString -Date.prototype.toISOString = () => 'expecteddate' - -const consoleError = console.error -const errors = [] -console.error = (err) => { - errors.push(err) -} -t.teardown(() => { - os.type = osType - os.release = osRelease - // needs to put process back in its place in order for tap to exit properly - process = _process - Date.prototype.toISOString = _toISOString - console.error = consoleError -}) -t.afterEach(() => { - errors.length = 0 - npm.log.level = 'silent' - // clear out the 'A complete log' message - npm.log.record.length = 0 - delete process.exitCode -}) + t.teardown(() => { + delete process.exitCode + process.removeAllListeners('exit') + }) -const mocks = { - '../../../lib/utils/error-message.js': (err) => ({ - ...err, - summary: [['ERR', err.message]], - detail: [['ERR', err.message]], - }), + return { + ...rest, + errors, + 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(resolve => { + process.once('exit', resolve) + exitHandler(...args) + }), + } } -const exitHandler = t.mock('../../../lib/utils/exit-handler.js', mocks) -exitHandler.setNpm(npm) - -t.test('exit handler never called - loglevel silent', (t) => { - npm.log.level = 'silent' - process.emit('exit', 1) - const logData = fs.readFileSync(logFile, 'utf8') - t.match(logData, 'Exit handler never called!') - t.match(errors, [''], 'logs one empty string to console.error') - t.end() -}) +// Create errors with properties to be used in tests +const err = (message = '', options = {}, noStack = false) => { + const e = Object.assign( + new Error(message), + typeof options !== 'object' ? { code: options } : options + ) + e.stack = options.stack || `Error: ${message}` + if (noStack) { + delete e.stack + } + return e +} -t.test('exit handler never called - loglevel notice', (t) => { - npm.log.level = 'notice' - process.emit('exit', 1) - const logData = fs.readFileSync(logFile, 'utf8') - t.match(logData, 'Exit handler never called!') - t.match(errors, ['', ''], 'logs two empty strings to console.error') - t.end() -}) +t.test('handles unknown error with logs and debug file', async (t) => { + const { exitHandler, debugFile, logs } = await mockExitHandler(t) -t.test('handles unknown error', (t) => { - t.plan(2) + await exitHandler(err('Unknown error', 'ECODE')) - npm.log.level = 'notice' + const debugContent = await debugFile() - process.once('timeEnd', (msg) => { - t.equal(msg, 'npm', 'should trigger timeEnd for npm') + t.equal(process.exitCode, 1) + logs.forEach((logItem, i) => { + const logLines = format(i, ...logItem).trim().split(os.EOL) + logLines.forEach((line) => { + t.match(debugContent.trim(), line, 'log appears in debug file') + }) }) - exitHandler(err) - const logData = fs.readFileSync(logFile, 'utf8') - t.matchSnapshot( - logData, - 'should have expected log contents for unknown error' - ) - t.end() + const lastLog = debugContent + .split('\n') + .reduce((__, l) => parseInt(l.match(/^(\d+)\s/)[1])) + t.equal(logs.length, lastLog + 1) + t.match(logs.error, [ + ['code', 'ECODE'], + ['ERR SUMMARY', 'Unknown error'], + ['ERR DETAIL', 'Unknown error'], + ]) + t.match(debugContent, /\d+ error code ECODE/) + t.match(debugContent, /\d+ error ERR SUMMARY Unknown error/) + t.match(debugContent, /\d+ error ERR DETAIL Unknown error/) + t.matchSnapshot(logs, 'logs') + t.matchSnapshot(debugContent, 'debug file contents') }) -t.test('fail to write logfile', (t) => { - t.plan(1) - - t.teardown(() => { - npm.config.set('cache', cacheFolder) +t.test('exit handler never called - loglevel silent', async (t) => { + const { logs, errors } = await mockExitHandler(t, { + config: { loglevel: 'silent' }, }) + process.emit('exit', 1) + t.match(logs.error, [ + ['', /Exit handler never called/], + ['', /error with npm itself/], + ]) + t.strictSame(errors, [''], 'logs one empty string to console.error') +}) - const badDir = t.testdir({ - _logs: 'is a file', - }) +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, ['', ''], 'logs two empty strings to console.error') +}) + +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.match(logs.error, [ + ['', /Exit handler never called/], + ['', /error with npm itself/], + ]) + t.strictSame(errors, [''], 'logs one empty string to console.error') +}) - npm.config.set('cache', badDir) +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.match(errors, [/Error: Exit prior to setting npm in exit handler/]) +}) - t.doesNotThrow( - () => exitHandler(err), - 'should not throw on cache write failure' - ) +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.match(errors, [/Error: something happened/]) }) -t.test('console.log output using --json', (t) => { - t.plan(1) +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.match(errors, [/something happened/]) +}) - npm.config.set('json', true) - t.teardown(() => { - npm.config.set('json', false) +t.test('console.log output using --json', async (t) => { + const { exitHandler, errors } = await mockExitHandler(t, { + config: { + json: true, + }, }) - exitHandler(new Error('Error: EBADTHING Something happened')) + await exitHandler(err('Error: EBADTHING Something happened')) + + t.equal(process.exitCode, 1) t.same( JSON.parse(errors[0]), { @@ -185,213 +221,223 @@ t.test('console.log output using --json', (t) => { ) }) -t.test('throw a non-error obj', (t) => { - t.plan(2) +t.test('throw a non-error obj', async (t) => { + const { exitHandler, logs } = await mockExitHandler(t) - const weirdError = { + await exitHandler({ code: 'ESOMETHING', message: 'foo bar', - } - - process.once('exit', code => { - t.equal(code, 1, 'exits with exitCode 1') }) - exitHandler(weirdError) - t.match( - npm.log.record.find(r => r.level === 'error'), - { message: 'foo bar' } - ) + + t.equal(process.exitCode, 1) + t.match(logs.error, [ + ['weird error', { code: 'ESOMETHING', message: 'foo bar' }], + ]) }) -t.test('throw a string error', (t) => { - t.plan(2) - const error = 'foo bar' +t.test('throw a string error', async (t) => { + const { exitHandler, logs } = await mockExitHandler(t) - process.once('exit', code => { - t.equal(code, 1, 'exits with exitCode 1') - }) - exitHandler(error) - t.match( - npm.log.record.find(r => r.level === 'error'), - { message: 'foo bar' } - ) + await exitHandler('foo bar') + + t.equal(process.exitCode, 1) + t.match(logs.error, [ + ['', 'foo bar'], + ]) }) -t.test('update notification', (t) => { - const updateMsg = 'you should update npm!' - npm.updateNotification = updateMsg - npm.log.level = 'silent' +t.test('update notification', async (t) => { + const { exitHandler, logs, npm } = await mockExitHandler(t) + npm.updateNotification = 'you should update npm!' - t.teardown(() => { - delete npm.updateNotification - }) + await exitHandler() - exitHandler() - t.match( - npm.log.record.find(r => r.level === 'notice'), - { message: 'you should update npm!' } - ) - t.end() + t.match(logs.notice, [ + ['', 'you should update npm!'], + ]) }) -t.test('npm.config not ready', (t) => { - t.plan(1) +t.test('npm.config not ready', async (t) => { + const { exitHandler, logs, errors } = await mockExitHandler(t, { + load: false, + }) - const { Npm: Unloaded } = mockNpm(t) - const unloaded = new Unloaded() + await exitHandler() - t.teardown(() => { - exitHandler.setNpm(npm) + t.equal(process.exitCode, 1) + t.match(errors, [ + /Error: Exit prior to config file resolving./, + ], 'should exit with config error msg') + t.match(logs.verbose, [ + ['stack', /Error: Exit prior to config file resolving./], + ], 'should exit with config error msg') +}) + +t.test('timing with no error', async (t) => { + const { exitHandler, timingFile, npm, logs } = await mockExitHandler(t, { + config: { + timing: true, + }, }) - exitHandler.setNpm(unloaded) + await exitHandler() + const timingFileData = await timingFile() + + t.equal(process.exitCode, 0) + + t.match(logs.error, [ + ['', /A complete log of this run can be found in:[\s\S]*-debug-\d\.log/], + ]) - exitHandler() t.match( - errors[0], - /Error: Exit prior to config file resolving./, - 'should exit with config error msg' + timingFileData, + Object.keys(npm.finishedTimers).reduce((acc, k) => { + acc[k] = Number + return acc + }, {}) ) - t.end() + t.strictSame(npm.unfinishedTimers, new Map()) + t.match(timingFileData, { + command: [], + version: '1.0.0', + npm: Number, + logfile: String, + logfiles: [String], + }) }) -t.test('timing', (t) => { - npm.config.set('timing', true) - - t.teardown(() => { - fs.unlinkSync(timingFile) - npm.config.set('timing', false) +t.test('unfinished timers', async (t) => { + const { exitHandler, timingFile, npm } = await mockExitHandler(t, { + config: { + timing: true, + }, }) - exitHandler() - const timingData = JSON.parse(fs.readFileSync(timingFile, 'utf8')) - t.match(timingData, { version: '1.0.0', 'config:load:defaults': Number }) - t.end() -}) + process.emit('time', 'foo') + process.emit('time', 'bar') -t.test('timing - with error', (t) => { - npm.config.set('timing', true) + await exitHandler() + const timingFileData = await timingFile() - t.teardown(() => { - fs.unlinkSync(timingFile) - npm.config.set('timing', false) + t.equal(process.exitCode, 0) + t.match(npm.unfinishedTimers, new Map([['foo', Number], ['bar', Number]])) + t.match(timingFileData, { + command: [], + version: '1.0.0', + npm: Number, + logfile: String, + logfiles: [String], + unfinished: { + foo: [Number, Number], + bar: [Number, Number], + }, }) - - exitHandler(err) - const timingData = JSON.parse(fs.readFileSync(timingFile, 'utf8')) - t.match(timingData, { version: '1.0.0', 'config:load:defaults': Number }) - t.end() }) -t.test('uses code from errno', (t) => { - t.plan(1) +t.test('uses code from errno', async (t) => { + const { exitHandler, logs } = await mockExitHandler(t) - process.once('exit', code => { - t.equal(code, 127, 'should set exitCode from errno') - }) - exitHandler(Object.assign( - new Error('Error with errno'), - { - errno: 127, - } - )) + await exitHandler(err('Error with errno', { errno: 127 })) + t.equal(process.exitCode, 127) + t.match(logs.error, [['errno', 127]]) }) -t.test('uses code from number', (t) => { - t.plan(1) +t.test('uses code from number', async (t) => { + const { exitHandler, logs } = await mockExitHandler(t) - process.once('exit', code => { - t.equal(code, 404, 'should set exitCode from a number') - }) - exitHandler(Object.assign( - new Error('Error with code type number'), - { - code: 404, - } - )) + await exitHandler(err('Error with code type number', 404)) + t.equal(process.exitCode, 404) + t.match(logs.error, [['code', 404]]) }) -t.test('call exitHandler with no error', (t) => { - t.plan(1) - process.once('exit', code => { - t.equal(code, 0, 'should end up with exitCode 0 (default)') - }) - exitHandler() +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)) + t.equal(process.exitCode, 1) + t.match(logs.error, keys.map((k) => [k, `${k}-hey`]), 'all special keys get logged') }) -t.test('defaults to log error msg if stack is missing', (t) => { - const { Npm: Unloaded } = mockNpm(t) - const unloaded = new Unloaded() +t.test('verbose logs replace info on err props', async t => { + const { exitHandler, logs } = await mockExitHandler(t) - t.teardown(() => { - exitHandler.setNpm(npm) - }) + const keys = ['type', 'stack', 'statusCode', 'pkgid'] + const properties = keys.reduce((acc, k) => { + acc[k] = `${k}-https://user:pass@registry.npmjs.org/` + return acc + }, {}) - exitHandler.setNpm(unloaded) - const noStackErr = Object.assign( - new Error('Error with no stack'), - { - code: 'ENOSTACK', - errno: 127, - } + await exitHandler(err('Error with code type number', properties)) + t.equal(process.exitCode, 1) + t.match( + logs.verbose.filter(([p]) => p !== 'logfile'), + keys.map((k) => [k, `${k}-https://user:***@registry.npmjs.org/`]), + 'all special keys get replaced' ) - delete noStackErr.stack +}) - exitHandler(noStackErr) - t.equal(errors[0], 'Error with no stack', 'should use error msg') - t.end() +t.test('call exitHandler with no error', async (t) => { + const { exitHandler, logs } = await mockExitHandler(t) + + await exitHandler() + + t.equal(process.exitCode, 0) + 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 }) + + await exitHandler(err('Error with no stack', { code: 'ENOSTACK', errno: 127 }, true)) + t.equal(process.exitCode, 127) + t.same(errors, ['Error with no stack'], 'should use error msg') + t.match(logs.error, [ + ['code', 'ENOSTACK'], + ['errno', 127], + ]) }) -t.test('exits uncleanly when only emitting exit event', (t) => { - t.plan(2) +t.test('exits uncleanly when only emitting exit event', async (t) => { + const { logs } = await mockExitHandler(t) - npm.log.level = 'silent' process.emit('exit') - const logData = fs.readFileSync(logFile, 'utf8') - t.match(logData, 'Exit handler never called!') - t.match(process.exitCode, 1, 'exitCode coerced to 1') + + t.match(logs.error, [['', 'Exit handler never called!']]) + t.equal(process.exitCode, 1, 'exitCode coerced to 1') t.end() }) -t.test('do no fancy handling for shellouts', t => { - const { command } = npm - const LOG_RECORD = [] - npm.command = 'exec' +t.test('do no fancy handling for shellouts', async t => { + const { exitHandler, npm, logs } = await mockExitHandler(t) - t.teardown(() => { - npm.command = command - }) - t.beforeEach(() => LOG_RECORD.length = 0) + npm.command = 'exec' - const loudNoises = () => npm.log.record - .filter(({ level }) => ['warn', 'error'].includes(level)) + const loudNoises = () => + logs.filter(([level]) => ['warn', 'error'].includes(level)) - t.test('shellout with a numeric error code', t => { - t.plan(2) - process.once('exit', code => { - t.equal(code, 5, 'got expected exit code') - }) - exitHandler(Object.assign(new Error(), { code: 5 })) + t.test('shellout with a numeric error code', async t => { + await exitHandler(err('', 5)) + t.equal(process.exitCode, 5, 'got expected exit code') t.strictSame(loudNoises(), [], 'no noisy warnings') }) - t.test('shellout without a numeric error code (something in npm)', t => { - t.plan(2) - process.once('exit', code => { - t.equal(code, 1, 'got expected exit code') - }) - exitHandler(Object.assign(new Error(), { code: 'banana stand' })) + t.test('shellout without a numeric error code (something in npm)', async t => { + await exitHandler(err('', 'banana stand')) + t.equal(process.exitCode, 1, 'got expected exit code') // should log some warnings and errors, because something weird happened t.strictNotSame(loudNoises(), [], 'bring the noise') t.end() }) - t.test('shellout with code=0 (extra weird?)', t => { - t.plan(2) - process.once('exit', code => { - t.equal(code, 1, 'got expected exit code') - }) - exitHandler(Object.assign(new Error(), { code: 0 })) + t.test('shellout with code=0 (extra weird?)', async t => { + await exitHandler(Object.assign(new Error(), { code: 0 })) + t.equal(process.exitCode, 1, 'got expected exit code') t.strictNotSame(loudNoises(), [], 'bring the noise') }) |