From 7bbd88f111b907576b59556fbf07cf038f7e5f0f Mon Sep 17 00:00:00 2001 From: Luke Karrys Date: Sun, 25 Sep 2022 01:31:56 -0700 Subject: feat: write eresolve error files to the logs directory Also refactor all files written to the logs directory to use the same code path for file name creation. --- lib/npm.js | 15 ++- lib/utils/error-message.js | 10 +- lib/utils/exit-handler.js | 35 ++++-- lib/utils/explain-eresolve.js | 35 +++--- lib/utils/log-file.js | 17 +-- lib/utils/run-id.js | 3 - lib/utils/timers.js | 17 +-- .../test/lib/utils/error-message.js.test.cjs | 22 ++-- .../test/lib/utils/exit-handler.js.test.cjs | 4 +- .../test/lib/utils/explain-eresolve.js.test.cjs | 136 +++------------------ tap-snapshots/test/lib/utils/log-file.js.test.cjs | 2 +- test/lib/utils/error-message.js | 19 +-- test/lib/utils/exit-handler.js | 55 ++++++++- test/lib/utils/explain-eresolve.js | 37 +++--- test/lib/utils/log-file.js | 15 ++- test/lib/utils/timers.js | 6 +- 16 files changed, 194 insertions(+), 234 deletions(-) delete mode 100644 lib/utils/run-id.js diff --git a/lib/npm.js b/lib/npm.js index a178dca72..4198ed905 100644 --- a/lib/npm.js +++ b/lib/npm.js @@ -18,11 +18,9 @@ const replaceInfo = require('./utils/replace-info.js') const updateNotifier = require('./utils/update-notifier.js') const pkg = require('../package.json') const cmdList = require('./utils/cmd-list.js') -const runId = require('./utils/run-id.js') let warnedNonDashArg = false const _load = Symbol('_load') -const RUN_ID = runId() class Npm extends EventEmitter { static get version () { @@ -34,16 +32,16 @@ class Npm extends EventEmitter { loadErr = null argv = [] + #runId = new Date().toISOString().replace(/[.:]/g, '_') #loadPromise = null #tmpFolder = null #title = 'npm' #argvClean = [] #chalk = null - #logFile = new LogFile({ id: RUN_ID }) + #logFile = new LogFile() #display = new Display() #timers = new Timers({ - id: RUN_ID, start: 'npm', listener: (name, ms) => { const args = ['timing', name, `Completed in ${ms}ms`] @@ -209,6 +207,7 @@ class Npm extends EventEmitter { writeTimingFile () { this.#timers.writeFile({ + id: this.#runId, command: this.#argvClean, logfiles: this.logFiles, version: this.version, @@ -289,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') @@ -297,7 +296,7 @@ class Npm extends EventEmitter { this.time('npm:load:timers', () => this.#timers.load({ - dir: this.config.get('timing') ? this.logsDir : null, + path: this.config.get('timing') ? this.logPath : null, }) ) @@ -371,6 +370,10 @@ class Npm extends EventEmitter { return this.config.get('logs-dir') || join(this.cache, '_logs') } + logPath = (file = '') => { + return resolve(this.logsDir, `${this.#runId}-${file}`) + } + get timingFile () { return this.#timers.file } diff --git a/lib/utils/error-message.js b/lib/utils/error-message.js index adf10a56f..aee376120 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 d8ae9994d..19bbba240 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 7f6a10869..480cd8e5c 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 a18eb2878..a10b69531 100644 --- a/lib/utils/log-file.js +++ b/lib/utils/log-file.js @@ -7,16 +7,11 @@ const MiniPass = require('minipass') const fsMiniPass = require('fs-minipass') const fs = require('@npmcli/fs') const log = require('./log-shim') -const runId = require('./run-id') const padZero = (n, length) => n.toString().padStart(length.toString().length, '0') const globify = pattern => pattern.split('\\').join('/') 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 @@ -34,16 +29,14 @@ class LogFiles { #fileLogCount = 0 #totalLogCount = 0 - #dir = null + #path = null #logsMax = null #files = [] constructor ({ - id = runId(), maxLogsPerFile = 50_000, maxFilesPerProcess = 5, } = {}) { - this.#logId = id this.#MAX_LOGS_PER_FILE = maxLogsPerFile this.#MAX_FILES_PER_PROCESS = maxFilesPerProcess this.on() @@ -73,10 +66,10 @@ class LogFiles { 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 @@ -84,7 +77,7 @@ 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 @@ -164,7 +157,7 @@ class LogFiles { } #getLogFilePath (count = '') { - return path.resolve(this.#dir, `${this.#logId}-debug-${count}.log`) + return this.#path(`debug-${count}.log`) } #openLogFile () { diff --git a/lib/utils/run-id.js b/lib/utils/run-id.js deleted file mode 100644 index b7e7cf797..000000000 --- a/lib/utils/run-id.js +++ /dev/null @@ -1,3 +0,0 @@ -module.exports = (d = new Date()) => { - return d.toISOString().replace(/[.:]/g, '_') -} diff --git a/lib/utils/timers.js b/lib/utils/timers.js index d4f8d8bde..05b7f1813 100644 --- a/lib/utils/timers.js +++ b/lib/utils/timers.js @@ -1,8 +1,6 @@ const EE = require('events') -const { resolve } = require('path') const fs = require('@npmcli/fs') const log = require('./log-shim') -const runId = require('./run-id') // This is an event emiiter but on/off // only listen on a single internal event that gets @@ -10,16 +8,14 @@ const runId = require('./run-id') class Timers extends EE { file = null - #id = null #unfinished = new Map() #finished = {} #onTimeEnd = Symbol('onTimeEnd') #initialListener = null #initialTimer = null - constructor ({ id = runId(), listener = null, start = 'npm' } = {}) { + constructor ({ listener = null, start = 'npm' } = {}) { super() - this.#id = id this.#initialListener = listener this.#initialTimer = start this.#init() @@ -71,9 +67,9 @@ class Timers extends EE { return end } - load ({ dir } = {}) { - if (dir) { - this.file = resolve(dir, `${this.#id}-timing.json`) + load ({ path } = {}) { + if (path) { + this.file = path('timing.json') } } @@ -86,10 +82,7 @@ class Timers extends EE { const globalStart = this.started const globalEnd = this.#finished.npm || Date.now() const content = { - metadata: { - id: this.#id, - ...metadata, - }, + metadata, timers: this.#finished, // add any unfinished timers with their relative start/end unfinishedTimers: [...this.#unfinished.entries()].reduce((acc, [name, start]) => { 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 8e772e869..de21a46d2 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 edb7edaa5..4d52c02d9 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 354081d11..99ad5c0f3 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 7a3918493..912a4365f 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/lib/utils/error-message.js b/test/lib/utils/error-message.js index 3fec501ef..29753c303 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 de4ce61aa..1378d7b75 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,55 @@ 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) => { + console.log(dir) + if (dir.includes('LOGS_DIR') && dir.endsWith('error-file.txt')) { + console.log('throw') + 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 }, diff --git a/test/lib/utils/explain-eresolve.js b/test/lib/utils/explain-eresolve.js index f9710ee88..2c1fed778 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 3c7bb3fe8..41a0bc5a5 100644 --- a/test/lib/utils/log-file.js +++ b/test/lib/utils/log-file.js @@ -6,11 +6,11 @@ const os = require('os') const fsMiniPass = require('fs-minipass') const rimraf = require('rimraf') const LogFile = require('../../../lib/utils/log-file.js') -const runId = require('../../../lib/utils/run-id.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) => { @@ -20,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 = runId(cloneDate) + const dateId = getId(cloneDate) if (oldStyle) { acc[`${dateId}-debug.log`] = 'hello' } else { @@ -42,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: (f = '') => path.join(root, `${id}-${f}`), ...options }) + t.teardown(() => logFile.off()) return { root, diff --git a/test/lib/utils/timers.js b/test/lib/utils/timers.js index 259ecd5dd..eee7aea14 100644 --- a/test/lib/utils/timers.js +++ b/test/lib/utils/timers.js @@ -68,11 +68,11 @@ t.test('finish unstarted timer', async (t) => { }) t.test('writes file', async (t) => { - const { timers } = mockTimers(t, { id: 'TIMING_FILE' }) + const { timers } = mockTimers(t) const dir = t.testdir() process.emit('time', 'foo') process.emit('timeEnd', 'foo') - timers.load({ dir }) + timers.load({ path: (f) => resolve(dir, `TIMING_FILE-${f}`) }) timers.writeFile({ some: 'data' }) const data = JSON.parse(fs.readFileSync(resolve(dir, 'TIMING_FILE-timing.json'))) t.match(data, { @@ -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']]) -- cgit v1.2.3