lib: fix emit warning for debuglog.time when disabled

PR-URL: nodejs#54275
Reviewed-By: James M Snell <[email protected]>
Reviewed-By: Joyee Cheung <[email protected]>
Reviewed-By: Rafael Gonzaga <[email protected]>

Author: H4ad

lib/internal/util/debuglog.js

@@ -133,6 +133,7 @@ function pad(value) {
 const kNone = 1 << 0;
 const kSkipLog = 1 << 1;
 const kSkipTrace = 1 << 2;
+const kShouldSkipAll = kSkipLog | kSkipTrace;
 
 const kSecond = 1000;
 const kMinute = 60 * kSecond;
@@ -377,8 +378,6 @@ function debugWithTimer(set, cb) {
   let debugLogCategoryEnabled = false;
   let timerFlags = kNone;
 
-  const skipAll = kSkipLog | kSkipTrace;
-
   function ensureTimerFlagsAreUpdated() {
     timerFlags &= ~kSkipTrace;
 
@@ -393,7 +392,7 @@ function debugWithTimer(set, cb) {
   function internalStartTimer(logLabel, traceLabel) {
     ensureTimerFlagsAreUpdated();
 
-    if (timerFlags === skipAll) {
+    if ((timerFlags & kShouldSkipAll) === kShouldSkipAll) {
       return;
     }
 
@@ -413,7 +412,7 @@ function debugWithTimer(set, cb) {
   function internalEndTimer(logLabel, traceLabel) {
     ensureTimerFlagsAreUpdated();
 
-    if (timerFlags === skipAll) {
+    if ((timerFlags & kShouldSkipAll) === kShouldSkipAll) {
       return;
     }
 
@@ -434,7 +433,7 @@ function debugWithTimer(set, cb) {
   function internalLogTimer(logLabel, traceLabel, args) {
     ensureTimerFlagsAreUpdated();
 
-    if (timerFlags === skipAll) {
+    if ((timerFlags & kShouldSkipAll) === kShouldSkipAll) {
       return;
     }
 
@@ -477,7 +476,7 @@ function debugWithTimer(set, cb) {
   const startTimer = (logLabel, traceLabel) => {
     init();
 
-    if (timerFlags !== skipAll)
+    if ((timerFlags & kShouldSkipAll) !== kShouldSkipAll)
       internalStartTimer(logLabel, traceLabel);
   };
 
@@ -487,7 +486,7 @@ function debugWithTimer(set, cb) {
   const endTimer = (logLabel, traceLabel) => {
     init();
 
-    if (timerFlags !== skipAll)
+    if ((timerFlags & kShouldSkipAll) !== kShouldSkipAll)
       internalEndTimer(logLabel, traceLabel);
   };
 
@@ -497,7 +496,7 @@ function debugWithTimer(set, cb) {
   const logTimer = (logLabel, traceLabel, args) => {
     init();
 
-    if (timerFlags !== skipAll)
+    if ((timerFlags & kShouldSkipAll) !== kShouldSkipAll)
       internalLogTimer(logLabel, traceLabel, args);
   };
 

test/fixtures/GH-54265/dep1.js

@@ -0,0 +1,4 @@
+// dep1.js
+module.exports = function requireDep2() {
+  require("./dep2.js");
+};

test/fixtures/GH-54265/dep2.js

@@ -0,0 +1,3 @@
+// dep2.js
+
+// (empty)

test/fixtures/GH-54265/index.js

@@ -0,0 +1,10 @@
+// index.js
+const Module = require("module");
+const requireDep2 = require("./dep1.js");
+
+const globalCache = Module._cache;
+Module._cache = Object.create(null);
+require("./require-hook.js");
+Module._cache = globalCache;
+
+requireDep2();

test/fixtures/GH-54265/require-hook.js

@@ -0,0 +1,9 @@
+// require-hook.js
+const Module = require("module");
+const requireDep2 = require("./dep1.js");
+
+const originalJSLoader = Module._extensions[".js"];
+Module._extensions[".js"] = function customJSLoader(module, filename) {
+  requireDep2();
+  return originalJSLoader(module, filename);
+};

test/parallel/test-module-print-timing.mjs

@@ -4,6 +4,7 @@ import { readFile } from 'node:fs/promises';
 import { it } from 'node:test';
 import tmpdir from '../common/tmpdir.js';
 import { spawnSyncAndAssert } from '../common/child_process.js';
+import fixtures from '../common/fixtures.js';
 
 tmpdir.refresh();
 
@@ -153,3 +154,19 @@ it('should support enable tracing dynamically', async () => {
   const vmTraces = outputFileJson.filter((trace) => trace.name === "require('vm')");
   assert.strictEqual(vmTraces.length, 0);
 });
+
+it('should not print when is disabled and found duplicated labels (GH-54265)', () => {
+  const testFile = fixtures.path('GH-54265/index.js');
+
+  spawnSyncAndAssert(process.execPath, [
+    testFile,
+  ], {
+    cwd: tmpdir.path,
+    env: {
+      ...process.env,
+    },
+  }, {
+    stdout: '',
+    stderr: '',
+  });
+});