nodejs/deps/npm/test/lib/cli/exit-handler.js

const fs = require('node:fs')
const { join, resolve } = require('node:path')
const EventEmitter = require('node:events')
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')
const tmock = require('../../fixtures/tmock')
const { version: NPM_VERSION } = require('../../../package.json')

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 = (path) => cleanDate(cleanCwd(path))
  // Config loading is dependent on env so strip those from snapshots
  .replace(/.*timing config:load:.*\n/gm, '')
  // logfile cleaning is not awaited so it races with the process.exit
  // in this test and can cause snapshot failures so we always remove them
  .replace(/.*silly logfile.*cleaning.*\n/gm, '')
  .replace(/(Completed in )\d+(ms)/g, '$1{TIME}$2')
  .replace(/(removing )\d+( files)/g, '$1${NUM}2')
  .replaceAll(`node ${process.version}`, '{NODE-VERSION}')
  .replaceAll(`${os.type()} ${os.release()}`, '{OS}')
  .replaceAll(`v${NPM_VERSION}`, '{NPM-VERSION}')

// 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.
mockGlobals(t, {
  process: Object.assign(new EventEmitter(), {
    // these are process properties that are needed in the running code and tests
    ...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),
    exit (code) {
      this.emit('exit', code)
    },
  }),
}, { replace: true })

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 } : {}),
    }),
    getError: (...args) => ({
      ...errorMessage.getError(...args),
      ...(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,
    config: (dirs) => ({
      loglevel: 'notice',
      ...(typeof config === 'function' ? config(dirs) : config),
    }),
    globals: {
      'console.error': (err) => errors.push(err),
    },
  })

  const ExitHandler = tmock(t, '{LIB}/cli/exit-handler.js', mocks)

  const exitHandler = new ExitHandler({ process })
  exitHandler.registerUncaughtHandlers()

  if (npm) {
    exitHandler.setNpm(npm)
  }

  t.teardown(() => {
    process.removeAllListeners('exit')
  })

  return {
    ...rest,
    errors: () => [
      ...rest.outputErrors,
      ...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: (argErr) => new Promise(res => {
      process.once('exit', res)
      if (npm) {
        npm.exec(command || 'root')
          .then(() => exitHandler.exit())
          .catch((err) => exitHandler.exit(err))
      } else {
        exitHandler.exit(argErr || error)
      }
    }),
  }
}

// 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('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()

  const fileLogs = await debugFile()
  const fileLines = fileLogs.split('\n')

  const lineNumber = /^(\d+)\s/
  const lastLog = fileLines[fileLines.length - 1].match(lineNumber)[1]

  t.equal(process.exitCode, 1)

  logs.forEach((logItem, i) => {
    const logLines = logItem.split('\n').map(l => `${i} ${l}`)
    for (const line of logLines) {
      t.match(fileLogs.trim(), line, 'log appears in debug file')
    }
  })

  t.equal(logs.length, parseInt(lastLog) + 1)
  t.match(logs.error, [
    'code ECODE',
    'Unknown error',
    'A complete log of this run can be found in:',
  ])
  t.match(fileLogs, /\d+ error code ECODE/)
  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', async t => {
  t.test('loglevel silent', async (t) => {
    const { logs, errors } = await mockExitHandler(t, {
      config: { loglevel: 'silent' },
    })
    process.emit('exit', 0)
    t.strictSame(logs, [])
    t.strictSame(errors(), [''], 'one empty string')
    t.equal(process.exitCode, 1)
  })

  t.test('loglevel notice', async (t) => {
    const { logs, errors } = await mockExitHandler(t)
    process.emit('exit', 2)
    t.equal(process.exitCode, 2)
    t.match(logs.error, [
      'Exit handler never called!',
      /error with npm itself/,
    ])
    t.strictSame(errors(), [])
  })

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

  t.equal(process.exitCode, 1)
  t.same(
    JSON.parse(outputs[0]),
    {
      error: {
        code: 'EBADTHING', // should default error code to E[A-Z]+
        summary: 'Error: EBADTHING Something happened',
        detail: '',
      },
    },
    'should output expected json output'
  )
})

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({ more_data: 2 })

  await exitHandler()

  t.equal(process.exitCode, 1)
  t.same(
    JSON.parse(outputs[0]),
    {
      output_data: 1,
      more_data: 2,
      error: {
        code: 'EBADTHING', // should default error code to E[A-Z]+
        summary: 'Error: EBADTHING Something happened',
        detail: '',
      },
    },
    'should output expected json output'
  )
})

t.test('output buffer without json', async (t) => {
  const { exitHandler, outputs, logs } = await mockExitHandler(t, {
    error: err('Error: EBADTHING Something happened'),
  })

  output.buffer('output_data')
  output.buffer('more_data')

  await exitHandler()

  t.equal(process.exitCode, 1)
  t.same(
    outputs,
    ['output_data', 'more_data'],
    'should output expected output'
  )
  t.match(logs.error, ['code EBADTHING'])
})

t.test('throw a non-error obj', async (t) => {
  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' }",
  ])
})

t.test('throw a string error', async (t) => {
  const { exitHandler, logs } = await mockExitHandler(t, {
    error: 'foo bar',
  })

  await exitHandler()

  t.equal(process.exitCode, 1)
  t.match(logs.error, [
    'foo bar',
  ])
})

t.test('update notification - shows even with loglevel error', async (t) => {
  const { exitHandler, logs, npm } = await mockExitHandler(t, {
    config: { loglevel: 'error' },
  })
  npm.updateNotification = 'you should update npm!'

  await exitHandler()

  t.match(logs.notice, ['you should update npm!'])
})

t.test('update notification - hidden with silent', async (t) => {
  const { exitHandler, logs, npm } = await mockExitHandler(t, {
    config: { loglevel: 'silent' },
  })
  npm.updateNotification = 'you should update npm!'

  await exitHandler()

  t.strictSame(logs.notice, [])
})

t.test('npm.config not ready', async (t) => {
  const { exitHandler, logs, errors } = await mockExitHandler(t, {
    load: false,
  })

  await exitHandler()

  t.equal(process.exitCode, 1)
  t.equal(errors().length, 1)

  t.match(errors(), [
    /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()
  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,
    }),
    mocks: {
      // we want the fs.writeFileSync in the Timers class to fail
      '{LIB}/utils/timers.js': tmock(t, '{LIB}/utils/timers.js', {
        'node:fs': {
          ...fs,
          writeFileSync: (file, ...rest) => {
            if (file.includes('LOGS_DIR')) {
              throw new Error('err')
            }

            return fs.writeFileSync(file, ...rest)
          },
        },
      }),
    },
  })

  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'),
    }),
    mocks: {
      // we want the fsMiniPass.WriteStreamSync in the LogFile class to fail
      '{LIB}/utils/log-file.js': tmock(t, '{LIB}/utils/log-file.js', {
        'fs-minipass': {
          ...fsMiniPass,
          WriteStreamSync: (file) => {
            if (file.includes('LOGS_DIR')) {
              throw new Error('err')
            }
          },
        },
      }),
    },
  })

  await exitHandler()

  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()

  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, ['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'),
    }),
    files: [
      ['error-file.txt', '# error file content'],
    ],
    mocks: {
      'node:fs': {
        ...fs,
        writeFileSync: (dir) => {
          if (dir.includes('LOGS_DIR') && dir.endsWith('error-file.txt')) {
            throw new Error('err')
          }
        },
      },
    },
  })

  await exitHandler()

  t.match(logs.warn[0], /Could not write error message to.*error-file\.txt.*err/)
})

t.test('timing with no error', async (t) => {
  const { exitHandler, timingFile, npm, logs } = await mockExitHandler(t, {
    config: { timing: true, loglevel: 'silly' },
  })

  await exitHandler()
  const timingFileData = await timingFile()

  t.equal(process.exitCode, 0)

  const msg = logs.info.byTitle('timing')[0]
  t.match(msg, /Timing info written to:/)

  t.match(timingFileData, {
    metadata: {
      command: [],
      version: npm.version,
      logfiles: [String],
    },
    timers: {
      'npm:load': Number,
      npm: Number,
    },
  })
})

t.test('timing message hidden by loglevel', async (t) => {
  const { exitHandler, logs } = await mockExitHandler(t, {
    config: { timing: true, loglevel: 'notice' },
  })

  await exitHandler()

  t.equal(process.exitCode, 0)

  t.strictSame(logs.info, [], 'no log message')
})

t.test('unfinished timers', async (t) => {
  const { exitHandler, timingFile, npm } = await mockExitHandler(t, {
    config: { timing: true },
  })

  time.start('foo')
  time.start('bar')

  await exitHandler()
  const timingFileData = await timingFile()

  t.equal(process.exitCode, 0)
  t.match(timingFileData, {
    metadata: {
      command: [],
      version: npm.version,
      logfiles: [String],
    },
    timers: {
      npm: Number,
    },
    unfinishedTimers: {
      foo: [Number, Number],
      bar: [Number, Number],
    },
  })
})

t.test('uses code from errno', async (t) => {
  const { exitHandler, logs } = await mockExitHandler(t, {
    error: 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, {
    error: 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 keys = ['code', 'syscall', 'file', 'path', 'dest', 'errno']
  const properties = keys.reduce((acc, k) => {
    acc[k] = `${k}-hey`
    return acc
  }, {})

  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 keys = ['type', 'stack', 'pkgid']
  const properties = keys.reduce((acc, k) => {
    acc[k] = `${k}-https://user:pass@registry.npmjs.org/`
    return acc
  }, {})

  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)),
    keys.map((k) => `${k} ${k}-https://user:***@registry.npmjs.org/`),
    'all special keys get replaced'
  )
})

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 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.match(errors(), ['Error with no stack'], 'should use error msg')
  t.strictSame(logs.error, [])
})

t.test('exits uncleanly when only emitting exit event', async (t) => {
  const { logs } = await mockExitHandler(t)

  process.emit('exit')

  t.match(logs.error, ['Exit handler never called!'])
  t.equal(process.exitCode, 1, 'exitCode coerced to 1')
})

t.test('do no fancy handling for shellouts', async t => {
  const mockShelloutExit = (t, opts) => mockExitHandler(t, {
    command: 'exec',
    argv: ['-c', 'exit'],
    config: {
      timing: false,
      progress: false,
      ...opts.config,
    },
    ...opts,
  })

  t.test('shellout with a numeric error code', async t => {
    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')
    t.strictSame(errors(), [])
  })

  t.test('shellout without a numeric error code (something in npm)', async t => {
    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.test('shellout with code=0 (extra weird?)', async t => {
    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.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: '' },
    })
  })
})