feat(#2191): Add support for NODE_DEBUG

docs/api/Debug.md

@@ -0,0 +1,62 @@
+# Debug
+
+Undici (and subsenquently `fetch` and `websocket`) exposes a debug statement that can be enabled by setting `NODE_DEBUG` within the environment.
+
+The flags availabile are:
+
+## `undici`
+
+This flag enables debug statements for the core undici library.
+
+```sh
+NODE_DEBUG=undici node script.js
+
+UNDICI 16241: connecting to nodejs.org using https:h1
+UNDICI 16241: connecting to nodejs.org using https:h1
+UNDICI 16241: connected to nodejs.org using https:h1
+UNDICI 16241: sending request to GET https://nodejs.org//
+UNDICI 16241: received response to GET https://nodejs.org// - HTTP 307
+UNDICI 16241: connecting to nodejs.org using https:h1
+UNDICI 16241: trailers received from GET https://nodejs.org//
+UNDICI 16241: connected to nodejs.org using https:h1
+UNDICI 16241: sending request to GET https://nodejs.org//en
+UNDICI 16241: received response to GET https://nodejs.org//en - HTTP 200
+UNDICI 16241: trailers received from GET https://nodejs.org//en
+```
+
+## `fetch`
+
+This flag enables debug statements for the `fetch` API.
+
+> **Note**: statements are pretty similar to the ones in the `undici` flag, but scoped to `fetch`
+
+```sh
+NODE_DEBUG=fetch node script.js
+
+FETCH 16241: connecting to nodejs.org using https:h1
+FETCH 16241: connecting to nodejs.org using https:h1
+FETCH 16241: connected to nodejs.org using https:h1
+FETCH 16241: sending request to GET https://nodejs.org//
+FETCH 16241: received response to GET https://nodejs.org// - HTTP 307
+FETCH 16241: connecting to nodejs.org using https:h1
+FETCH 16241: trailers received from GET https://nodejs.org//
+FETCH 16241: connected to nodejs.org using https:h1
+FETCH 16241: sending request to GET https://nodejs.org//en
+FETCH 16241: received response to GET https://nodejs.org//en - HTTP 200
+FETCH 16241: trailers received from GET https://nodejs.org//en
+```
+
+## `websocket`
+
+This flag enables debug statements for the `Websocket` API.
+
+> **Note**: statements can overlap with `UNDICI` ones if `undici` or `fetch` flag has been enabled as well.
+
+```sh
+NODE_DEBUG=fetch node script.js
+
+WEBSOCKET 18309: connecting to echo.websocket.org using https:h1
+WEBSOCKET 18309: connected to echo.websocket.org using https:h1
+WEBSOCKET 18309: sending request to GET https://echo.websocket.org//
+WEBSOCKET 18309: connection opened <ip_address>
+```

docs/api/DiagnosticsChannel.md

@@ -105,7 +105,7 @@ You can not assume that this event is related to any specific request.
 import diagnosticsChannel from 'diagnostics_channel'
 
 diagnosticsChannel.channel('undici:client:beforeConnect').subscribe(({ connectParams, connector }) => {
-  // const { host, hostname, protocol, port, servername } = connectParams
+  // const { host, hostname, protocol, port, servername, version } = connectParams
   // connector is a function that creates the socket
 })
 ```
@@ -118,7 +118,7 @@ This message is published after a connection is established.
 import diagnosticsChannel from 'diagnostics_channel'
 
 diagnosticsChannel.channel('undici:client:connected').subscribe(({ socket, connectParams, connector }) => {
-  // const { host, hostname, protocol, port, servername } = connectParams
+  // const { host, hostname, protocol, port, servername, version } = connectParams
  // connector is a function that creates the socket
 })
 ```
@@ -131,7 +131,7 @@ This message is published if it did not succeed to create new connection
 import diagnosticsChannel from 'diagnostics_channel'
 
 diagnosticsChannel.channel('undici:client:connectError').subscribe(({ error, socket, connectParams, connector }) => {
-  // const { host, hostname, protocol, port, servername } = connectParams
+  // const { host, hostname, protocol, port, servername, version } = connectParams
   // connector is a function that creates the socket
   console.log(`Connect failed with ${error.message}`)
 })

docsify/sidebar.md

@@ -18,6 +18,7 @@
   * [MockErrors](/docs/api/MockErrors.md "Undici API - MockErrors")
   * [API Lifecycle](/docs/api/api-lifecycle.md "Undici API - Lifecycle")
   * [Diagnostics Channel Support](/docs/api/DiagnosticsChannel.md "Diagnostics Channel Support")
+  * [Debug](/docs/api/Debug.md.md "Undici API - Debugging Undici")
   * [WebSocket](/docs/api/WebSocket.md "Undici API - WebSocket")
   * [MIME Type Parsing](/docs/api/ContentType.md "Undici API - MIME Type Parsing")
   * [CacheStorage](/docs/api/CacheStorage.md "Undici API - CacheStorage")

lib/client.js

@@ -9,6 +9,7 @@ const net = require('net')
 const http = require('http')
 const { pipeline } = require('stream')
 const util = require('./core/util')
+const { channels } = require('./core/diagnostics')
 const timers = require('./timers')
 const Request = require('./core/request')
 const DispatcherBase = require('./dispatcher-base')
@@ -108,21 +109,6 @@ const FastBuffer = Buffer[Symbol.species]
 
 const kClosedResolve = Symbol('kClosedResolve')
 
-const channels = {}
-
-try {
-  const diagnosticsChannel = require('diagnostics_channel')
-  channels.sendHeaders = diagnosticsChannel.channel('undici:client:sendHeaders')
-  channels.beforeConnect = diagnosticsChannel.channel('undici:client:beforeConnect')
-  channels.connectError = diagnosticsChannel.channel('undici:client:connectError')
-  channels.connected = diagnosticsChannel.channel('undici:client:connected')
-} catch {
-  channels.sendHeaders = { hasSubscribers: false }
-  channels.beforeConnect = { hasSubscribers: false }
-  channels.connectError = { hasSubscribers: false }
-  channels.connected = { hasSubscribers: false }
-}
-
 /**
  * @type {import('../types/client').default}
  */
@@ -1191,6 +1177,7 @@ async function connect (client) {
         hostname,
         protocol,
         port,
+        version: client[kHTTPConnVersion],
         servername: client[kServerName],
         localAddress: client[kLocalAddress]
       },
@@ -1284,6 +1271,7 @@ async function connect (client) {
           hostname,
           protocol,
           port,
+          version: client[kHTTPConnVersion],
           servername: client[kServerName],
           localAddress: client[kLocalAddress]
         },
@@ -1306,6 +1294,7 @@ async function connect (client) {
           hostname,
           protocol,
           port,
+          version: client[kHTTPConnVersion],
           servername: client[kServerName],
           localAddress: client[kLocalAddress]
         },

lib/core/diagnostics.js

@@ -0,0 +1,202 @@
+'use strict'
+const diagnosticsChannel = require('diagnostics_channel')
+const util = require('util')
+
+const undiciDebugLog = util.debuglog('undici')
+const fetchDebuglog = util.debuglog('fetch')
+const websocketDebuglog = util.debuglog('websocket')
+let isClientSet = false
+const channels = {
+  // Client
+  beforeConnect: diagnosticsChannel.channel('undici:client:beforeConnect'),
+  connected: diagnosticsChannel.channel('undici:client:connected'),
+  connectError: diagnosticsChannel.channel('undici:client:connectError'),
+  sendHeaders: diagnosticsChannel.channel('undici:client:sendHeaders'),
+  // Request
+  create: diagnosticsChannel.channel('undici:request:create'),
+  bodySent: diagnosticsChannel.channel('undici:request:bodySent'),
+  headers: diagnosticsChannel.channel('undici:request:headers'),
+  trailers: diagnosticsChannel.channel('undici:request:trailers'),
+  error: diagnosticsChannel.channel('undici:request:error'),
+  // WebSocket
+  open: diagnosticsChannel.channel('undici:websocket:open'),
+  close: diagnosticsChannel.channel('undici:websocket:close'),
+  socketError: diagnosticsChannel.channel('undici:websocket:socket_error'),
+  ping: diagnosticsChannel.channel('undici:websocket:ping'),
+  pong: diagnosticsChannel.channel('undici:websocket:pong')
+}
+
+if (undiciDebugLog.enabled || fetchDebuglog.enabled) {
+  const debuglog = fetchDebuglog.enabled ? fetchDebuglog : undiciDebugLog
+
+  // Track all Client events
+  diagnosticsChannel.channel('undici:client:beforeConnect').subscribe(evt => {
+    const {
+      connectParams: { version, protocol, port, host }
+    } = evt
+    debuglog(
+      'connecting to %s using %s%s',
+      `${host}${port ? `:${port}` : ''}`,
+      protocol,
+      version
+    )
+  })
+
+  diagnosticsChannel.channel('undici:client:connected').subscribe(evt => {
+    const {
+      connectParams: { version, protocol, port, host }
+    } = evt
+    debuglog(
+      'connected to %s using %s%s',
+      `${host}${port ? `:${port}` : ''}`,
+      protocol,
+      version
+    )
+  })
+
+  diagnosticsChannel.channel('undici:client:connectError').subscribe(evt => {
+    const {
+      connectParams: { version, protocol, port, host },
+      error
+    } = evt
+    debuglog(
+      'connection to %s using %s%s errored - %s',
+      `${host}${port ? `:${port}` : ''}`,
+      protocol,
+      version,
+      error.message
+    )
+  })
+
+  diagnosticsChannel.channel('undici:client:sendHeaders').subscribe(evt => {
+    const {
+      request: { method, path, origin }
+    } = evt
+    debuglog('sending request to %s %s/%s', method, origin, path)
+  })
+
+  // Track Request events
+  diagnosticsChannel.channel('undici:request:headers').subscribe(evt => {
+    const {
+      request: { method, path, origin },
+      response: { statusCode }
+    } = evt
+    debuglog(
+      'received response to %s %s/%s - HTTP %d',
+      method,
+      origin,
+      path,
+      statusCode
+    )
+  })
+
+  diagnosticsChannel.channel('undici:request:trailers').subscribe(evt => {
+    const {
+      request: { method, path, origin }
+    } = evt
+    debuglog('trailers received from %s %s/%s', method, origin, path)
+  })
+
+  diagnosticsChannel.channel('undici:request:error').subscribe(evt => {
+    const {
+      request: { method, path, origin },
+      error
+    } = evt
+    debuglog(
+      'request to %s %s/%s errored - %s',
+      method,
+      origin,
+      path,
+      error.message
+    )
+  })
+
+  isClientSet = true
+}
+
+if (websocketDebuglog.enabled) {
+  if (!isClientSet) {
+    const debuglog = undiciDebugLog.enabled ? undiciDebugLog : websocketDebuglog
+    diagnosticsChannel.channel('undici:client:beforeConnect').subscribe(evt => {
+      const {
+        connectParams: { version, protocol, port, host }
+      } = evt
+      debuglog(
+        'connecting to %s%s using %s%s',
+        host,
+        port ? `:${port}` : '',
+        protocol,
+        version
+      )
+    })
+
+    diagnosticsChannel.channel('undici:client:connected').subscribe(evt => {
+      const {
+        connectParams: { version, protocol, port, host }
+      } = evt
+      debuglog(
+        'connected to %s%s using %s%s',
+        host,
+        port ? `:${port}` : '',
+        protocol,
+        version
+      )
+    })
+
+    diagnosticsChannel.channel('undici:client:connectError').subscribe(evt => {
+      const {
+        connectParams: { version, protocol, port, host },
+        error
+      } = evt
+      debuglog(
+        'connection to %s%s using %s%s errored - %s',
+        host,
+        port ? `:${port}` : '',
+        protocol,
+        version,
+        error.message
+      )
+    })
+
+    diagnosticsChannel.channel('undici:client:sendHeaders').subscribe(evt => {
+      const {
+        request: { method, path, origin }
+      } = evt
+      debuglog('sending request to %s %s/%s', method, origin, path)
+    })
+  }
+
+  // Track all WebSocket events
+  diagnosticsChannel.channel('undici:websocket:open').subscribe(evt => {
+    const {
+      address: { address, port }
+    } = evt
+    websocketDebuglog('connection opened %s%s', address, port ? `:${port}` : '')
+  })
+
+  diagnosticsChannel.channel('undici:websocket:close').subscribe(evt => {
+    const { websocket, code, reason } = evt
+    websocketDebuglog(
+      'closed connection to %s - %s %s',
+      websocket.url,
+      code,
+      reason
+    )
+  })
+
+  diagnosticsChannel.channel('undici:websocket:socket_error').subscribe(err => {
+    websocketDebuglog('connection errored - %s', err.message)
+  })
+
+  diagnosticsChannel.channel('undici:websocket:ping').subscribe(evt => {
+    websocketDebuglog('ping received')
+  })
+
+  diagnosticsChannel.channel('undici:websocket:pong').subscribe(evt => {
+    websocketDebuglog('pong received')
+  })
+}
+
+module.exports = {
+  channels
+}

lib/core/request.js

@@ -7,6 +7,7 @@ const {
 const assert = require('assert')
 const { kHTTP2BuildRequest, kHTTP2CopyHeaders, kHTTP1BuildRequest } = require('./symbols')
 const util = require('./util')
+const { channels } = require('./diagnostics.js')
 const { headerNameLowerCasedRecord } = require('./constants')
 
 // headerCharRegex have been lifted from
@@ -25,25 +26,8 @@ const invalidPathRegex = /[^\u0021-\u00ff]/
 
 const kHandler = Symbol('handler')
 
-const channels = {}
-
 let extractBody
 
-try {
-  const diagnosticsChannel = require('diagnostics_channel')
-  channels.create = diagnosticsChannel.channel('undici:request:create')
-  channels.bodySent = diagnosticsChannel.channel('undici:request:bodySent')
-  channels.headers = diagnosticsChannel.channel('undici:request:headers')
-  channels.trailers = diagnosticsChannel.channel('undici:request:trailers')
-  channels.error = diagnosticsChannel.channel('undici:request:error')
-} catch {
-  channels.create = { hasSubscribers: false }
-  channels.bodySent = { hasSubscribers: false }
-  channels.headers = { hasSubscribers: false }
-  channels.trailers = { hasSubscribers: false }
-  channels.error = { hasSubscribers: false }
-}
-
 class Request {
   constructor (origin, {
     path,