feat: add logs-dir config to set custom logging location

This also allows logs-max to be set to 0 to disable log file writing.

Closes #4466
Closes #4206

12 files changed, 362 insertions, 283 deletions

diff --git a/lib/cli.js b/lib/cli.js
index 3d0c32d4b..6583bd0c0 100644
--- a/lib/cli.js
+++ b/lib/cli.js
@@ -30,14 +30,12 @@ module.exports = async process => {
   }
 
   const log = require('./utils/log-shim.js')
-  const replaceInfo = require('./utils/replace-info.js')
-  log.verbose('cli', replaceInfo(process.argv))
-
+  // only log node and npm paths in argv initially since argv can contain
+  // sensitive info. a cleaned version will be logged later
+  log.verbose('cli', process.argv.slice(0, 2).join(' '))
   log.info('using', 'npm@%s', npm.version)
   log.info('using', 'node@%s', process.version)
 
-  const updateNotifier = require('./utils/update-notifier.js')
-
   let cmd
   // now actually fire up npm and run the command.
   // this is how to use npm programmatically:
@@ -54,8 +52,6 @@ module.exports = async process => {
       npm.config.set('usage', false, 'cli')
     }
 
-    updateNotifier(npm)
-
     cmd = npm.argv.shift()
     if (!cmd) {
       npm.output(await npm.usage)
diff --git a/lib/commands/bin.js b/lib/commands/bin.js
index 77028f06d..07d33167d 100644
--- a/lib/commands/bin.js
+++ b/lib/commands/bin.js
@@ -1,3 +1,4 @@
+const log = require('../utils/log-shim.js')
 const envPath = require('../utils/path.js')
 const BaseCommand = require('../base-command.js')
 
@@ -11,8 +12,7 @@ class Bin extends BaseCommand {
     const b = this.npm.bin
     this.npm.output(b)
     if (this.npm.config.get('global') && !envPath.includes(b)) {
-      // XXX: does this need to be console?
-      console.error('(not in PATH env variable)')
+      log.error('bin', '(not in PATH env variable)')
     }
   }
 }
diff --git a/lib/commands/doctor.js b/lib/commands/doctor.js
index 630150c08..22a25477e 100644
--- a/lib/commands/doctor.js
+++ b/lib/commands/doctor.js
@@ -131,10 +131,6 @@ class Doctor extends BaseCommand {
 
     if (!this.npm.silent) {
       this.npm.output(table(outTable, tableOpts))
-      if (!allOk) {
-        // TODO is this really needed?
-        console.error('')
-      }
     }
     if (!allOk) {
       throw new Error('Some problems found. See above for recommendations.')
diff --git a/lib/commands/view.js b/lib/commands/view.js
index 85087057d..99cf29813 100644
--- a/lib/commands/view.js
+++ b/lib/commands/view.js
@@ -1,3 +1,6 @@
+/* eslint-disable no-console */
+// XXX: remove console.log later
+
 // npm view [pkg [pkg ...]]
 
 const color = require('ansicolors')
diff --git a/lib/npm.js b/lib/npm.js
index 9999cf195..4cd1d05b3 100644
--- a/lib/npm.js
+++ b/lib/npm.js
@@ -1,5 +1,5 @@
 const EventEmitter = require('events')
-const { resolve, dirname } = require('path')
+const { resolve, dirname, join } = require('path')
 const Config = require('@npmcli/config')
 
 // Patch the global fs module here at the app level
@@ -10,6 +10,7 @@ const { shellouts } = require('./utils/cmd-list.js')
 const usage = require('./utils/npm-usage.js')
 
 const which = require('which')
+const fs = require('@npmcli/fs')
 
 const deref = require('./utils/deref-command.js')
 const LogFile = require('./utils/log-file.js')
@@ -17,45 +18,45 @@ const Timers = require('./utils/timers.js')
 const Display = require('./utils/display.js')
 const log = require('./utils/log-shim')
 const replaceInfo = require('./utils/replace-info.js')
+const updateNotifier = require('./utils/update-notifier.js')
+const pkg = require('../package.json')
 
 let warnedNonDashArg = false
 const _load = Symbol('_load')
-const _tmpFolder = Symbol('_tmpFolder')
-const _title = Symbol('_title')
-const pkg = require('../package.json')
 
 class Npm extends EventEmitter {
   static get version () {
     return pkg.version
   }
 
-  #unloaded = false
-  #timers = null
-  #logFile = null
-  #display = null
-
-  constructor () {
-    super()
-    this.command = null
-    this.#logFile = new LogFile()
-    this.#display = new Display()
-    this.#timers = new Timers({
-      start: 'npm',
-      listener: (name, ms) => {
-        const args = ['timing', name, `Completed in ${ms}ms`]
-        this.#logFile.log(...args)
-        this.#display.log(...args)
-      },
-    })
-    this.config = new Config({
-      npmPath: dirname(__dirname),
-      definitions,
-      flatten,
-      shorthands,
-    })
-    this[_title] = process.title
-    this.updateNotification = null
-  }
+  command = null
+  updateNotification = null
+  loadErr = null
+  deref = deref
+  argv = []
+
+  #loadPromise = null
+  #tmpFolder = null
+  #title = 'npm'
+  #argvClean = []
+
+  #logFile = new LogFile()
+  #display = new Display()
+  #timers = new Timers({
+    start: 'npm',
+    listener: (name, ms) => {
+      const args = ['timing', name, `Completed in ${ms}ms`]
+      this.#logFile.log(...args)
+      this.#display.log(...args)
+    },
+  })
+
+  config = new Config({
+    npmPath: dirname(__dirname),
+    definitions,
+    flatten,
+    shorthands,
+  })
 
   get version () {
     return this.constructor.version
@@ -65,10 +66,6 @@ class Npm extends EventEmitter {
     return shellouts
   }
 
-  deref (c) {
-    return deref(c)
-  }
-
   // Get an instantiated npm command
   // npm.command is already taken as the currently running command, a refactor
   // would be needed to change this
@@ -88,7 +85,7 @@ class Npm extends EventEmitter {
   // Call an npm command
   async exec (cmd, args) {
     const command = await this.cmd(cmd)
-    process.emit('time', `command:${cmd}`)
+    const timeEnd = this.time(`command:${cmd}`)
 
     // since 'test', 'start', 'stop', etc. commands re-enter this function
     // to call the run-script command, we need to only set it one time.
@@ -97,6 +94,11 @@ class Npm extends EventEmitter {
       this.command = command.name
     }
 
+    // this is async but we dont await it, since its ok if it doesnt
+    // finish before the command finishes running. it uses command and argv
+    // so it must be initiated here, after the command name is set
+    updateNotifier(this).then((msg) => (this.updateNotification = msg))
+
     // Options are prefixed by a hyphen-minus (-, \u2d).
     // Other dash-type chars look similar but are invalid.
     if (!warnedNonDashArg) {
@@ -112,68 +114,60 @@ class Npm extends EventEmitter {
         })
     }
 
+    const isGlobal = this.config.get('global')
     const workspacesEnabled = this.config.get('workspaces')
     const implicitWorkspace = this.config.get('workspace', 'default').length > 0
     const workspacesFilters = this.config.get('workspace')
-    if (workspacesEnabled === false && workspacesFilters.length > 0) {
-      throw new Error('Can not use --no-workspaces and --workspace at the same time')
-    }
-
+    const includeWorkspaceRoot = this.config.get('include-workspace-root')
     // only call execWorkspaces when we have workspaces explicitly set
     // or when it is implicit and not in our ignore list
-    const filterByWorkspaces =
-      (workspacesEnabled || workspacesFilters.length > 0)
-      && (!implicitWorkspace || !command.ignoreImplicitWorkspace)
+    const hasWorkspaceFilters = workspacesFilters.length > 0
+    const invalidWorkspaceConfig = workspacesEnabled === false && hasWorkspaceFilters
+    const filterByWorkspaces = (workspacesEnabled || hasWorkspaceFilters) &&
+      (!implicitWorkspace || !command.ignoreImplicitWorkspace)
     // normally this would go in the constructor, but our tests don't
     // actually use a real npm object so this.npm.config isn't always
     // populated.  this is the compromise until we can make that a reality
     // and then move this into the constructor.
-    command.workspaces = this.config.get('workspaces')
+    command.workspaces = workspacesEnabled
     command.workspacePaths = null
     // normally this would be evaluated in base-command#setWorkspaces, see
     // above for explanation
-    command.includeWorkspaceRoot = this.config.get('include-workspace-root')
+    command.includeWorkspaceRoot = includeWorkspaceRoot
 
+    let execPromise = Promise.resolve()
     if (this.config.get('usage')) {
       this.output(command.usage)
-      return
-    }
-    if (filterByWorkspaces) {
-      if (this.config.get('global')) {
-        throw new Error('Workspaces not supported for global packages')
+    } else if (invalidWorkspaceConfig) {
+      execPromise = Promise.reject(
+        new Error('Can not use --no-workspaces and --workspace at the same time'))
+    } else if (filterByWorkspaces) {
+      if (isGlobal) {
+        execPromise = Promise.reject(new Error('Workspaces not supported for global packages'))
+      } else {
+        execPromise = command.execWorkspaces(args, workspacesFilters)
       }
-
-      return command.execWorkspaces(args, this.config.get('workspace')).finally(() => {
-        process.emit('timeEnd', `command:${cmd}`)
-      })
     } else {
-      return command.exec(args).finally(() => {
-        process.emit('timeEnd', `command:${cmd}`)
-      })
+      execPromise = command.exec(args)
     }
+
+    return execPromise.finally(timeEnd)
   }
 
   async load () {
-    if (!this.loadPromise) {
-      process.emit('time', 'npm:load')
-      this.loadPromise = new Promise((resolve, reject) => {
-        this[_load]()
-          .catch(er => er)
-          .then(er => {
-            this.loadErr = er
-            if (!er && this.config.get('force')) {
-              log.warn('using --force', 'Recommended protections disabled.')
-            }
-
-            process.emit('timeEnd', 'npm:load')
-            if (er) {
-              return reject(er)
-            }
-            resolve()
-          })
-      })
+    if (!this.#loadPromise) {
+      this.#loadPromise = this.time('npm:load', () => this[_load]().catch(er => er).then((er) => {
+        this.loadErr = er
+        if (!er) {
+          if (this.config.get('force')) {
+            log.warn('using --force', 'Recommended protections disabled.')
+          }
+        } else {
+          throw er
+        }
+      }))
     }
-    return this.loadPromise
+    return this.#loadPromise
   }
 
   get loaded () {
@@ -184,106 +178,115 @@ class Npm extends EventEmitter {
   // during any tests to cleanup all of our listeners
   // Everything in here should be synchronous
   unload () {
-    // Track if we've already unloaded so we dont
-    // write multiple timing files. This is only an
-    // issue in tests right now since we unload
-    // in both tap teardowns and the exit handler
-    if (this.#unloaded) {
-      return
-    }
     this.#timers.off()
     this.#display.off()
     this.#logFile.off()
-    if (this.loaded && this.config.get('timing')) {
-      this.#timers.writeFile({
-        command: process.argv.slice(2),
-        // We used to only ever report a single log file
-        // so to be backwards compatible report the last logfile
-        // XXX: remove this in npm 9 or just keep it forever
-        logfile: this.logFiles[this.logFiles.length - 1],
-        logfiles: this.logFiles,
-        version: this.version,
-      })
-    }
-    this.#unloaded = true
+  }
+
+  time (name, fn) {
+    return this.#timers.time(name, fn)
+  }
+
+  writeTimingFile () {
+    this.#timers.writeFile({
+      command: this.#argvClean,
+      // We used to only ever report a single log file
+      // so to be backwards compatible report the last logfile
+      // XXX: remove this in npm 9 or just keep it forever
+      logfile: this.logFiles[this.logFiles.length - 1],
+      logfiles: this.logFiles,
+      version: this.version,
+    })
   }
 
   get title () {
-    return this[_title]
+    return this.#title
   }
 
   set title (t) {
     process.title = t
-    this[_title] = t
+    this.#title = t
   }
 
   async [_load] () {
-    process.emit('time', 'npm:load:whichnode')
-    let node
-    try {
-      node = which.sync(process.argv[0])
-    } catch {
-      // TODO should we throw here?
-    }
-    process.emit('timeEnd', 'npm:load:whichnode')
+    const node = this.time('npm:load:whichnode', () => {
+      try {
+        return which.sync(process.argv[0])
+      } catch {} // TODO should we throw here?
+    })
+
     if (node && node.toUpperCase() !== process.execPath.toUpperCase()) {
       log.verbose('node symlink', node)
       process.execPath = node
       this.config.execPath = node
     }
 
-    process.emit('time', 'npm:load:configload')
-    await this.config.load()
-    process.emit('timeEnd', 'npm:load:configload')
+    await this.time('npm:load:configload', () => this.config.load())
+
+    // mkdir this separately since the logs dir can be set to
+    // a different location. an error here should be surfaced
+    // right away since it will error in cacache later
+    await this.time('npm:load:mkdirpcache', () =>
+      fs.mkdir(this.cache, { recursive: true, owner: 'inherit' }))
+
+    // its ok if this fails. user might have specified an invalid dir
+    // which we will tell them about at the end
+    await this.time('npm:load:mkdirplogs', () =>
+      fs.mkdir(this.logsDir, { recursive: true, owner: 'inherit' })
+        .catch((e) => log.warn('logfile', `could not create logs-dir: ${e}`)))
 
-    this.argv = this.config.parsedArgv.remain
     // note: this MUST be shorter than the actual argv length, because it
     // uses the same memory, so node will truncate it if it's too long.
-    // if it's a token revocation, then the argv contains a secret, so
-    // don't show that.  (Regrettable historical choice to put it there.)
-    // Any other secrets are configs only, so showing only the positional
-    // args keeps those from being leaked.
-    process.emit('time', 'npm:load:setTitle')
-    const tokrev = deref(this.argv[0]) === 'token' && this.argv[1] === 'revoke'
-    this.title = tokrev
-      ? 'npm token revoke' + (this.argv[2] ? ' ***' : '')
-      : replaceInfo(['npm', ...this.argv].join(' '))
-    process.emit('timeEnd', 'npm:load:setTitle')
-
-    process.emit('time', 'npm:load:display')
-    this.#display.load({
-      // Use logColor since that is based on stderr
-      color: this.logColor,
-      progress: this.flatOptions.progress,
-      silent: this.silent,
-      timing: this.config.get('timing'),
-      loglevel: this.config.get('loglevel'),
-      unicode: this.config.get('unicode'),
-      heading: this.config.get('heading'),
+    this.time('npm:load:setTitle', () => {
+      const { parsedArgv: { cooked, remain } } = this.config
+      this.argv = remain
+      // Secrets are mostly in configs, so title is set using only the positional args
+      // to keep those from being leaked.
+      this.title = ['npm'].concat(replaceInfo(remain)).join(' ').trim()
+      // The cooked argv is also logged separately for debugging purposes. It is
+      // cleaned as a best effort by replacing known secrets like basic auth
+      // password and strings that look like npm tokens. XXX: for this to be
+      // safer the config should create a sanitized version of the argv as it
+      // has the full context of what each option contains.
+      this.#argvClean = replaceInfo(cooked)
+      log.verbose('title', this.title)
+      log.verbose('argv', this.#argvClean.map(JSON.stringify).join(' '))
     })
-    process.emit('timeEnd', 'npm:load:display')
-    process.env.COLOR = this.color ? '1' : '0'
 
-    process.emit('time', 'npm:load:logFile')
-    this.#logFile.load({
-      dir: resolve(this.cache, '_logs'),
-      logsMax: this.config.get('logs-max'),
+    this.time('npm:load:display', () => {
+      this.#display.load({
+        // Use logColor since that is based on stderr
+        color: this.logColor,
+        progress: this.flatOptions.progress,
+        silent: this.silent,
+        timing: this.config.get('timing'),
+        loglevel: this.config.get('loglevel'),
+        unicode: this.config.get('unicode'),
+        heading: this.config.get('heading'),
+      })
+      process.env.COLOR = this.color ? '1' : '0'
     })
-    log.verbose('logfile', this.#logFile.files[0])
-    process.emit('timeEnd', 'npm:load:logFile')
 
-    process.emit('time', 'npm:load:timers')
-    this.#timers.load({
-      dir: this.cache,
+    this.time('npm:load:logFile', () => {
+      this.#logFile.load({
+        dir: this.logsDir,
+        logsMax: this.config.get('logs-max'),
+      })
+      log.verbose('logfile', this.#logFile.files[0] || 'no logfile created')
     })
-    process.emit('timeEnd', 'npm:load:timers')
 
-    process.emit('time', 'npm:load:configScope')
-    const configScope = this.config.get('scope')
-    if (configScope && !/^@/.test(configScope)) {
-      this.config.set('scope', `@${configScope}`, this.config.find('scope'))
-    }
-    process.emit('timeEnd', 'npm:load:configScope')
+    this.time('npm:load:timers', () =>
+      this.#timers.load({
+        dir: this.config.get('timing') ? this.timingDir : null,
+      })
+    )
+
+    this.time('npm:load:configScope', () => {
+      const configScope = this.config.get('scope')
+      if (configScope && !/^@/.test(configScope)) {
+        this.config.set('scope', `@${configScope}`, this.config.find('scope'))
+      }
+    })
   }
 
   get flatOptions () {
@@ -329,6 +332,19 @@ class Npm extends EventEmitter {
     return this.#logFile.files
   }
 
+  get logsDir () {
+    return this.config.get('logs-dir') || join(this.cache, '_logs')
+  }
+
+  get timingFile () {
+    return this.#timers.file
+  }
+
+  get timingDir () {
+    // XXX(npm9): make this always in logs-dir
+    return this.config.get('logs-dir') || this.cache
+  }
+
   get cache () {
     return this.config.get('cache')
   }
@@ -395,11 +411,11 @@ class Npm extends EventEmitter {
 
   // XXX add logging to see if we actually use this
   get tmp () {
-    if (!this[_tmpFolder]) {
+    if (!this.#tmpFolder) {
       const rand = require('crypto').randomBytes(4).toString('hex')
-      this[_tmpFolder] = `npm-${process.pid}-${rand}`
+      this.#tmpFolder = `npm-${process.pid}-${rand}`
     }
-    return resolve(this.config.get('tmp'), this[_tmpFolder])
+    return resolve(this.config.get('tmp'), this.#tmpFolder)
   }
 
   // output to stdout in a progress bar compatible way
@@ -409,5 +425,12 @@ class Npm extends EventEmitter {
     console.log(...msg)
     log.showProgress()
   }
+
+  outputError (...msg) {
+    log.clearProgress()
+    // eslint-disable-next-line no-console
+    console.error(...msg)
+    log.showProgress()
+  }
 }
 module.exports = Npm
diff --git a/lib/utils/config/definitions.js b/lib/utils/config/definitions.js
index abc989d0e..04da7f607 100644
--- a/lib/utils/config/definitions.js
+++ b/lib/utils/config/definitions.js
@@ -1229,11 +1229,25 @@ define('loglevel', {
   },
 })
 
+define('logs-dir', {
+  default: null,
+  type: [null, path],
+  defaultDescription: `
+    A directory named \`_logs\` inside the cache
+`,
+  description: `
+    The location of npm's log directory.  See [\`npm
+    logging\`](/using-npm/logging) for more information.
+  `,
+})
+
 define('logs-max', {
   default: 10,
   type: Number,
   description: `
     The maximum number of log files to store.
+
+    If set to 0, no log files will be written for the current run.
   `,
 })
 
@@ -2025,8 +2039,8 @@ define('timing', {
   default: false,
   type: Boolean,
   description: `
-    If true, writes an \`npm-debug\` log to \`_logs\` and timing information
-    to \`_timing.json\`, both in your cache, even if the command completes
+    If true, writes a debug log to \`logs-dir\` and timing information
+    to \`_timing.json\` in the cache, even if the command completes
     successfully.  \`_timing.json\` is a newline delimited list of JSON
     objects.
 
diff --git a/lib/utils/exit-handler.js b/lib/utils/exit-handler.js
index 6186ea81d..f96d162ce 100644
--- a/lib/utils/exit-handler.js
+++ b/lib/utils/exit-handler.js
@@ -1,14 +1,15 @@
 const os = require('os')
-const log = require('./log-shim.js')
 
+const log = require('./log-shim.js')
 const errorMessage = require('./error-message.js')
 const replaceInfo = require('./replace-info.js')
 
 const messageText = msg => msg.map(line => line.slice(1).join(' ')).join('\n')
+const indent = (val) => Array.isArray(val) ? val.map(v => indent(v)) : `    ${val}`
 
 let npm = null // set by the cli
 let exitHandlerCalled = false
-let showLogFileMessage = false
+let showLogFileError = false
 
 process.on('exit', code => {
   log.disableProgress()
@@ -36,42 +37,73 @@ process.on('exit', code => {
   if (!exitHandlerCalled) {
     process.exitCode = code || 1
     log.error('', 'Exit handler never called!')
+    // eslint-disable-next-line no-console
     console.error('')
     log.error('', 'This is an error with npm itself. Please report this error at:')
     log.error('', '    <https://github.com/npm/cli/issues>')
-    showLogFileMessage = true
-  }
-
-  // In timing mode we always show the log file message
-  if (hasLoadedNpm && npm.config.get('timing')) {
-    showLogFileMessage = true
+    showLogFileError = true
   }
 
   // npm must be loaded to know where the log file was written
-  if (showLogFileMessage && hasLoadedNpm) {
-    // just a line break if not in silent mode
-    if (!npm.silent) {
-      console.error('')
-    }
+  if (hasLoadedNpm) {
+    // write the timing file now, this might do nothing based on the configs set.
+    // we need to call it here in case it errors so we dont tell the user
+    // about a timing file that doesn't exist
+    npm.writeTimingFile()
 
-    log.error(
-      '',
-      [
-        'A complete log of this run can be found in:',
-        ...npm.logFiles.map(f => '    ' + f),
-      ].join('\n')
-    )
-  }
+    const logsDir = npm.logsDir
+    const logFiles = npm.logFiles
 
-  // This removes any listeners npm setup and writes files if necessary
-  // This is mostly used for tests to avoid max listener warnings
-  if (hasLoadedNpm) {
+    const timingDir = npm.timingDir
+    const timingFile = npm.timingFile
+
+    const timing = npm.config.get('timing')
+    const logsMax = npm.config.get('logs-max')
+
+    // Determine whether to show log file message and why it is
+    // being shown since in timing mode we always show the log file message
+    const logMethod = showLogFileError ? 'error' : timing ? 'info' : null
+
+    if (logMethod) {
+      if (!npm.silent) {
+        // just a line break if not in silent mode
+        // eslint-disable-next-line no-console
+        console.error('')
+      }
+
+      const message = []
+
+      if (timingFile) {
+        message.push('Timing info written to:', indent(timingFile))
+      } else if (timing) {
+        message.push(
+          `The timing file was not written due to an error writing to the directory: ${timingDir}`
+        )
+      }
+
+      if (logFiles.length) {
+        message.push('A complete log of this run can be found in:', ...indent(logFiles))
+      } else if (logsMax <= 0) {
+        // user specified no log file
+        message.push(`Log files were not written due to the config logs-max=${logsMax}`)
+      } else {
+        // could be an error writing to the directory
+        message.push(
+          `Log files were not written due to an error writing to the directory: ${logsDir}`,
+          'You can rerun the command with `--loglevel=verbose` to see the logs in your terminal'
+        )
+      }
+
+      log[logMethod]('', message.join('\n'))
+    }
+
+    // This removes any listeners npm setup, mostly for tests to avoid max listener warnings
     npm.unload()
   }
 
   // these are needed for the tests to have a clean slate in each test case
   exitHandlerCalled = false
-  showLogFileMessage = false
+  showLogFileError = false
 })
 
 const exitHandler = err => {
@@ -84,12 +116,14 @@ const exitHandler = err => {
 
   if (!hasNpm) {
     err = err || new Error('Exit prior to setting npm in exit handler')
+    // eslint-disable-next-line no-console
     console.error(err.stack || err.message)
     return process.exit(1)
   }
 
   if (!hasLoadedNpm) {
     err = err || new Error('Exit prior to config file resolving.')
+    // eslint-disable-next-line no-console
     console.error(err.stack || err.message)
   }
 
@@ -135,10 +169,8 @@ const exitHandler = err => {
         }
       }
 
-      const args = replaceInfo(process.argv)
       log.verbose('cwd', process.cwd())
       log.verbose('', os.type() + ' ' + os.release())
-      log.verbose('argv', args.map(JSON.stringify).join(' '))
       log.verbose('node', process.version)
       log.verbose('npm ', 'v' + npm.version)
 
@@ -162,7 +194,7 @@ const exitHandler = err => {
             detail: messageText(msg.detail),
           },
         }
-        console.error(JSON.stringify(error, null, 2))
+        npm.outputError(JSON.stringify(error, null, 2))
       }
 
       if (typeof err.errno === 'number') {
@@ -175,17 +207,18 @@ const exitHandler = err => {
 
   log.verbose('exit', exitCode || 0)
 
-  showLogFileMessage = (hasLoadedNpm && npm.silent) || noLogMessage
+  showLogFileError = (hasLoadedNpm && npm.silent) || noLogMessage
     ? false
     : !!exitCode
 
   // explicitly call process.exit now so we don't hang on things like the
-  // update notifier, also flush stdout beforehand because process.exit doesn't
+  // update notifier, also flush stdout/err beforehand because process.exit doesn't
   // wait for that to happen.
-  process.stdout.write('', () => process.exit(exitCode))
+  let flushed = 0
+  const flush = [process.stderr, process.stdout]
+  const exit = () => ++flushed === flush.length && process.exit(exitCode)
+  flush.forEach((f) => f.write('', exit))
 }
 
 module.exports = exitHandler
-module.exports.setNpm = n => {
-  npm = n
-}
+module.exports.setNpm = n => (npm = n)
diff --git a/lib/utils/log-file.js b/lib/utils/log-file.js
index 0bf1e0054..282c72700 100644
--- a/lib/utils/log-file.js
+++ b/lib/utils/log-file.js
@@ -5,8 +5,8 @@ const rimraf = promisify(require('rimraf'))
 const glob = promisify(require('glob'))
 const MiniPass = require('minipass')
 const fsMiniPass = require('fs-minipass')
+const fs = require('@npmcli/fs')
 const log = require('./log-shim')
-const withChownSync = require('./with-chown-sync')
 
 const padZero = (n, length) => n.toString().padStart(length.toString().length, '0')
 
@@ -82,7 +82,9 @@ class LogFiles {
     this[_endStream]()
   }
 
-  load ({ dir, logsMax } = {}) {
+  load ({ dir, logsMax = Infinity } = {}) {
+    // dir is user configurable and is required to exist so
+    // this can error if the dir is missing or not configured correctly
     this.#dir = dir
     this.#logsMax = logsMax
 
@@ -90,16 +92,22 @@ class LogFiles {
     if (!this.#logStream) {
       return
     }
+
+    log.verbose('logfile', `logs-max:${logsMax} dir:${dir}`)
+
     // Pipe our initial stream to our new file stream and
     // set that as the new log logstream for future writes
-    const initialFile = this[_openLogFile]()
-    if (initialFile) {
-      this.#logStream = this.#logStream.pipe(initialFile)
+    // if logs max is 0 then the user does not want a log file
+    if (this.#logsMax > 0) {
+      const initialFile = this[_openLogFile]()
+      if (initialFile) {
+        this.#logStream = this.#logStream.pipe(initialFile)
+      }
     }
 
-    // Kickoff cleaning process. This is async but it wont delete
-    // our next log file since it deletes oldest first. Return the
-    // result so it can be awaited in tests
+    // Kickoff cleaning process, even if we aren't writing a logfile.
+    // This is async but it will always ignore the current logfile
+    // Return the result so it can be awaited in tests
     return this[_cleanLogs]()
   }
 
@@ -164,8 +172,8 @@ class LogFiles {
     return LogFiles.format(this.#totalLogCount++, ...args)
   }
 
-  [_getLogFilePath] (prefix, suffix, sep = '-') {
-    return path.resolve(this.#dir, prefix + sep + 'debug' + sep + suffix + '.log')
+  [_getLogFilePath] (count = '') {
+    return path.resolve(this.#dir, `${this.#logId}-debug-${count}.log`)
   }
 
   [_openLogFile] () {
@@ -173,17 +181,19 @@ class LogFiles {
     const count = this.#files.length
 
     try {
-      const logStream = withChownSync(
-        // Pad with zeros so that our log files are always sorted properly
-        // We never want to write files ending in `-9.log` and `-10.log` because
-        // log file cleaning is done by deleting the oldest so in this example
-        // `-10.log` would be deleted next
-        this[_getLogFilePath](this.#logId, padZero(count, this.#MAX_FILES_PER_PROCESS)),
-        // Some effort was made to make the async, but we need to write logs
-        // during process.on('exit') which has to be synchronous. So in order
-        // to never drop log messages, it is easiest to make it sync all the time
-        // and this was measured to be about 1.5% slower for 40k lines of output
-        (f) => new fsMiniPass.WriteStreamSync(f, { flags: 'a' })
+      // Pad with zeros so that our log files are always sorted properly
+      // We never want to write files ending in `-9.log` and `-10.log` because
+      // log file cleaning is done by deleting the oldest so in this example
+      // `-10.log` would be deleted next
+      const f = this[_getLogFilePath](padZero(count, this.#MAX_FILES_PER_PROCESS))
+      // Some effort was made to make the async, but we need to write logs
+      // during process.on('exit') which has to be synchronous. So in order
+      // to never drop log messages, it is easiest to make it sync all the time
+      // and this was measured to be about 1.5% slower for 40k lines of output
+      const logStream = fs.withOwnerSync(
+        f,
+        () => new fsMiniPass.WriteStreamSync(f, { flags: 'a' }),
+        { owner: 'inherit' }
       )
       if (count > 0) {
         // Reset file log count if we are opening
@@ -193,9 +203,7 @@ class LogFiles {
       this.#files.push(logStream.path)
       return logStream
     } catch (e) {
-      // XXX: do something here for errors?
-      // log to display only?
-      return null
+      log.warn('logfile', `could not be created: ${e}`)
     }
   }
 
@@ -206,14 +214,16 @@ class LogFiles {
     // Promise that succeeds when we've tried to delete everything,
     // just for the benefit of testing this function properly.
 
-    if (typeof this.#logsMax !== 'number') {
-      return
-    }
-
     try {
-      // Handle the old (prior to 8.2.0) log file names which did not have an counter suffix
-      // so match by anything after `-debug` and before `.log` (including nothing)
-      const logGlob = this[_getLogFilePath]('*-', '*', '')
+      const logPath = this[_getLogFilePath]()
+      const logGlob = path.join(path.dirname(logPath), path.basename(logPath)
+        // tell glob to only match digits
+        .replace(/\d/g, '[0123456789]')
+        // Handle the old (prior to 8.2.0) log file names which did not have a
+        // counter suffix
+        .replace(/-\.log$/, '*.log')
+      )
+
       // Always ignore the currently written files
       const files = await glob(logGlob, { ignore: this.#files })
       const toDelete = files.length - this.#logsMax
@@ -233,6 +243,8 @@ class LogFiles {
       }
     } catch (e) {
       log.warn('logfile', 'error cleaning log files', e)
+    } finally {
+      log.silly('logfile', 'done cleaning log files')
     }
   }
 }
diff --git a/lib/utils/replace-info.js b/lib/utils/replace-info.js
index e9d19ef5f..b9ce61935 100644
--- a/lib/utils/replace-info.js
+++ b/lib/utils/replace-info.js
@@ -1,33 +1,31 @@
-const URL = require('url').URL
+const { cleanUrl } = require('npm-registry-fetch')
+const isString = (v) => typeof v === 'string'
 
-// replaces auth info in an array of arguments or in a strings
-function replaceInfo (arg) {
-  const isArray = Array.isArray(arg)
-  const isString = str => typeof str === 'string'
-
-  if (!isArray && !isString(arg)) {
-    return arg
-  }
+// split on \s|= similar to how nopt parses options
+const splitAndReplace = (str) => {
+  // stateful regex, don't move out of this scope
+  const splitChars = /[\s=]/g
 
-  const testUrlAndReplace = str => {
-    try {
-      const url = new URL(str)
-      return url.password === '' ? str : str.replace(url.password, '***')
-    } catch (e) {
-      return str
-    }
+  let match = null
+  let result = ''
+  let index = 0
+  while (match = splitChars.exec(str)) {
+    result += cleanUrl(str.slice(index, match.index)) + match[0]
+    index = splitChars.lastIndex
   }
 
-  const args = isString(arg) ? arg.split(' ') : arg
-  const info = args.map(a => {
-    if (isString(a) && a.indexOf(' ') > -1) {
-      return a.split(' ').map(testUrlAndReplace).join(' ')
-    }
+  return result + cleanUrl(str.slice(index))
+}
 
-    return testUrlAndReplace(a)
-  })
+// replaces auth info in an array of arguments or in a strings
+function replaceInfo (arg) {
+  if (isString(arg)) {
+    return splitAndReplace(arg)
+  } else if (Array.isArray(arg)) {
+    return arg.map((a) => isString(a) ? splitAndReplace(a) : a)
+  }
 
-  return isString(arg) ? info.join(' ') : info
+  return arg
 }
 
 module.exports = replaceInfo
diff --git a/lib/utils/timers.js b/lib/utils/timers.js
index acff29eb0..3336c3b51 100644
--- a/lib/utils/timers.js
+++ b/lib/utils/timers.js
@@ -1,8 +1,7 @@
 const EE = require('events')
-const path = require('path')
-const fs = require('graceful-fs')
+const { resolve } = require('path')
+const fs = require('@npmcli/fs')
 const log = require('./log-shim')
-const withChownSync = require('./with-chown-sync.js')
 
 const _timeListener = Symbol('timeListener')
 const _timeEndListener = Symbol('timeEndListener')
@@ -12,10 +11,11 @@ const _init = Symbol('init')
 // only listen on a single internal event that gets
 // emitted whenever a timer ends
 class Timers extends EE {
+  file = null
+
   #unfinished = new Map()
   #finished = {}
   #onTimeEnd = Symbol('onTimeEnd')
-  #dir = null
   #initialListener = null
   #initialTimer = null
 
@@ -62,11 +62,27 @@ class Timers extends EE {
     }
   }
 
-  load ({ dir }) {
-    this.#dir = dir
+  time (name, fn) {
+    process.emit('time', name)
+    const end = () => process.emit('timeEnd', name)
+    if (typeof fn === 'function') {
+      const res = fn()
+      return res && res.finally ? res.finally(end) : (end(), res)
+    }
+    return end
+  }
+
+  load ({ dir } = {}) {
+    if (dir) {
+      this.file = resolve(dir, '_timing.json')
+    }
   }
 
   writeFile (fileData) {
+    if (!this.file) {
+      return
+    }
+
     try {
       const globalStart = this.started
       const globalEnd = this.#finished.npm || Date.now()
@@ -79,16 +95,17 @@ class Timers extends EE {
           return acc
         }, {}),
       }
-      withChownSync(
-        path.resolve(this.#dir, '_timing.json'),
-        (f) =>
-          // we append line delimited json to this file...forever
-          // XXX: should we also write a process specific timing file?
-          // with similar rules to the debug log (max files, etc)
-          fs.appendFileSync(f, JSON.stringify(content) + '\n')
+      // we append line delimited json to this file...forever
+      // XXX: should we also write a process specific timing file?
+      // with similar rules to the debug log (max files, etc)
+      fs.withOwnerSync(
+        this.file,
+        () => fs.appendFileSync(this.file, JSON.stringify(content) + '\n'),
+        { owner: 'inherit' }
       )
     } catch (e) {
-      log.warn('timing', 'could not write timing file', e)
+      this.file = null
+      log.warn('timing', `could not write timing file: ${e}`)
     }
   }
 
diff --git a/lib/utils/update-notifier.js b/lib/utils/update-notifier.js
index 875c3a99a..dde0202b7 100644
--- a/lib/utils/update-notifier.js
+++ b/lib/utils/update-notifier.js
@@ -122,5 +122,5 @@ module.exports = async npm => {
   // fails, it's ok.  might be using /dev/null as the cache or something weird
   // like that.
   writeFile(lastCheckedFile(npm), '').catch(() => {})
-  npm.updateNotification = notification
+  return notification
 }
diff --git a/lib/utils/with-chown-sync.js b/lib/utils/with-chown-sync.js
deleted file mode 100644
index 481b5696d..000000000
--- a/lib/utils/with-chown-sync.js
+++ /dev/null
@@ -1,13 +0,0 @@
-const mkdirp = require('mkdirp-infer-owner')
-const fs = require('graceful-fs')
-const path = require('path')
-
-module.exports = (file, method) => {
-  const dir = path.dirname(file)
-  mkdirp.sync(dir)
-  const result = method(file)
-  const st = fs.lstatSync(dir)
-  fs.chownSync(dir, st.uid, st.gid)
-  fs.chownSync(file, st.uid, st.gid)
-  return result
-}