fix: dont expose as many public properties of timers

Author: lukekarrys

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

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')

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}`)
         }
       }
     }

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)
     },
   }

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())
   })
 

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,40 +14,20 @@ 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)
   })
   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)
 })