fix: replace debug with node debug (#2592)

* fix: replace debug module with node builtin debug

* update readme

* use %s instead of %o

* remove comment

* use %s instead of %o

* add test

* fix

README.md

@@ -1643,10 +1643,10 @@ It does this by manipulating the modules cache of Node in a way that conflicts w
 
 ## Debugging
 
-Nock uses [`debug`](https://github.com/visionmedia/debug), so just run with environmental variable `DEBUG` set to `nock.*`.
+Nock uses node internals [`debuglog`](https://nodejs.org/api/util.html#utildebuglogsection-callbackg), so just run with environmental variable `NODE_DEBUG` set to `nock:*`.
 
 ```console
-user@local$ DEBUG=nock.* node my_test.js
+user@local$ NODE_DEBUG=nock:* node my_test.js
 ```
 
 Each step in the matching process is logged this way and can be useful when determining why a request was not intercepted by Nock.
@@ -1660,11 +1660,11 @@ await got('http://example.com/?foo=bar&baz=foz')
 ```
 
 ```console
-user@local$ DEBUG=nock.scope:example.com node my_test.js
+user@local$ DEBUG=nock:scope:example.com node my_test.js
 ...
-nock.scope:example.com Interceptor queries: {"foo":"bar"} +1ms
-nock.scope:example.com     Request queries: {"foo":"bar","baz":"foz"} +0ms
-nock.scope:example.com query matching failed +0ms
+NOCK:SCOPE:EXAMPLE.COM 103514: Interceptor queries: {"foo":"bar"}
+NOCK:SCOPE:EXAMPLE.COM 103514:     Request queries: {"foo":"bar","baz":"foz"}
+NOCK:SCOPE:EXAMPLE.COM 103514: query matching failed
 ```
 
 ## Contributing

lib/back.js

@@ -9,10 +9,9 @@ const {
   removeAll: cleanAll,
 } = require('./intercept')
 const { loadDefs, define } = require('./scope')
-
+const { back: debug } = require('./debug')
 const { format } = require('util')
 const path = require('path')
-const debug = require('debug')('nock.back')
 
 let _mode = null
 

lib/common.js

@@ -1,6 +1,6 @@
 'use strict'
 
-const debug = require('debug')('nock.common')
+const { common: debug } = require('./debug')
 const timers = require('timers')
 const url = require('url')
 const util = require('util')

lib/debug.js

@@ -0,0 +1,12 @@
+'use strict'
+
+const { debuglog } = require('util')
+
+module.exports.back = debuglog('nock:back')
+module.exports.common = debuglog('nock:common')
+module.exports.intercept = debuglog('nock:intercept')
+module.exports.request_overrider = debuglog('nock:request_overrider')
+module.exports.playback_interceptor = debuglog('nock:playback_interceptor')
+module.exports.recorder = debuglog('nock:recorder')
+module.exports.socket = debuglog('nock:socket')
+module.exports.scopeDebuglog = namespace => debuglog(`nock:scope:${namespace}`)

lib/intercept.js

@@ -8,7 +8,7 @@ const { InterceptedRequestRouter } = require('./intercepted_request_router')
 const common = require('./common')
 const { inherits } = require('util')
 const http = require('http')
-const debug = require('debug')('nock.intercept')
+const { intercept: debug } = require('./debug')
 const globalEmitter = require('./global_emitter')
 const { createResponse } = require('./create_response')
 

lib/intercepted_request_router.js

@@ -1,6 +1,6 @@
 'use strict'
 
-const debug = require('debug')('nock.request_overrider')
+const { request_overrider: debug } = require('./debug')
 const {
   IncomingMessage,
   ClientRequest,

lib/interceptor.js

@@ -242,14 +242,7 @@ module.exports = class Interceptor {
   }
 
   match(req, options, body) {
-    // check if the logger is enabled because the stringifies can be expensive.
-    if (this.scope.logger.enabled) {
-      this.scope.logger(
-        'attempting match %s, body = %s',
-        stringify(options),
-        stringify(body),
-      )
-    }
+    this.scope.logger('attempting match %j, body = %j', options, body)
 
     const method = (options.method || 'GET').toUpperCase()
     let { path = '/' } = options

lib/playback_interceptor.js

@@ -3,7 +3,7 @@
 const stream = require('stream')
 const util = require('util')
 const zlib = require('zlib')
-const debug = require('debug')('nock.playback_interceptor')
+const { playback_interceptor: debug } = require('./debug')
 const common = require('./common')
 
 function parseJSONRequestBody(req, requestBody) {

lib/recorder.js

@@ -1,6 +1,6 @@
 'use strict'
 
-const debug = require('debug')('nock.recorder')
+const { recorder: debug } = require('./debug')
 const querystring = require('querystring')
 const { inspect } = require('util')
 

lib/scope.js

@@ -3,11 +3,11 @@
 /**
  * @module nock/scope
  */
+const { scopeDebuglog } = require('./debug')
 const { addInterceptor, isOn } = require('./intercept')
 const common = require('./common')
 const assert = require('assert')
 const url = require('url')
-const debug = require('debug')('nock.scope')
 const { EventEmitter } = require('events')
 const Interceptor = require('./interceptor')
 
@@ -99,7 +99,7 @@ class Scope extends EventEmitter {
       logNamespace = this.urlParts.host
     }
 
-    this.logger = debug.extend(logNamespace)
+    this.logger = scopeDebuglog(logNamespace)
   }
 
   add(key, interceptor) {

lib/socket.js

@@ -1,7 +1,7 @@
 'use strict'
 
 const { EventEmitter } = require('events')
-const debug = require('debug')('nock.socket')
+const { socket: debug } = require('./debug')
 
 module.exports = class Socket extends EventEmitter {
   constructor(options) {

package.json

@@ -22,7 +22,6 @@
   "main": "./index.js",
   "types": "types",
   "dependencies": {
-    "debug": "^4.1.0",
     "json-stringify-safe": "^5.0.1",
     "propagate": "^2.0.0"
   },

tests/got/fixtures/logging.mjs

@@ -0,0 +1,7 @@
+import nock from '../../../index.js'
+import got from 'got'
+
+nock('http://example.test').post('/deep/link').reply(200, 'Hello World!')
+
+const exampleBody = 'Hello yourself!'
+await got.post('http://example.test/deep/link', { body: exampleBody })

tests/got/test_logging.js

@@ -1,55 +1,96 @@
 'use strict'
 
-const debug = require('debug')
-const sinon = require('sinon')
+const { join } = require('node:path')
+const { spawn } = require('node:child_process')
 const { expect } = require('chai')
-const nock = require('../..')
-const got = require('./got_client')
 
 describe('Logging using the `debug` package', () => {
-  let logFn
-  beforeEach(() => {
-    logFn = sinon.stub(debug, 'log')
-    debug.enable('nock*')
-  })
-
-  afterEach(() => {
-    debug.disable('nock*')
-  })
-
   it('match debugging works', async () => {
-    nock('http://example.test').post('/deep/link').reply(200, 'Hello World!')
-
-    const exampleBody = 'Hello yourself!'
-    await got.post('http://example.test/deep/link', { body: exampleBody })
-
     // the log function will have been a few dozen times, there are a few specific to matching we want to validate:
 
-    // the log when an interceptor is chosen
-    expect(logFn).to.have.been.calledWith(
-      sinon.match('matched base path (1 interceptor)'),
-    )
+    let resolveTest
+    let rejectTest
+    const p = new Promise((resolve, reject) => {
+      resolveTest = resolve
+      rejectTest = reject
+    })
+    const assertions = [
+      /NOCK:BACK \d+: New nock back mode: dryrun/,
+      /NOCK:RECORDER \d+: 0 restoring all the overridden http\/https properties/,
+      /NOCK:COMMON \d+: restoring requests/,
+      /NOCK:INTERCEPT \d+: restoring overridden ClientRequest/,
+      /NOCK:INTERCEPT \d+: - ClientRequest was not overridden/,
+      /NOCK:COMMON \d+: overriding requests/,
+      /NOCK:COMMON \d+: - overriding request for http/,
+      /NOCK:COMMON \d+: - overridden request for http/,
+      /NOCK:COMMON \d+: - overriding request for https/,
+      /NOCK:COMMON \d+: - overridden request for https/,
+      /NOCK:INTERCEPT \d+: Overriding ClientRequest/,
+      /NOCK:INTERCEPT \d+: ClientRequest overridden/,
+      /NOCK:SCOPE:EXAMPLE.TEST \d+: reply.headers: {}/,
+      /NOCK:SCOPE:EXAMPLE.TEST \d+: reply.rawHeaders: \[\]/,
+      /NOCK:COMMON \d+: options.hostname in the end: "example.test"/,
+      /NOCK:COMMON \d+: options.host in the end: "example.test:80"/,
+      /NOCK:INTERCEPT \d+: interceptors for "example.test:80"/,
+      /NOCK:INTERCEPT \d+: filtering interceptors for basepath http:\/\/example.test:80/,
+      /NOCK:INTERCEPT \d+: matched base path \(1 interceptor\)/,
+      /NOCK:COMMON \d+: options.host: example.test:80/,
+      /NOCK:COMMON \d+: options.hostname in the end: "example.test"/,
+      /NOCK:COMMON \d+: options.host in the end: "example.test:80"/,
+      /NOCK:INTERCEPT \d+: interceptors for "example.test:80"/,
+      /NOCK:INTERCEPT \d+: filtering interceptors for basepath http:\/\/example.test:80/,
+      /NOCK:INTERCEPT \d+: matched base path \(1 interceptor\)/,
+      /NOCK:INTERCEPT \d+: using 1 interceptors/,
+      /NOCK:REQUEST_OVERRIDER \d+: request write/,
+      /NOCK:REQUEST_OVERRIDER \d+: request end/,
+      /NOCK:REQUEST_OVERRIDER \d+: ending/,
+      /NOCK:SCOPE:EXAMPLE.TEST \d+: attempting match {"protocol":"http:","hostname":"example.test","hash":"","search":"","pathname":"\/deep\/link","path":"\/deep\/link","href":"http:\/\/example.test\/deep\/link","method":"POST","retry":{"limit":2,"methods":\["GET","PUT","HEAD","DELETE","OPTIONS","TRACE"\],"statusCodes":\[408,413,429,500,502,503,504,521,522,524\],"errorCodes":\["ETIMEDOUT","ECONNRESET","EADDRINUSE","ECONNREFUSED","EPIPE","ENOTFOUND","ENETUNREACH","EAI_AGAIN"\],"maxRetryAfter":null},"headers":{"user-agent":"got \(https:\/\/github.com\/sindresorhus\/got\)","content-length":"15","accept-encoding":"gzip, deflate, br"},"hooks":{"init":\[\],"beforeRequest":\[\],"beforeRedirect":\[\],"beforeRetry":\[\],"beforeError":\[\],"afterResponse":\[\]},"decompress":true,"throwHttpErrors":true,"followRedirect":true,"isStream":false,"responseType":"text","resolveBodyOnly":false,"maxRedirects":10,"prefixUrl":"","methodRewriting":true,"ignoreInvalidCookies":false,"http2":false,"allowGetBody":false,"pagination":{"countLimit":null,"backoff":0,"requestLimit":10000,"stackAllItems":true},"cacheOptions":{},"url":"http:\/\/example.test\/deep\/link","username":"","password":"","proto":"http","port":80,"host":"example.test:80"}, body = "Hello yourself!"/,
+      /NOCK:SCOPE:EXAMPLE.TEST \d+: query matching skipped/,
+      /NOCK:SCOPE:EXAMPLE.TEST \d+: matching http:\/\/example.test:80\/deep\/link to POST http:\/\/example.test:80\/deep\/link: true/,
+      /NOCK:SCOPE:EXAMPLE.TEST \d+: interceptor identified, starting mocking/,
+      /NOCK:SCOPE:EXAMPLE.TEST \d+: response.rawHeaders: \[\]/,
+      /NOCK:SCOPE:EXAMPLE.TEST \d+: emitting response/,
+      /^$/,
+    ]
 
-    // the log of the Interceptor match
-    expect(logFn).to.have.been.calledWith(
-      // debug namespace for the scope that includes the host
-      sinon.match('nock.scope:example.test'),
-      // This is a JSON blob which contains, among other things the complete
-      // request URL.
-      sinon.match('"href":"http://example.test/deep/link"'),
-      // This is the JSON-stringified body.
-      `"${exampleBody}"`,
-    )
-
-    expect(logFn).to.have.been.calledWith(sinon.match('query matching skipped'))
-
-    expect(logFn).to.have.been.calledWith(
-      sinon.match(
-        'matching http://example.test:80/deep/link to POST http://example.test:80/deep/link: true',
-      ),
-    )
-    expect(logFn).to.have.been.calledWith(
-      sinon.match('interceptor identified, starting mocking'),
+    const child = spawn(
+      process.execPath,
+      [join(__dirname, './fixtures/logging.mjs')],
+      {
+        env: {
+          NODE_DEBUG: 'nock:*',
+        },
+      },
     )
+    const chunks = []
+    child.stderr.setEncoding('utf8')
+    child.stderr.on('data', chunk => {
+      chunks.push(chunk)
+    })
+    child.stderr.on('end', () => {
+      const lines = extractLines(chunks)
+      try {
+        expect(lines.length).to.be.equal(assertions.length)
+        for (let i = 1; i < lines.length; i++) {
+          expect(lines[i], `${i}: ${lines[i]}`).to.match(assertions[i])
+        }
+      } catch (e) {
+        rejectTest(e)
+        return
+      }
+      resolveTest()
+    })
+    await p
   })
 })
+
+const removeEscapeColorsRE =
+  // eslint-disable-next-line no-control-regex
+  /[\u001b\u009b][[()#;?]*(?:[0-9]{1,4}(?:;[0-9]{0,4})*)?[0-9A-ORZcf-nqry=><]/g
+
+function extractLines(chunks) {
+  return chunks
+    .join('')
+    .split('\n')
+    .map(v => v.replace(removeEscapeColorsRE, ''))
+}