feat: streaming debug logfile

This decouples the log file writing from the terminal logging. We now
open an append only file at the start of the process and stream logs to
it. We still only display the log file message in timing mode or if
there is an error, but the file is still written regardless.

All logging now goes through `proc-log` and this is the first step to
removing `npmlog`. For now `npmlog` is still used for the terminal
logging but with a shim in front of it to make it easier to test and
use in conjunction with `proc-log`. Ref: npm/statusboard#366

This also refactors many of the tests to always use an explicit
`t.testdir` for their cache since the file is opened on each `new Npm()`.
Tests are also refactored to use more of `MockNpm` with behavior to
add config items and load `npm` if necessary. A new fixture `mockGlobals`
was also added to make much of this more ergonomic. Ref: npm/statusboard#410

Closes npm/statusboard#411
Closes npm/statusboard#367

PR-URL: https://github.com/npm/cli/pull/4062
Credit: @lukekarrys
Close: #4062
Reviewed-by: @wraithgar

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')
   })