util: Improving --trace-deprecation

This patch allows `util.deprecate` to print the deprecation messages
multiple times, if the calls are made from different lines of source
code.

lib/internal/util.js

@@ -1,5 +1,37 @@
 'use strict';
 
+const util = require('util');
+const warnedLocations = new Set();
+
+function getActualCallerLocation() {
+  // We split only five times, because stack trace will be like this
+  //   1. Error:
+  //   2. getActualCallerLocation
+  //   3. printDeprecationMessage
+  //   4. `deprecated` function in `util.deprecate`
+  //   5. The function which called `util.deprecate`
+  // So, we pick the fifth entry in the stack trace.
+  var location = (new Error()).stack.split('\n', 5).pop();
+
+  if (/\(.*:\d+:\d+\)/.test(location)) {
+    // If the location is of the following format
+    //     at printer (/home/thefourtheye/Desktop/Test.js:2:15)
+    // we pick only the string within the parens and only till the first :
+    return location.match(/\((.*?:\d+):\d+\)/)[1];
+  } else {
+    // If the location is of the following format
+    //     at /home/thefourtheye/Desktop/Test.js:16:5
+    // we remove `at` and take the string excluding the part after last :
+    return location.replace(/\s*at\s*/, '').split(':').slice(0, -1).join(':');
+  }
+
+}
+
+exports.deprecate = function(fn, msg) {
+  return util.deprecate(fn, `(node) ${msg}`);
+};
+
+// `printDeprecationMessage` should not be invoked directly. Use `deprecate`.
 exports.printDeprecationMessage = function(msg, warned) {
   if (process.noDeprecation)
     return true;
@@ -9,10 +41,21 @@ exports.printDeprecationMessage = function(msg, warned) {
 
   if (process.throwDeprecation)
     throw new Error(msg);
-  else if (process.traceDeprecation)
-    console.trace(msg);
-  else
+  else if (process.traceDeprecation) {
+    let location = getActualCallerLocation();
+
+    if (!warnedLocations.has(location)) {
+      warnedLocations.add(location);
+      console.trace(msg);
+    }
+
+    // return false, because we might have to warn again if the calling
+    // location is different next time.
+    return false;
+  }
+  else {
     console.error(msg);
+  }
 
   return true;
 };

lib/util.js

@@ -754,50 +754,50 @@ function hasOwnProperty(obj, prop) {
 
 // Deprecated old stuff.
 
-exports.p = exports.deprecate(function() {
+exports.p = internalUtil.deprecate(function() {
   for (var i = 0, len = arguments.length; i < len; ++i) {
     console.error(exports.inspect(arguments[i]));
   }
-}, 'util.p: Use console.error() instead');
+}, 'util.p is deprecated. Use console.error instead');
 
 
-exports.exec = exports.deprecate(function() {
+exports.exec = internalUtil.deprecate(function() {
   return require('child_process').exec.apply(this, arguments);
-}, 'util.exec is now called `child_process.exec`.');
+}, 'util.exec is deprecated. Use child_process.exec instead');
 
 
-exports.print = exports.deprecate(function() {
+exports.print = internalUtil.deprecate(function() {
   for (var i = 0, len = arguments.length; i < len; ++i) {
     process.stdout.write(String(arguments[i]));
   }
-}, 'util.print: Use console.log instead');
+}, 'util.print is deprecated. Use console.log instead');
 
 
-exports.puts = exports.deprecate(function() {
+exports.puts = internalUtil.deprecate(function() {
   for (var i = 0, len = arguments.length; i < len; ++i) {
     process.stdout.write(arguments[i] + '\n');
   }
-}, 'util.puts: Use console.log instead');
+}, 'util.puts is deprecated. Use console.log instead');
 
 
-exports.debug = exports.deprecate(function(x) {
+exports.debug = internalUtil.deprecate(function(x) {
   process.stderr.write('DEBUG: ' + x + '\n');
-}, 'util.debug: Use console.error instead');
+}, 'util.debug is deprecated. Use console.error instead');
 
 
-exports.error = exports.deprecate(function(x) {
+exports.error = internalUtil.deprecate(function(x) {
   for (var i = 0, len = arguments.length; i < len; ++i) {
     process.stderr.write(arguments[i] + '\n');
   }
-}, 'util.error: Use console.error instead');
+}, 'util.error is deprecated. Use console.error instead');
 
 
-exports.pump = exports.deprecate(function(readStream, writeStream, callback) {
+exports.pump = internalUtil.deprecate(function(readStream, writeStream, cb) {
   var callbackCalled = false;
 
   function call(a, b, c) {
-    if (callback && !callbackCalled) {
-      callback(a, b, c);
+    if (cb && !callbackCalled) {
+      cb(a, b, c);
       callbackCalled = true;
     }
   }
@@ -827,7 +827,7 @@ exports.pump = exports.deprecate(function(readStream, writeStream, callback) {
     readStream.destroy();
     call(err);
   });
-}, 'util.pump(): Use readableStream.pipe() instead');
+}, 'util.pump is deprecated. Use readableStream.pipe instead');
 
 
 exports._errnoException = function(err, syscall, original) {

test/fixtures/deprecated-multiple-times-same-line.js

@@ -0,0 +1 @@
+require('util').p('This is deprecated'); require('util').p('This is deprecated');

test/fixtures/deprecated-multiple-times.js

@@ -0,0 +1,3 @@
+require('util').p('This is deprecated');
+require('util').p('This is deprecated');
+require('util').p('This is deprecated');

test/fixtures/deprecated-with-paren-in-(name).js

@@ -0,0 +1 @@
+require('util').p('This is deprecated');

test/sequential/test-deprecation-flags.js

@@ -8,13 +8,22 @@ var node = process.execPath;
 var normal = [depmod];
 var noDep = ['--no-deprecation', depmod];
 var traceDep = ['--trace-deprecation', depmod];
+var traceDepMultiple = ['--trace-deprecation',
+    require.resolve('../fixtures/deprecated-multiple-times.js')];
+var traceDepMultipleSameLine = ['--trace-deprecation',
+    require.resolve('../fixtures/deprecated-multiple-times-same-line.js')];
+var traceDepParen = ['--trace-deprecation',
+    require.resolve('../fixtures/deprecated-with-paren-in-(name).js')];
+var traceMessage =
+        'Trace: (node) util.p is deprecated. Use console.error instead';
 
 execFile(node, normal, function(er, stdout, stderr) {
   console.error('normal: show deprecation warning');
   assert.equal(er, null);
   assert.equal(stdout, '');
   assert.equal(stderr,
-               'util.p: Use console.error() instead\n\'This is deprecated\'\n');
+               '(node) util.p is deprecated. ' +
+               'Use console.error instead\n\'This is deprecated\'\n');
   console.log('normal ok');
 });
 
@@ -32,7 +41,50 @@ execFile(node, traceDep, function(er, stdout, stderr) {
   assert.equal(stdout, '');
   var stack = stderr.trim().split('\n');
   // just check the top and bottom.
-  assert.equal(stack[0], 'Trace: util.p: Use console.error() instead');
+  assert.equal(stack[0], traceMessage);
   assert.equal(stack.pop(), '\'This is deprecated\'');
   console.log('trace ok');
 });
+
+execFile(node, traceDepMultiple, function(er, stdout, stderr) {
+  console.error('--trace-deprecation: deprecation message printed 3 times');
+  assert.equal(er, null);
+  assert.equal(stdout, '');
+
+  var count = stderr.trim().split('\n').filter(function(currentLine) {
+    return currentLine === traceMessage;
+  }).length;
+
+  // because we invoked the same function three times
+  assert.equal(count, 3);
+
+  console.log('trace ok');
+});
+
+execFile(node, traceDepMultipleSameLine, function(er, stdout, stderr) {
+  console.error('--trace-deprecation: deprecation message printed only once');
+  assert.equal(er, null);
+  assert.equal(stdout, '');
+
+  var count = stderr.trim().split('\n').filter(function(currentLine) {
+    return currentLine === traceMessage;
+  }).length;
+
+  // because we invoked the same function two times, but in the same line
+  assert.equal(count, 1);
+
+  console.log('trace ok');
+});
+
+execFile(node, traceDepParen, function(er, stdout, stderr) {
+  console.error('--trace-deprecation: deprecation with paren in the file name');
+  assert.equal(er, null);
+  assert.equal(stdout, '');
+
+  var stack = stderr.trim().split('\n');
+  // just check the top and bottom.
+  assert.equal(stack[0], traceMessage);
+  assert.equal(stack.pop(), '\'This is deprecated\'');
+  console.log('trace ok');
+});
+