diff --git a/docs/content/using-npm/config.md b/docs/content/using-npm/config.md index 2b05c842f1190..2de35fa2a46c3 100644 --- a/docs/content/using-npm/config.md +++ b/docs/content/using-npm/config.md @@ -1707,12 +1707,11 @@ particular, use care when overriding this setting for public packages. * Default: false * Type: Boolean -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. +If true, writes timing information to a process specific json file in the +cache or `logs-dir`. The file name ends with `-timing.json`. You can quickly view it with this [json](https://npm.im/json) command line: -`npm exec -- json -g < ~/.npm/_timing.json`. +`cat ~/.npm/_logs/*-timing.json | npm exec -- json -g`. diff --git a/docs/content/using-npm/logging.md b/docs/content/using-npm/logging.md index d699c8dca6ccc..e52c19004d542 100644 --- a/docs/content/using-npm/logging.md +++ b/docs/content/using-npm/logging.md @@ -12,8 +12,7 @@ The `npm` CLI has various mechanisms for showing different levels of information 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. +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. @@ -62,9 +61,10 @@ The [`--timing` config](/using-npm/config#timing) 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` +1. Write timing information to a process specific 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. +This file contains a `timers` object where the keys are an identifier for the +portion of the process being timed and the value is the number of milliseconds it took to complete. ### Registry Response Headers diff --git a/lib/npm.js b/lib/npm.js index b116ec5cc68a4..852d91ad3f890 100644 --- a/lib/npm.js +++ b/lib/npm.js @@ -32,6 +32,7 @@ class Npm extends EventEmitter { loadErr = null argv = [] + #runId = new Date().toISOString().replace(/[.:]/g, '_') #loadPromise = null #tmpFolder = null #title = 'npm' @@ -206,11 +207,8 @@ class Npm extends EventEmitter { writeTimingFile () { this.#timers.writeFile({ + id: this.#runId, 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, }) @@ -290,7 +288,7 @@ class Npm extends EventEmitter { this.time('npm:load:logFile', () => { this.#logFile.load({ - dir: this.logsDir, + path: this.logPath, logsMax: this.config.get('logs-max'), }) log.verbose('logfile', this.#logFile.files[0] || 'no logfile created') @@ -298,7 +296,7 @@ class Npm extends EventEmitter { this.time('npm:load:timers', () => this.#timers.load({ - dir: this.config.get('timing') ? this.timingDir : null, + path: this.config.get('timing') ? this.logPath : null, }) ) @@ -372,13 +370,12 @@ class Npm extends EventEmitter { return this.config.get('logs-dir') || join(this.cache, '_logs') } - get timingFile () { - return this.#timers.file + get logPath () { + return resolve(this.logsDir, `${this.#runId}-`) } - get timingDir () { - // XXX(npm9): make this always in logs-dir - return this.config.get('logs-dir') || this.cache + get timingFile () { + return this.#timers.file } get cache () { diff --git a/lib/utils/config/definitions.js b/lib/utils/config/definitions.js index fc39bddc70a42..ae38efc32b5ae 100644 --- a/lib/utils/config/definitions.js +++ b/lib/utils/config/definitions.js @@ -2062,13 +2062,11 @@ define('timing', { default: false, type: Boolean, description: ` - 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. + If true, writes timing information to a process specific json file in + the cache or \`logs-dir\`. The file name ends with \`-timing.json\`. You can quickly view it with this [json](https://npm.im/json) command - line: \`npm exec -- json -g < ~/.npm/_timing.json\`. + line: \`cat ~/.npm/_logs/*-timing.json | npm exec -- json -g\`. `, }) diff --git a/lib/utils/display.js b/lib/utils/display.js index a19f72297e838..b23b2467ff4e6 100644 --- a/lib/utils/display.js +++ b/lib/utils/display.js @@ -3,11 +3,6 @@ const npmlog = require('npmlog') const log = require('./log-shim.js') const { explain } = require('./explain-eresolve.js') -const _logHandler = Symbol('logHandler') -const _eresolveWarn = Symbol('eresolveWarn') -const _log = Symbol('log') -const _npmlog = Symbol('npmlog') - class Display { constructor () { // pause by default until config is loaded @@ -16,11 +11,11 @@ class Display { } on () { - process.on('log', this[_logHandler]) + process.on('log', this.#logHandler) } off () { - process.off('log', this[_logHandler]) + process.off('log', this.#logHandler) // Unbalanced calls to enable/disable progress // will leave change listeners on the tracker // This pretty much only happens in tests but @@ -72,16 +67,16 @@ class Display { } log (...args) { - this[_logHandler](...args) + this.#logHandler(...args) } - [_logHandler] = (level, ...args) => { + #logHandler = (level, ...args) => { try { - this[_log](level, ...args) + this.#log(level, ...args) } catch (ex) { try { // if it crashed once, it might again! - this[_npmlog]('verbose', `attempt to log ${inspect(args)} crashed`, ex) + this.#npmlog('verbose', `attempt to log ${inspect(args)} crashed`, ex) } catch (ex2) { // eslint-disable-next-line no-console console.error(`attempt to log ${inspect(args)} crashed`, ex, ex2) @@ -89,13 +84,13 @@ class Display { } } - [_log] (...args) { - return this[_eresolveWarn](...args) || this[_npmlog](...args) + #log (...args) { + return this.#eresolveWarn(...args) || this.#npmlog(...args) } // Explicitly call these on npmlog and not log shim // This is the final place we should call npmlog before removing it. - [_npmlog] (level, ...args) { + #npmlog (level, ...args) { npmlog[level](...args) } @@ -103,13 +98,13 @@ class Display { // log.warn() method so that when we see a peerDep override // explanation from Arborist, we can replace the object with a // highly abbreviated explanation of what's being overridden. - [_eresolveWarn] (level, heading, message, expl) { + #eresolveWarn (level, heading, message, expl) { if (level === 'warn' && heading === 'ERESOLVE' && expl && typeof expl === 'object' ) { - this[_npmlog](level, heading, message) - this[_npmlog](level, '', explain(expl, log.useColor(), 2)) + this.#npmlog(level, heading, message) + this.#npmlog(level, '', explain(expl, log.useColor(), 2)) // Return true to short circuit other log in chain return true } diff --git a/lib/utils/error-message.js b/lib/utils/error-message.js index adf10a56f6d66..aee376120ba27 100644 --- a/lib/utils/error-message.js +++ b/lib/utils/error-message.js @@ -8,6 +8,7 @@ const log = require('./log-shim') module.exports = (er, npm) => { const short = [] const detail = [] + const files = [] if (er.message) { er.message = replaceInfo(er.message) @@ -17,14 +18,17 @@ module.exports = (er, npm) => { } switch (er.code) { - case 'ERESOLVE': + case 'ERESOLVE': { short.push(['ERESOLVE', er.message]) detail.push(['', '']) // XXX(display): error messages are logged so we use the logColor since that is based // on stderr. This should be handled solely by the display layer so it could also be // printed to stdout if necessary. - detail.push(['', report(er, !!npm.logColor, resolve(npm.cache, 'eresolve-report.txt'))]) + const { explanation, file } = report(er, !!npm.logColor) + detail.push(['', explanation]) + files.push(['eresolve-report.txt', file]) break + } case 'ENOLOCK': { const cmd = npm.command || '' @@ -398,5 +402,5 @@ module.exports = (er, npm) => { break } - return { summary: short, detail: detail } + return { summary: short, detail, files } } diff --git a/lib/utils/exit-handler.js b/lib/utils/exit-handler.js index d8ae9994dfecc..f1843347bc324 100644 --- a/lib/utils/exit-handler.js +++ b/lib/utils/exit-handler.js @@ -1,4 +1,5 @@ const os = require('os') +const fs = require('@npmcli/fs') const log = require('./log-shim.js') const errorMessage = require('./error-message.js') @@ -18,11 +19,10 @@ process.on('exit', code => { // unfinished timer check below process.emit('timeEnd', 'npm') - const hasNpm = !!npm - const hasLoadedNpm = hasNpm && npm.config.loaded + const hasLoadedNpm = npm?.config.loaded // Unfinished timers can be read before config load - if (hasNpm) { + if (npm) { for (const [name, timer] of npm.unfinishedTimers) { log.verbose('unfinished npm timer', name, timer) } @@ -111,10 +111,9 @@ const exitHandler = err => { log.disableProgress() - const hasNpm = !!npm - const hasLoadedNpm = hasNpm && npm.config.loaded + const hasLoadedNpm = npm?.config.loaded - if (!hasNpm) { + if (!npm) { err = err || new Error('Exit prior to setting npm in exit handler') // eslint-disable-next-line no-console console.error(err.stack || err.message) @@ -181,8 +180,24 @@ const exitHandler = err => { } } - const msg = errorMessage(err, npm) - for (const errline of [...msg.summary, ...msg.detail]) { + const { summary, detail, files = [] } = errorMessage(err, npm) + + for (let [file, content] of files) { + file = `${npm.logPath}${file}` + content = `'Log files:\n${npm.logFiles.join('\n')}\n\n${content.trim()}\n` + try { + fs.withOwnerSync( + file, + () => fs.writeFileSync(file, content), + { owner: 'inherit' } + ) + detail.push(['', `\n\nFor a full report see:\n${file}`]) + } catch (err) { + log.warn('', `Could not write error message to ${file} due to ${err}`) + } + } + + for (const errline of [...summary, ...detail]) { log.error(...errline) } @@ -190,8 +205,8 @@ const exitHandler = err => { const error = { error: { code: err.code, - summary: messageText(msg.summary), - detail: messageText(msg.detail), + summary: messageText(summary), + detail: messageText(detail), }, } npm.outputError(JSON.stringify(error, null, 2)) diff --git a/lib/utils/explain-eresolve.js b/lib/utils/explain-eresolve.js index 7f6a10869c73c..480cd8e5cd4e6 100644 --- a/lib/utils/explain-eresolve.js +++ b/lib/utils/explain-eresolve.js @@ -1,7 +1,6 @@ // this is called when an ERESOLVE error is caught in the exit-handler, // or when there's a log.warn('eresolve', msg, explanation), to turn it // into a human-intelligible explanation of what's wrong and how to fix. -const { writeFileSync } = require('fs') const { explainEdge, explainNode, printNode } = require('./explain-dep.js') // expl is an explanation object that comes from Arborist. It looks like: @@ -45,27 +44,25 @@ const explain = (expl, color, depth) => { } // generate a full verbose report and tell the user how to fix it -const report = (expl, color, fullReport) => { - const orNoStrict = expl.strictPeerDeps ? '--no-strict-peer-deps, ' : '' - const fix = `Fix the upstream dependency conflict, or retry -this command with ${orNoStrict}--force, or --legacy-peer-deps -to accept an incorrect (and potentially broken) dependency resolution.` - - writeFileSync(fullReport, `# npm resolution error report - -${new Date().toISOString()} - -${explain(expl, false, Infinity)} +const report = (expl, color) => { + const flags = [ + expl.strictPeerDeps ? '--no-strict-peer-deps' : '', + '--force', + '--legacy-peer-deps', + ].filter(Boolean) -${fix} + const or = (arr) => arr.length <= 2 + ? arr.join(' or ') : + arr.map((v, i, l) => i + 1 === l.length ? `or ${v}` : v).join(', ') -Raw JSON explanation object: - -${JSON.stringify(expl, null, 2)} -`, 'utf8') + const fix = `Fix the upstream dependency conflict, or retry +this command with ${or(flags)} +to accept an incorrect (and potentially broken) dependency resolution.` - return explain(expl, color, 4) + - `\n\n${fix}\n\nSee ${fullReport} for a full report.` + return { + explanation: `${explain(expl, color, 4)}\n\n${fix}`, + file: `# npm resolution error report\n\n${explain(expl, false, Infinity)}\n\n${fix}`, + } } module.exports = { diff --git a/lib/utils/log-file.js b/lib/utils/log-file.js index d62329c8551e2..3351ae6cdd3d5 100644 --- a/lib/utils/log-file.js +++ b/lib/utils/log-file.js @@ -11,19 +11,7 @@ const log = require('./log-shim') const padZero = (n, length) => n.toString().padStart(length.toString().length, '0') const globify = pattern => pattern.split('\\').join('/') -const _logHandler = Symbol('logHandler') -const _formatLogItem = Symbol('formatLogItem') -const _getLogFilePath = Symbol('getLogFilePath') -const _openLogFile = Symbol('openLogFile') -const _cleanLogs = Symbol('cleanlogs') -const _endStream = Symbol('endStream') -const _isBuffered = Symbol('isBuffered') - class LogFiles { - // If we write multiple log files we want them all to have the same - // identifier for sorting and matching purposes - #logId = null - // Default to a plain minipass stream so we can buffer // initial writes before we know the cache location #logStream = null @@ -41,7 +29,7 @@ class LogFiles { #fileLogCount = 0 #totalLogCount = 0 - #dir = null + #path = null #logsMax = null #files = [] @@ -49,16 +37,11 @@ class LogFiles { maxLogsPerFile = 50_000, maxFilesPerProcess = 5, } = {}) { - this.#logId = LogFiles.logId(new Date()) this.#MAX_LOGS_PER_FILE = maxLogsPerFile this.#MAX_FILES_PER_PROCESS = maxFilesPerProcess this.on() } - static logId (d) { - return d.toISOString().replace(/[.:]/g, '_') - } - static format (count, level, title, ...args) { let prefix = `${count} ${level}` if (title) { @@ -75,18 +58,18 @@ class LogFiles { on () { this.#logStream = new MiniPass() - process.on('log', this[_logHandler]) + process.on('log', this.#logHandler) } off () { - process.off('log', this[_logHandler]) - this[_endStream]() + process.off('log', this.#logHandler) + this.#endStream() } - load ({ dir, logsMax = Infinity } = {}) { + load ({ path, 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.#path = path this.#logsMax = logsMax // Log stream has already ended @@ -94,13 +77,13 @@ class LogFiles { return } - log.verbose('logfile', `logs-max:${logsMax} dir:${dir}`) + log.verbose('logfile', `logs-max:${logsMax} dir:${this.#path}`) // Pipe our initial stream to our new file stream and // set that as the new log logstream for future writes // if logs max is 0 then the user does not want a log file if (this.#logsMax > 0) { - const initialFile = this[_openLogFile]() + const initialFile = this.#openLogFile() if (initialFile) { this.#logStream = this.#logStream.pipe(initialFile) } @@ -109,29 +92,29 @@ class LogFiles { // 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]() + return this.#cleanLogs() } log (...args) { - this[_logHandler](...args) + this.#logHandler(...args) } get files () { return this.#files } - get [_isBuffered] () { + get #isBuffered () { return this.#logStream instanceof MiniPass } - [_endStream] (output) { + #endStream (output) { if (this.#logStream) { this.#logStream.end(output) this.#logStream = null } } - [_logHandler] = (level, ...args) => { + #logHandler = (level, ...args) => { // Ignore pause and resume events since we // write everything to the log file if (level === 'pause' || level === 'resume') { @@ -143,9 +126,9 @@ class LogFiles { return } - const logOutput = this[_formatLogItem](level, ...args) + const logOutput = this.#formatLogItem(level, ...args) - if (this[_isBuffered]) { + if (this.#isBuffered) { // Cant do anything but buffer the output if we dont // have a file stream yet this.#logStream.write(logOutput) @@ -155,29 +138,29 @@ class LogFiles { // Open a new log file if we've written too many logs to this one if (this.#fileLogCount >= this.#MAX_LOGS_PER_FILE) { // Write last chunk to the file and close it - this[_endStream](logOutput) + this.#endStream(logOutput) if (this.#files.length >= this.#MAX_FILES_PER_PROCESS) { // but if its way too many then we just stop listening this.off() } else { // otherwise we are ready for a new file for the next event - this.#logStream = this[_openLogFile]() + this.#logStream = this.#openLogFile() } } else { this.#logStream.write(logOutput) } } - [_formatLogItem] (...args) { + #formatLogItem (...args) { this.#fileLogCount += 1 return LogFiles.format(this.#totalLogCount++, ...args) } - [_getLogFilePath] (count = '') { - return path.resolve(this.#dir, `${this.#logId}-debug-${count}.log`) + #getLogFilePath (count = '') { + return `${this.#path}debug-${count}.log` } - [_openLogFile] () { + #openLogFile () { // Count in filename will be 0 indexed const count = this.#files.length @@ -186,7 +169,7 @@ class LogFiles { // 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)) + 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 @@ -210,7 +193,7 @@ class LogFiles { } } - async [_cleanLogs] () { + async #cleanLogs () { // module to clean out the old log files // this is a best-effort attempt. if a rm fails, we just // log a message about it and move on. We do return a @@ -218,7 +201,7 @@ class LogFiles { // just for the benefit of testing this function properly. try { - const logPath = 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]') diff --git a/lib/utils/timers.js b/lib/utils/timers.js index 3336c3b519259..c84bbba3819ab 100644 --- a/lib/utils/timers.js +++ b/lib/utils/timers.js @@ -1,12 +1,7 @@ const EE = require('events') -const { resolve } = require('path') const fs = require('@npmcli/fs') const log = require('./log-shim') -const _timeListener = Symbol('timeListener') -const _timeEndListener = Symbol('timeEndListener') -const _init = Symbol('init') - // This is an event emiiter but on/off // only listen on a single internal event that gets // emitted whenever a timer ends @@ -23,7 +18,7 @@ class Timers extends EE { super() this.#initialListener = listener this.#initialTimer = start - this[_init]() + this.#init() } get unfinished () { @@ -34,7 +29,7 @@ class Timers extends EE { return this.#finished } - [_init] () { + #init () { this.on() if (this.#initialListener) { this.on(this.#initialListener) @@ -47,8 +42,8 @@ class Timers extends EE { if (listener) { super.on(this.#onTimeEnd, listener) } else { - process.on('time', this[_timeListener]) - process.on('timeEnd', this[_timeEndListener]) + process.on('time', this.#timeListener) + process.on('timeEnd', this.#timeEndListener) } } @@ -57,8 +52,8 @@ class Timers extends EE { super.off(this.#onTimeEnd, listener) } else { this.removeAllListeners(this.#onTimeEnd) - process.off('time', this[_timeListener]) - process.off('timeEnd', this[_timeEndListener]) + process.off('time', this.#timeListener) + process.off('timeEnd', this.#timeEndListener) } } @@ -72,13 +67,13 @@ class Timers extends EE { return end } - load ({ dir } = {}) { - if (dir) { - this.file = resolve(dir, '_timing.json') + load ({ path } = {}) { + if (path) { + this.file = `${path}timing.json` } } - writeFile (fileData) { + writeFile (metadata) { if (!this.file) { return } @@ -87,20 +82,17 @@ class Timers extends EE { const globalStart = this.started const globalEnd = this.#finished.npm || Date.now() const content = { - ...fileData, - ...this.#finished, + metadata, + timers: this.#finished, // add any unfinished timers with their relative start/end - unfinished: [...this.#unfinished.entries()].reduce((acc, [name, start]) => { + unfinishedTimers: [...this.#unfinished.entries()].reduce((acc, [name, start]) => { acc[name] = [start - globalStart, globalEnd - globalStart] return acc }, {}), } - // 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'), + () => fs.writeFileSync(this.file, JSON.stringify(content) + '\n'), { owner: 'inherit' } ) } catch (e) { @@ -109,11 +101,11 @@ class Timers extends EE { } } - [_timeListener] = (name) => { + #timeListener = (name) => { this.#unfinished.set(name, Date.now()) } - [_timeEndListener] = (name) => { + #timeEndListener = (name) => { if (this.#unfinished.has(name)) { const ms = Date.now() - this.#unfinished.get(name) this.#finished[name] = ms 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 ddf2396a6fe00..df9313270d056 100644 --- a/tap-snapshots/test/lib/utils/config/definitions.js.test.cjs +++ b/tap-snapshots/test/lib/utils/config/definitions.js.test.cjs @@ -1762,12 +1762,11 @@ exports[`test/lib/utils/config/definitions.js TAP > config description for timin * Default: false * Type: Boolean -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. +If true, writes timing information to a process specific json file in the +cache or \`logs-dir\`. The file name ends with \`-timing.json\`. You can quickly view it with this [json](https://npm.im/json) command line: -\`npm exec -- json -g < ~/.npm/_timing.json\`. +\`cat ~/.npm/_logs/*-timing.json | npm exec -- json -g\`. ` exports[`test/lib/utils/config/definitions.js TAP > config description for tmp 1`] = ` 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 2c51efec54afe..89ca7c952b182 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 @@ -1580,12 +1580,11 @@ particular, use care when overriding this setting for public packages. * Default: false * Type: Boolean -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. +If true, writes timing information to a process specific json file in the +cache or \`logs-dir\`. The file name ends with \`-timing.json\`. You can quickly view it with this [json](https://npm.im/json) command line: -\`npm exec -- json -g < ~/.npm/_timing.json\`. +\`cat ~/.npm/_logs/*-timing.json | npm exec -- json -g\`. 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 8e772e8691860..de21a46d2f6e8 100644 --- a/tap-snapshots/test/lib/utils/error-message.js.test.cjs +++ b/tap-snapshots/test/lib/utils/error-message.js.test.cjs @@ -509,7 +509,7 @@ Array [ ], 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", + "logs-max:10 dir:{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-false-loaded-true-cachePath-false-cacheDest-false-/cache/_logs/{DATE}-", ], Array [ "logfile", @@ -549,7 +549,7 @@ Array [ ], 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", + "logs-max:10 dir:{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-false-loaded-true-cachePath-false-cacheDest-true-/cache/_logs/{DATE}-", ], Array [ "logfile", @@ -592,7 +592,7 @@ Array [ ], 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", + "logs-max:10 dir:{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-false-loaded-true-cachePath-true-cacheDest-false-/cache/_logs/{DATE}-", ], Array [ "logfile", @@ -635,7 +635,7 @@ Array [ ], 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", + "logs-max:10 dir:{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-false-loaded-true-cachePath-true-cacheDest-true-/cache/_logs/{DATE}-", ], Array [ "logfile", @@ -825,7 +825,7 @@ Array [ ], 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", + "logs-max:10 dir:{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-true-loaded-true-cachePath-false-cacheDest-false-/cache/_logs/{DATE}-", ], Array [ "logfile", @@ -876,7 +876,7 @@ Array [ ], 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", + "logs-max:10 dir:{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-true-loaded-true-cachePath-false-cacheDest-true-/cache/_logs/{DATE}-", ], Array [ "logfile", @@ -927,7 +927,7 @@ Array [ ], 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", + "logs-max:10 dir:{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-true-loaded-true-cachePath-true-cacheDest-false-/cache/_logs/{DATE}-", ], Array [ "logfile", @@ -978,7 +978,7 @@ Array [ ], 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", + "logs-max:10 dir:{CWD}/test/lib/utils/tap-testdir-error-message-eacces-eperm--windows-true-loaded-true-cachePath-true-cacheDest-true-/cache/_logs/{DATE}-", ], Array [ "logfile", @@ -1176,6 +1176,12 @@ Object { "explanation", ], ], + "files": Array [ + Array [ + "eresolve-report.txt", + "report", + ], + ], "summary": Array [ Array [ "ERESOLVE", 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 edb7edaa5d5f5..4d52c02d97dd3 100644 --- a/tap-snapshots/test/lib/utils/exit-handler.js.test.cjs +++ b/tap-snapshots/test/lib/utils/exit-handler.js.test.cjs @@ -15,7 +15,7 @@ exports[`test/lib/utils/exit-handler.js TAP handles unknown error with logs and 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 +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/{DATE}- 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 @@ -47,7 +47,7 @@ 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 logs-max:10 dir:{CWD}/test/lib/utils/tap-testdir-exit-handler-handles-unknown-error-with-logs-and-debug-file/cache/_logs/{DATE}- 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 diff --git a/tap-snapshots/test/lib/utils/explain-eresolve.js.test.cjs b/tap-snapshots/test/lib/utils/explain-eresolve.js.test.cjs index 354081d110319..99ad5c0f31e90 100644 --- a/tap-snapshots/test/lib/utils/explain-eresolve.js.test.cjs +++ b/tap-snapshots/test/lib/utils/explain-eresolve.js.test.cjs @@ -29,11 +29,9 @@ node_modules/@isaacs/testing-peer-dep-conflict-chain-c @isaacs/testing-peer-dep-conflict-chain-c@"1" from the root project ` -exports[`test/lib/utils/explain-eresolve.js TAP chain-conflict > report 1`] = ` +exports[`test/lib/utils/explain-eresolve.js TAP chain-conflict > report from color 1`] = ` # npm resolution error report -\${TIME} - While resolving: project@1.2.3 Found: @isaacs/testing-peer-dep-conflict-chain-d@2.0.0 node_modules/@isaacs/testing-peer-dep-conflict-chain-d @@ -45,16 +43,8 @@ node_modules/@isaacs/testing-peer-dep-conflict-chain-c @isaacs/testing-peer-dep-conflict-chain-c@"1" from the root project Fix the upstream dependency conflict, or retry -this command with --force, or --legacy-peer-deps +this command with --force or --legacy-peer-deps to accept an incorrect (and potentially broken) dependency resolution. - -Raw JSON explanation object: - -{ - "name": "chain-conflict", - "json": true -} - ` exports[`test/lib/utils/explain-eresolve.js TAP chain-conflict > report with color 1`] = ` @@ -69,10 +59,8 @@ Could not resolve dependency: @isaacs/testing-peer-dep-conflict-chain-c@"1" from the root project Fix the upstream dependency conflict, or retry -this command with --force, or --legacy-peer-deps +this command with --force or --legacy-peer-deps to accept an incorrect (and potentially broken) dependency resolution. - -See \${REPORT} for a full report. ` exports[`test/lib/utils/explain-eresolve.js TAP chain-conflict > report with no color 1`] = ` @@ -87,10 +75,8 @@ node_modules/@isaacs/testing-peer-dep-conflict-chain-c @isaacs/testing-peer-dep-conflict-chain-c@"1" from the root project Fix the upstream dependency conflict, or retry -this command with --force, or --legacy-peer-deps +this command with --force or --legacy-peer-deps to accept an incorrect (and potentially broken) dependency resolution. - -See \${REPORT} for a full report. ` exports[`test/lib/utils/explain-eresolve.js TAP cycleNested > explain with color, depth of 2 1`] = ` @@ -130,11 +116,9 @@ node_modules/@isaacs/peer-dep-cycle-c @isaacs/peer-dep-cycle-a@"1.x" from the root project ` -exports[`test/lib/utils/explain-eresolve.js TAP cycleNested > report 1`] = ` +exports[`test/lib/utils/explain-eresolve.js TAP cycleNested > report from color 1`] = ` # npm resolution error report -\${TIME} - Found: @isaacs/peer-dep-cycle-c@2.0.0 node_modules/@isaacs/peer-dep-cycle-c @isaacs/peer-dep-cycle-c@"2.x" from the root project @@ -155,14 +139,6 @@ node_modules/@isaacs/peer-dep-cycle-c Fix the upstream dependency conflict, or retry this command with --no-strict-peer-deps, --force, or --legacy-peer-deps to accept an incorrect (and potentially broken) dependency resolution. - -Raw JSON explanation object: - -{ - "name": "cycleNested", - "json": true -} - ` exports[`test/lib/utils/explain-eresolve.js TAP cycleNested > report with color 1`] = ` @@ -186,8 +162,6 @@ Conflicting peer dependency: @isaacs/peer-dep-cycle-c@1.0.0[2 Fix the upstream dependency conflict, or retry this command with --no-strict-peer-deps, --force, or --legacy-peer-deps to accept an incorrect (and potentially broken) dependency resolution. - -See \${REPORT} for a full report. ` exports[`test/lib/utils/explain-eresolve.js TAP cycleNested > report with no color 1`] = ` @@ -211,8 +185,6 @@ node_modules/@isaacs/peer-dep-cycle-c Fix the upstream dependency conflict, or retry this command with --no-strict-peer-deps, --force, or --legacy-peer-deps to accept an incorrect (and potentially broken) dependency resolution. - -See \${REPORT} for a full report. ` exports[`test/lib/utils/explain-eresolve.js TAP eslint-plugin case > explain with color, depth of 2 1`] = ` @@ -255,11 +227,9 @@ node_modules/eslint dev eslint-plugin-eslint-plugin@"^3.1.0" from the root project ` -exports[`test/lib/utils/explain-eresolve.js TAP eslint-plugin case > report 1`] = ` +exports[`test/lib/utils/explain-eresolve.js TAP eslint-plugin case > report from color 1`] = ` # npm resolution error report -\${TIME} - While resolving: eslint-plugin-react@7.24.0 Found: eslint@6.8.0 node_modules/eslint @@ -287,16 +257,8 @@ node_modules/eslint dev eslint-plugin-eslint-plugin@"^3.1.0" from the root project Fix the upstream dependency conflict, or retry -this command with --force, or --legacy-peer-deps +this command with --force or --legacy-peer-deps to accept an incorrect (and potentially broken) dependency resolution. - -Raw JSON explanation object: - -{ - "name": "eslint-plugin case", - "json": true -} - ` exports[`test/lib/utils/explain-eresolve.js TAP eslint-plugin case > report with color 1`] = ` @@ -319,10 +281,8 @@ Conflicting peer dependency: eslint@7.31.0 dev eslint-plugin-eslint-plugin@"^3.1.0" from the root project Fix the upstream dependency conflict, or retry -this command with --force, or --legacy-peer-deps +this command with --force or --legacy-peer-deps to accept an incorrect (and potentially broken) dependency resolution. - -See \${REPORT} for a full report. ` exports[`test/lib/utils/explain-eresolve.js TAP eslint-plugin case > report with no color 1`] = ` @@ -345,10 +305,8 @@ node_modules/eslint dev eslint-plugin-eslint-plugin@"^3.1.0" from the root project Fix the upstream dependency conflict, or retry -this command with --force, or --legacy-peer-deps +this command with --force or --legacy-peer-deps to accept an incorrect (and potentially broken) dependency resolution. - -See \${REPORT} for a full report. ` exports[`test/lib/utils/explain-eresolve.js TAP gatsby > explain with color, depth of 2 1`] = ` @@ -391,11 +349,9 @@ node_modules/ink-box gatsby@"" from the root project ` -exports[`test/lib/utils/explain-eresolve.js TAP gatsby > report 1`] = ` +exports[`test/lib/utils/explain-eresolve.js TAP gatsby > report from color 1`] = ` # npm resolution error report -\${TIME} - While resolving: gatsby-recipes@0.2.31 Found: ink@3.0.0-7 node_modules/ink @@ -421,14 +377,6 @@ node_modules/ink-box Fix the upstream dependency conflict, or retry this command with --no-strict-peer-deps, --force, or --legacy-peer-deps to accept an incorrect (and potentially broken) dependency resolution. - -Raw JSON explanation object: - -{ - "name": "gatsby", - "json": true -} - ` exports[`test/lib/utils/explain-eresolve.js TAP gatsby > report with color 1`] = ` @@ -456,8 +404,6 @@ Could not resolve dependency: Fix the upstream dependency conflict, or retry this command with --no-strict-peer-deps, --force, or --legacy-peer-deps to accept an incorrect (and potentially broken) dependency resolution. - -See \${REPORT} for a full report. ` exports[`test/lib/utils/explain-eresolve.js TAP gatsby > report with no color 1`] = ` @@ -485,8 +431,6 @@ node_modules/ink-box Fix the upstream dependency conflict, or retry this command with --no-strict-peer-deps, --force, or --legacy-peer-deps to accept an incorrect (and potentially broken) dependency resolution. - -See \${REPORT} for a full report. ` exports[`test/lib/utils/explain-eresolve.js TAP no current node, but has current edge > explain with color, depth of 2 1`] = ` @@ -509,11 +453,9 @@ node_modules/eslint-plugin-jsdoc dev eslint-plugin-jsdoc@"^22.1.0" from the root project ` -exports[`test/lib/utils/explain-eresolve.js TAP no current node, but has current edge > report 1`] = ` +exports[`test/lib/utils/explain-eresolve.js TAP no current node, but has current edge > report from color 1`] = ` # npm resolution error report -\${TIME} - While resolving: eslint@7.22.0 Found: dev eslint@"file:." from the root project @@ -523,16 +465,8 @@ node_modules/eslint-plugin-jsdoc dev eslint-plugin-jsdoc@"^22.1.0" from the root project Fix the upstream dependency conflict, or retry -this command with --force, or --legacy-peer-deps +this command with --force or --legacy-peer-deps to accept an incorrect (and potentially broken) dependency resolution. - -Raw JSON explanation object: - -{ - "name": "no current node, but has current edge", - "json": true -} - ` exports[`test/lib/utils/explain-eresolve.js TAP no current node, but has current edge > report with color 1`] = ` @@ -545,10 +479,8 @@ Could not resolve dependency: dev eslint-plugin-jsdoc@"^22.1.0" from the root project Fix the upstream dependency conflict, or retry -this command with --force, or --legacy-peer-deps +this command with --force or --legacy-peer-deps to accept an incorrect (and potentially broken) dependency resolution. - -See \${REPORT} for a full report. ` exports[`test/lib/utils/explain-eresolve.js TAP no current node, but has current edge > report with no color 1`] = ` @@ -561,10 +493,8 @@ node_modules/eslint-plugin-jsdoc dev eslint-plugin-jsdoc@"^22.1.0" from the root project Fix the upstream dependency conflict, or retry -this command with --force, or --legacy-peer-deps +this command with --force or --legacy-peer-deps to accept an incorrect (and potentially broken) dependency resolution. - -See \${REPORT} for a full report. ` exports[`test/lib/utils/explain-eresolve.js TAP no current node, no current edge, idk > explain with color, depth of 2 1`] = ` @@ -591,11 +521,9 @@ node_modules/eslint-plugin-jsdoc dev eslint-plugin-jsdoc@"^22.1.0" from the root project ` -exports[`test/lib/utils/explain-eresolve.js TAP no current node, no current edge, idk > report 1`] = ` +exports[`test/lib/utils/explain-eresolve.js TAP no current node, no current edge, idk > report from color 1`] = ` # npm resolution error report -\${TIME} - While resolving: eslint@7.22.0 Found: peer eslint@"^6.0.0" from eslint-plugin-jsdoc@22.2.0 node_modules/eslint-plugin-jsdoc @@ -607,16 +535,8 @@ node_modules/eslint-plugin-jsdoc dev eslint-plugin-jsdoc@"^22.1.0" from the root project Fix the upstream dependency conflict, or retry -this command with --force, or --legacy-peer-deps +this command with --force or --legacy-peer-deps to accept an incorrect (and potentially broken) dependency resolution. - -Raw JSON explanation object: - -{ - "name": "no current node, no current edge, idk", - "json": true -} - ` exports[`test/lib/utils/explain-eresolve.js TAP no current node, no current edge, idk > report with color 1`] = ` @@ -631,10 +551,8 @@ Could not resolve dependency: dev eslint-plugin-jsdoc@"^22.1.0" from the root project Fix the upstream dependency conflict, or retry -this command with --force, or --legacy-peer-deps +this command with --force or --legacy-peer-deps to accept an incorrect (and potentially broken) dependency resolution. - -See \${REPORT} for a full report. ` exports[`test/lib/utils/explain-eresolve.js TAP no current node, no current edge, idk > report with no color 1`] = ` @@ -649,10 +567,8 @@ node_modules/eslint-plugin-jsdoc dev eslint-plugin-jsdoc@"^22.1.0" from the root project Fix the upstream dependency conflict, or retry -this command with --force, or --legacy-peer-deps +this command with --force or --legacy-peer-deps to accept an incorrect (and potentially broken) dependency resolution. - -See \${REPORT} for a full report. ` exports[`test/lib/utils/explain-eresolve.js TAP withShrinkwrap > explain with color, depth of 2 1`] = ` @@ -682,11 +598,9 @@ node_modules/@isaacs/peer-dep-cycle-b @isaacs/peer-dep-cycle-a@"1.x" from the root project ` -exports[`test/lib/utils/explain-eresolve.js TAP withShrinkwrap > report 1`] = ` +exports[`test/lib/utils/explain-eresolve.js TAP withShrinkwrap > report from color 1`] = ` # npm resolution error report -\${TIME} - While resolving: @isaacs/peer-dep-cycle-b@1.0.0 Found: @isaacs/peer-dep-cycle-c@2.0.0 node_modules/@isaacs/peer-dep-cycle-c @@ -702,14 +616,6 @@ node_modules/@isaacs/peer-dep-cycle-b Fix the upstream dependency conflict, or retry this command with --no-strict-peer-deps, --force, or --legacy-peer-deps to accept an incorrect (and potentially broken) dependency resolution. - -Raw JSON explanation object: - -{ - "name": "withShrinkwrap", - "json": true -} - ` exports[`test/lib/utils/explain-eresolve.js TAP withShrinkwrap > report with color 1`] = ` @@ -728,8 +634,6 @@ Could not resolve dependency: Fix the upstream dependency conflict, or retry this command with --no-strict-peer-deps, --force, or --legacy-peer-deps to accept an incorrect (and potentially broken) dependency resolution. - -See \${REPORT} for a full report. ` exports[`test/lib/utils/explain-eresolve.js TAP withShrinkwrap > report with no color 1`] = ` @@ -748,6 +652,4 @@ node_modules/@isaacs/peer-dep-cycle-b Fix the upstream dependency conflict, or retry this command with --no-strict-peer-deps, --force, or --legacy-peer-deps to accept an incorrect (and potentially broken) dependency resolution. - -See \${REPORT} for a full report. ` 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 7a39184939026..912a4365f6810 100644 --- a/tap-snapshots/test/lib/utils/log-file.js.test.cjs +++ b/tap-snapshots/test/lib/utils/log-file.js.test.cjs @@ -6,7 +6,7 @@ */ 'use strict' exports[`test/lib/utils/log-file.js TAP snapshot > must match snapshot 1`] = ` -0 verbose logfile logs-max:10 dir:{CWD}/test/lib/utils/tap-testdir-log-file-snapshot +0 verbose logfile logs-max:10 dir:{CWD}/test/lib/utils/tap-testdir-log-file-snapshot/{DATE}- 1 silly logfile done cleaning log files 2 error no prefix 3 error prefix with prefix diff --git a/test/fixtures/mock-npm.js b/test/fixtures/mock-npm.js index 330c341474da3..72cfa4b0c4beb 100644 --- a/test/fixtures/mock-npm.js +++ b/test/fixtures/mock-npm.js @@ -174,8 +174,8 @@ const LoadMockNpm = async (t, { .join('\n') }, timingFile: async () => { - const data = await fs.readFile(path.resolve(dirs.cache, '_timing.json'), 'utf8') - return JSON.parse(data) // XXX: this fails if multiple timings are written + const data = await fs.readFile(npm.timingFile, 'utf8') + return JSON.parse(data) }, } } diff --git a/test/lib/npm.js b/test/lib/npm.js index 135a02cc98a3d..2bf7f426db409 100644 --- a/test/lib/npm.js +++ b/test/lib/npm.js @@ -513,19 +513,23 @@ t.test('timings', async t => { process.emit('timeEnd', 'foo') process.emit('time', 'bar') npm.writeTimingFile() - t.equal(npm.timingFile, join(cache, '_timing.json')) + t.match(npm.timingFile, cache) + t.match(npm.timingFile, /-timing.json$/) const timings = await timingFile() t.match(timings, { - command: [], - logfile: String, - logfiles: [String], - version: String, - unfinished: { + metadata: { + command: [], + logfiles: [String], + version: String, + }, + unfinishedTimers: { bar: [Number, Number], npm: [Number, Number], }, - foo: Number, - 'npm:load': Number, + timers: { + foo: Number, + 'npm:load': Number, + }, }) }) diff --git a/test/lib/utils/error-message.js b/test/lib/utils/error-message.js index 3fec501ef9ff7..29753c3039f36 100644 --- a/test/lib/utils/error-message.js +++ b/test/lib/utils/error-message.js @@ -4,6 +4,12 @@ const { load: _loadMockNpm } = require('../../fixtures/mock-npm.js') const mockGlobals = require('../../fixtures/mock-globals.js') const { cleanCwd, cleanDate } = require('../../fixtures/clean-snapshot.js') +t.formatSnapshot = (p) => { + if (Array.isArray(p.files) && !p.files.length) { + delete p.files + } + return p +} t.cleanSnapshot = p => cleanDate(cleanCwd(p)) mockGlobals(t, { @@ -420,7 +426,7 @@ t.test('bad platform', async t => { }) t.test('explain ERESOLVE errors', async t => { - const npm = await loadMockNpm(t) + const { npm, ...rest } = await loadMockNpm(t) const EXPLAIN_CALLED = [] const er = Object.assign(new Error('could not resolve'), { @@ -428,19 +434,16 @@ t.test('explain ERESOLVE errors', async t => { }) t.matchSnapshot(errorMessage(er, { - ...npm, + npm, + ...rest, mocks: { '../../../lib/utils/explain-eresolve.js': { report: (...args) => { EXPLAIN_CALLED.push(args) - return 'explanation' + return { explanation: 'explanation', file: 'report' } }, }, }, })) - t.match(EXPLAIN_CALLED, [[ - er, - false, - path.resolve(npm.cache, 'eresolve-report.txt'), - ]]) + t.match(EXPLAIN_CALLED, [[er, false]]) }) diff --git a/test/lib/utils/exit-handler.js b/test/lib/utils/exit-handler.js index 23942cca1c078..7d2e7e061c365 100644 --- a/test/lib/utils/exit-handler.js +++ b/test/lib/utils/exit-handler.js @@ -1,5 +1,7 @@ const t = require('tap') const os = require('os') +const fs = require('@npmcli/fs') +const { join } = require('path') const EventEmitter = require('events') const { format } = require('../../../lib/utils/log-file') const { load: loadMockNpm } = require('../../fixtures/mock-npm') @@ -45,7 +47,7 @@ mockGlobals(t, { }), }, { replace: true }) -const mockExitHandler = async (t, { init, load, testdir, config, globals, mocks } = {}) => { +const mockExitHandler = async (t, { init, load, testdir, config, mocks, files } = {}) => { const errors = [] const { npm, logMocks, ...rest } = await loadMockNpm(t, { @@ -69,9 +71,9 @@ const mockExitHandler = async (t, { init, load, testdir, config, globals, mocks const exitHandler = t.mock('../../../lib/utils/exit-handler.js', { '../../../lib/utils/error-message.js': (err) => ({ - ...err, summary: [['ERR SUMMARY', err.message]], detail: [['ERR DETAIL', err.message]], + ...(files ? { files } : {}), }), os: { type: () => 'Foo', @@ -311,6 +313,53 @@ t.test('log file error', async (t) => { t.match(logs.error.filter(([t]) => t === ''), [['', `error writing to the directory`]]) }) +t.test('files from error message', async (t) => { + const { exitHandler, logs, cache } = await mockExitHandler(t, { + files: [ + ['error-file.txt', '# error file content'], + ], + }) + + await exitHandler(err('Error message')) + + const logFiles = fs.readdirSync(join(cache, '_logs')) + const errorFileName = logFiles.find(f => f.endsWith('error-file.txt')) + const errorFile = fs.readFileSync(join(cache, '_logs', errorFileName)).toString() + + const [log] = logs.error.filter(([t]) => t === '') + + t.match(log[1], /For a full report see:\n.*-error-file\.txt/) + t.match(errorFile, '# error file content') + t.match(errorFile, 'Log files:') +}) + +t.test('files from error message with error', async (t) => { + const { exitHandler, logs } = await mockExitHandler(t, { + config: { + 'logs-dir': 'LOGS_DIR', + }, + files: [ + ['error-file.txt', '# error file content'], + ], + mocks: { + '@npmcli/fs': { + ...fs, + writeFileSync: (dir) => { + if (dir.includes('LOGS_DIR') && dir.endsWith('error-file.txt')) { + throw new Error('err') + } + }, + }, + }, + }) + + await exitHandler(err('Error message')) + + const [log] = logs.warn.filter(([t]) => t === '') + + t.match(log[1], /Could not write error message to.*error-file\.txt.*err/) +}) + t.test('timing with no error', async (t) => { const { exitHandler, timingFile, npm, logs } = await mockExitHandler(t, { config: { timing: true }, @@ -326,7 +375,7 @@ t.test('timing with no error', async (t) => { t.match(msg, /Timing info written to:/) t.match( - timingFileData, + timingFileData.timers, Object.keys(npm.finishedTimers).reduce((acc, k) => { acc[k] = Number return acc @@ -334,11 +383,14 @@ t.test('timing with no error', async (t) => { ) t.strictSame(npm.unfinishedTimers, new Map()) t.match(timingFileData, { - command: [], - version: '1.0.0', - npm: Number, - logfile: String, - logfiles: [String], + metadata: { + command: [], + version: '1.0.0', + logfiles: [String], + }, + timers: { + npm: Number, + }, }) }) @@ -356,12 +408,15 @@ t.test('unfinished timers', async (t) => { t.equal(process.exitCode, 0) t.match(npm.unfinishedTimers, new Map([['foo', Number], ['bar', Number]])) t.match(timingFileData, { - command: [], - version: '1.0.0', - npm: Number, - logfile: String, - logfiles: [String], - unfinished: { + metadata: { + command: [], + version: '1.0.0', + logfiles: [String], + }, + timers: { + npm: Number, + }, + unfinishedTimers: { foo: [Number, Number], bar: [Number, Number], }, diff --git a/test/lib/utils/explain-eresolve.js b/test/lib/utils/explain-eresolve.js index f9710ee889ab1..2c1fed77899e9 100644 --- a/test/lib/utils/explain-eresolve.js +++ b/test/lib/utils/explain-eresolve.js @@ -1,41 +1,32 @@ const t = require('tap') -const npm = {} -const { explain, report } = require('../../../lib/utils/explain-eresolve.js') -const { statSync, readFileSync, unlinkSync } = require('fs') -// strip out timestamps from reports -const read = f => readFileSync(f, 'utf8') - .replace(/\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}.\d{3}Z/g, '${TIME}') - const { resolve } = require('path') +const { explain, report } = require('../../../lib/utils/explain-eresolve.js') const cases = require('../../fixtures/eresolve-explanations.js') +const { cleanDate } = require('../../fixtures/clean-snapshot.js') for (const [name, expl] of Object.entries(cases)) { // no sense storing the whole contents of each object in the snapshot // we can trust that JSON.stringify still works just fine. - expl.toJSON = () => { - return { name, json: true } - } + expl.toJSON = () => ({ name, json: true }) t.test(name, t => { - npm.cache = t.testdir() - const reportFile = resolve(npm.cache, 'eresolve-report.txt') - t.cleanSnapshot = str => str.split(reportFile).join('${REPORT}') + const dir = t.testdir() + const fileReport = resolve(dir, 'eresolve-report.txt') + const opts = { file: fileReport, date: new Date().toISOString() } + + t.cleanSnapshot = str => cleanDate(str.split(fileReport).join('${REPORT}')) - npm.color = true - t.matchSnapshot(report(expl, true, reportFile), 'report with color') - const reportData = read(reportFile) - t.matchSnapshot(reportData, 'report') - unlinkSync(reportFile) + const color = report(expl, true, opts) + t.matchSnapshot(color.explanation, 'report with color') + t.matchSnapshot(color.file, 'report from color') - t.matchSnapshot(report(expl, false, reportFile), 'report with no color') - t.equal(read(reportFile), reportData, 'same report written for object') - unlinkSync(reportFile) + const noColor = report(expl, false, opts) + t.matchSnapshot(noColor.explanation, 'report with no color') + t.equal(noColor.file, color.file, 'same report written for object') t.matchSnapshot(explain(expl, true, 2), 'explain with color, depth of 2') - t.throws(() => statSync(reportFile), { code: 'ENOENT' }, 'no report') t.matchSnapshot(explain(expl, false, 6), 'explain with no color, depth of 6') - t.throws(() => statSync(reportFile), { code: 'ENOENT' }, 'no report') t.end() }) diff --git a/test/lib/utils/log-file.js b/test/lib/utils/log-file.js index ce6f0bf4cf51f..4be5231c1c4fa 100644 --- a/test/lib/utils/log-file.js +++ b/test/lib/utils/log-file.js @@ -6,10 +6,11 @@ const os = require('os') const fsMiniPass = require('fs-minipass') const rimraf = require('rimraf') const LogFile = require('../../../lib/utils/log-file.js') -const { cleanCwd } = require('../../fixtures/clean-snapshot') +const { cleanCwd, cleanDate } = require('../../fixtures/clean-snapshot') -t.cleanSnapshot = (path) => cleanCwd(path) +t.cleanSnapshot = (path) => cleanDate(cleanCwd(path)) +const getId = (d = new Date()) => d.toISOString().replace(/[.:]/g, '_') const last = arr => arr[arr.length - 1] const range = (n) => Array.from(Array(n).keys()) const makeOldLogs = (count, oldStyle) => { @@ -19,7 +20,7 @@ const makeOldLogs = (count, oldStyle) => { return range(oldStyle ? count : (count / 2)).reduce((acc, i) => { const cloneDate = new Date(d.getTime()) cloneDate.setSeconds(i) - const dateId = LogFile.logId(cloneDate) + const dateId = getId(cloneDate) if (oldStyle) { acc[`${dateId}-debug.log`] = 'hello' } else { @@ -41,10 +42,15 @@ const cleanErr = (message) => { const loadLogFile = async (t, { buffer = [], mocks, testdir = {}, ...options } = {}) => { const root = t.testdir(testdir) + const MockLogFile = t.mock('../../../lib/utils/log-file.js', mocks) const logFile = new MockLogFile(Object.keys(options).length ? options : undefined) + buffer.forEach((b) => logFile.log(...b)) - await logFile.load({ dir: root, ...options }) + + const id = getId() + await logFile.load({ path: path.join(root, `${id}-`), ...options }) + t.teardown(() => logFile.off()) return { root, diff --git a/test/lib/utils/timers.js b/test/lib/utils/timers.js index 30e54700c63a9..23d8eb6e2cafe 100644 --- a/test/lib/utils/timers.js +++ b/test/lib/utils/timers.js @@ -72,13 +72,13 @@ t.test('writes file', async (t) => { const dir = t.testdir() process.emit('time', 'foo') process.emit('timeEnd', 'foo') - timers.load({ dir }) + timers.load({ path: resolve(dir, `TIMING_FILE-`) }) timers.writeFile({ some: 'data' }) - const data = JSON.parse(fs.readFileSync(resolve(dir, '_timing.json'))) + const data = JSON.parse(fs.readFileSync(resolve(dir, 'TIMING_FILE-timing.json'))) t.match(data, { - some: 'data', - foo: Number, - unfinished: { + metadata: { some: 'data' }, + timers: { foo: Number }, + unfinishedTimers: { npm: [Number, Number], }, }) @@ -88,7 +88,7 @@ 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.load({ path: join(dir, 'does', 'not', 'exist') }) timers.writeFile() t.match(logs.warn, [['timing', 'could not write timing file']])