From 694dba9fd9a8d71facc7b832bf8f00ca9468e68a Mon Sep 17 00:00:00 2001 From: Luke Karrys Date: Mon, 22 Apr 2024 17:02:29 -0700 Subject: [PATCH] fix: dont expose as many public properties of timers --- lib/cli/exit-handler.js | 2 +- lib/npm.js | 7 +++-- lib/utils/timers.js | 61 ++++++++++++++++++++------------------- test/fixtures/mock-npm.js | 2 +- test/lib/npm.js | 41 ++------------------------ test/lib/utils/timers.js | 45 ++++++++--------------------- 6 files changed, 53 insertions(+), 105 deletions(-) diff --git a/lib/cli/exit-handler.js b/lib/cli/exit-handler.js index 8d1d5a3e0ef34..7d81e79356748 100644 --- a/lib/cli/exit-handler.js +++ b/lib/cli/exit-handler.js @@ -45,7 +45,7 @@ process.on('exit', code => { // write the timing file now, this might do nothing based on the configs set. // we need to call it here in case it errors so we dont tell the user // about a timing file that doesn't exist - npm.writeTimingFile() + npm.finish() const logsDir = npm.logsDir const logFiles = npm.logFiles diff --git a/lib/npm.js b/lib/npm.js index e0f3f40a72874..1deae661bc100 100644 --- a/lib/npm.js +++ b/lib/npm.js @@ -38,7 +38,7 @@ class Npm { #display = null #logFile = new LogFile() - #timers = new Timers({ start: 'npm' }) + #timers = new Timers() // all these options are only used by tests in order to make testing more // closely resemble real world usage. for now, npm has no programmatic API so @@ -117,8 +117,8 @@ class Npm { this.#logFile.off() } - writeTimingFile () { - this.#timers.writeFile({ + finish () { + this.#timers.finish({ id: this.#runId, command: this.#argvClean, logfiles: this.logFiles, @@ -209,6 +209,7 @@ class Npm { this.#timers.load({ path: this.config.get('timing') ? this.logPath : null, + timing: this.config.get('timing'), }) const configScope = this.config.get('scope') diff --git a/lib/utils/timers.js b/lib/utils/timers.js index b27ddd588db06..16a255961fee3 100644 --- a/lib/utils/timers.js +++ b/lib/utils/timers.js @@ -5,7 +5,8 @@ const { log, time } = require('proc-log') const INITIAL_TIMER = 'npm' class Timers extends EE { - file = null + #file + #timing #unfinished = new Map() #finished = {} @@ -17,14 +18,6 @@ class Timers extends EE { this.started = this.#unfinished.get(INITIAL_TIMER) } - get unfinished () { - return this.#unfinished - } - - get finished () { - return this.#finished - } - on () { process.on('time', this.#timeHandler) } @@ -33,36 +26,46 @@ class Timers extends EE { process.off('time', this.#timeHandler) } - load ({ path } = {}) { - if (path) { - this.file = `${path}timing.json` - } + load ({ path, timing } = {}) { + this.#timing = timing + this.#file = `${path}timing.json` } - writeFile (metadata) { - if (!this.file) { + finish (metadata) { + time.end(INITIAL_TIMER) + + for (const [name, timer] of this.#unfinished) { + log.silly('unfinished npm timer', name, timer) + } + + if (!this.#timing) { + // Not in timing mode, nothing else to do here return } try { - const globalStart = this.started - const globalEnd = this.#finished[INITIAL_TIMER] || Date.now() - const content = { - metadata, - timers: this.#finished, - // add any unfinished timers with their relative start/end - unfinishedTimers: [...this.#unfinished.entries()].reduce((acc, [name, start]) => { - acc[name] = [start - globalStart, globalEnd - globalStart] - return acc - }, {}), - } - fs.writeFileSync(this.file, JSON.stringify(content) + '\n') + this.#writeFile(metadata) + log.info('timing', `Timing info written to: ${this.#file}`) } catch (e) { - this.file = null log.warn('timing', `could not write timing file: ${e}`) } } + #writeFile (metadata) { + const globalStart = this.started + const globalEnd = this.#finished[INITIAL_TIMER] + const content = { + metadata, + timers: this.#finished, + // add any unfinished timers with their relative start/end + unfinishedTimers: [...this.#unfinished.entries()].reduce((acc, [name, start]) => { + acc[name] = [start - globalStart, globalEnd - globalStart] + return acc + }, {}), + } + fs.writeFileSync(this.#file, JSON.stringify(content) + '\n') + } + #timeHandler = (level, name) => { const now = Date.now() switch (level) { @@ -76,7 +79,7 @@ class Timers extends EE { this.#unfinished.delete(name) log.timing(name, `Completed in ${ms}ms`) } else { - log.silly('timing', "Tried to end timer that doesn't exist:", name) + log.silly('timing', `Tried to end timer that doesn't exist: ${name}`) } } } diff --git a/test/fixtures/mock-npm.js b/test/fixtures/mock-npm.js index d1879da7f845e..4a58b869858fd 100644 --- a/test/fixtures/mock-npm.js +++ b/test/fixtures/mock-npm.js @@ -295,7 +295,7 @@ const setupMockNpm = async (t, { .join('\n') }, timingFile: async () => { - const data = await fs.readFile(npm.timingFile, 'utf8') + const data = await fs.readFile(npm.logPath + 'timing.json', 'utf8') return JSON.parse(data) }, } diff --git a/test/lib/npm.js b/test/lib/npm.js index 915e63d0060bc..63ac48958cf44 100644 --- a/test/lib/npm.js +++ b/test/lib/npm.js @@ -380,48 +380,14 @@ t.test('cache dir', async t => { }) t.test('timings', async t => { - t.test('gets/sets timers', async t => { - const { npm, logs } = await loadMockNpm(t, { - config: { - timing: true, - }, - }) - time.start('foo') - time.start('bar') - t.match(npm.unfinishedTimers.get('foo'), Number, 'foo timer is a number') - t.match(npm.unfinishedTimers.get('bar'), Number, 'foo timer is a number') - time.end('foo') - time.end('bar') - time.end('baz') - // npm timer is started by default - time.end('npm') - t.match(logs.timing.byTitle('foo'), [ - /Completed in [0-9]+ms/, - ]) - t.match(logs.timing.byTitle('bar'), [ - /Completed in [0-9]+ms/, - ]) - t.match(logs.timing.byTitle('npm'), [ - /Completed in [0-9]+ms/, - ]) - t.match(logs.silly.byTitle('timing'), [ - `timing Tried to end timer that doesn't exist: baz`, - ]) - t.notOk(npm.unfinishedTimers.has('foo'), 'foo timer is gone') - t.notOk(npm.unfinishedTimers.has('bar'), 'bar timer is gone') - t.match(npm.finishedTimers, { foo: Number, bar: Number, npm: Number }) - }) - t.test('writes timings file', async t => { - const { npm, cache, timingFile } = await loadMockNpm(t, { + const { npm, timingFile } = await loadMockNpm(t, { config: { timing: true }, }) time.start('foo') time.end('foo') time.start('bar') - npm.writeTimingFile() - t.match(npm.timingFile, cache) - t.match(npm.timingFile, /-timing.json$/) + npm.finish() const timings = await timingFile() t.match(timings, { metadata: { @@ -431,7 +397,6 @@ t.test('timings', async t => { }, unfinishedTimers: { bar: [Number, Number], - npm: [Number, Number], }, timers: { foo: Number, @@ -444,7 +409,7 @@ t.test('timings', async t => { const { npm, timingFile } = await loadMockNpm(t, { config: { timing: false }, }) - npm.writeTimingFile() + npm.finish() await t.rejects(() => timingFile()) }) diff --git a/test/lib/utils/timers.js b/test/lib/utils/timers.js index 1901738feb975..4e5bfb104db97 100644 --- a/test/lib/utils/timers.js +++ b/test/lib/utils/timers.js @@ -4,7 +4,7 @@ const fs = require('graceful-fs') const { log, time } = require('proc-log') const tmock = require('../../fixtures/tmock') -const mockTimers = (t, options) => { +const mockTimers = (t) => { const logs = log.LEVELS.reduce((acc, l) => { acc[l] = [] return acc @@ -14,7 +14,7 @@ const mockTimers = (t, options) => { } process.on('log', logHandler) const Timers = tmock(t, '{LIB}/utils/timers') - const timers = new Timers(options) + const timers = new Timers() t.teardown(() => { timers.off() process.off('log', logHandler) @@ -22,32 +22,12 @@ const mockTimers = (t, options) => { return { timers, logs } } -t.test('listens/stops on process', async (t) => { - const { timers } = mockTimers(t) - time.start('foo') - time.start('bar') - time.end('bar') - t.match(timers.unfinished, new Map([['foo', Number]])) - t.match(timers.finished, { bar: Number }) - timers.off() - time.start('baz') - t.notOk(timers.unfinished.get('baz')) -}) - -t.test('initial timer is named npm', async (t) => { - const { timers } = mockTimers(t) - time.end('npm') - t.match(timers.finished, { npm: Number }) -}) - t.test('logs timing events', async (t) => { - const events = [] - const listener = (...args) => events.push(args) - const { timers, logs } = mockTimers(t, { listener }) + const { timers, logs } = mockTimers(t) time.start('foo') time.start('bar') time.end('bar') - timers.off(listener) + timers.off() time.end('foo') t.equal(logs.timing.length, 1) t.match(logs.timing[0], /^bar Completed in [0-9]ms/) @@ -64,14 +44,15 @@ t.test('writes file', async (t) => { const dir = t.testdir() time.start('foo') time.end('foo') - timers.load({ path: resolve(dir, `TIMING_FILE-`) }) - timers.writeFile({ some: 'data' }) + time.start('ohno') + timers.load({ timing: true, path: resolve(dir, `TIMING_FILE-`) }) + timers.finish({ some: 'data' }) const data = JSON.parse(fs.readFileSync(resolve(dir, 'TIMING_FILE-timing.json'))) t.match(data, { metadata: { some: 'data' }, - timers: { foo: Number }, + timers: { foo: Number, npm: Number }, unfinishedTimers: { - npm: [Number, Number], + ohno: [Number, Number], }, }) }) @@ -80,20 +61,18 @@ t.test('fails to write file', async (t) => { const { logs, timers } = mockTimers(t) const dir = t.testdir() - timers.load({ path: join(dir, 'does', 'not', 'exist') }) - timers.writeFile() + timers.load({ timing: true, path: join(dir, 'does', 'not', 'exist') }) + timers.finish() t.match(logs.warn, ['timing could not write timing file:']) - t.equal(timers.file, null) }) t.test('no dir and no file', async (t) => { const { logs, timers } = mockTimers(t) timers.load() - timers.writeFile() + timers.finish() t.strictSame(logs.warn, []) t.strictSame(logs.silly, []) - t.equal(timers.file, null) })