feat: use proc-log and drop npmlog support (#85)

BREAKING CHANGE: this drops support for passing in a `log` property. All
logs are now emitted on the process object via `proc-log`

Author: lukekarrys

README.md

@@ -337,14 +337,6 @@ to the registry.
 
 See also [`opts.proxy`](#opts-proxy)
 
-##### <a name="opts-log"></a> `opts.log`
-
-* Type: [`npmlog`](https://npm.im/npmlog)-like
-* Default: null
-
-Logger object to use for logging operation details. Must have the same methods
-as `npmlog`.
-
 ##### <a name="opts-mapJSON"></a> `opts.mapJSON`
 
 * Type: Function

lib/check-response.js

@@ -3,23 +3,24 @@
 const errors = require('./errors.js')
 const { Response } = require('minipass-fetch')
 const defaultOpts = require('./default-opts.js')
+const log = require('proc-log')
 
 /* eslint-disable-next-line max-len */
 const moreInfoUrl = 'https://github.com/npm/cli/wiki/No-auth-for-URI,-but-auth-present-for-scoped-registry'
 const checkResponse =
-  async ({ method, uri, res, registry, startTime, auth, opts }) => {
+  async ({ method, uri, res, startTime, auth, opts }) => {
     opts = { ...defaultOpts, ...opts }
     if (res.headers.has('npm-notice') && !res.headers.has('x-local-cache')) {
-      opts.log.notice('', res.headers.get('npm-notice'))
+      log.notice('', res.headers.get('npm-notice'))
     }
 
     if (res.status >= 400) {
-      logRequest(method, res, startTime, opts)
+      logRequest(method, res, startTime)
       if (auth && auth.scopeAuthKey && !auth.token && !auth.auth) {
       // we didn't have auth for THIS request, but we do have auth for
       // requests to the registry indicated by the spec's scope value.
       // Warn the user.
-        opts.log.warn('registry', `No auth for URI, but auth present for scoped registry.
+        log.warn('registry', `No auth for URI, but auth present for scoped registry.
 
 URI: ${uri}
 Scoped Registry Key: ${auth.scopeAuthKey}
@@ -38,7 +39,7 @@ More info here: ${moreInfoUrl}`)
   }
 module.exports = checkResponse
 
-function logRequest (method, res, startTime, opts) {
+function logRequest (method, res, startTime) {
   const elapsedTime = Date.now() - startTime
   const attempt = res.headers.get('x-fetch-attempts')
   const attemptStr = attempt && attempt > 1 ? ` attempt #${attempt}` : ''
@@ -58,7 +59,7 @@ function logRequest (method, res, startTime, opts) {
     urlStr = res.url
   }
 
-  opts.log.http(
+  log.http(
     'fetch',
     `${method.toUpperCase()} ${res.status} ${urlStr} ${elapsedTime}ms${attemptStr}${cacheStr}`
   )

lib/default-opts.js

@@ -1,6 +1,5 @@
 const pkg = require('../package.json')
 module.exports = {
-  log: require('./silentlog.js'),
   maxSockets: 12,
   method: 'GET',
   registry: 'https://registry.npmjs.org/',

package.json

@@ -36,13 +36,13 @@
     "minipass-fetch": "^1.4.1",
     "minipass-json-stream": "^1.0.1",
     "minizlib": "^2.1.2",
-    "npm-package-arg": "^9.0.0"
+    "npm-package-arg": "^9.0.0",
+    "proc-log": "^2.0.0"
   },
   "devDependencies": {
     "@npmcli/template-oss": "^2.7.1",
     "cacache": "^15.3.0",
     "nock": "^13.2.4",
-    "npmlog": "^6.0.1",
     "require-inject": "^1.4.4",
     "ssri": "^8.0.1",
     "tap": "^15.1.6"

test/auth.js

@@ -1,15 +1,12 @@
 'use strict'
 
-const npmlog = require('npmlog')
 const t = require('tap')
 const tnock = require('./util/tnock.js')
 
 const fetch = require('..')
 const getAuth = require('../lib/auth.js')
 
-npmlog.level = process.env.LOGLEVEL || 'silent'
 const OPTS = {
-  log: npmlog,
   timeout: 0,
   retry: {
     retries: 1,

test/cache.js

@@ -2,7 +2,6 @@
 
 const { promisify } = require('util')
 const statAsync = promisify(require('fs').stat)
-const npmlog = require('npmlog')
 const path = require('path')
 const t = require('tap')
 const tnock = require('./util/tnock.js')
@@ -11,10 +10,8 @@ const fetch = require('..')
 
 const testDir = t.testdir({})
 
-npmlog.level = process.env.LOGLEVEL || 'silent'
 const REGISTRY = 'https://mock.reg'
 const OPTS = {
-  log: npmlog,
   memoize: false,
   timeout: 0,
   retry: {

test/check-response.js

@@ -3,7 +3,6 @@ const t = require('tap')
 
 const checkResponse = require('../lib/check-response.js')
 const errors = require('../lib/errors.js')
-const silentLog = require('../lib/silentlog.js')
 const registry = 'registry'
 const startTime = Date.now()
 
@@ -56,27 +55,27 @@ t.test('all checks are ok, nothing to report', t => {
   t.end()
 })
 
-t.test('log x-fetch-attempts header value', t => {
+t.test('log x-fetch-attempts header value', async t => {
   const headers = new Headers()
   headers.get = header => header === 'x-fetch-attempts' ? 3 : undefined
   const res = Object.assign({}, mockFetchRes, {
     headers,
     status: 400,
   })
   t.plan(2)
-  t.rejects(checkResponse({
+  let msg
+  process.on('log', (level, ...args) => {
+    if (level === 'http') {
+      ;[, msg] = args
+    }
+  })
+  await t.rejects(checkResponse({
     method: 'get',
     res,
     registry,
     startTime,
-    opts: {
-      log: Object.assign({}, silentLog, {
-        http (header, msg) {
-          t.ok(msg.endsWith('attempt #3'), 'should log correct number of attempts')
-        },
-      }),
-    },
   }))
+  t.ok(msg.endsWith('attempt #3'), 'should log correct number of attempts')
 })
 
 t.test('log the url fetched', t => {
@@ -90,21 +89,22 @@ t.test('log the url fetched', t => {
     body: new EE(),
   })
   t.plan(2)
+  let header, msg
+  process.on('log', (level, ...args) => {
+    if (level === 'http') {
+      ;[header, msg] = args
+    }
+  })
   checkResponse({
     method: 'get',
     res,
     registry,
     startTime,
-    opts: {
-      log: Object.assign({}, silentLog, {
-        http (header, msg) {
-          t.equal(header, 'fetch')
-          t.match(msg, /^GET 200 http:\/\/example.com\/foo\/bar\/baz [0-9]+m?s/)
-        },
-      }),
-    },
+
   })
   res.body.emit('end')
+  t.equal(header, 'fetch')
+  t.match(msg, /^GET 200 http:\/\/example.com\/foo\/bar\/baz [0-9]+m?s/)
 })
 
 t.test('redact password from log', t => {
@@ -118,34 +118,40 @@ t.test('redact password from log', t => {
     body: new EE(),
   })
   t.plan(2)
+  let header, msg
+  process.on('log', (level, ...args) => {
+    if (level === 'http') {
+      ;[header, msg] = args
+    }
+  })
   checkResponse({
     method: 'get',
     res,
     registry,
     startTime,
-    opts: {
-      log: Object.assign({}, silentLog, {
-        http (header, msg) {
-          t.equal(header, 'fetch')
-          t.match(msg, /^GET 200 http:\/\/username:\*\*\*@example.com\/foo\/bar\/baz [0-9]+m?s/)
-        },
-      }),
-    },
   })
   res.body.emit('end')
+  t.equal(header, 'fetch')
+  t.match(msg, /^GET 200 http:\/\/username:\*\*\*@example.com\/foo\/bar\/baz [0-9]+m?s/)
 })
 
 /* eslint-disable-next-line max-len */
 const moreInfoUrl = 'https://github.com/npm/cli/wiki/No-auth-for-URI,-but-auth-present-for-scoped-registry'
 
-t.test('report auth for registry, but not for this request', t => {
+t.test('report auth for registry, but not for this request', async t => {
   const res = Object.assign({}, mockFetchRes, {
     buffer: () => Promise.resolve(Buffer.from('ok')),
     status: 400,
     url: 'https://example.com/',
   })
   t.plan(3)
-  t.rejects(checkResponse({
+  let header, msg
+  process.on('log', (level, ...args) => {
+    if (level === 'warn') {
+      ;[header, msg] = args
+    }
+  })
+  await t.rejects(checkResponse({
     method: 'get',
     res,
     uri: 'https://example.com/',
@@ -156,20 +162,14 @@ t.test('report auth for registry, but not for this request', t => {
       auth: null,
       token: null,
     },
-    opts: {
-      log: Object.assign({}, silentLog, {
-        warn (header, msg) {
-          t.equal(header, 'registry')
-          t.equal(msg, `No auth for URI, but auth present for scoped registry.
+  }), errors.HttpErrorGeneral)
+  t.equal(header, 'registry')
+  t.equal(msg, `No auth for URI, but auth present for scoped registry.
 
 URI: https://example.com/
 Scoped Registry Key: //some-scope-registry.com/
 
 More info here: ${moreInfoUrl}`)
-        },
-      }),
-    },
-  }), errors.HttpErrorGeneral)
 })
 
 t.test('logs the value of x-local-cache-status when set', t => {
@@ -183,22 +183,22 @@ t.test('logs the value of x-local-cache-status when set', t => {
     body: new EE(),
   })
   t.plan(2)
+  let header, msg
+  process.on('log', (level, ...args) => {
+    if (level === 'http') {
+      ;[header, msg] = args
+    }
+  })
   checkResponse({
     method: 'get',
     res,
     registry,
     startTime,
-    opts: {
-      log: Object.assign({}, silentLog, {
-        http (header, msg) {
-          t.equal(header, 'fetch')
-          t.match(
-            msg,
-            /^GET 200 http:\/\/username:\*\*\*@example.com\/foo\/bar\/baz [0-9]+m?s \(cache hit\)$/
-          )
-        },
-      }),
-    },
   })
   res.body.emit('end')
+  t.equal(header, 'fetch')
+  t.match(
+    msg,
+    /^GET 200 http:\/\/username:\*\*\*@example.com\/foo\/bar\/baz [0-9]+m?s \(cache hit\)$/
+  )
 })

test/errors.js

@@ -1,16 +1,13 @@
 'use strict'
 
 const npa = require('npm-package-arg')
-const npmlog = require('npmlog')
 const t = require('tap')
 const tnock = require('./util/tnock.js')
 const errors = require('../lib/errors.js')
 
 const fetch = require('..')
 
-npmlog.level = process.env.LOGLEVEL || 'silent'
 const OPTS = {
-  log: npmlog,
   timeout: 0,
   retry: {
     retries: 1,

test/index.js

@@ -1,11 +1,9 @@
 'use strict'
 
 const Minipass = require('minipass')
-const npmlog = require('npmlog')
 const ssri = require('ssri')
 const t = require('tap')
 const zlib = require('zlib')
-const silentLog = require('../lib/silentlog.js')
 const defaultOpts = require('../lib/default-opts.js')
 const tnock = require('./util/tnock.js')
 
@@ -17,9 +15,7 @@ defaultOpts.registry = 'https://mock.reg/'
 
 const fetch = require('..')
 
-npmlog.level = process.env.LOGLEVEL || 'silent'
 const OPTS = {
-  log: npmlog,
   timeout: 0,
   retry: {
     retries: 1,
@@ -349,24 +345,25 @@ t.test('method configurable', t => {
     })
 })
 
-t.test('npm-notice header logging', t => {
+t.test('npm-notice header logging', async t => {
   tnock(t, defaultOpts.registry)
     .get('/hello')
     .reply(200, { hello: 'world' }, {
       'npm-notice': 'npm <3 u',
     })
-  const opts = {
-    ...OPTS,
-    log: Object.assign({}, silentLog, {
-      notice (header, msg) {
-        t.equal(header, '', 'empty log header thing')
-        t.equal(msg, 'npm <3 u', 'logged out npm-notice at NOTICE level')
-      },
-    }),
-  }
+
+  let header, msg
+  process.on('log', (level, ...args) => {
+    if (level === 'notice') {
+      ;[header, msg] = args
+    }
+  })
+
   t.plan(3)
-  return fetch('/hello', opts)
-    .then(res => t.equal(res.status, 200, 'got successful response'))
+  const res = await fetch('/hello', { ...OPTS })
+  t.equal(res.status, 200, 'got successful response')
+  t.equal(header, '', 'empty log header thing')
+  t.equal(msg, 'npm <3 u', 'logged out npm-notice at NOTICE level')
 })
 
 t.test('optionally verifies request body integrity', t => {