diff --git a/docs/content/using-npm/config.md b/docs/content/using-npm/config.md index df259715f08f2..eb38c760b192c 100644 --- a/docs/content/using-npm/config.md +++ b/docs/content/using-npm/config.md @@ -1027,6 +1027,17 @@ See also the `foreground-scripts` config. +#### `logs-dir` + +* Default: A directory named `_logs` inside the cache +* Type: null or Path + +The location of npm's log directory. See [`npm logging`](/using-npm/logging) +for more information. + + + + #### `logs-max` * Default: 10 @@ -1034,6 +1045,8 @@ See also the `foreground-scripts` config. The maximum number of log files to store. +If set to 0, no log files will be written for the current run. + @@ -1628,9 +1641,9 @@ particular, use care when overriding this setting for public packages. * Default: false * Type: Boolean -If true, writes an `npm-debug` log to `_logs` and timing information to -`_timing.json`, both in your cache, even if the command completes -successfully. `_timing.json` is a newline delimited list of JSON objects. +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. You can quickly view it with this [json](https://npm.im/json) command line: `npm exec -- json -g < ~/.npm/_timing.json`. diff --git a/docs/content/using-npm/logging.md b/docs/content/using-npm/logging.md index b7c5e89977899..eb83b167e698b 100644 --- a/docs/content/using-npm/logging.md +++ b/docs/content/using-npm/logging.md @@ -1,13 +1,24 @@ --- title: Logging section: 7 -description: Why, What & How we Log +description: Why, What & How We Log --- ### Description The `npm` CLI has various mechanisms for showing different levels of information back to end-users for certain commands, configurations & environments. +### Setting Log File Location + +All logs are written to a debug log, with the path to that file printed if the execution of a command fails. + +The default location of the logs directory is a directory named `_logs` inside the npm cache. This can be changed +with the `logs-dir` config option. + +Log files will be removed from the `logs-dir` when the number of log files exceeds `logs-max`, with the oldest logs being deleted first. + +To turn off logs completely set `--logs-max=0`. + ### Setting Log Levels #### `loglevel` @@ -28,8 +39,6 @@ The default value of `loglevel` is `"notice"` but there are several levels/types All logs pertaining to a level proceeding the current setting will be shown. -All logs are written to a debug log, with the path to that file printed if the execution of a command fails. - ##### Aliases The log levels listed above have various corresponding aliases, including: @@ -47,6 +56,15 @@ The log levels listed above have various corresponding aliases, including: The `npm` CLI began hiding the output of lifecycle scripts for `npm install` as of `v7`. Notably, this means you will not see logs/output from packages that may be using "install scripts" to display information back to you or from your own project's scripts defined in `package.json`. If you'd like to change this behavior & log this output you can set `foreground-scripts` to `true`. +### Timing Information + +The `--timing` config can be set which does two things: + +1. Always shows the full path to the debug log regardless of command exit status +1. Write timing information to a timing file in the cache or `logs-dir` + +This file is a newline delimited list of JSON objects that can be inspected to see timing data for each task in a `npm` CLI run. + ### Registry Response Headers #### `npm-notice` @@ -55,6 +73,15 @@ The `npm` CLI reads from & logs any `npm-notice` headers that are returned from This header is not cached, and will not be logged if the request is served from the cache. +### Logs and Sensitive Information + +The `npm` CLI makes a best effort to redact the following from terminal output and log files: + +- Passwords inside basic auth URLs +- npm tokens + +However, this behavior should not be relied on to keep all possible sensitive information redacted. If you are concerned about secrets in your log file or terminal output, you can use `--loglevel=silent` and `--logs-max=0` to ensure no logs are written to your terminal or filesystem. + ### See also * [config](/using-npm/config) diff --git a/lib/cli.js b/lib/cli.js index 3d0c32d4beda3..6583bd0c00206 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 77028f06dd49a..07d33167d0d07 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 630150c0886fe..22a25477e22e0 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 85087057d65e9..99cf2981306fa 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 9999cf195d7b1..4cd1d05b373ec 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 ddccb147586f4..7b94d82cf69be 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 6186ea81dcc02..f96d162ce9753 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('', ' ') - 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 0bf1e0054ea2b..282c72700e58e 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 e9d19ef5fb2ba..b9ce61935ffb7 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 acff29eb0521b..3336c3b519259 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 875c3a99a2579..dde0202b76fe2 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 481b5696ddabf..0000000000000 --- 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 -} diff --git a/node_modules/@npmcli/fs/lib/common/owner-sync.js b/node_modules/@npmcli/fs/lib/common/owner-sync.js new file mode 100644 index 0000000000000..2055c4b21dec9 --- /dev/null +++ b/node_modules/@npmcli/fs/lib/common/owner-sync.js @@ -0,0 +1,92 @@ +const { dirname, resolve } = require('path') + +const fileURLToPath = require('./file-url-to-path/index.js') +const fs = require('../fs.js') + +// given a path, find the owner of the nearest parent +const find = (path) => { + // if we have no getuid, permissions are irrelevant on this platform + if (!process.getuid) { + return {} + } + + // fs methods accept URL objects with a scheme of file: so we need to unwrap + // those into an actual path string before we can resolve it + const resolved = path != null && path.href && path.origin + ? resolve(fileURLToPath(path)) + : resolve(path) + + let stat + + try { + stat = fs.lstatSync(resolved) + } finally { + // if we got a stat, return its contents + if (stat) { + return { uid: stat.uid, gid: stat.gid } + } + + // try the parent directory + if (resolved !== dirname(resolved)) { + return find(dirname(resolved)) + } + + // no more parents, never got a stat, just return an empty object + return {} + } +} + +// given a path, uid, and gid update the ownership of the path if necessary +const update = (path, uid, gid) => { + // nothing to update, just exit + if (uid === undefined && gid === undefined) { + return + } + + try { + // see if the permissions are already the same, if they are we don't + // need to do anything, so return early + const stat = fs.statSync(path) + if (uid === stat.uid && gid === stat.gid) { + return + } + } catch (err) {} + + try { + fs.chownSync(path, uid, gid) + } catch (err) {} +} + +// accepts a `path` and the `owner` property of an options object and normalizes +// it into an object with numerical `uid` and `gid` +const validate = (path, input) => { + let uid + let gid + + if (typeof input === 'string' || typeof input === 'number') { + uid = input + gid = input + } else if (input && typeof input === 'object') { + uid = input.uid + gid = input.gid + } + + if (uid === 'inherit' || gid === 'inherit') { + const owner = find(path) + if (uid === 'inherit') { + uid = owner.uid + } + + if (gid === 'inherit') { + gid = owner.gid + } + } + + return { uid, gid } +} + +module.exports = { + find, + update, + validate, +} diff --git a/node_modules/@npmcli/fs/lib/copy-file.js b/node_modules/@npmcli/fs/lib/copy-file.js index d9875aba11f79..8888266d627f0 100644 --- a/node_modules/@npmcli/fs/lib/copy-file.js +++ b/node_modules/@npmcli/fs/lib/copy-file.js @@ -1,22 +1,16 @@ const fs = require('./fs.js') const getOptions = require('./common/get-options.js') -const owner = require('./common/owner.js') +const withOwner = require('./with-owner.js') const copyFile = async (src, dest, opts) => { const options = getOptions(opts, { - copy: ['mode', 'owner'], + copy: ['mode'], wrap: 'mode', }) - const { uid, gid } = await owner.validate(dest, options.owner) - // the node core method as of 16.5.0 does not support the mode being in an // object, so we have to pass the mode value directly - const result = await fs.copyFile(src, dest, options.mode) - - await owner.update(dest, uid, gid) - - return result + return withOwner(dest, () => fs.copyFile(src, dest, options.mode), opts) } module.exports = copyFile diff --git a/node_modules/@npmcli/fs/lib/fs.js b/node_modules/@npmcli/fs/lib/fs.js index 29e5fb5735683..457da10eed03e 100644 --- a/node_modules/@npmcli/fs/lib/fs.js +++ b/node_modules/@npmcli/fs/lib/fs.js @@ -1,8 +1,14 @@ const fs = require('fs') const promisify = require('@gar/promisify') -// this module returns the core fs module wrapped in a proxy that promisifies +const isLower = (s) => s === s.toLowerCase() && s !== s.toUpperCase() + +const fsSync = Object.fromEntries(Object.entries(fs).filter(([k, v]) => + typeof v === 'function' && (k.endsWith('Sync') || !isLower(k[0])) +)) + +// this module returns the core fs async fns wrapped in a proxy that promisifies // method calls within the getter. we keep it in a separate module so that the // overridden methods have a consistent way to get to promisified fs methods -// without creating a circular dependency -module.exports = promisify(fs) +// without creating a circular dependency. the ctors and sync methods are kept untouched +module.exports = { ...promisify(fs), ...fsSync } diff --git a/node_modules/@npmcli/fs/lib/index.js b/node_modules/@npmcli/fs/lib/index.js index e40d748a7da60..43892df5fee07 100644 --- a/node_modules/@npmcli/fs/lib/index.js +++ b/node_modules/@npmcli/fs/lib/index.js @@ -6,5 +6,7 @@ module.exports = { mkdtemp: require('./mkdtemp.js'), rm: require('./rm/index.js'), withTempDir: require('./with-temp-dir.js'), + withOwner: require('./with-owner.js'), + withOwnerSync: require('./with-owner-sync.js'), writeFile: require('./write-file.js'), } diff --git a/node_modules/@npmcli/fs/lib/mkdir/index.js b/node_modules/@npmcli/fs/lib/mkdir/index.js index 04ff447903454..e2691042daa26 100644 --- a/node_modules/@npmcli/fs/lib/mkdir/index.js +++ b/node_modules/@npmcli/fs/lib/mkdir/index.js @@ -1,7 +1,7 @@ const fs = require('../fs.js') const getOptions = require('../common/get-options.js') const node = require('../common/node.js') -const owner = require('../common/owner.js') +const withOwner = require('../with-owner.js') const polyfill = require('./polyfill.js') @@ -12,21 +12,18 @@ const useNative = node.satisfies('>=10.12.0') // extends mkdir with the ability to specify an owner of the new dir const mkdir = async (path, opts) => { const options = getOptions(opts, { - copy: ['mode', 'recursive', 'owner'], + copy: ['mode', 'recursive'], wrap: 'mode', }) - const { uid, gid } = await owner.validate(path, options.owner) // the polyfill is tested separately from this module, no need to hack // process.version to try to trigger it just for coverage // istanbul ignore next - const result = useNative - ? await fs.mkdir(path, options) - : await polyfill(path, options) - - await owner.update(path, uid, gid) - - return result + return withOwner( + path, + () => useNative ? fs.mkdir(path, options) : polyfill(path, options), + opts + ) } module.exports = mkdir diff --git a/node_modules/@npmcli/fs/lib/mkdtemp.js b/node_modules/@npmcli/fs/lib/mkdtemp.js index b7f078029d111..60b12a788de90 100644 --- a/node_modules/@npmcli/fs/lib/mkdtemp.js +++ b/node_modules/@npmcli/fs/lib/mkdtemp.js @@ -2,11 +2,11 @@ const { dirname, sep } = require('path') const fs = require('./fs.js') const getOptions = require('./common/get-options.js') -const owner = require('./common/owner.js') +const withOwner = require('./with-owner.js') const mkdtemp = async (prefix, opts) => { const options = getOptions(opts, { - copy: ['encoding', 'owner'], + copy: ['encoding'], wrap: 'encoding', }) @@ -16,13 +16,8 @@ const mkdtemp = async (prefix, opts) => { // /tmp -> /tmpABCDEF, infers from / // /tmp/ -> /tmp/ABCDEF, infers from /tmp const root = prefix.endsWith(sep) ? prefix : dirname(prefix) - const { uid, gid } = await owner.validate(root, options.owner) - const result = await fs.mkdtemp(prefix, options) - - await owner.update(result, uid, gid) - - return result + return withOwner(root, () => fs.mkdtemp(prefix, options), opts) } module.exports = mkdtemp diff --git a/node_modules/@npmcli/fs/lib/with-owner-sync.js b/node_modules/@npmcli/fs/lib/with-owner-sync.js new file mode 100644 index 0000000000000..3597d1c810475 --- /dev/null +++ b/node_modules/@npmcli/fs/lib/with-owner-sync.js @@ -0,0 +1,21 @@ +const getOptions = require('./common/get-options.js') +const owner = require('./common/owner-sync.js') + +const withOwnerSync = (path, fn, opts) => { + const options = getOptions(opts, { + copy: ['owner'], + }) + + const { uid, gid } = owner.validate(path, options.owner) + + const result = fn({ uid, gid }) + + owner.update(path, uid, gid) + if (typeof result === 'string') { + owner.update(result, uid, gid) + } + + return result +} + +module.exports = withOwnerSync diff --git a/node_modules/@npmcli/fs/lib/with-owner.js b/node_modules/@npmcli/fs/lib/with-owner.js new file mode 100644 index 0000000000000..a679102883dbb --- /dev/null +++ b/node_modules/@npmcli/fs/lib/with-owner.js @@ -0,0 +1,21 @@ +const getOptions = require('./common/get-options.js') +const owner = require('./common/owner.js') + +const withOwner = async (path, fn, opts) => { + const options = getOptions(opts, { + copy: ['owner'], + }) + + const { uid, gid } = await owner.validate(path, options.owner) + + const result = await fn({ uid, gid }) + + await Promise.all([ + owner.update(path, uid, gid), + typeof result === 'string' ? owner.update(result, uid, gid) : null, + ]) + + return result +} + +module.exports = withOwner diff --git a/node_modules/@npmcli/fs/lib/with-temp-dir.js b/node_modules/@npmcli/fs/lib/with-temp-dir.js index 353d5555d10f6..ac9ebb714b989 100644 --- a/node_modules/@npmcli/fs/lib/with-temp-dir.js +++ b/node_modules/@npmcli/fs/lib/with-temp-dir.js @@ -27,7 +27,7 @@ const withTempDir = async (root, fn, opts) => { try { await rm(target, { force: true, recursive: true }) - } catch (err) {} + } catch {} if (err) { throw err diff --git a/node_modules/@npmcli/fs/lib/write-file.js b/node_modules/@npmcli/fs/lib/write-file.js index 01de531d980c4..ff900571a1f28 100644 --- a/node_modules/@npmcli/fs/lib/write-file.js +++ b/node_modules/@npmcli/fs/lib/write-file.js @@ -1,19 +1,14 @@ const fs = require('./fs.js') const getOptions = require('./common/get-options.js') -const owner = require('./common/owner.js') +const withOwner = require('./with-owner.js') const writeFile = async (file, data, opts) => { const options = getOptions(opts, { - copy: ['encoding', 'mode', 'flag', 'signal', 'owner'], + copy: ['encoding', 'mode', 'flag', 'signal'], wrap: 'encoding', }) - const { uid, gid } = await owner.validate(file, options.owner) - const result = await fs.writeFile(file, data, options) - - await owner.update(file, uid, gid) - - return result + return withOwner(file, () => fs.writeFile(file, data, options), opts) } module.exports = writeFile diff --git a/node_modules/@npmcli/fs/package.json b/node_modules/@npmcli/fs/package.json index cb64ac82023f2..799bf514f200b 100644 --- a/node_modules/@npmcli/fs/package.json +++ b/node_modules/@npmcli/fs/package.json @@ -1,11 +1,11 @@ { "name": "@npmcli/fs", - "version": "1.1.0", + "version": "2.1.0", "description": "filesystem utilities for the npm cli", "main": "lib/index.js", "files": [ - "bin", - "lib" + "bin/", + "lib/" ], "scripts": { "preversion": "npm test", @@ -14,11 +14,16 @@ "snap": "tap", "test": "tap", "npmclilint": "npmcli-lint", - "lint": "eslint '**/*.js'", + "lint": "eslint \"**/*.js\"", "lintfix": "npm run lint -- --fix", "posttest": "npm run lint", "postsnap": "npm run lintfix --", - "postlint": "npm-template-check" + "postlint": "template-oss-check", + "template-oss-apply": "template-oss-apply --force" + }, + "repository": { + "type": "git", + "url": "https://github.com/npm/fs.git" }, "keywords": [ "npm", @@ -27,15 +32,19 @@ "author": "GitHub Inc.", "license": "ISC", "devDependencies": { - "@npmcli/template-oss": "^2.3.1", - "tap": "^15.0.9" + "@npmcli/eslint-config": "^3.0.1", + "@npmcli/template-oss": "3.1.2", + "tap": "^15.1.6" }, "dependencies": { - "@gar/promisify": "^1.0.1", + "@gar/promisify": "^1.1.3", "semver": "^7.3.5" }, - "templateVersion": "2.3.1", "engines": { - "node": "^12.13.0 || ^14.15.0 || >=16" + "node": "^12.13.0 || ^14.15.0 || >=16.0.0" + }, + "templateOSS": { + "//@npmcli/template-oss": "This file is partially managed by @npmcli/template-oss. Edits may be overwritten.", + "version": "3.1.2" } } diff --git a/node_modules/cacache/package.json b/node_modules/cacache/package.json index c240fa446df48..edae9a4f995b4 100644 --- a/node_modules/cacache/package.json +++ b/node_modules/cacache/package.json @@ -1,6 +1,6 @@ { "name": "cacache", - "version": "16.0.2", + "version": "16.0.3", "cache-version": { "content": "2", "index": "5" @@ -8,8 +8,8 @@ "description": "Fast, fault-tolerant, cross-platform, disk-based, data-agnostic, content-addressable cache.", "main": "lib/index.js", "files": [ - "bin", - "lib" + "bin/", + "lib/" ], "scripts": { "benchmarks": "node test/benchmarks", @@ -20,15 +20,18 @@ "snap": "tap", "coverage": "tap", "test-docker": "docker run -it --rm --name pacotest -v \"$PWD\":/tmp -w /tmp node:latest npm test", - "lint": "eslint '**/*.js'", + "lint": "eslint \"**/*.js\"", "npmclilint": "npmcli-lint", "lintfix": "npm run lint -- --fix", "postsnap": "npm run lintfix --", - "postlint": "npm-template-check", - "template-copy": "npm-template-copy --force", - "posttest": "npm run lint" + "postlint": "template-oss-check", + "posttest": "npm run lint", + "template-oss-apply": "template-oss-apply --force" + }, + "repository": { + "type": "git", + "url": "https://github.com/npm/cacache.git" }, - "repository": "https://github.com/npm/cacache", "keywords": [ "cache", "caching", @@ -46,13 +49,13 @@ ], "license": "ISC", "dependencies": { - "@npmcli/fs": "^1.0.0", + "@npmcli/fs": "^2.1.0", "@npmcli/move-file": "^1.1.2", "chownr": "^2.0.0", "fs-minipass": "^2.1.0", "glob": "^7.2.0", "infer-owner": "^1.0.4", - "lru-cache": "^7.5.1", + "lru-cache": "^7.7.1", "minipass": "^3.1.6", "minipass-collect": "^1.0.2", "minipass-flush": "^1.0.5", @@ -66,23 +69,25 @@ "unique-filename": "^1.1.1" }, "devDependencies": { - "@npmcli/template-oss": "^2.9.2", + "@npmcli/eslint-config": "^3.0.1", + "@npmcli/template-oss": "3.1.2", "benchmark": "^2.1.4", "chalk": "^4.1.2", "require-inject": "^1.4.4", "tacks": "^1.3.0", - "tap": "^15.0.9" + "tap": "^16.0.0" }, "tap": { "100": true, "test-regex": "test/[^/]*.js" }, "engines": { - "node": "^12.13.0 || ^14.15.0 || >=16" + "node": "^12.13.0 || ^14.15.0 || >=16.0.0" }, "templateOSS": { + "//@npmcli/template-oss": "This file is partially managed by @npmcli/template-oss. Edits may be overwritten.", "windowsCI": false, - "version": "2.9.2" + "version": "3.1.2" }, "author": "GitHub Inc." } diff --git a/node_modules/lru-cache/index.js b/node_modules/lru-cache/index.js index e37f51616452e..978b8f4ee9595 100644 --- a/node_modules/lru-cache/index.js +++ b/node_modules/lru-cache/index.js @@ -1,6 +1,17 @@ const perf = typeof performance === 'object' && performance && typeof performance.now === 'function' ? performance : Date +const hasAbortController = typeof AbortController !== 'undefined' + +/* istanbul ignore next - minimal backwards compatibility polyfill */ +const AC = hasAbortController ? AbortController : Object.assign( + class AbortController { + constructor () { this.signal = new AC.AbortSignal } + abort () { this.signal.aborted = true } + }, + { AbortSignal: class AbortSignal { constructor () { this.aborted = false }}} +) + const warned = new Set() const deprecatedOption = (opt, instead) => { const code = `LRU_CACHE_OPTION_${opt}` @@ -24,12 +35,15 @@ const deprecatedProperty = (field, instead) => { warn(code, `${field} property`, `cache.${instead}`, get) } } -const shouldWarn = (code) => typeof process === 'object' && + +const shouldWarn = code => typeof process === 'object' && process && - !(process.noDeprecation || warned.has(code)) + !warned.has(code) + const warn = (code, what, instead, fn) => { warned.add(code) - process.emitWarning(`The ${what} is deprecated. Please use ${instead} instead.`, 'DeprecationWarning', code, fn) + const msg = `The ${what} is deprecated. Please use ${instead} instead.` + process.emitWarning(msg, 'DeprecationWarning', code, fn) } const isPosInt = n => n && n === Math.floor(n) && n > 0 && isFinite(n) @@ -58,7 +72,7 @@ class ZeroArray extends Array { class Stack { constructor (max) { - const UintArray = getUintArray(max) + const UintArray = max ? getUintArray(max) : Array this.heap = new UintArray(max) this.length = 0 } @@ -73,7 +87,7 @@ class Stack { class LRUCache { constructor (options = {}) { const { - max, + max = 0, ttl, ttlResolution = 1, ttlAutopurge, @@ -83,8 +97,9 @@ class LRUCache { disposeAfter, noDisposeOnSet, noUpdateTTL, - maxSize, + maxSize = 0, sizeCalculation, + fetchMethod, } = options // deprecated options, don't trigger a warning for getting them if @@ -95,17 +110,17 @@ class LRUCache { stale, } = options instanceof LRUCache ? {} : options - if (!isPosInt(max)) { - throw new TypeError('max option must be an integer') + if (max !== 0 && !isPosInt(max)) { + throw new TypeError('max option must be a nonnegative integer') } - const UintArray = getUintArray(max) + const UintArray = max ? getUintArray(max) : Array if (!UintArray) { throw new Error('invalid max value: ' + max) } this.max = max - this.maxSize = maxSize || 0 + this.maxSize = maxSize this.sizeCalculation = sizeCalculation || length if (this.sizeCalculation) { if (!this.maxSize) { @@ -115,6 +130,13 @@ class LRUCache { throw new TypeError('sizeCalculating set to non-function') } } + + this.fetchMethod = fetchMethod || null + if (this.fetchMethod && typeof this.fetchMethod !== 'function') { + throw new TypeError('fetchMethod must be a function if specified') + } + + this.keyMap = new Map() this.keyList = new Array(max).fill(null) this.valList = new Array(max).fill(null) @@ -139,7 +161,7 @@ class LRUCache { this.noDisposeOnSet = !!noDisposeOnSet this.noUpdateTTL = !!noUpdateTTL - if (this.maxSize) { + if (this.maxSize !== 0) { if (!isPosInt(this.maxSize)) { throw new TypeError('maxSize must be a positive integer if specified') } @@ -159,6 +181,20 @@ class LRUCache { this.initializeTTLTracking() } + // do not allow completely unbounded caches + if (this.max === 0 && this.ttl === 0 && this.maxSize === 0) { + throw new TypeError('At least one of max, maxSize, or ttl is required') + } + if (!this.ttlAutopurge && !this.max && !this.maxSize) { + const code = 'LRU_CACHE_UNBOUNDED' + if (shouldWarn(code)) { + warned.add(code) + const msg = 'TTL caching without ttlAutopurge, max, or maxSize can ' + + 'result in unbounded memory consumption.' + process.emitWarning(msg, 'UnboundedCacheWarning', code, LRUCache) + } + } + if (stale) { deprecatedOption('stale', 'allowStale') } @@ -170,9 +206,14 @@ class LRUCache { } } + getRemainingTTL (key) { + return this.has(key) ? Infinity : 0 + } + initializeTTLTracking () { this.ttls = new ZeroArray(this.max) this.starts = new ZeroArray(this.max) + this.setItemTTL = (index, ttl) => { this.starts[index] = ttl !== 0 ? perf.now() : 0 this.ttls[index] = ttl @@ -188,9 +229,11 @@ class LRUCache { } } } + this.updateItemAge = (index) => { this.starts[index] = this.ttls[index] !== 0 ? perf.now() : 0 } + // debounce calls to perf.now() to 1s so we're not hitting // that costly call repeatedly. let cachedNow = 0 @@ -206,6 +249,16 @@ class LRUCache { } return n } + + this.getRemainingTTL = (key) => { + const index = this.keyMap.get(key) + if (index === undefined) { + return 0 + } + return this.ttls[index] === 0 || this.starts[index] === 0 ? Infinity + : ((this.starts[index] + this.ttls[index]) - (cachedNow || getNow())) + } + this.isStale = (index) => { return this.ttls[index] !== 0 && this.starts[index] !== 0 && ((cachedNow || getNow()) - this.starts[index] > this.ttls[index]) @@ -219,9 +272,17 @@ class LRUCache { this.calculatedSize = 0 this.sizes = new ZeroArray(this.max) this.removeItemSize = index => this.calculatedSize -= this.sizes[index] - this.addItemSize = (index, v, k, size, sizeCalculation) => { - const s = size || (sizeCalculation ? sizeCalculation(v, k) : 0) - this.sizes[index] = isPosInt(s) ? s : 0 + this.requireSize = (k, v, size, sizeCalculation) => { + if (sizeCalculation && !size) { + size = sizeCalculation(v, k) + } + if (!isPosInt(size)) { + throw new TypeError('size must be positive integer') + } + return size + } + this.addItemSize = (index, v, k, size) => { + this.sizes[index] = size const maxSize = this.maxSize - this.sizes[index] while (this.calculatedSize > maxSize) { this.evict() @@ -239,15 +300,19 @@ class LRUCache { } } removeItemSize (index) {} - addItemSize (index, v, k, size, sizeCalculation) {} + addItemSize (index, v, k, size) {} + requireSize (k, v, size, sizeCalculation) { + if (size || sizeCalculation) { + throw new TypeError('cannot set size without setting maxSize on cache') + } + } *indexes ({ allowStale = this.allowStale } = {}) { if (this.size) { - for (let i = this.tail, j; true; ) { + for (let i = this.tail; true; ) { if (!this.isValidIndex(i)) { break } - j = i === this.head if (allowStale || !this.isStale(i)) { yield i } @@ -262,14 +327,13 @@ class LRUCache { *rindexes ({ allowStale = this.allowStale } = {}) { if (this.size) { - for (let i = this.head, j; true; ) { + for (let i = this.head; true; ) { if (!this.isValidIndex(i)) { break } if (allowStale || !this.isStale(i)) { yield i } - // either the tail now, or WAS the tail, and deleted if (i === this.tail) { break } else { @@ -389,6 +453,7 @@ class LRUCache { sizeCalculation = this.sizeCalculation, noUpdateTTL = this.noUpdateTTL, } = {}) { + size = this.requireSize(k, v, size, sizeCalculation) let index = this.size === 0 ? undefined : this.keyMap.get(k) if (index === undefined) { // addition @@ -400,21 +465,25 @@ class LRUCache { this.prev[index] = this.tail this.tail = index this.size ++ - this.addItemSize(index, v, k, size, sizeCalculation) + this.addItemSize(index, v, k, size) noUpdateTTL = false } else { // update const oldVal = this.valList[index] if (v !== oldVal) { - if (!noDisposeOnSet) { - this.dispose(oldVal, k, 'set') - if (this.disposeAfter) { - this.disposed.push([oldVal, k, 'set']) + if (this.isBackgroundFetch(oldVal)) { + oldVal.__abortController.abort() + } else { + if (!noDisposeOnSet) { + this.dispose(oldVal, k, 'set') + if (this.disposeAfter) { + this.disposed.push([oldVal, k, 'set']) + } } } this.removeItemSize(index) this.valList[index] = v - this.addItemSize(index, v, k, size, sizeCalculation) + this.addItemSize(index, v, k, size) } this.moveToTail(index) } @@ -458,9 +527,13 @@ class LRUCache { const head = this.head const k = this.keyList[head] const v = this.valList[head] - this.dispose(v, k, 'evict') - if (this.disposeAfter) { - this.disposed.push([v, k, 'evict']) + if (this.isBackgroundFetch(v)) { + v.__abortController.abort() + } else { + this.dispose(v, k, 'evict') + if (this.disposeAfter) { + this.disposed.push([v, k, 'evict']) + } } this.removeItemSize(head) this.head = this.next[head] @@ -481,22 +554,117 @@ class LRUCache { } } + backgroundFetch (k, index, options) { + const v = index === undefined ? undefined : this.valList[index] + if (this.isBackgroundFetch(v)) { + return v + } + const ac = new AbortController() + const fetchOpts = { + signal: ac.signal, + options, + } + const p = Promise.resolve(this.fetchMethod(k, v, fetchOpts)).then(v => { + if (!ac.signal.aborted) { + this.set(k, v, fetchOpts.options) + } + return v + }) + p.__abortController = ac + p.__staleWhileFetching = v + if (index === undefined) { + this.set(k, p, fetchOpts.options) + index = this.keyMap.get(k) + } else { + this.valList[index] = p + } + return p + } + + isBackgroundFetch (p) { + return p && typeof p === 'object' && typeof p.then === 'function' && + Object.prototype.hasOwnProperty.call(p, '__staleWhileFetching') + } + + // this takes the union of get() and set() opts, because it does both + async fetch (k, { + allowStale = this.allowStale, + updateAgeOnGet = this.updateAgeOnGet, + ttl = this.ttl, + noDisposeOnSet = this.noDisposeOnSet, + size = 0, + sizeCalculation = this.sizeCalculation, + noUpdateTTL = this.noUpdateTTL, + } = {}) { + if (!this.fetchMethod) { + return this.get(k, {allowStale, updateAgeOnGet}) + } + + const options = { + allowStale, + updateAgeOnGet, + ttl, + noDisposeOnSet, + size, + sizeCalculation, + noUpdateTTL, + } + + let index = this.keyMap.get(k) + if (index === undefined) { + return this.backgroundFetch(k, index, options) + } else { + // in cache, maybe already fetching + const v = this.valList[index] + if (this.isBackgroundFetch(v)) { + return allowStale && v.__staleWhileFetching !== undefined + ? v.__staleWhileFetching : v + } + + if (!this.isStale(index)) { + this.moveToTail(index) + if (updateAgeOnGet) { + this.updateItemAge(index) + } + return v + } + + // ok, it is stale, and not already fetching + // refresh the cache. + const p = this.backgroundFetch(k, index, options) + return allowStale && p.__staleWhileFetching !== undefined + ? p.__staleWhileFetching : p + } + } + get (k, { allowStale = this.allowStale, updateAgeOnGet = this.updateAgeOnGet, } = {}) { const index = this.keyMap.get(k) if (index !== undefined) { + const value = this.valList[index] + const fetching = this.isBackgroundFetch(value) if (this.isStale(index)) { - const value = allowStale ? this.valList[index] : undefined - this.delete(k) - return value + // delete only if not an in-flight background fetch + if (!fetching) { + this.delete(k) + return allowStale ? value : undefined + } else { + return allowStale ? value.__staleWhileFetching : undefined + } } else { + // if we're currently fetching it, we don't actually have it yet + // it's not stale, which means this isn't a staleWhileRefetching, + // so we just return undefined + if (fetching) { + return undefined + } this.moveToTail(index) if (updateAgeOnGet) { this.updateItemAge(index) } - return this.valList[index] + return value } } } @@ -540,9 +708,14 @@ class LRUCache { this.clear() } else { this.removeItemSize(index) - this.dispose(this.valList[index], k, 'delete') - if (this.disposeAfter) { - this.disposed.push([this.valList[index], k, 'delete']) + const v = this.valList[index] + if (this.isBackgroundFetch(v)) { + v.__abortController.abort() + } else { + this.dispose(v, k, 'delete') + if (this.disposeAfter) { + this.disposed.push([v, k, 'delete']) + } } this.keyMap.delete(k) this.keyList[index] = null @@ -569,16 +742,19 @@ class LRUCache { } clear () { - if (this.dispose !== LRUCache.prototype.dispose) { - for (const index of this.rindexes({ allowStale: true })) { - this.dispose(this.valList[index], this.keyList[index], 'delete') - } - } - if (this.disposeAfter) { - for (const index of this.rindexes({ allowStale: true })) { - this.disposed.push([this.valList[index], this.keyList[index], 'delete']) + for (const index of this.rindexes({ allowStale: true })) { + const v = this.valList[index] + if (this.isBackgroundFetch(v)) { + v.__abortController.abort() + } else { + const k = this.keyList[index] + this.dispose(v, k, 'delete') + if (this.disposeAfter) { + this.disposed.push([v, k, 'delete']) + } } } + this.keyMap.clear() this.valList.fill(null) this.keyList.fill(null) diff --git a/node_modules/lru-cache/package.json b/node_modules/lru-cache/package.json index a62f74c2b648a..84d199c2b21b3 100644 --- a/node_modules/lru-cache/package.json +++ b/node_modules/lru-cache/package.json @@ -1,7 +1,7 @@ { "name": "lru-cache", "description": "A cache object that deletes the least-recently-used items.", - "version": "7.5.1", + "version": "7.7.1", "author": "Isaac Z. Schlueter ", "keywords": [ "mru", @@ -22,6 +22,7 @@ "devDependencies": { "@size-limit/preset-small-lib": "^7.0.8", "benchmark": "^2.1.4", + "clock-mock": "^1.0.3", "size-limit": "^7.0.8", "tap": "^15.1.6" }, diff --git a/node_modules/npm-registry-fetch/lib/check-response.js b/node_modules/npm-registry-fetch/lib/check-response.js index 872ec8a888694..714513908df40 100644 --- a/node_modules/npm-registry-fetch/lib/check-response.js +++ b/node_modules/npm-registry-fetch/lib/check-response.js @@ -4,6 +4,7 @@ const errors = require('./errors.js') const { Response } = require('minipass-fetch') const defaultOpts = require('./default-opts.js') const log = require('proc-log') +const cleanUrl = require('./clean-url.js') /* eslint-disable-next-line max-len */ const moreInfoUrl = 'https://github.com/npm/cli/wiki/No-auth-for-URI,-but-auth-present-for-scoped-registry' @@ -45,19 +46,7 @@ function logRequest (method, res, startTime) { const attemptStr = attempt && attempt > 1 ? ` attempt #${attempt}` : '' const cacheStatus = res.headers.get('x-local-cache-status') const cacheStr = cacheStatus ? ` (cache ${cacheStatus})` : '' - - let urlStr - try { - const { URL } = require('url') - const url = new URL(res.url) - if (url.password) { - url.password = '***' - } - - urlStr = url.toString() - } catch (er) { - urlStr = res.url - } + const urlStr = cleanUrl(res.url) log.http( 'fetch', diff --git a/node_modules/npm-registry-fetch/lib/clean-url.js b/node_modules/npm-registry-fetch/lib/clean-url.js new file mode 100644 index 0000000000000..ba31dc462f3c5 --- /dev/null +++ b/node_modules/npm-registry-fetch/lib/clean-url.js @@ -0,0 +1,24 @@ +const { URL } = require('url') + +const replace = '***' +const tokenRegex = /\bnpm_[a-zA-Z0-9]{36}\b/g +const guidRegex = /\b[0-9a-f]{8}-[0-9a-f]{4}-[0-9a-f]{4}-[0-9a-f]{4}-[0-9a-f]{12}\b/g + +const cleanUrl = (str) => { + if (typeof str !== 'string' || !str) { + return str + } + + try { + const url = new URL(str) + if (url.password) { + str = str.replace(url.password, replace) + } + } catch {} + + return str + .replace(tokenRegex, `npm_${replace}`) + .replace(guidRegex, `npm_${replace}`) +} + +module.exports = cleanUrl diff --git a/node_modules/npm-registry-fetch/lib/index.js b/node_modules/npm-registry-fetch/lib/index.js index 19c921403e5cd..6c834aa4af5ef 100644 --- a/node_modules/npm-registry-fetch/lib/index.js +++ b/node_modules/npm-registry-fetch/lib/index.js @@ -104,11 +104,11 @@ function regFetch (uri, /* istanbul ignore next */ opts_ = {}) { opts.preferOnline = true } - const doFetch = async body => { + const doFetch = async fetchBody => { const p = fetch(uri, { agent: opts.agent, algorithms: opts.algorithms, - body, + body: fetchBody, cache: getCacheMode(opts), cachePath: opts.cache, ca: opts.ca, @@ -239,3 +239,5 @@ function getHeaders (uri, auth, opts) { return headers } + +module.exports.cleanUrl = require('./clean-url.js') diff --git a/node_modules/npm-registry-fetch/lib/silentlog.js b/node_modules/npm-registry-fetch/lib/silentlog.js deleted file mode 100644 index 483bd44c7086a..0000000000000 --- a/node_modules/npm-registry-fetch/lib/silentlog.js +++ /dev/null @@ -1,14 +0,0 @@ -'use strict' - -const noop = Function.prototype -module.exports = { - error: noop, - warn: noop, - notice: noop, - info: noop, - verbose: noop, - silly: noop, - http: noop, - pause: noop, - resume: noop, -} diff --git a/node_modules/npm-registry-fetch/package.json b/node_modules/npm-registry-fetch/package.json index 75236be2a9015..9e15f627cd5a7 100644 --- a/node_modules/npm-registry-fetch/package.json +++ b/node_modules/npm-registry-fetch/package.json @@ -1,15 +1,15 @@ { "name": "npm-registry-fetch", - "version": "13.0.1", + "version": "13.1.0", "description": "Fetch-based http client for use with npm registry APIs", "main": "lib", "files": [ - "bin", - "lib" + "bin/", + "lib/" ], "scripts": { "eslint": "eslint", - "lint": "eslint '**/*.js'", + "lint": "eslint \"**/*.js\"", "lintfix": "npm run lint -- --fix", "prepublishOnly": "git push origin --follow-tags", "preversion": "npm test", @@ -18,11 +18,14 @@ "posttest": "npm run lint", "npmclilint": "npmcli-lint", "postsnap": "npm run lintfix --", - "postlint": "npm-template-check", + "postlint": "template-oss-check", "snap": "tap", - "template-copy": "npm-template-copy --force" + "template-oss-apply": "template-oss-apply --force" + }, + "repository": { + "type": "git", + "url": "https://github.com/npm/npm-registry-fetch.git" }, - "repository": "https://github.com/npm/npm-registry-fetch", "keywords": [ "npm", "registry", @@ -31,17 +34,18 @@ "author": "GitHub Inc.", "license": "ISC", "dependencies": { - "make-fetch-happen": "^10.0.3", + "make-fetch-happen": "^10.0.6", "minipass": "^3.1.6", - "minipass-fetch": "^2.0.1", + "minipass-fetch": "^2.0.3", "minipass-json-stream": "^1.0.1", "minizlib": "^2.1.2", - "npm-package-arg": "^9.0.0", + "npm-package-arg": "^9.0.1", "proc-log": "^2.0.0" }, "devDependencies": { - "@npmcli/template-oss": "^2.8.1", - "cacache": "^15.3.0", + "@npmcli/eslint-config": "^3.0.1", + "@npmcli/template-oss": "3.1.2", + "cacache": "^16.0.2", "nock": "^13.2.4", "require-inject": "^1.4.4", "ssri": "^8.0.1", @@ -52,9 +56,10 @@ "test-ignore": "test[\\\\/](util|cache)[\\\\/]" }, "engines": { - "node": "^12.13.0 || ^14.15.0 || >=16" + "node": "^12.13.0 || ^14.15.0 || >=16.0.0" }, "templateOSS": { - "version": "2.8.1" + "//@npmcli/template-oss": "This file is partially managed by @npmcli/template-oss. Edits may be overwritten.", + "version": "3.1.2" } } diff --git a/package-lock.json b/package-lock.json index 648a7496f8a70..a9c1156753b9a 100644 --- a/package-lock.json +++ b/package-lock.json @@ -12,6 +12,7 @@ "@npmcli/arborist", "@npmcli/ci-detect", "@npmcli/config", + "@npmcli/fs", "@npmcli/map-workspaces", "@npmcli/package-json", "@npmcli/run-script", @@ -90,6 +91,7 @@ "@npmcli/arborist": "^5.0.3", "@npmcli/ci-detect": "^2.0.0", "@npmcli/config": "^4.0.1", + "@npmcli/fs": "^2.1.0", "@npmcli/map-workspaces": "^2.0.2", "@npmcli/package-json": "^1.0.1", "@npmcli/run-script": "^3.0.1", @@ -97,7 +99,7 @@ "ansicolors": "~0.3.2", "ansistyles": "~0.1.3", "archy": "~1.0.0", - "cacache": "^16.0.2", + "cacache": "^16.0.3", "chalk": "^4.1.2", "chownr": "^2.0.0", "cli-columns": "^4.0.0", @@ -135,7 +137,7 @@ "npm-package-arg": "^9.0.1", "npm-pick-manifest": "^7.0.0", "npm-profile": "^6.0.2", - "npm-registry-fetch": "^13.0.1", + "npm-registry-fetch": "^13.1.0", "npm-user-validate": "^1.0.1", "npmlog": "^6.0.1", "opener": "^1.5.2", @@ -865,16 +867,16 @@ } }, "node_modules/@npmcli/fs": { - "version": "1.1.0", - "resolved": "https://registry.npmjs.org/@npmcli/fs/-/fs-1.1.0.tgz", - "integrity": "sha512-VhP1qZLXcrXRIaPoqb4YA55JQxLNF3jNR4T55IdOJa3+IFJKNYHtPvtXx8slmeMavj37vCzCfrqQM1vWLsYKLA==", + "version": "2.1.0", + "resolved": "https://registry.npmjs.org/@npmcli/fs/-/fs-2.1.0.tgz", + "integrity": "sha512-DmfBvNXGaetMxj9LTp8NAN9vEidXURrf5ZTslQzEAi/6GbW+4yjaLFQc6Tue5cpZ9Frlk4OBo/Snf1Bh/S7qTQ==", "inBundle": true, "dependencies": { - "@gar/promisify": "^1.0.1", + "@gar/promisify": "^1.1.3", "semver": "^7.3.5" }, "engines": { - "node": "^12.13.0 || ^14.15.0 || >=16" + "node": "^12.13.0 || ^14.15.0 || >=16.0.0" } }, "node_modules/@npmcli/git": { @@ -1046,19 +1048,6 @@ "tap": "^15.0.9" } }, - "node_modules/@npmcli/template-oss/node_modules/@npmcli/fs": { - "version": "2.0.1", - "resolved": "https://registry.npmjs.org/@npmcli/fs/-/fs-2.0.1.tgz", - "integrity": "sha512-vlaJ+kcURCo0SK1afdX5BQ9hgbXDKhpOxdIOg3jvn7wnKp8NcSDjvYc490VuJn2ciOgAFXV9qZzZPgHlcpXkxA==", - "dev": true, - "dependencies": { - "@gar/promisify": "^1.1.3", - "semver": "^7.3.5" - }, - "engines": { - "node": "^12.13.0 || ^14.15.0 || >=16" - } - }, "node_modules/@tootallnate/once": { "version": "2.0.0", "resolved": "https://registry.npmjs.org/@tootallnate/once/-/once-2.0.0.tgz", @@ -1604,18 +1593,18 @@ "inBundle": true }, "node_modules/cacache": { - "version": "16.0.2", - "resolved": "https://registry.npmjs.org/cacache/-/cacache-16.0.2.tgz", - "integrity": "sha512-Q17j7s8X81i/QYVrKVQ/qwWGT+pYLfpTcZ+X+p/Qw9FULy9JEfb2FECYTTt6mPV6A/vk92nRZ80ncpKxiGTrIA==", + "version": "16.0.3", + "resolved": "https://registry.npmjs.org/cacache/-/cacache-16.0.3.tgz", + "integrity": "sha512-eC7wYodNCVb97kuHGk5P+xZsvUJHkhSEOyNwkenqQPAsOtrTjvWOE5vSPNBpz9d8X3acIf6w2Ub5s4rvOCTs4g==", "inBundle": true, "dependencies": { - "@npmcli/fs": "^1.0.0", + "@npmcli/fs": "^2.1.0", "@npmcli/move-file": "^1.1.2", "chownr": "^2.0.0", "fs-minipass": "^2.1.0", "glob": "^7.2.0", "infer-owner": "^1.0.4", - "lru-cache": "^7.5.1", + "lru-cache": "^7.7.1", "minipass": "^3.1.6", "minipass-collect": "^1.0.2", "minipass-flush": "^1.0.5", @@ -1629,7 +1618,7 @@ "unique-filename": "^1.1.1" }, "engines": { - "node": "^12.13.0 || ^14.15.0 || >=16" + "node": "^12.13.0 || ^14.15.0 || >=16.0.0" } }, "node_modules/caching-transform": { @@ -4828,9 +4817,9 @@ } }, "node_modules/lru-cache": { - "version": "7.5.1", - "resolved": "https://registry.npmjs.org/lru-cache/-/lru-cache-7.5.1.tgz", - "integrity": "sha512-q1TS8IqKvcg3aScamKCHpepSrHF537Ww7nHahBOxhDu9D2YoBXAsj/7uFdZFj1xJr9LmyeJ62AdyofCHafUbIA==", + "version": "7.7.1", + "resolved": "https://registry.npmjs.org/lru-cache/-/lru-cache-7.7.1.tgz", + "integrity": "sha512-cRffBiTW8s73eH4aTXqBcTLU0xQnwGV3/imttRHGWCrbergmnK4D6JXQd8qin5z43HnDwRI+o7mVW0LEB+tpAw==", "inBundle": true, "engines": { "node": ">=12" @@ -5441,21 +5430,21 @@ } }, "node_modules/npm-registry-fetch": { - "version": "13.0.1", - "resolved": "https://registry.npmjs.org/npm-registry-fetch/-/npm-registry-fetch-13.0.1.tgz", - "integrity": "sha512-Ak+LXVtSrCLOdscFW/apUw67OPNph8waHsPKM9UOJosL7i59EF5XoSWQMEsXEOeifM9Bb4/2+WrQC4t/pd8DGg==", + "version": "13.1.0", + "resolved": "https://registry.npmjs.org/npm-registry-fetch/-/npm-registry-fetch-13.1.0.tgz", + "integrity": "sha512-TIYL5X8CcwDhbFMXFDShNcpG6OMCYK6VzvSr6MUWP20tCU2DJ4ao2qQg3DT+3Pet8mO6/cgbZpon4LMh3duYLg==", "inBundle": true, "dependencies": { - "make-fetch-happen": "^10.0.3", + "make-fetch-happen": "^10.0.6", "minipass": "^3.1.6", - "minipass-fetch": "^2.0.1", + "minipass-fetch": "^2.0.3", "minipass-json-stream": "^1.0.1", "minizlib": "^2.1.2", - "npm-package-arg": "^9.0.0", + "npm-package-arg": "^9.0.1", "proc-log": "^2.0.0" }, "engines": { - "node": "^12.13.0 || ^14.15.0 || >=16" + "node": "^12.13.0 || ^14.15.0 || >=16.0.0" } }, "node_modules/npm-user-validate": { @@ -11275,11 +11264,11 @@ } }, "@npmcli/fs": { - "version": "1.1.0", - "resolved": "https://registry.npmjs.org/@npmcli/fs/-/fs-1.1.0.tgz", - "integrity": "sha512-VhP1qZLXcrXRIaPoqb4YA55JQxLNF3jNR4T55IdOJa3+IFJKNYHtPvtXx8slmeMavj37vCzCfrqQM1vWLsYKLA==", + "version": "2.1.0", + "resolved": "https://registry.npmjs.org/@npmcli/fs/-/fs-2.1.0.tgz", + "integrity": "sha512-DmfBvNXGaetMxj9LTp8NAN9vEidXURrf5ZTslQzEAi/6GbW+4yjaLFQc6Tue5cpZ9Frlk4OBo/Snf1Bh/S7qTQ==", "requires": { - "@gar/promisify": "^1.0.1", + "@gar/promisify": "^1.1.3", "semver": "^7.3.5" } }, @@ -11405,18 +11394,6 @@ "@npmcli/package-json": "^1.0.1", "json-parse-even-better-errors": "^2.3.1", "which": "^2.0.2" - }, - "dependencies": { - "@npmcli/fs": { - "version": "2.0.1", - "resolved": "https://registry.npmjs.org/@npmcli/fs/-/fs-2.0.1.tgz", - "integrity": "sha512-vlaJ+kcURCo0SK1afdX5BQ9hgbXDKhpOxdIOg3jvn7wnKp8NcSDjvYc490VuJn2ciOgAFXV9qZzZPgHlcpXkxA==", - "dev": true, - "requires": { - "@gar/promisify": "^1.1.3", - "semver": "^7.3.5" - } - } } }, "@tootallnate/once": { @@ -11834,17 +11811,17 @@ "integrity": "sha1-y5T662HIaWRR2zZTThQi+U8K7og=" }, "cacache": { - "version": "16.0.2", - "resolved": "https://registry.npmjs.org/cacache/-/cacache-16.0.2.tgz", - "integrity": "sha512-Q17j7s8X81i/QYVrKVQ/qwWGT+pYLfpTcZ+X+p/Qw9FULy9JEfb2FECYTTt6mPV6A/vk92nRZ80ncpKxiGTrIA==", + "version": "16.0.3", + "resolved": "https://registry.npmjs.org/cacache/-/cacache-16.0.3.tgz", + "integrity": "sha512-eC7wYodNCVb97kuHGk5P+xZsvUJHkhSEOyNwkenqQPAsOtrTjvWOE5vSPNBpz9d8X3acIf6w2Ub5s4rvOCTs4g==", "requires": { - "@npmcli/fs": "^1.0.0", + "@npmcli/fs": "^2.1.0", "@npmcli/move-file": "^1.1.2", "chownr": "^2.0.0", "fs-minipass": "^2.1.0", "glob": "^7.2.0", "infer-owner": "^1.0.4", - "lru-cache": "^7.5.1", + "lru-cache": "^7.7.1", "minipass": "^3.1.6", "minipass-collect": "^1.0.2", "minipass-flush": "^1.0.5", @@ -14464,9 +14441,9 @@ "dev": true }, "lru-cache": { - "version": "7.5.1", - "resolved": "https://registry.npmjs.org/lru-cache/-/lru-cache-7.5.1.tgz", - "integrity": "sha512-q1TS8IqKvcg3aScamKCHpepSrHF537Ww7nHahBOxhDu9D2YoBXAsj/7uFdZFj1xJr9LmyeJ62AdyofCHafUbIA==" + "version": "7.7.1", + "resolved": "https://registry.npmjs.org/lru-cache/-/lru-cache-7.7.1.tgz", + "integrity": "sha512-cRffBiTW8s73eH4aTXqBcTLU0xQnwGV3/imttRHGWCrbergmnK4D6JXQd8qin5z43HnDwRI+o7mVW0LEB+tpAw==" }, "make-dir": { "version": "3.1.0", @@ -14911,16 +14888,16 @@ } }, "npm-registry-fetch": { - "version": "13.0.1", - "resolved": "https://registry.npmjs.org/npm-registry-fetch/-/npm-registry-fetch-13.0.1.tgz", - "integrity": "sha512-Ak+LXVtSrCLOdscFW/apUw67OPNph8waHsPKM9UOJosL7i59EF5XoSWQMEsXEOeifM9Bb4/2+WrQC4t/pd8DGg==", + "version": "13.1.0", + "resolved": "https://registry.npmjs.org/npm-registry-fetch/-/npm-registry-fetch-13.1.0.tgz", + "integrity": "sha512-TIYL5X8CcwDhbFMXFDShNcpG6OMCYK6VzvSr6MUWP20tCU2DJ4ao2qQg3DT+3Pet8mO6/cgbZpon4LMh3duYLg==", "requires": { - "make-fetch-happen": "^10.0.3", + "make-fetch-happen": "^10.0.6", "minipass": "^3.1.6", - "minipass-fetch": "^2.0.1", + "minipass-fetch": "^2.0.3", "minipass-json-stream": "^1.0.1", "minizlib": "^2.1.2", - "npm-package-arg": "^9.0.0", + "npm-package-arg": "^9.0.1", "proc-log": "^2.0.0" } }, diff --git a/package.json b/package.json index d51ffcd4dc4fb..ac5f5dd0bc9b0 100644 --- a/package.json +++ b/package.json @@ -58,6 +58,7 @@ "@npmcli/arborist": "^5.0.3", "@npmcli/ci-detect": "^2.0.0", "@npmcli/config": "^4.0.1", + "@npmcli/fs": "^2.1.0", "@npmcli/map-workspaces": "^2.0.2", "@npmcli/package-json": "^1.0.1", "@npmcli/run-script": "^3.0.1", @@ -65,7 +66,7 @@ "ansicolors": "~0.3.2", "ansistyles": "~0.1.3", "archy": "~1.0.0", - "cacache": "^16.0.2", + "cacache": "^16.0.3", "chalk": "^4.1.2", "chownr": "^2.0.0", "cli-columns": "^4.0.0", @@ -103,7 +104,7 @@ "npm-package-arg": "^9.0.1", "npm-pick-manifest": "^7.0.0", "npm-profile": "^6.0.2", - "npm-registry-fetch": "^13.0.1", + "npm-registry-fetch": "^13.1.0", "npm-user-validate": "^1.0.1", "npmlog": "^6.0.1", "opener": "^1.5.2", @@ -131,6 +132,7 @@ "@npmcli/arborist", "@npmcli/ci-detect", "@npmcli/config", + "@npmcli/fs", "@npmcli/map-workspaces", "@npmcli/package-json", "@npmcli/run-script", diff --git a/tap-snapshots/test/lib/commands/config.js.test.cjs b/tap-snapshots/test/lib/commands/config.js.test.cjs index 8e97915230719..3594cf25d5b73 100644 --- a/tap-snapshots/test/lib/commands/config.js.test.cjs +++ b/tap-snapshots/test/lib/commands/config.js.test.cjs @@ -89,6 +89,7 @@ exports[`test/lib/commands/config.js TAP config list --json > output matches sna "location": "user", "lockfile-version": null, "loglevel": "notice", + "logs-dir": null, "logs-max": 10, "long": false, "maxsockets": 15, @@ -241,6 +242,7 @@ local-address = null location = "user" lockfile-version = null loglevel = "notice" +logs-dir = null logs-max = 10 ; long = false ; overridden by cli maxsockets = 15 diff --git a/tap-snapshots/test/lib/utils/config/definitions.js.test.cjs b/tap-snapshots/test/lib/utils/config/definitions.js.test.cjs index 373f094a59af9..b4dce9b52fc42 100644 --- a/tap-snapshots/test/lib/utils/config/definitions.js.test.cjs +++ b/tap-snapshots/test/lib/utils/config/definitions.js.test.cjs @@ -85,6 +85,7 @@ Array [ "location", "lockfile-version", "loglevel", + "logs-dir", "logs-max", "long", "maxsockets", @@ -1098,6 +1099,16 @@ Any logs of a higher level than the setting are shown. The default is See also the \`foreground-scripts\` config. ` +exports[`test/lib/utils/config/definitions.js TAP > config description for logs-dir 1`] = ` +#### \`logs-dir\` + +* Default: A directory named \`_logs\` inside the cache +* Type: null or Path + +The location of npm's log directory. See [\`npm logging\`](/using-npm/logging) +for more information. +` + exports[`test/lib/utils/config/definitions.js TAP > config description for logs-max 1`] = ` #### \`logs-max\` @@ -1105,6 +1116,8 @@ exports[`test/lib/utils/config/definitions.js TAP > config description for logs- * Type: Number The maximum number of log files to store. + +If set to 0, no log files will be written for the current run. ` exports[`test/lib/utils/config/definitions.js TAP > config description for long 1`] = ` @@ -1720,9 +1733,9 @@ exports[`test/lib/utils/config/definitions.js TAP > config description for timin * Default: false * Type: Boolean -If true, writes an \`npm-debug\` log to \`_logs\` and timing information to -\`_timing.json\`, both in your cache, even if the command completes -successfully. \`_timing.json\` is a newline delimited list of JSON objects. +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. You can quickly view it with this [json](https://npm.im/json) command line: \`npm exec -- json -g < ~/.npm/_timing.json\`. diff --git a/tap-snapshots/test/lib/utils/config/describe-all.js.test.cjs b/tap-snapshots/test/lib/utils/config/describe-all.js.test.cjs index 3a7d90db01be6..ac0d0e25d3685 100644 --- a/tap-snapshots/test/lib/utils/config/describe-all.js.test.cjs +++ b/tap-snapshots/test/lib/utils/config/describe-all.js.test.cjs @@ -901,6 +901,17 @@ See also the \`foreground-scripts\` config. +#### \`logs-dir\` + +* Default: A directory named \`_logs\` inside the cache +* Type: null or Path + +The location of npm's log directory. See [\`npm logging\`](/using-npm/logging) +for more information. + + + + #### \`logs-max\` * Default: 10 @@ -908,6 +919,8 @@ See also the \`foreground-scripts\` config. The maximum number of log files to store. +If set to 0, no log files will be written for the current run. + @@ -1502,9 +1515,9 @@ particular, use care when overriding this setting for public packages. * Default: false * Type: Boolean -If true, writes an \`npm-debug\` log to \`_logs\` and timing information to -\`_timing.json\`, both in your cache, even if the command completes -successfully. \`_timing.json\` is a newline delimited list of JSON objects. +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. You can quickly view it with this [json](https://npm.im/json) command line: \`npm exec -- json -g < ~/.npm/_timing.json\`. diff --git a/tap-snapshots/test/lib/utils/error-message.js.test.cjs b/tap-snapshots/test/lib/utils/error-message.js.test.cjs index 6316f04fd0998..8e772e8691860 100644 --- a/tap-snapshots/test/lib/utils/error-message.js.test.cjs +++ b/tap-snapshots/test/lib/utils/error-message.js.test.cjs @@ -499,6 +499,18 @@ Object { exports[`test/lib/utils/error-message.js TAP eacces/eperm {"windows":false,"loaded":true,"cachePath":false,"cacheDest":false} > must match snapshot 2`] = ` Array [ + Array [ + "title", + "npm", + ], + Array [ + "argv", + "", + ], + Array [ + "logfile", + "logs-max:10 dir:{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-false-loaded-true-cachePath-false-cacheDest-false-/cache/_logs", + ], Array [ "logfile", "{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-false-loaded-true-cachePath-false-cacheDest-false-/cache/_logs/{DATE}-debug-0.log", @@ -527,6 +539,18 @@ Object { exports[`test/lib/utils/error-message.js TAP eacces/eperm {"windows":false,"loaded":true,"cachePath":false,"cacheDest":true} > must match snapshot 2`] = ` Array [ + Array [ + "title", + "npm", + ], + Array [ + "argv", + "", + ], + Array [ + "logfile", + "logs-max:10 dir:{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-false-loaded-true-cachePath-false-cacheDest-true-/cache/_logs", + ], Array [ "logfile", "{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-false-loaded-true-cachePath-false-cacheDest-true-/cache/_logs/{DATE}-debug-0.log", @@ -558,6 +582,18 @@ Object { exports[`test/lib/utils/error-message.js TAP eacces/eperm {"windows":false,"loaded":true,"cachePath":true,"cacheDest":false} > must match snapshot 2`] = ` Array [ + Array [ + "title", + "npm", + ], + Array [ + "argv", + "", + ], + Array [ + "logfile", + "logs-max:10 dir:{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-false-loaded-true-cachePath-true-cacheDest-false-/cache/_logs", + ], Array [ "logfile", "{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-false-loaded-true-cachePath-true-cacheDest-false-/cache/_logs/{DATE}-debug-0.log", @@ -589,6 +625,18 @@ Object { exports[`test/lib/utils/error-message.js TAP eacces/eperm {"windows":false,"loaded":true,"cachePath":true,"cacheDest":true} > must match snapshot 2`] = ` Array [ + Array [ + "title", + "npm", + ], + Array [ + "argv", + "", + ], + Array [ + "logfile", + "logs-max:10 dir:{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-false-loaded-true-cachePath-true-cacheDest-true-/cache/_logs", + ], Array [ "logfile", "{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-false-loaded-true-cachePath-true-cacheDest-true-/cache/_logs/{DATE}-debug-0.log", @@ -767,6 +815,18 @@ Object { exports[`test/lib/utils/error-message.js TAP eacces/eperm {"windows":true,"loaded":true,"cachePath":false,"cacheDest":false} > must match snapshot 2`] = ` Array [ + Array [ + "title", + "npm", + ], + Array [ + "argv", + "", + ], + Array [ + "logfile", + "logs-max:10 dir:{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-true-loaded-true-cachePath-false-cacheDest-false-/cache/_logs", + ], Array [ "logfile", "{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-true-loaded-true-cachePath-false-cacheDest-false-/cache/_logs/{DATE}-debug-0.log", @@ -806,6 +866,18 @@ Object { exports[`test/lib/utils/error-message.js TAP eacces/eperm {"windows":true,"loaded":true,"cachePath":false,"cacheDest":true} > must match snapshot 2`] = ` Array [ + Array [ + "title", + "npm", + ], + Array [ + "argv", + "", + ], + Array [ + "logfile", + "logs-max:10 dir:{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-true-loaded-true-cachePath-false-cacheDest-true-/cache/_logs", + ], Array [ "logfile", "{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-true-loaded-true-cachePath-false-cacheDest-true-/cache/_logs/{DATE}-debug-0.log", @@ -845,6 +917,18 @@ Object { exports[`test/lib/utils/error-message.js TAP eacces/eperm {"windows":true,"loaded":true,"cachePath":true,"cacheDest":false} > must match snapshot 2`] = ` Array [ + Array [ + "title", + "npm", + ], + Array [ + "argv", + "", + ], + Array [ + "logfile", + "logs-max:10 dir:{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-true-loaded-true-cachePath-true-cacheDest-false-/cache/_logs", + ], Array [ "logfile", "{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-true-loaded-true-cachePath-true-cacheDest-false-/cache/_logs/{DATE}-debug-0.log", @@ -884,6 +968,18 @@ Object { exports[`test/lib/utils/error-message.js TAP eacces/eperm {"windows":true,"loaded":true,"cachePath":true,"cacheDest":true} > must match snapshot 2`] = ` Array [ + Array [ + "title", + "npm", + ], + Array [ + "argv", + "", + ], + Array [ + "logfile", + "logs-max:10 dir:{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-true-loaded-true-cachePath-true-cacheDest-true-/cache/_logs", + ], Array [ "logfile", "{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-true-loaded-true-cachePath-true-cacheDest-true-/cache/_logs/{DATE}-debug-0.log", diff --git a/tap-snapshots/test/lib/utils/exit-handler.js.test.cjs b/tap-snapshots/test/lib/utils/exit-handler.js.test.cjs index 0aaf235fd14b6..edb7edaa5d5f5 100644 --- a/tap-snapshots/test/lib/utils/exit-handler.js.test.cjs +++ b/tap-snapshots/test/lib/utils/exit-handler.js.test.cjs @@ -9,44 +9,54 @@ exports[`test/lib/utils/exit-handler.js TAP handles unknown error with logs and 0 timing npm:load:whichnode Completed in {TIME}ms 15 timing config:load Completed in {TIME}ms 16 timing npm:load:configload Completed in {TIME}ms -17 timing npm:load:setTitle Completed in {TIME}ms -19 timing npm:load:display Completed in {TIME}ms -20 verbose logfile {CWD}/test/lib/utils/tap-testdir-exit-handler-handles-unknown-error-with-logs-and-debug-file/cache/_logs/{DATE}-debug-0.log -21 timing npm:load:logFile Completed in {TIME}ms -22 timing npm:load:timers Completed in {TIME}ms -23 timing npm:load:configScope Completed in {TIME}ms -24 timing npm:load Completed in {TIME}ms -25 verbose stack Error: Unknown error -26 verbose cwd {CWD} -27 verbose Foo 1.0.0 -28 verbose argv "/node" "{CWD}/test/lib/utils/exit-handler.js" -29 verbose node v1.0.0 -30 verbose npm v1.0.0 -31 error code ECODE -32 error ERR SUMMARY Unknown error -33 error ERR DETAIL Unknown error -34 verbose exit 1 -36 timing npm Completed in {TIME}ms -37 verbose code 1 -38 error A complete log of this run can be found in: -38 error {CWD}/test/lib/utils/tap-testdir-exit-handler-handles-unknown-error-with-logs-and-debug-file/cache/_logs/{DATE}-debug-0.log +17 timing npm:load:mkdirpcache Completed in {TIME}ms +18 timing npm:load:mkdirplogs Completed in {TIME}ms +19 verbose title npm +20 verbose argv +21 timing npm:load:setTitle Completed in {TIME}ms +23 timing npm:load:display Completed in {TIME}ms +24 verbose logfile logs-max:10 dir:{CWD}/test/lib/utils/tap-testdir-exit-handler-handles-unknown-error-with-logs-and-debug-file/cache/_logs +25 verbose logfile {CWD}/test/lib/utils/tap-testdir-exit-handler-handles-unknown-error-with-logs-and-debug-file/cache/_logs/{DATE}-debug-0.log +26 timing npm:load:logFile Completed in {TIME}ms +27 timing npm:load:timers Completed in {TIME}ms +28 timing npm:load:configScope Completed in {TIME}ms +29 timing npm:load Completed in {TIME}ms +30 silly logfile done cleaning log files +31 verbose stack Error: Unknown error +32 verbose cwd {CWD} +33 verbose Foo 1.0.0 +34 verbose node v1.0.0 +35 verbose npm v1.0.0 +36 error code ECODE +37 error ERR SUMMARY Unknown error +38 error ERR DETAIL Unknown error +39 verbose exit 1 +41 timing npm Completed in {TIME}ms +42 verbose code 1 +43 error A complete log of this run can be found in: +43 error {CWD}/test/lib/utils/tap-testdir-exit-handler-handles-unknown-error-with-logs-and-debug-file/cache/_logs/{DATE}-debug-0.log ` exports[`test/lib/utils/exit-handler.js TAP handles unknown error with logs and debug file > logs 1`] = ` timing npm:load:whichnode Completed in {TIME}ms timing config:load Completed in {TIME}ms timing npm:load:configload Completed in {TIME}ms +timing npm:load:mkdirpcache Completed in {TIME}ms +timing npm:load:mkdirplogs Completed in {TIME}ms +verbose title npm +verbose argv timing npm:load:setTitle Completed in {TIME}ms timing npm:load:display Completed in {TIME}ms +verbose logfile logs-max:10 dir:{CWD}/test/lib/utils/tap-testdir-exit-handler-handles-unknown-error-with-logs-and-debug-file/cache/_logs verbose logfile {CWD}/test/lib/utils/tap-testdir-exit-handler-handles-unknown-error-with-logs-and-debug-file/cache/_logs/{DATE}-debug-0.log timing npm:load:logFile Completed in {TIME}ms timing npm:load:timers Completed in {TIME}ms timing npm:load:configScope Completed in {TIME}ms timing npm:load Completed in {TIME}ms +silly logfile done cleaning log files verbose stack Error: Unknown error verbose cwd {CWD} verbose Foo 1.0.0 -verbose argv "/node" "{CWD}/test/lib/utils/exit-handler.js" verbose node v1.0.0 verbose npm v1.0.0 error code ECODE diff --git a/tap-snapshots/test/lib/utils/log-file.js.test.cjs b/tap-snapshots/test/lib/utils/log-file.js.test.cjs index ecce9eafcc925..7a39184939026 100644 --- a/tap-snapshots/test/lib/utils/log-file.js.test.cjs +++ b/tap-snapshots/test/lib/utils/log-file.js.test.cjs @@ -6,63 +6,65 @@ */ 'use strict' exports[`test/lib/utils/log-file.js TAP snapshot > must match snapshot 1`] = ` -0 error no prefix -1 error prefix with prefix -2 error prefix 1 2 3 -3 verbose { obj: { with: { many: [Object] } } } -4 verbose {"obj":{"with":{"many":{"props":1}}}} -5 verbose { -5 verbose "obj": { -5 verbose "with": { -5 verbose "many": { -5 verbose "props": 1 -5 verbose } -5 verbose } -5 verbose } -5 verbose } -6 verbose [ 'test', 'with', 'an', 'array' ] -7 verbose ["test","with","an","array"] -8 verbose [ -8 verbose "test", -8 verbose "with", -8 verbose "an", -8 verbose "array" -8 verbose ] -9 verbose [ 'test', [ 'with', [ 'an', [Array] ] ] ] -10 verbose ["test",["with",["an",["array"]]]] -11 verbose [ -11 verbose "test", -11 verbose [ -11 verbose "with", -11 verbose [ -11 verbose "an", -11 verbose [ -11 verbose "array" -11 verbose ] -11 verbose ] -11 verbose ] -11 verbose ] -12 error pre has many errors Error: message -12 error pre at stack trace line 0 -12 error pre at stack trace line 1 -12 error pre at stack trace line 2 -12 error pre at stack trace line 3 -12 error pre at stack trace line 4 -12 error pre at stack trace line 5 -12 error pre at stack trace line 6 -12 error pre at stack trace line 7 -12 error pre at stack trace line 8 -12 error pre at stack trace line 9 Error: message2 -12 error pre at stack trace line 0 -12 error pre at stack trace line 1 -12 error pre at stack trace line 2 -12 error pre at stack trace line 3 -12 error pre at stack trace line 4 -12 error pre at stack trace line 5 -12 error pre at stack trace line 6 -12 error pre at stack trace line 7 -12 error pre at stack trace line 8 -12 error pre at stack trace line 9 -13 error nostack [Error: message] +0 verbose logfile logs-max:10 dir:{CWD}/test/lib/utils/tap-testdir-log-file-snapshot +1 silly logfile done cleaning log files +2 error no prefix +3 error prefix with prefix +4 error prefix 1 2 3 +5 verbose { obj: { with: { many: [Object] } } } +6 verbose {"obj":{"with":{"many":{"props":1}}}} +7 verbose { +7 verbose "obj": { +7 verbose "with": { +7 verbose "many": { +7 verbose "props": 1 +7 verbose } +7 verbose } +7 verbose } +7 verbose } +8 verbose [ 'test', 'with', 'an', 'array' ] +9 verbose ["test","with","an","array"] +10 verbose [ +10 verbose "test", +10 verbose "with", +10 verbose "an", +10 verbose "array" +10 verbose ] +11 verbose [ 'test', [ 'with', [ 'an', [Array] ] ] ] +12 verbose ["test",["with",["an",["array"]]]] +13 verbose [ +13 verbose "test", +13 verbose [ +13 verbose "with", +13 verbose [ +13 verbose "an", +13 verbose [ +13 verbose "array" +13 verbose ] +13 verbose ] +13 verbose ] +13 verbose ] +14 error pre has many errors Error: message +14 error pre at stack trace line 0 +14 error pre at stack trace line 1 +14 error pre at stack trace line 2 +14 error pre at stack trace line 3 +14 error pre at stack trace line 4 +14 error pre at stack trace line 5 +14 error pre at stack trace line 6 +14 error pre at stack trace line 7 +14 error pre at stack trace line 8 +14 error pre at stack trace line 9 Error: message2 +14 error pre at stack trace line 0 +14 error pre at stack trace line 1 +14 error pre at stack trace line 2 +14 error pre at stack trace line 3 +14 error pre at stack trace line 4 +14 error pre at stack trace line 5 +14 error pre at stack trace line 6 +14 error pre at stack trace line 7 +14 error pre at stack trace line 8 +14 error pre at stack trace line 9 +15 error nostack [Error: message] ` diff --git a/test/fixtures/mock-npm.js b/test/fixtures/mock-npm.js index ea608d6644446..13f8a0ea01c7e 100644 --- a/test/fixtures/mock-npm.js +++ b/test/fixtures/mock-npm.js @@ -4,15 +4,18 @@ const path = require('path') const mockLogs = require('./mock-logs') const mockGlobals = require('./mock-globals') const log = require('../../lib/utils/log-shim') +const envConfigKeys = Object.keys(require('../../lib/utils/config/definitions.js')) const RealMockNpm = (t, otherMocks = {}) => { const mock = { ...mockLogs(otherMocks), outputs: [], + outputErrors: [], joinedOutput: () => mock.outputs.map(o => o.join(' ')).join('\n'), } const Npm = t.mock('../../lib/npm.js', { + '../../lib/utils/update-notifier.js': async () => {}, ...otherMocks, ...mock.logMocks, }) @@ -23,9 +26,17 @@ const RealMockNpm = (t, otherMocks = {}) => { super.output(...args) } + originalOutputError (...args) { + super.outputError(...args) + } + output (...args) { mock.outputs.push(args) } + + outputError (...args) { + mock.outputErrors.push(args) + } } return mock @@ -88,19 +99,30 @@ const LoadMockNpm = async (t, { // XXX: remove this for a solution where cache argv is passed in mockGlobals(t, { 'process.env.npm_config_cache': cache, + ...(globals ? result(globals, { prefix, cache }) : {}), + // Some configs don't work because they can't be set via npm.config.set until + // config is loaded. But some config items are needed before that. So this is + // an explicit set of configs that must be loaded as env vars. + // XXX(npm9): make this possible by passing in argv directly to npm/config + ...Object.entries(config) + .filter(([k]) => envConfigKeys.includes(k)) + .reduce((acc, [k, v]) => { + acc[`process.env.npm_config_${k.replace(/-/g, '_')}`] = v.toString() + return acc + }, {}), }) - if (globals) { - mockGlobals(t, result(globals, { prefix, cache })) - } - const npm = init ? new Npm() : null t.teardown(() => npm && npm.unload()) if (load) { await npm.load() for (const [k, v] of Object.entries(result(config, { npm, prefix, cache }))) { - npm.config.set(k, v) + if (typeof v === 'object' && v.value && v.where) { + npm.config.set(k, v.value, v.where) + } else { + npm.config.set(k, v) + } } // Set global loglevel *again* since it possibly got reset during load // XXX: remove with npmlog @@ -115,6 +137,7 @@ const LoadMockNpm = async (t, { Npm, npm, prefix, + globalPrefix, testdir: dir, cache, debugFile: async () => { diff --git a/test/fixtures/sandbox.js b/test/fixtures/sandbox.js index d51281d41d104..7e57468e0c5bb 100644 --- a/test/fixtures/sandbox.js +++ b/test/fixtures/sandbox.js @@ -264,6 +264,7 @@ class Sandbox extends EventEmitter { const mockedLogs = mockLogs(this[_mocks]) this[_logs] = mockedLogs.logs const Npm = this[_test].mock('../../lib/npm.js', { + '../../lib/utils/update-notifier.js': async () => {}, ...this[_mocks], ...mockedLogs.logMocks, }) @@ -314,6 +315,7 @@ class Sandbox extends EventEmitter { const mockedLogs = mockLogs(this[_mocks]) this[_logs] = mockedLogs.logs const Npm = this[_test].mock('../../lib/npm.js', { + '../../lib/utils/update-notifier.js': async () => {}, ...this[_mocks], ...mockedLogs.logMocks, }) diff --git a/test/lib/cli.js b/test/lib/cli.js index f02c57d8cf730..b6606c69fc429 100644 --- a/test/lib/cli.js +++ b/test/lib/cli.js @@ -1,9 +1,8 @@ const t = require('tap') -const mockGlobals = require('../fixtures/mock-globals.js') const { load: loadMockNpm } = require('../fixtures/mock-npm.js') -const cliMock = async (t, mocks) => { +const cliMock = async (t, opts) => { let exitHandlerArgs = null let npm = null const exitHandlerMock = (...args) => { @@ -12,10 +11,9 @@ const cliMock = async (t, mocks) => { } exitHandlerMock.setNpm = _npm => npm = _npm - const { Npm, outputs, logMocks, logs } = await loadMockNpm(t, { mocks, init: false }) + const { Npm, outputs, logMocks, logs } = await loadMockNpm(t, { ...opts, init: false }) const cli = t.mock('../../lib/cli.js', { '../../lib/npm.js': Npm, - '../../lib/utils/update-notifier.js': async () => null, '../../lib/utils/unsupported.js': { checkForBrokenNode: () => {}, checkForUnsupportedNode: () => {}, @@ -31,6 +29,7 @@ const cliMock = async (t, mocks) => { exitHandlerCalled: () => exitHandlerArgs, exitHandlerNpm: () => npm, logs, + logsBy: (title) => logs.verbose.filter(([p]) => p === title).map(([p, ...rest]) => rest), } } @@ -39,17 +38,15 @@ t.afterEach(() => { }) t.test('print the version, and treat npm_g as npm -g', async t => { - mockGlobals(t, { - 'process.argv': ['node', 'npm_g', '-v'], + const { logsBy, logs, cli, Npm, outputs, exitHandlerCalled } = await cliMock(t, { + globals: { 'process.argv': ['node', 'npm_g', '-v'] }, }) - - const { logs, cli, Npm, outputs, exitHandlerCalled } = await cliMock(t) await cli(process) t.strictSame(process.argv, ['node', 'npm', '-g', '-v'], 'system process.argv was rewritten') - t.strictSame(logs.verbose.filter(([p]) => p !== 'logfile'), [ - ['cli', process.argv], - ]) + t.strictSame(logsBy('cli'), [['node npm']]) + t.strictSame(logsBy('title'), [['npm']]) + t.strictSame(logsBy('argv'), [['"--global" "--version"']]) t.strictSame(logs.info, [ ['using', 'npm@%s', Npm.version], ['using', 'node@%s', process.version], @@ -59,68 +56,82 @@ t.test('print the version, and treat npm_g as npm -g', async t => { }) t.test('calling with --versions calls npm version with no args', async t => { - t.plan(6) - mockGlobals(t, { - 'process.argv': ['node', 'npm', 'install', 'or', 'whatever', '--versions'], - }) - const { logs, cli, Npm, outputs, exitHandlerCalled } = await cliMock(t, { - '../../lib/commands/version.js': class Version { - async exec (args) { - t.strictSame(args, []) - } + const { logsBy, cli, outputs, exitHandlerCalled } = await cliMock(t, { + mocks: { + '../../lib/commands/version.js': class Version { + async exec (args) { + t.strictSame(args, []) + } + }, + }, + globals: { + 'process.argv': ['node', 'npm', 'install', 'or', 'whatever', '--versions'], }, }) - await cli(process) - t.equal(process.title, 'npm install or whatever') - t.strictSame(logs.verbose.filter(([p]) => p !== 'logfile'), [ - ['cli', process.argv], - ]) - t.strictSame(logs.info, [ - ['using', 'npm@%s', Npm.version], - ['using', 'node@%s', process.version], - ]) + t.equal(process.title, 'npm install or whatever') + t.strictSame(logsBy('cli'), [['node npm']]) + t.strictSame(logsBy('title'), [['npm install or whatever']]) + t.strictSame(logsBy('argv'), [['"install" "or" "whatever" "--versions"']]) t.strictSame(outputs, []) t.strictSame(exitHandlerCalled(), []) }) t.test('logged argv is sanitized', async t => { - mockGlobals(t, { - 'process.argv': [ - 'node', - 'npm', - 'version', - 'https://username:password@npmjs.org/test_url_with_a_password', - ], - }) - const { logs, cli, Npm } = await cliMock(t, { - '../../lib/commands/version.js': class Version { - async exec (args) {} + const { logsBy, cli } = await cliMock(t, { + mocks: { + '../../lib/commands/version.js': class Version { + async exec () {} + }, + }, + globals: { + 'process.argv': [ + 'node', + 'npm', + 'version', + '--registry', + 'https://u:password@npmjs.org/password', + ], }, }) await cli(process) - t.ok(process.title.startsWith('npm version https://username:***@npmjs.org')) - t.strictSame(logs.verbose.filter(([p]) => p !== 'logfile'), [ - [ - 'cli', - ['node', 'npm', 'version', 'https://username:***@npmjs.org/test_url_with_a_password'], - ], - ]) - t.strictSame(logs.info, [ - ['using', 'npm@%s', Npm.version], - ['using', 'node@%s', process.version], - ]) + t.equal(process.title, 'npm version') + t.strictSame(logsBy('cli'), [['node npm']]) + t.strictSame(logsBy('title'), [['npm version']]) + t.strictSame(logsBy('argv'), [['"version" "--registry" "https://u:***@npmjs.org/password"']]) }) -t.test('print usage if no params provided', async t => { - mockGlobals(t, { - 'process.argv': ['node', 'npm'], +t.test('logged argv is sanitized with equals', async t => { + const { logsBy, cli } = await cliMock(t, { + mocks: { + '../../lib/commands/version.js': class Version { + async exec () {} + }, + }, + globals: { + 'process.argv': [ + 'node', + 'npm', + 'version', + '--registry=https://u:password@npmjs.org', + ], + }, }) + await cli(process) + + t.strictSame(logsBy('argv'), [['"version" "--registry" "https://u:***@npmjs.org"']]) +}) - const { cli, outputs, exitHandlerCalled, exitHandlerNpm } = await cliMock(t) +t.test('print usage if no params provided', async t => { + const { cli, outputs, exitHandlerCalled, exitHandlerNpm } = await cliMock(t, { + globals: { + 'process.argv': ['node', 'npm'], + }, + }) await cli(process) + t.match(outputs[0][0], 'Usage:', 'outputs npm usage') t.match(exitHandlerCalled(), [], 'should call exitHandler with no args') t.ok(exitHandlerNpm(), 'exitHandler npm is set') @@ -128,12 +139,13 @@ t.test('print usage if no params provided', async t => { }) t.test('print usage if non-command param provided', async t => { - mockGlobals(t, { - 'process.argv': ['node', 'npm', 'tset'], + const { cli, outputs, exitHandlerCalled, exitHandlerNpm } = await cliMock(t, { + globals: { + 'process.argv': ['node', 'npm', 'tset'], + }, }) - - const { cli, outputs, exitHandlerCalled, exitHandlerNpm } = await cliMock(t) await cli(process) + t.match(outputs[0][0], 'Unknown command: "tset"') t.match(outputs[0][0], 'Did you mean this?') t.match(exitHandlerCalled(), [], 'should call exitHandler with no args') @@ -142,21 +154,22 @@ t.test('print usage if non-command param provided', async t => { }) t.test('load error calls error handler', async t => { - mockGlobals(t, { - 'process.argv': ['node', 'npm', 'asdf'], - }) - const err = new Error('test load error') const { cli, exitHandlerCalled } = await cliMock(t, { - '../../lib/utils/config/index.js': { - definitions: null, - flatten: null, - shorthands: null, + mocks: { + '../../lib/utils/config/index.js': { + definitions: null, + flatten: null, + shorthands: null, + }, + '@npmcli/config': class BadConfig { + async load () { + throw err + } + }, }, - '@npmcli/config': class BadConfig { - async load () { - throw err - } + globals: { + 'process.argv': ['node', 'npm', 'asdf'], }, }) await cli(process) diff --git a/test/lib/commands/bin.js b/test/lib/commands/bin.js index 4de5a923b3eb6..a889b13361624 100644 --- a/test/lib/commands/bin.js +++ b/test/lib/commands/bin.js @@ -1,76 +1,60 @@ const t = require('tap') -const { fake: mockNpm } = require('../../fixtures/mock-npm') +const { relative, join } = require('path') +const { load: loadMockNpm } = require('../../fixtures/mock-npm') +const mockGlobals = require('../../fixtures/mock-globals') -t.test('bin', async t => { - t.plan(2) - const dir = '/bin/dir' - - const Bin = require('../../../lib/commands/bin.js') +const mockBin = async (t, { args = [], config = {} } = {}) => { + const { npm, outputs, ...rest } = await loadMockNpm(t, { + config, + }) + const cmd = await npm.cmd('bin') + await npm.exec('bin', args) + + return { + npm, + cmd, + bin: outputs[0][0], + ...rest, + } +} - const npm = mockNpm({ - bin: dir, +t.test('bin', async t => { + const { cmd, bin, prefix, outputErrors } = await mockBin(t, { config: { global: false }, - output: (output) => { - t.equal(output, dir, 'prints the correct directory') - }, }) - const bin = new Bin(npm) - t.match(bin.usage, 'bin', 'usage has command name in it') - await bin.exec([]) + t.match(cmd.usage, 'bin', 'usage has command name in it') + t.equal(relative(prefix, bin), join('node_modules/.bin'), 'prints the correct directory') + t.strictSame(outputErrors, []) }) t.test('bin -g', async t => { - t.plan(1) - const consoleError = console.error - t.teardown(() => { - console.error = consoleError + mockGlobals(t, { 'process.platform': 'posix' }) + const { globalPrefix, bin, outputErrors } = await mockBin(t, { + config: { global: true }, }) - console.error = (output) => { - t.fail('should not have printed to console.error') - } - const dir = '/bin/dir' - - const Bin = t.mock('../../../lib/commands/bin.js', { - '../../../lib/utils/path.js': [dir], - }) + t.equal(relative(globalPrefix, bin), 'bin', 'prints the correct directory') + t.strictSame(outputErrors, []) +}) - const npm = mockNpm({ - bin: dir, +t.test('bin -g win32', async t => { + mockGlobals(t, { 'process.platform': 'win32' }) + const { globalPrefix, bin, outputErrors } = await mockBin(t, { config: { global: true }, - output: (output) => { - t.equal(output, dir, 'prints the correct directory') - }, }) - const bin = new Bin(npm) - await bin.exec([]) + t.equal(relative(globalPrefix, bin), '', 'prints the correct directory') + t.strictSame(outputErrors, []) }) t.test('bin -g (not in path)', async t => { - t.plan(2) - const consoleError = console.error - t.teardown(() => { - console.error = consoleError - }) - - console.error = (output) => { - t.equal(output, '(not in PATH env variable)', 'prints env warning') - } - const dir = '/bin/dir' - - const Bin = t.mock('../../../lib/commands/bin.js', { - '../../../lib/utils/path.js': ['/not/my/dir'], - }) - const npm = mockNpm({ - bin: dir, + const { logs } = await mockBin(t, { config: { global: true }, - output: (output) => { - t.equal(output, dir, 'prints the correct directory') + globals: { + 'process.env.PATH': 'emptypath', }, }) - const bin = new Bin(npm) - await bin.exec([]) + t.strictSame(logs.error[0], ['bin', '(not in PATH env variable)']) }) diff --git a/test/lib/commands/doctor.js b/test/lib/commands/doctor.js index 5badab99a1d56..620d908d3030e 100644 --- a/test/lib/commands/doctor.js +++ b/test/lib/commands/doctor.js @@ -52,17 +52,7 @@ const dirs = { }, } -let consoleError = false -t.afterEach(() => { - consoleError = false -}) - const globals = { - console: { - error: () => { - consoleError = true - }, - }, process: { platform: 'test-not-windows', version: 'v1.0.0', @@ -104,7 +94,6 @@ t.test('all clear', async t => { .get('/dist/index.json').reply(200, nodeVersions) await npm.exec('doctor', []) t.matchSnapshot(joinedOutput(), 'output') - t.notOk(consoleError, 'console.error not called') t.matchSnapshot({ info: logs.info, warn: logs.warn, error: logs.error }, 'logs') }) @@ -122,7 +111,6 @@ t.test('all clear in color', async t => { npm.config.set('color', 'always') await npm.exec('doctor', []) t.matchSnapshot(joinedOutput(), 'everything is ok in color') - t.notOk(consoleError, 'console.error not called') t.matchSnapshot({ info: logs.info, warn: logs.warn, error: logs.error }, 'logs') }) @@ -142,7 +130,6 @@ t.test('silent', async t => { .get('/dist/index.json').reply(200, nodeVersions) await npm.exec('doctor', []) t.matchSnapshot(joinedOutput(), 'output') - t.notOk(consoleError, 'console.error not called') t.matchSnapshot({ info: logs.info, warn: logs.warn, error: logs.error }, 'logs') }) @@ -159,7 +146,6 @@ t.test('ping 404', async t => { .get('/dist/index.json').reply(200, nodeVersions) await t.rejects(npm.exec('doctor', [])) t.matchSnapshot(joinedOutput(), 'ping 404') - t.ok(consoleError, 'console.error called') t.matchSnapshot({ info: logs.info, warn: logs.warn, error: logs.error }, 'logs') }) diff --git a/test/lib/npm.js b/test/lib/npm.js index 3ae2af35c287d..4302437a6f018 100644 --- a/test/lib/npm.js +++ b/test/lib/npm.js @@ -139,10 +139,11 @@ t.test('npm.load', async t => { }) t.test('forceful loading', async t => { - mockGlobals(t, { - 'process.argv': [...process.argv, '--force', '--color', 'always'], + const { logs } = await loadMockNpm(t, { + globals: { + 'process.argv': [...process.argv, '--force', '--color', 'always'], + }, }) - const { logs } = await loadMockNpm(t) t.match(logs.warn, [ [ 'using --force', @@ -153,23 +154,21 @@ t.test('npm.load', async t => { t.test('node is a symlink', async t => { const node = process.platform === 'win32' ? 'node.exe' : 'node' - mockGlobals(t, { - 'process.argv': [ - node, - process.argv[1], - '--usage', - '--scope=foo', - 'token', - 'revoke', - 'blergggg', - ], - }) const { npm, logs, outputs, prefix } = await loadMockNpm(t, { prefixDir: { bin: t.fixture('symlink', dirname(process.execPath)), }, globals: ({ prefix }) => ({ 'process.env.PATH': resolve(prefix, 'bin'), + 'process.argv': [ + node, + process.argv[1], + '--usage', + '--scope=foo', + 'token', + 'revoke', + 'blergggg', + ], }), }) @@ -181,6 +180,9 @@ t.test('npm.load', async t => { ], [ ['npm:load:whichnode', /Completed in [0-9.]+ms/], ['node symlink', resolve(prefix, 'bin', node)], + ['title', 'npm token revoke blergggg'], + ['argv', '"--usage" "--scope" "foo" "token" "revoke" "blergggg"'], + ['logfile', /logs-max:\d+ dir:.*/], ['logfile', /.*-debug-0.log/], ['npm:load', /Completed in [0-9.]+ms/], ]) @@ -226,15 +228,6 @@ t.test('npm.load', async t => { }) t.test('--no-workspaces with --workspace', async t => { - mockGlobals(t, { - 'process.argv': [ - process.execPath, - process.argv[1], - '--color', 'false', - '--workspaces', 'false', - '--workspace', 'a', - ], - }) const { npm } = await loadMockNpm(t, { load: false, prefixDir: { @@ -253,6 +246,15 @@ t.test('npm.load', async t => { workspaces: ['./packages/*'], }), }, + globals: { + 'process.argv': [ + process.execPath, + process.argv[1], + '--color', 'false', + '--workspaces', 'false', + '--workspace', 'a', + ], + }, }) await t.rejects( npm.exec('run', []), @@ -261,14 +263,6 @@ t.test('npm.load', async t => { }) t.test('workspace-aware configs and commands', async t => { - mockGlobals(t, { - 'process.argv': [ - process.execPath, - process.argv[1], - '--color', 'false', - '--workspaces', 'true', - ], - }) const { npm, outputs } = await loadMockNpm(t, { prefixDir: { packages: { @@ -293,6 +287,14 @@ t.test('npm.load', async t => { workspaces: ['./packages/*'], }), }, + globals: { + 'process.argv': [ + process.execPath, + process.argv[1], + '--color', 'false', + '--workspaces', 'true', + ], + }, }) // verify that calling the command with a short name still sets @@ -317,17 +319,6 @@ t.test('npm.load', async t => { }) t.test('workspaces in global mode', async t => { - mockGlobals(t, { - 'process.argv': [ - process.execPath, - process.argv[1], - '--color', - 'false', - '--workspaces', - '--global', - 'true', - ], - }) const { npm } = await loadMockNpm(t, { prefixDir: { packages: { @@ -352,6 +343,17 @@ t.test('npm.load', async t => { workspaces: ['./packages/*'], }), }, + globals: { + 'process.argv': [ + process.execPath, + process.argv[1], + '--color', + 'false', + '--workspaces', + '--global', + 'true', + ], + }, }) // verify that calling the command with a short name still sets // the npm.command property to the full canonical name of the cmd. @@ -365,68 +367,93 @@ t.test('npm.load', async t => { t.test('set process.title', async t => { t.test('basic title setting', async t => { - mockGlobals(t, { - 'process.argv': [ - process.execPath, - process.argv[1], - '--usage', - '--scope=foo', - 'ls', - ], + const { npm } = await loadMockNpm(t, { + globals: { + 'process.argv': [ + process.execPath, + process.argv[1], + '--usage', + '--scope=foo', + 'ls', + ], + }, }) - const { npm } = await loadMockNpm(t) t.equal(npm.title, 'npm ls') t.equal(process.title, 'npm ls') }) t.test('do not expose token being revoked', async t => { - mockGlobals(t, { - 'process.argv': [ - process.execPath, - process.argv[1], - '--usage', - '--scope=foo', - 'token', - 'revoke', - 'deadbeefcafebad', - ], + const { npm } = await loadMockNpm(t, { + globals: { + 'process.argv': [ + process.execPath, + process.argv[1], + '--usage', + '--scope=foo', + 'token', + 'revoke', + `npm_${'a'.repeat(36)}`, + ], + }, }) - const { npm } = await loadMockNpm(t) - t.equal(npm.title, 'npm token revoke ***') - t.equal(process.title, 'npm token revoke ***') + t.equal(npm.title, 'npm token revoke npm_***') + t.equal(process.title, 'npm token revoke npm_***') }) t.test('do show *** unless a token is actually being revoked', async t => { - mockGlobals(t, { - 'process.argv': [ - process.execPath, - process.argv[1], - '--usage', - '--scope=foo', - 'token', - 'revoke', - ], + const { npm } = await loadMockNpm(t, { + globals: { + 'process.argv': [ + process.execPath, + process.argv[1], + '--usage', + '--scope=foo', + 'token', + 'revoke', + 'notatoken', + ], + }, }) - const { npm } = await loadMockNpm(t) - t.equal(npm.title, 'npm token revoke') - t.equal(process.title, 'npm token revoke') + t.equal(npm.title, 'npm token revoke notatoken') + t.equal(process.title, 'npm token revoke notatoken') }) }) -t.test('debug-log', async t => { - const { npm, debugFile } = await loadMockNpm(t, { load: false }) +t.test('debug log', async t => { + t.test('writes log file', async t => { + const { npm, debugFile } = await loadMockNpm(t, { load: false }) + + const log1 = ['silly', 'test', 'before load'] + const log2 = ['silly', 'test', 'after load'] - const log1 = ['silly', 'test', 'before load'] - const log2 = ['silly', 'test', 'after load'] + process.emit('log', ...log1) + await npm.load() + process.emit('log', ...log2) - process.emit('log', ...log1) - await npm.load() - process.emit('log', ...log2) + const debug = await debugFile() + t.equal(npm.logFiles.length, 1, 'one debug file') + t.match(debug, log1.join(' '), 'before load appears') + t.match(debug, log2.join(' '), 'after load log appears') + }) + + t.test('with bad dir', async t => { + const { npm } = await loadMockNpm(t, { + config: { + 'logs-dir': 'LOGS_DIR', + }, + mocks: { + '@npmcli/fs': { + mkdir: async (dir) => { + if (dir.includes('LOGS_DIR')) { + throw new Error('err') + } + }, + }, + }, + }) - const debug = await debugFile() - t.equal(npm.logFiles.length, 1, 'one debug file') - t.match(debug, log1.join(' '), 'before load appears') - t.match(debug, log2.join(' '), 'after load log appears') + t.equal(npm.logFiles.length, 0, 'no log file') + }) }) t.test('timings', async t => { @@ -458,13 +485,14 @@ t.test('timings', async t => { }) t.test('writes timings file', async t => { - const { npm, timingFile } = await loadMockNpm(t, { + const { npm, cache, timingFile } = await loadMockNpm(t, { config: { timing: true }, }) process.emit('time', 'foo') process.emit('timeEnd', 'foo') process.emit('time', 'bar') - npm.unload() + npm.writeTimingFile() + t.equal(npm.timingFile, join(cache, '_timing.json')) const timings = await timingFile() t.match(timings, { command: [], @@ -484,21 +512,16 @@ t.test('timings', async t => { const { npm, timingFile } = await loadMockNpm(t, { config: { false: true }, }) - npm.unload() + npm.writeTimingFile() await t.rejects(() => timingFile()) }) }) t.test('output clears progress and console.logs the message', async t => { - t.plan(2) + t.plan(4) let showingProgress = true const logs = [] - mockGlobals(t, { - 'console.log': (...args) => { - t.equal(showingProgress, false, 'should not be showing progress right now') - logs.push(args) - }, - }) + const errors = [] const { npm } = await loadMockNpm(t, { load: false, mocks: { @@ -507,9 +530,22 @@ t.test('output clears progress and console.logs the message', async t => { showProgress: () => showingProgress = true, }, }, + globals: { + 'console.log': (...args) => { + t.equal(showingProgress, false, 'should not be showing progress right now') + logs.push(args) + }, + 'console.error': (...args) => { + t.equal(showingProgress, false, 'should not be showing progress right now') + errors.push(args) + }, + }, }) npm.originalOutput('hello') + npm.originalOutputError('error') + t.match(logs, [['hello']]) + t.match(errors, [['error']]) t.end() }) @@ -522,14 +558,6 @@ t.test('unknown command', async t => { }) t.test('explicit workspace rejection', async t => { - mockGlobals(t, { - 'process.argv': [ - process.execPath, - process.argv[1], - '--color', 'false', - '--workspace', './packages/a', - ], - }) const mock = await loadMockNpm(t, { prefixDir: { packages: { @@ -547,6 +575,14 @@ t.test('explicit workspace rejection', async t => { workspaces: ['./packages/a'], }), }, + globals: { + 'process.argv': [ + process.execPath, + process.argv[1], + '--color', 'false', + '--workspace', './packages/a', + ], + }, }) await t.rejects( mock.npm.exec('ping', []), @@ -572,15 +608,17 @@ t.test('implicit workspace rejection', async t => { workspaces: ['./packages/a'], }), }, - }) - const cwd = join(mock.npm.config.localPrefix, 'packages', 'a') - mock.npm.config.set('workspace', [cwd], 'default') - mockGlobals(t, { - 'process.argv': [ - process.execPath, - process.argv[1], - '--color', 'false', - ], + globals: { + 'process.argv': [ + process.execPath, + process.argv[1], + '--color', 'false', + '--workspace', './packages/a', + ], + }, + config: ({ prefix }) => ({ + workspace: { value: [join(prefix, 'packages', 'a')], where: 'default' }, + }), }) await t.rejects( mock.npm.exec('owner', []), @@ -606,19 +644,17 @@ t.test('implicit workspace accept', async t => { workspaces: ['./packages/a'], }), }, + globals: ({ prefix }) => ({ + 'process.cwd': () => prefix, + 'process.argv': [ + process.execPath, + process.argv[1], + '--color', 'false', + ], + }), + config: ({ prefix }) => ({ + workspace: { value: [join(prefix, 'packages', 'a')], where: 'default' }, + }), }) - const cwd = join(mock.npm.config.localPrefix, 'packages', 'a') - mock.npm.config.set('workspace', [cwd], 'default') - mockGlobals(t, { - 'process.cwd': () => mock.npm.config.cwd, - 'process.argv': [ - process.execPath, - process.argv[1], - '--color', 'false', - ], - }) - await t.rejects( - mock.npm.exec('org', []), - /.*Usage/ - ) + await t.rejects(mock.npm.exec('org', []), /.*Usage/) }) diff --git a/test/lib/utils/exit-handler.js b/test/lib/utils/exit-handler.js index 6a96d92ddb250..73bbf06fe85e7 100644 --- a/test/lib/utils/exit-handler.js +++ b/test/lib/utils/exit-handler.js @@ -21,9 +21,10 @@ t.formatSnapshot = (obj) => { } t.cleanSnapshot = (path) => cleanDate(cleanCwd(path)) -// Config loading is dependent on env so strip those from snapshots + // 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') + .replace(/(removing )\d+( files)/g, '$1${NUM}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 @@ -44,9 +45,8 @@ mockGlobals(t, { }), }, { replace: true }) -const mockExitHandler = async (t, { init, load, testdir, config } = {}) => { +const mockExitHandler = async (t, { init, load, testdir, config, globals, mocks } = {}) => { const errors = [] - mockGlobals(t, { 'console.error': (err) => errors.push(err) }) const { npm, logMocks, ...rest } = await loadMockNpm(t, { init, @@ -56,11 +56,15 @@ const mockExitHandler = async (t, { init, load, testdir, config } = {}) => { '../../package.json': { version: '1.0.0', }, + ...mocks, }, config: { loglevel: 'notice', ...config, }, + globals: { + 'console.error': (err) => errors.push(err), + }, }) const exitHandler = t.mock('../../../lib/utils/exit-handler.js', { @@ -74,6 +78,7 @@ const mockExitHandler = async (t, { init, load, testdir, config } = {}) => { release: () => '1.0.0', }, ...logMocks, + ...mocks, }) if (npm) { @@ -89,13 +94,14 @@ const mockExitHandler = async (t, { init, load, testdir, config } = {}) => { ...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 => { + // 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. Also + // introduce a small artificial delay so the logs are consistently finished + // by the time the exit handler forces process.exit + exitHandler: (...args) => new Promise(resolve => setTimeout(() => { process.once('exit', resolve) exitHandler(...args) - }), + }, 50)), } } @@ -199,17 +205,15 @@ t.test('exit handler called - no npm with error without stack', async (t) => { }) t.test('console.log output using --json', async (t) => { - const { exitHandler, errors } = await mockExitHandler(t, { - config: { - json: true, - }, + const { exitHandler, outputErrors } = await mockExitHandler(t, { + config: { json: true }, }) await exitHandler(err('Error: EBADTHING Something happened')) t.equal(process.exitCode, 1) t.same( - JSON.parse(errors[0]), + JSON.parse(outputErrors[0]), { error: { code: 'EBADTHING', // should default error code to E[A-Z]+ @@ -273,11 +277,43 @@ t.test('npm.config not ready', async (t) => { ], 'should exit with config error msg') }) -t.test('timing with no error', async (t) => { - const { exitHandler, timingFile, npm, logs } = await mockExitHandler(t, { +t.test('no logs dir', async (t) => { + const { exitHandler, logs } = await mockExitHandler(t, { + config: { 'logs-max': 0 }, + }) + + await exitHandler(new Error()) + + t.match(logs.error.filter(([t]) => t === ''), [ + ['', 'Log files were not written due to the config logs-max=0'], + ]) +}) + +t.test('log file error', async (t) => { + const { exitHandler, logs } = await mockExitHandler(t, { config: { + 'logs-dir': 'LOGS_DIR', timing: true, }, + mocks: { + '@npmcli/fs': { + mkdir: async (dir) => { + if (dir.includes('LOGS_DIR')) { + throw new Error('err') + } + }, + }, + }, + }) + + await exitHandler(new Error()) + + t.match(logs.error.filter(([t]) => t === ''), [['', `error writing to the directory`]]) +}) + +t.test('timing with no error', async (t) => { + const { exitHandler, timingFile, npm, logs } = await mockExitHandler(t, { + config: { timing: true }, }) await exitHandler() @@ -285,9 +321,9 @@ t.test('timing with no error', async (t) => { t.equal(process.exitCode, 0) - t.match(logs.error, [ - ['', /A complete log of this run can be found in:[\s\S]*-debug-\d\.log/], - ]) + const msg = logs.info.filter(([t]) => t === '')[0][1] + t.match(msg, /A complete log of this run can be found in:/) + t.match(msg, /Timing info written to:/) t.match( timingFileData, @@ -308,9 +344,7 @@ t.test('timing with no error', async (t) => { t.test('unfinished timers', async (t) => { const { exitHandler, timingFile, npm } = await mockExitHandler(t, { - config: { - timing: true, - }, + config: { timing: true }, }) process.emit('time', 'foo') @@ -376,7 +410,7 @@ t.test('verbose logs replace info on err props', async t => { await exitHandler(err('Error with code type number', properties)) t.equal(process.exitCode, 1) t.match( - logs.verbose.filter(([p]) => p !== 'logfile'), + logs.verbose.filter(([p]) => !['logfile', 'title', 'argv'].includes(p)), keys.map((k) => [k, `${k}-https://user:***@registry.npmjs.org/`]), 'all special keys get replaced' ) diff --git a/test/lib/utils/log-file.js b/test/lib/utils/log-file.js index 007ce221b0940..ce6f0bf4cf51f 100644 --- a/test/lib/utils/log-file.js +++ b/test/lib/utils/log-file.js @@ -116,12 +116,12 @@ t.test('max files per process', async t => { } for (const i of range(5)) { - logFile.log('verbose', `log ${i}`) + logFile.log('verbose', `ignored after maxlogs hit ${i}`) } const logs = await readLogs() t.equal(logs.length, maxFilesPerProcess, 'total log files') - t.equal(last(last(logs).logs), '49 error log 49') + t.match(last(last(logs).logs), /49 error log \d+/) }) t.test('stream error', async t => { @@ -182,8 +182,7 @@ t.test('turns off', async t => { logFile.load() const logs = await readLogs() - t.equal(logs.length, 1) - t.equal(logs[0].logs[0], '0 error test') + t.match(last(last(logs).logs), /^\d+ error test$/) }) t.test('cleans logs', async t => { @@ -198,7 +197,7 @@ t.test('cleans logs', async t => { }) t.test('doesnt clean current log by default', async t => { - const logsMax = 0 + const logsMax = 1 const { readLogs, logFile } = await loadLogFile(t, { logsMax, testdir: makeOldLogs(10), @@ -207,7 +206,6 @@ t.test('doesnt clean current log by default', async t => { logFile.log('error', 'test') const logs = await readLogs() - t.equal(logs.length, 1) t.match(last(logs).content, /\d+ error test/) }) @@ -221,8 +219,7 @@ t.test('negative logs max', async t => { logFile.log('error', 'test') const logs = await readLogs() - t.equal(logs.length, 1) - t.match(last(logs).content, /\d+ error test/) + t.equal(logs.length, 0) }) t.test('doesnt need to clean', async t => { @@ -257,7 +254,7 @@ t.test('cleans old style logs too', async t => { const oldLogs = 10 const { readLogs } = await loadLogFile(t, { logsMax, - testdir: makeOldLogs(oldLogs, false), + testdir: makeOldLogs(oldLogs, true), }) const logs = await readLogs() @@ -304,7 +301,7 @@ t.test('delete log file while open', async t => { }) t.test('snapshot', async t => { - const { logFile, readLogs } = await loadLogFile(t) + const { logFile, readLogs } = await loadLogFile(t, { logsMax: 10 }) logFile.log('error', '', 'no prefix') logFile.log('error', 'prefix', 'with prefix') diff --git a/test/lib/utils/replace-info.js b/test/lib/utils/replace-info.js index e4b83783a55a7..c7fffdb544096 100644 --- a/test/lib/utils/replace-info.js +++ b/test/lib/utils/replace-info.js @@ -19,12 +19,30 @@ t.equal( 'should return numbers' ) +t.equal( + replaceInfo(' == = = '), + ' == = = ', + 'should return same string with only separators' +) + +t.equal( + replaceInfo(''), + '', + 'should return empty string' +) + t.equal( replaceInfo('https://user:pass@registry.npmjs.org/'), 'https://user:***@registry.npmjs.org/', 'should replace single item' ) +t.equal( + replaceInfo(`https://registry.npmjs.org/path/npm_${'a'.repeat('36')}`), + 'https://registry.npmjs.org/path/npm_***', + 'should replace single item token' +) + t.equal( replaceInfo('https://example.npmjs.org'), 'https://example.npmjs.org', @@ -49,6 +67,12 @@ t.equal( 'should replace single item within a phrase' ) +t.equal( + replaceInfo('Something --x=https://user:pass@registry.npmjs.org/ foo bar'), + 'Something --x=https://user:***@registry.npmjs.org/ foo bar', + 'should replace single item within a phrase separated by =' +) + t.same( replaceInfo([ 'Something https://user:pass@registry.npmjs.org/ foo bar', @@ -60,7 +84,21 @@ t.same( 'http://foo:***@registry.npmjs.org', 'http://example.npmjs.org', ], - 'should replace single item within a phrase' + 'should replace items in an array' +) + +t.same( + replaceInfo([ + 'Something --x=https://user:pass@registry.npmjs.org/ foo bar', + '--url=http://foo:bar@registry.npmjs.org', + '--url=http://example.npmjs.org', + ]), + [ + 'Something --x=https://user:***@registry.npmjs.org/ foo bar', + '--url=http://foo:***@registry.npmjs.org', + '--url=http://example.npmjs.org', + ], + 'should replace items in an array with equals' ) t.same( diff --git a/test/lib/utils/timers.js b/test/lib/utils/timers.js index 6127f346b179e..30e54700c63a9 100644 --- a/test/lib/utils/timers.js +++ b/test/lib/utils/timers.js @@ -1,5 +1,5 @@ const t = require('tap') -const { resolve } = require('path') +const { resolve, join } = require('path') const fs = require('graceful-fs') const mockLogs = require('../../fixtures/mock-logs') @@ -31,6 +31,17 @@ t.test('listens/stops on process', async (t) => { t.notOk(timers.unfinished.get('baz')) }) +t.test('convenience time method', async (t) => { + const { timers } = mockTimers(t) + + const end = timers.time('later') + timers.time('sync', () => {}) + await timers.time('async', () => new Promise(r => setTimeout(r, 10))) + end() + + t.match(timers.finished, { later: Number, sync: Number, async: Number }) +}) + t.test('initial timer', async (t) => { const { timers } = mockTimers(t, { start: 'foo' }) process.emit('timeEnd', 'foo') @@ -75,8 +86,21 @@ t.test('writes file', async (t) => { t.test('fails to write file', async (t) => { const { logs, timers } = mockTimers(t) + const dir = t.testdir() + + timers.load({ dir: join(dir, 'does', 'not', 'exist') }) + timers.writeFile() + + t.match(logs.warn, [['timing', 'could not write timing file']]) + t.equal(timers.file, null) +}) + +t.test('no dir and no file', async (t) => { + const { logs, timers } = mockTimers(t) + + timers.load() timers.writeFile() - t.match(logs.warn, [ - ['timing', 'could not write timing file', Error], - ]) + + t.strictSame(logs, []) + t.equal(timers.file, null) }) diff --git a/test/lib/utils/update-notifier.js b/test/lib/utils/update-notifier.js index fa4af29476f12..a35886c6ef20a 100644 --- a/test/lib/utils/update-notifier.js +++ b/test/lib/utils/update-notifier.js @@ -85,12 +85,11 @@ t.afterEach(() => { const runUpdateNotifier = async ({ color = true, ...npmOptions } = {}) => { const _npm = { ...defaultNpm, ...npmOptions, logColor: color } - await t.mock('../../../lib/utils/update-notifier.js', { + return t.mock('../../../lib/utils/update-notifier.js', { '@npmcli/ci-detect': () => ciMock, pacote, fs, })(_npm) - return _npm.updateNotification } t.test('situations in which we do not notify', t => {