fix: use proc-log META for flush and force

Author: lukekarrys

lib/cli/exit-handler.js

@@ -1,4 +1,4 @@
-const { log, output, time } = require('proc-log')
+const { log, output, time, META } = require('proc-log')
 const errorMessage = require('../utils/error-message.js')
 const { redactLog: replaceInfo } = require('@npmcli/redact')
 
@@ -32,9 +32,10 @@ process.on('exit', code => {
     log.error('', 'This is an error with npm itself. Please report this error at:')
     log.error('', '    <https://github.com/npm/cli/issues>')
 
-    // This gets logged regardless of silent mode
-    // eslint-disable-next-line no-console
-    console.error('')
+    if (!npm || !npm.silent) {
+      // eslint-disable-next-line no-console
+      console.error('')
+    }
 
     showLogFileError = true
   }
@@ -120,8 +121,7 @@ const exitHandler = err => {
 
   // only show the notification if it finished.
   if (typeof npm.updateNotification === 'string') {
-    // TODO: use proc-log to send `force: true` along with event
-    npm.forceLog('notice', '', npm.updateNotification)
+    log.notice('', npm.updateNotification, { [META]: true, force: true })
   }
 
   let exitCode = process.exitCode || 0
@@ -200,8 +200,7 @@ const exitHandler = err => {
   }
 
   if (hasLoadedNpm) {
-    // TODO: use proc-log.output.flush() once it exists
-    npm.flushOutput(jsonError)
+    output.flush({ [META]: true, jsonError })
   }
 
   log.verbose('exit', exitCode || 0)

lib/npm.js

@@ -379,16 +379,6 @@ class Npm {
   get usage () {
     return usage(this)
   }
-
-  // TODO: move to proc-log and remove
-  forceLog (...args) {
-    this.#display.forceLog(...args)
-  }
-
-  // TODO: move to proc-log and remove
-  flushOutput (jsonError) {
-    this.#display.flushOutput(jsonError)
-  }
 }
 
 module.exports = Npm

lib/utils/display.js

@@ -1,5 +1,5 @@
 const proggy = require('proggy')
-const { log, output } = require('proc-log')
+const { log, output, META } = require('proc-log')
 const { explain } = require('./explain-eresolve.js')
 const { formatWithOptions } = require('./format')
 
@@ -32,17 +32,6 @@ const COLOR_PALETTE = ({ chalk: c }) => ({
   silly: c.blue.dim,
 })
 
-const LOG_LEVELS = log.LEVELS.reduce((acc, key) => {
-  acc[key] = key
-  return acc
-}, {})
-
-// TODO: move flush to proc-log
-const OUTPUT_LEVELS = ['flush', ...output.LEVELS].reduce((acc, key) => {
-  acc[key] = key
-  return acc
-}, {})
-
 const LEVEL_OPTIONS = {
   silent: {
     index: 0,
@@ -76,7 +65,7 @@ const LEVEL_OPTIONS = {
 
 const LEVEL_METHODS = {
   ...LEVEL_OPTIONS,
-  [LOG_LEVELS.timing]: {
+  [log.KEYS.timing]: {
     show: ({ timing, index }) => !!timing && index !== 0,
   },
 }
@@ -102,11 +91,13 @@ const setBlocking = (stream) => {
   return stream
 }
 
-const getLevel = (stringOrLevelObject) => {
-  if (typeof stringOrLevelObject === 'string') {
-    return { level: stringOrLevelObject }
+const withMeta = (handler) => (level, ...args) => {
+  let meta = {}
+  const last = args.at(-1)
+  if (last && typeof last === 'object' && Object.hasOwn(last, META)) {
+    meta = args.pop()
   }
-  return stringOrLevelObject
+  return handler(level, meta, ...args)
 }
 
 class Display {
@@ -136,6 +127,7 @@ class Display {
   #timing
   #json
   #heading
+  #silent
 
   // display streams
   #stdout
@@ -205,19 +197,11 @@ class Display {
     this.#timing = timing
     this.#json = json
     this.#heading = heading
-
-    // In silent mode we remove all the handlers
-    if (this.#levelIndex <= 0) {
-      this.off()
-      return
-    }
+    this.#silent = this.#levelIndex <= 0
 
     // Emit resume event on the logs which will flush output
     log.resume()
-
-    // TODO: this should be a proc-log method `proc-log.output.flush`?
-    this.#outputHandler(OUTPUT_LEVELS.flush)
-
+    output.flush()
     this.#startProgress({ progress, unicode })
   }
 
@@ -236,107 +220,98 @@ class Display {
 
   // Arrow function assigned to a private class field so it can be passed
   // directly as a listener and still reference "this"
-  #logHandler = (...args) => {
-    if (args[0] === LOG_LEVELS.resume) {
+  #logHandler = withMeta((level, meta, ...args) => {
+    if (level === log.KEYS.resume) {
       this.#logState.buffering = false
       this.#logState.buffer.forEach((item) => this.#tryWriteLog(...item))
       this.#logState.buffer.length = 0
       return
     }
 
-    if (args[0] === LOG_LEVELS.pause) {
+    if (level === log.KEYS.pause) {
       this.#logState.buffering = true
       return
     }
 
     if (this.#logState.buffering) {
-      this.#logState.buffer.push(args)
+      this.#logState.buffer.push([level, meta, ...args])
       return
     }
 
-    this.#tryWriteLog(...args)
-  }
+    this.#tryWriteLog(level, meta, ...args)
+  })
 
   // Arrow function assigned to a private class field so it can be passed
   // directly as a listener and still reference "this"
-  #outputHandler = (...args) => {
-    if (args[0] === OUTPUT_LEVELS.flush) {
+  #outputHandler = withMeta((level, meta, ...args) => {
+    if (level === output.KEYS.flush) {
       this.#outputState.buffering = false
-      if (args[1] && this.#json) {
+
+      if (meta.jsonError && this.#json) {
         const json = {}
-        for (const [, item] of this.#outputState.buffer) {
-          Object.assign(json, tryJsonParse(item))
+        for (const item of this.#outputState.buffer) {
+          // index 2 skips the level and meta
+          Object.assign(json, tryJsonParse(item[2]))
         }
-        this.#writeOutput('standard', JSON.stringify({ ...json, ...args[1] }, null, 2))
+        this.#writeOutput(
+          output.KEYS.standard,
+          meta,
+          JSON.stringify({ ...json, error: meta.jsonError }, null, 2)
+        )
       } else {
         this.#outputState.buffer.forEach((item) => this.#writeOutput(...item))
       }
+
       this.#outputState.buffer.length = 0
       return
     }
 
-    if (args[0] === OUTPUT_LEVELS.buffer) {
-      this.#outputState.buffer.push(['standard', ...args.slice(1)])
+    if (level === output.KEYS.buffer) {
+      this.#outputState.buffer.push([output.KEYS.standard, meta, ...args])
       return
     }
 
     if (this.#outputState.buffering) {
-      this.#outputState.buffer.push(args)
+      this.#outputState.buffer.push([level, meta, ...args])
       return
     }
 
-    this.#writeOutput(...args)
-  }
+    this.#writeOutput(level, meta, ...args)
+  })
 
   // OUTPUT
 
-  #writeOutput (...args) {
-    const { level } = getLevel(args.shift())
-
-    if (level === OUTPUT_LEVELS.standard) {
+  #writeOutput (level, meta, ...args) {
+    if (level === output.KEYS.standard) {
       this.#stdoutWrite({}, ...args)
       return
     }
 
-    if (level === OUTPUT_LEVELS.error) {
+    if (level === output.KEYS.error) {
       this.#stderrWrite({}, ...args)
     }
   }
 
-  // TODO: move this to proc-log and remove this public method
-  flushOutput (jsonError) {
-    this.#outputHandler(OUTPUT_LEVELS.flush, jsonError)
-  }
-
   // LOGS
 
-  // TODO: make proc-log able to send signal data like `force`
-  // when that happens, remove this public method
-  forceLog (level, ...args) {
-    // This will show the log regardless of the current loglevel except when silent
-    if (this.#levelIndex !== 0) {
-      this.#logHandler({ level, force: true }, ...args)
-    }
-  }
-
-  #tryWriteLog (...args) {
+  #tryWriteLog (level, meta, ...args) {
     try {
       // Also (and this is a really inexcusable kludge), we patch the
       // 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.
       // TODO: this could probably be moved to arborist now that display is refactored
-      const [level, heading, message, expl] = args
-      if (level === LOG_LEVELS.warn && heading === 'ERESOLVE' && expl && typeof expl === 'object') {
-        this.#writeLog(level, heading, message)
-        this.#writeLog(level, '', explain(expl, this.#stderrChalk, 2))
+      const [heading, message, expl] = args
+      if (level === log.KEYS.warn && heading === 'ERESOLVE' && expl && typeof expl === 'object') {
+        this.#writeLog(level, meta, heading, message)
+        this.#writeLog(level, meta, '', explain(expl, this.#stderrChalk, 2))
         return
       }
-      this.#writeLog(...args)
+      this.#writeLog(level, meta, ...args)
     } catch (ex) {
       try {
         // if it crashed once, it might again!
-        this.#writeLog(LOG_LEVELS.verbose, null, `attempt to log crashed`, ...args, ex)
+        this.#writeLog(log.KEYS.verbose, meta, '', `attempt to log crashed`, ...args, ex)
       } catch (ex2) {
         // This happens if the object has an inspect method that crashes so just console.error
         // with the errors but don't do anything else that might error again.
@@ -346,11 +321,10 @@ class Display {
     }
   }
 
-  #writeLog (...args) {
-    const { level, force = false } = getLevel(args.shift())
-
+  #writeLog (level, meta, ...args) {
     const levelOpts = LEVEL_METHODS[level]
     const show = levelOpts.show ?? (({ index }) => levelOpts.index <= index)
+    const force = meta.force && !this.#silent
 
     if (force || show({ index: this.#levelIndex, timing: this.#timing })) {
       // this mutates the array so we can pass args directly to format later
@@ -369,7 +343,7 @@ class Display {
   // PROGRESS
 
   #startProgress ({ progress, unicode }) {
-    if (!progress) {
+    if (!progress || this.#silent) {
       return
     }
     this.#progress = proggy.createClient({ normalize: true })

lib/utils/error-message.js

@@ -8,11 +8,9 @@ const messageText = msg => msg.map(line => line.slice(1).join(' ')).join('\n')
 const jsonError = (er, npm, { summary, detail }) => {
   if (npm?.config.loaded && npm.config.get('json')) {
     return {
-      error: {
-        code: er.code,
-        summary: messageText(summary),
-        detail: messageText(detail),
-      },
+      code: er.code,
+      summary: messageText(summary),
+      detail: messageText(detail),
     }
   }
 }

test/fixtures/mock-npm.js

@@ -2,6 +2,7 @@ const os = require('os')
 const fs = require('fs').promises
 const path = require('path')
 const tap = require('tap')
+const { output, META } = require('proc-log')
 const errorMessage = require('../../lib/utils/error-message')
 const mockLogs = require('./mock-logs.js')
 const mockGlobals = require('@npmcli/mock-globals')
@@ -79,7 +80,8 @@ const getMockNpm = async (t, { mocks, init, load, npm: npmOpts }) => {
       // error message fn. This is necessary for commands with buffered output
       // to read the output after exec is called. This is not *exactly* how it
       // works in practice, but it is close enough for now.
-      this.flushOutput(err ? errorMessage(err, this).json : null)
+      const jsonError = err && errorMessage(err, this).json
+      output.flush({ [META]: true, jsonError })
       if (err) {
         throw err
       }

test/lib/cli/exit-handler.js

@@ -78,11 +78,9 @@ const mockExitHandler = async (t, { config, mocks, files, ...opts } = {}) => {
       detail: [['ERR DETAIL', err.message]],
       ...(files ? { files } : {}),
       json: {
-        error: {
-          code: err.code,
-          summary: err.message,
-          detail: err.message,
-        },
+        code: err.code,
+        summary: err.message,
+        detail: err.message,
       },
     }),
     ...mocks,