lib: improve debuglog() performance

PR-URL: https://github.com/nodejs/node/pull/32260
Reviewed-By: James M Snell <jasnell@gmail.com>

28 files changed, 101 insertions, 40 deletions

diff --git a/lib/_http_agent.js b/lib/_http_agent.js
index 91ca52c4e6..6abb73975d 100644
--- a/lib/_http_agent.js
+++ b/lib/_http_agent.js
@@ -30,7 +30,9 @@ const {
 
 const net = require('net');
 const EventEmitter = require('events');
-const debug = require('internal/util/debuglog').debuglog('http');
+let debug = require('internal/util/debuglog').debuglog('http', (fn) => {
+  debug = fn;
+});
 const { async_id_symbol } = require('internal/async_hooks').symbols;
 const {
   codes: {
diff --git a/lib/_http_common.js b/lib/_http_common.js
index 2c836221f7..a667557f9d 100644
--- a/lib/_http_common.js
+++ b/lib/_http_common.js
@@ -39,7 +39,9 @@ const {
   readStop
 } = incoming;
 
-const debug = require('internal/util/debuglog').debuglog('http');
+let debug = require('internal/util/debuglog').debuglog('http', (fn) => {
+  debug = fn;
+});
 
 const kIncomingMessage = Symbol('IncomingMessage');
 const kOnHeaders = HTTPParser.kOnHeaders | 0;
diff --git a/lib/_stream_readable.js b/lib/_stream_readable.js
index f978113bb3..952f2d75b8 100644
--- a/lib/_stream_readable.js
+++ b/lib/_stream_readable.js
@@ -39,7 +39,9 @@ const EE = require('events');
 const Stream = require('stream');
 const { Buffer } = require('buffer');
 
-const debug = require('internal/util/debuglog').debuglog('stream');
+let debug = require('internal/util/debuglog').debuglog('stream', (fn) => {
+  debug = fn;
+});
 const BufferList = require('internal/streams/buffer_list');
 const destroyImpl = require('internal/streams/destroy');
 const {
diff --git a/lib/_tls_wrap.js b/lib/_tls_wrap.js
index 8b912d805c..d1e87e2a4c 100644
--- a/lib/_tls_wrap.js
+++ b/lib/_tls_wrap.js
@@ -46,7 +46,9 @@ const tls = require('tls');
 const common = require('_tls_common');
 const JSStreamSocket = require('internal/js_stream_socket');
 const { Buffer } = require('buffer');
-const debug = require('internal/util/debuglog').debuglog('tls');
+let debug = require('internal/util/debuglog').debuglog('tls', (fn) => {
+  debug = fn;
+});
 const { TCP, constants: TCPConstants } = internalBinding('tcp_wrap');
 const tls_wrap = internalBinding('tls_wrap');
 const { Pipe, constants: PipeConstants } = internalBinding('pipe_wrap');
diff --git a/lib/child_process.js b/lib/child_process.js
index d95f684101..9e1c37af8f 100644
--- a/lib/child_process.js
+++ b/lib/child_process.js
@@ -37,7 +37,12 @@ const {
   getSystemErrorName
 } = require('internal/util');
 const { isArrayBufferView } = require('internal/util/types');
-const debug = require('internal/util/debuglog').debuglog('child_process');
+let debug = require('internal/util/debuglog').debuglog(
+  'child_process',
+  (fn) => {
+    debug = fn;
+  }
+);
 const { Buffer } = require('buffer');
 const { Pipe, constants: PipeConstants } = internalBinding('pipe_wrap');
 const {
diff --git a/lib/https.js b/lib/https.js
index 77d3a241eb..1d3a6e5024 100644
--- a/lib/https.js
+++ b/lib/https.js
@@ -37,7 +37,9 @@ const {
   kServerResponse
 } = require('_http_server');
 const { ClientRequest } = require('_http_client');
-const debug = require('internal/util/debuglog').debuglog('https');
+let debug = require('internal/util/debuglog').debuglog('https', (fn) => {
+  debug = fn;
+});
 const { URL, urlToOptions, searchParamsSymbol } = require('internal/url');
 const { IncomingMessage, ServerResponse } = require('http');
 const { kIncomingMessage } = require('_http_common');
diff --git a/lib/internal/http2/core.js b/lib/internal/http2/core.js
index 2e92ce1888..1503130f9b 100644
--- a/lib/internal/http2/core.js
+++ b/lib/internal/http2/core.js
@@ -159,7 +159,9 @@ const { UV_EOF } = internalBinding('uv');
 
 const { StreamPipe } = internalBinding('stream_pipe');
 const { _connectionListener: httpConnectionListener } = http;
-const debug = require('internal/util/debuglog').debuglog('http2');
+let debug = require('internal/util/debuglog').debuglog('http2', (fn) => {
+  debug = fn;
+});
 
 // TODO(addaleax): See if this can be made more efficient by figuring out
 // whether debugging is enabled before we perform any further steps. Currently,
diff --git a/lib/internal/js_stream_socket.js b/lib/internal/js_stream_socket.js
index 1a805ae830..faad988e82 100644
--- a/lib/internal/js_stream_socket.js
+++ b/lib/internal/js_stream_socket.js
@@ -9,7 +9,12 @@ const assert = require('internal/assert');
 const { Socket } = require('net');
 const { JSStream } = internalBinding('js_stream');
 const uv = internalBinding('uv');
-const debug = require('internal/util/debuglog').debuglog('stream_socket');
+let debug = require('internal/util/debuglog').debuglog(
+  'stream_socket',
+  (fn) => {
+    debug = fn;
+  }
+);
 const { owner_symbol } = require('internal/async_hooks').symbols;
 const { ERR_STREAM_WRAP } = require('internal/errors').codes;
 
diff --git a/lib/internal/main/worker_thread.js b/lib/internal/main/worker_thread.js
index 6e3935d138..61045cf1c0 100644
--- a/lib/internal/main/worker_thread.js
+++ b/lib/internal/main/worker_thread.js
@@ -49,7 +49,9 @@ const {
 } = require('internal/process/execution');
 
 const publicWorker = require('worker_threads');
-const debug = require('internal/util/debuglog').debuglog('worker');
+let debug = require('internal/util/debuglog').debuglog('worker', (fn) => {
+  debug = fn;
+});
 
 const assert = require('internal/assert');
 
diff --git a/lib/internal/modules/cjs/helpers.js b/lib/internal/modules/cjs/helpers.js
index 2181fc2a42..3d224fb514 100644
--- a/lib/internal/modules/cjs/helpers.js
+++ b/lib/internal/modules/cjs/helpers.js
@@ -16,7 +16,9 @@ const path = require('path');
 const { pathToFileURL, fileURLToPath } = require('internal/url');
 const { URL } = require('url');
 
-const debug = require('internal/util/debuglog').debuglog('module');
+let debug = require('internal/util/debuglog').debuglog('module', (fn) => {
+  debug = fn;
+});
 
 function loadNativeModule(filename, request) {
   const mod = NativeModule.map.get(filename);
diff --git a/lib/internal/modules/cjs/loader.js b/lib/internal/modules/cjs/loader.js
index a128cb2ada..c2be5ea025 100644
--- a/lib/internal/modules/cjs/loader.js
+++ b/lib/internal/modules/cjs/loader.js
@@ -245,7 +245,9 @@ ObjectDefineProperty(Module.prototype, 'parent', {
   ) : getModuleParent
 });
 
-const debug = require('internal/util/debuglog').debuglog('module');
+let debug = require('internal/util/debuglog').debuglog('module', (fn) => {
+  debug = fn;
+});
 Module._debug = deprecate(debug, 'Module._debug is deprecated.', 'DEP0077');
 
 // Given a module name, and a list of paths to test, returns the first
diff --git a/lib/internal/modules/esm/create_dynamic_module.js b/lib/internal/modules/esm/create_dynamic_module.js
index 38344f6964..e831db8daa 100644
--- a/lib/internal/modules/esm/create_dynamic_module.js
+++ b/lib/internal/modules/esm/create_dynamic_module.js
@@ -8,7 +8,9 @@ const {
   Set,
 } = primordials;
 
-const debug = require('internal/util/debuglog').debuglog('esm');
+let debug = require('internal/util/debuglog').debuglog('esm', (fn) => {
+  debug = fn;
+});
 
 function createImport(impt, index) {
   const imptPath = JSONStringify(impt);
diff --git a/lib/internal/modules/esm/module_map.js b/lib/internal/modules/esm/module_map.js
index 9b7d86581e..9c51c7c487 100644
--- a/lib/internal/modules/esm/module_map.js
+++ b/lib/internal/modules/esm/module_map.js
@@ -4,7 +4,9 @@ const ModuleJob = require('internal/modules/esm/module_job');
 const {
   SafeMap,
 } = primordials;
-const debug = require('internal/util/debuglog').debuglog('esm');
+let debug = require('internal/util/debuglog').debuglog('esm', (fn) => {
+  debug = fn;
+});
 const { ERR_INVALID_ARG_TYPE } = require('internal/errors').codes;
 const { validateString } = require('internal/validators');
 
diff --git a/lib/internal/modules/esm/translators.js b/lib/internal/modules/esm/translators.js
index f314ba96b3..bb3528eddd 100644
--- a/lib/internal/modules/esm/translators.js
+++ b/lib/internal/modules/esm/translators.js
@@ -30,7 +30,9 @@ const { defaultTransformSource } = require(
 const createDynamicModule = require(
   'internal/modules/esm/create_dynamic_module');
 const { fileURLToPath, URL } = require('url');
-const { debuglog } = require('internal/util/debuglog');
+let debug = require('internal/util/debuglog').debuglog('esm', (fn) => {
+  debug = fn;
+});
 const { emitExperimentalWarning } = require('internal/util');
 const {
   ERR_UNKNOWN_BUILTIN_MODULE,
@@ -43,8 +45,6 @@ const { getOptionValue } = require('internal/options');
 const experimentalImportMetaResolve =
     getOptionValue('--experimental-import-meta-resolve');
 
-const debug = debuglog('esm');
-
 const translators = new SafeMap();
 exports.translators = translators;
 
diff --git a/lib/internal/policy/manifest.js b/lib/internal/policy/manifest.js
index ae5e6cd3f4..672eab1c38 100644
--- a/lib/internal/policy/manifest.js
+++ b/lib/internal/policy/manifest.js
@@ -21,7 +21,9 @@ const {
   ERR_MANIFEST_INVALID_RESOURCE_FIELD,
   ERR_MANIFEST_UNKNOWN_ONERROR,
 } = require('internal/errors').codes;
-const debug = require('internal/util/debuglog').debuglog('policy');
+let debug = require('internal/util/debuglog').debuglog('policy', (fn) => {
+  debug = fn;
+});
 const SRI = require('internal/policy/sri');
 const crypto = require('crypto');
 const { Buffer } = require('buffer');
diff --git a/lib/internal/repl/history.js b/lib/internal/repl/history.js
index 6404e821b1..5188af9475 100644
--- a/lib/internal/repl/history.js
+++ b/lib/internal/repl/history.js
@@ -8,7 +8,9 @@ const { Interface } = require('readline');
 const path = require('path');
 const fs = require('fs');
 const os = require('os');
-const debug = require('internal/util/debuglog').debuglog('repl');
+let debug = require('internal/util/debuglog').debuglog('repl', (fn) => {
+  debug = fn;
+});
 const { clearTimeout, setTimeout } = require('timers');
 
 // XXX(chrisdickinson): The 15ms debounce value is somewhat arbitrary.
diff --git a/lib/internal/repl/utils.js b/lib/internal/repl/utils.js
index 160417491f..9ce243a0bc 100644
--- a/lib/internal/repl/utils.js
+++ b/lib/internal/repl/utils.js
@@ -40,7 +40,9 @@ const {
   inspect,
 } = require('internal/util/inspect');
 
-const debug = require('internal/util/debuglog').debuglog('repl');
+let debug = require('internal/util/debuglog').debuglog('repl', (fn) => {
+  debug = fn;
+});
 
 const previewOptions = {
   colors: false,
diff --git a/lib/internal/source_map/prepare_stack_trace.js b/lib/internal/source_map/prepare_stack_trace.js
index df0d79a204..23e117b677 100644
--- a/lib/internal/source_map/prepare_stack_trace.js
+++ b/lib/internal/source_map/prepare_stack_trace.js
@@ -4,7 +4,9 @@ const {
   Error,
 } = primordials;
 
-const debug = require('internal/util/debuglog').debuglog('source_map');
+let debug = require('internal/util/debuglog').debuglog('source_map', (fn) => {
+  debug = fn;
+});
 const { getStringWidth } = require('internal/util/inspect');
 const { readFileSync } = require('fs');
 const { findSourceMap } = require('internal/source_map/source_map_cache');
diff --git a/lib/internal/source_map/source_map_cache.js b/lib/internal/source_map/source_map_cache.js
index 04926acfc1..db7a19e275 100644
--- a/lib/internal/source_map/source_map_cache.js
+++ b/lib/internal/source_map/source_map_cache.js
@@ -22,7 +22,9 @@ function ObjectGetValueSafe(obj, key) {
 
 // See https://sourcemaps.info/spec.html for SourceMap V3 specification.
 const { Buffer } = require('buffer');
-const debug = require('internal/util/debuglog').debuglog('source_map');
+let debug = require('internal/util/debuglog').debuglog('source_map', (fn) => {
+  debug = fn;
+});
 const { dirname, resolve } = require('path');
 const fs = require('fs');
 const { getOptionValue } = require('internal/options');
diff --git a/lib/internal/stream_base_commons.js b/lib/internal/stream_base_commons.js
index 31f1ba67f1..569a1419b5 100644
--- a/lib/internal/stream_base_commons.js
+++ b/lib/internal/stream_base_commons.js
@@ -37,7 +37,9 @@ const kAfterAsyncWrite = Symbol('kAfterAsyncWrite');
 const kHandle = Symbol('kHandle');
 const kSession = Symbol('kSession');
 
-const debug = require('internal/util/debuglog').debuglog('stream');
+let debug = require('internal/util/debuglog').debuglog('stream', (fn) => {
+  debug = fn;
+});
 const kBuffer = Symbol('kBuffer');
 const kBufferGen = Symbol('kBufferGen');
 const kBufferCb = Symbol('kBufferCb');
diff --git a/lib/internal/timers.js b/lib/internal/timers.js
index 1577e31779..ead8bec819 100644
--- a/lib/internal/timers.js
+++ b/lib/internal/timers.js
@@ -113,7 +113,9 @@ const L = require('internal/linkedlist');
 const PriorityQueue = require('internal/priority_queue');
 
 const { inspect } = require('internal/util/inspect');
-const debug = require('internal/util/debuglog').debuglog('timer');
+let debug = require('internal/util/debuglog').debuglog('timer', (fn) => {
+  debug = fn;
+});
 
 // *Must* match Environment::ImmediateInfo::Fields in src/env.h.
 const kCount = 0;
diff --git a/lib/internal/util/debuglog.js b/lib/internal/util/debuglog.js
index 72eb797474..fce2e2f0d8 100644
--- a/lib/internal/util/debuglog.js
+++ b/lib/internal/util/debuglog.js
@@ -35,6 +35,8 @@ function emitWarningIfNeeded(set) {
   }
 }
 
+function noop() {}
+
 function debuglogImpl(set) {
   set = set.toUpperCase();
   if (debugs[set] === undefined) {
@@ -48,7 +50,7 @@ function debuglogImpl(set) {
         process.stderr.write(format('%s %s: %s\n', set, coloredPID, msg));
       };
     } else {
-      debugs[set] = null;
+      debugs[set] = noop;
     }
   }
   return debugs[set];
@@ -58,16 +60,17 @@ function debuglogImpl(set) {
 // so it needs to be called lazily in top scopes of internal modules
 // that may be loaded before these run time states are allowed to
 // be accessed.
-function debuglog(set) {
-  let debug;
-  return function(...args) {
-    if (debug === undefined) {
-      // Only invokes debuglogImpl() when the debug function is
-      // called for the first time.
-      debug = debuglogImpl(set);
-    }
-    if (debug !== null)
-      debug(...args);
+function debuglog(set, cb) {
+  let debug = (...args) => {
+    // Only invokes debuglogImpl() when the debug function is
+    // called for the first time.
+    debug = debuglogImpl(set);
+    if (typeof cb === 'function')
+      cb(debug);
+    debug(...args);
+  };
+  return (...args) => {
+    debug(...args);
   };
 }
 
diff --git a/lib/internal/worker.js b/lib/internal/worker.js
index 4f01f33134..ff405c1115 100644
--- a/lib/internal/worker.js
+++ b/lib/internal/worker.js
@@ -68,7 +68,9 @@ const kOnErrorMessage = Symbol('kOnErrorMessage');
 const kParentSideStdio = Symbol('kParentSideStdio');
 
 const SHARE_ENV = SymbolFor('nodejs.worker_threads.SHARE_ENV');
-const debug = require('internal/util/debuglog').debuglog('worker');
+let debug = require('internal/util/debuglog').debuglog('worker', (fn) => {
+  debug = fn;
+});
 
 let cwdCounter;
 
diff --git a/lib/internal/worker/io.js b/lib/internal/worker/io.js
index 0a97f17595..60dd8cd67d 100644
--- a/lib/internal/worker/io.js
+++ b/lib/internal/worker/io.js
@@ -31,7 +31,9 @@ const {
 const { Readable, Writable } = require('stream');
 const EventEmitter = require('events');
 const { inspect } = require('internal/util/inspect');
-const debug = require('internal/util/debuglog').debuglog('worker');
+let debug = require('internal/util/debuglog').debuglog('worker', (fn) => {
+  debug = fn;
+});
 
 const kIncrementsPortRef = Symbol('kIncrementsPortRef');
 const kName = Symbol('kName');
diff --git a/lib/net.js b/lib/net.js
index eb5f509f02..352a1d0e99 100644
--- a/lib/net.js
+++ b/lib/net.js
@@ -35,7 +35,9 @@ const {
 const EventEmitter = require('events');
 const stream = require('stream');
 const { inspect } = require('internal/util/inspect');
-const debug = require('internal/util/debuglog').debuglog('net');
+let debug = require('internal/util/debuglog').debuglog('net', (fn) => {
+  debug = fn;
+});
 const { deprecate } = require('internal/util');
 const {
   isIP,
diff --git a/lib/repl.js b/lib/repl.js
index d5e41d41b6..a755dbf1bb 100644
--- a/lib/repl.js
+++ b/lib/repl.js
@@ -88,7 +88,9 @@ const CJSModule = require('internal/modules/cjs/loader').Module;
 let _builtinLibs = [...CJSModule.builtinModules]
   .filter((e) => !e.startsWith('_') && !e.includes('/'));
 const domain = require('domain');
-const debug = require('internal/util/debuglog').debuglog('repl');
+let debug = require('internal/util/debuglog').debuglog('repl', (fn) => {
+  debug = fn;
+});
 const {
   codes: {
     ERR_CANNOT_WATCH_SIGINT,
diff --git a/lib/timers.js b/lib/timers.js
index 324752506c..21f02300f8 100644
--- a/lib/timers.js
+++ b/lib/timers.js
@@ -53,7 +53,9 @@ const {
   promisify: { custom: customPromisify },
   deprecate
 } = require('internal/util');
-const debug = require('internal/util/debuglog').debuglog('timer');
+let debug = require('internal/util/debuglog').debuglog('timer', (fn) => {
+  debug = fn;
+});
 const { validateCallback } = require('internal/validators');
 
 const {
diff --git a/test/sequential/test-util-debug.js b/test/sequential/test-util-debug.js
index 6cad46f101..8bf5ae5e5a 100644
--- a/test/sequential/test-util-debug.js
+++ b/test/sequential/test-util-debug.js
@@ -118,7 +118,9 @@ function child(section) {
     value: tty.WriteStream.prototype.hasColors
   });
   // eslint-disable-next-line no-restricted-syntax
-  const debug = util.debuglog(section);
+  const debug = util.debuglog(section, common.mustCall((cb) => {
+    assert.strictEqual(typeof cb, 'function');
+  }));
   debug('this', { is: 'a' }, /debugging/);
   debug('num=%d str=%s obj=%j', 1, 'a', { foo: 'bar' });
   console.log('ok');