util,console: guard against overwritten util functions

lib/console.js

@@ -21,7 +21,7 @@
 
 'use strict';
 
-const util = require('util');
+const {format, inspect} = require('util');
 
 function Console(stdout, stderr, ignoreErrors = true) {
   if (!(this instanceof Console)) {
@@ -103,7 +103,7 @@ function write(ignoreErrors, stream, string, errorhandler) {
 Console.prototype.log = function log(...args) {
   write(this._ignoreErrors,
         this._stdout,
-        `${util.format.apply(null, args)}\n`,
+        `${format.apply(null, args)}\n`,
         this._stdoutErrorHandler);
 };
 
@@ -114,7 +114,7 @@ Console.prototype.info = Console.prototype.log;
 Console.prototype.warn = function warn(...args) {
   write(this._ignoreErrors,
         this._stderr,
-        `${util.format.apply(null, args)}\n`,
+        `${format.apply(null, args)}\n`,
         this._stderrErrorHandler);
 };
 
@@ -126,7 +126,7 @@ Console.prototype.dir = function dir(object, options) {
   options = Object.assign({customInspect: false}, options);
   write(this._ignoreErrors,
         this._stdout,
-        `${util.inspect(object, options)}\n`,
+        `${inspect(object, options)}\n`,
         this._stdoutErrorHandler);
 };
 
@@ -154,15 +154,15 @@ Console.prototype.trace = function trace(...args) {
   // exposed.
   var err = new Error();
   err.name = 'Trace';
-  err.message = util.format.apply(null, args);
+  err.message = format.apply(null, args);
   Error.captureStackTrace(err, trace);
   this.error(err.stack);
 };
 
 
 Console.prototype.assert = function assert(expression, ...args) {
   if (!expression) {
-    require('assert').ok(false, util.format.apply(null, args));
+    require('assert').ok(false, format.apply(null, args));
   }
 };
 

lib/util.js

@@ -59,7 +59,7 @@ function tryStringify(arg) {
   }
 }
 
-exports.format = function(f) {
+function format(f) {
   if (typeof f !== 'string') {
     const objects = new Array(arguments.length);
     for (var index = 0; index < arguments.length; index++) {
@@ -141,8 +141,8 @@ exports.format = function(f) {
     }
   }
   return str;
-};
-
+}
+exports.format = format;
 
 exports.deprecate = internalUtil.deprecate;
 
@@ -157,7 +157,7 @@ exports.debuglog = function(set) {
     if (new RegExp(`\\b${set}\\b`, 'i').test(debugEnviron)) {
       var pid = process.pid;
       debugs[set] = function() {
-        var msg = exports.format.apply(exports, arguments);
+        var msg = format.apply(exports, arguments);
         console.error('%s %d: %s', set, pid, msg);
       };
     } else {
@@ -936,7 +936,7 @@ function timestamp() {
 
 // log is just a thin wrapper to console.log that prepends a timestamp
 exports.log = function() {
-  console.log('%s - %s', timestamp(), exports.format.apply(exports, arguments));
+  console.log('%s - %s', timestamp(), format.apply(exports, arguments));
 };
 
 
@@ -1056,6 +1056,6 @@ exports._exceptionWithHostPort = function(err,
 
 // process.versions needs a custom function as some values are lazy-evaluated.
 process.versions[exports.inspect.custom] =
-  (depth) => exports.format(JSON.parse(JSON.stringify(process.versions)));
+  (depth) => format(JSON.parse(JSON.stringify(process.versions)));
 
 exports.promisify = internalUtil.promisify;

test/parallel/test-console.js

@@ -22,6 +22,7 @@
 'use strict';
 const common = require('../common');
 const assert = require('assert');
+const util = require('util');
 
 assert.ok(process.stdout.writable);
 assert.ok(process.stderr.writable);
@@ -159,3 +160,36 @@ assert.throws(() => {
 assert.doesNotThrow(() => {
   console.assert(true, 'this should not throw');
 });
+
+
+// Run with monkey-patched util.format() and util.inspect() to confirm it won't
+// run the monkey- patched functions but instead it will run the correct
+// original functions.
+{
+  const saveFormat = util.format;
+  util.format = () => {
+    assert.fail('monkey-patched util.format() should not be invoked');
+  };
+
+  const saveInspect = util.inspect;
+  util.inspect = () => {
+    assert.fail('monkey-patched util.inspect() should not be invoked');
+  };
+
+  assert.doesNotThrow(() => {
+    console.log('fhqwhgads');
+    console.warn('fhqwhgads');
+    console.dir('fhqwhgads');
+    console.trace('fhqwhgads');
+  });
+
+  // Should throw with `fhqwhgads` and not `monkey-patched ... should not be
+  // invoked`.
+  assert.throws(() => {
+    console.assert(false, 'fhqwhgads');
+  }, /fhqwhgads/);
+
+  // Restore util.format to avoid side effects.
+  util.format = saveFormat;
+  util.inspect = saveInspect;
+}

test/parallel/test-process-versions.js

@@ -1,6 +1,7 @@
 'use strict';
 const common = require('../common');
 const assert = require('assert');
+const util = require('util');
 
 const expected_keys = ['ares', 'http_parser', 'modules', 'node',
                        'uv', 'v8', 'zlib'];
@@ -28,3 +29,29 @@ assert(/^\d+\.\d+\.\d+(-.*)?$/.test(process.versions.uv));
 assert(/^\d+\.\d+\.\d+(-.*)?$/.test(process.versions.zlib));
 assert(/^\d+\.\d+\.\d+(\.\d+)?$/.test(process.versions.v8));
 assert(/^\d+$/.test(process.versions.modules));
+
+const testInspectCustom = () => {
+  const all = process.versions[util.inspect.custom]();
+  assert(all.startsWith('{ '));
+  assert(all.endsWith(' }'));
+  expected_keys.every((key) => {
+    const value = process.versions[key];
+    assert(all.includes(` ${key}: '${value}'`),
+           `Cannot find expected value ${value} for ${key} in ${all}`);
+  });
+};
+
+testInspectCustom();
+
+// run tests again with monkey-patched util.format()
+{
+  const saveFormat = util.format;
+  util.format = () => {
+    assert.fail('monkey-patched util.format() should not be invoked');
+  };
+
+  testInspectCustom();
+
+  // restore util.format to avoid side effects
+  util.format = saveFormat;
+}

test/parallel/test-util-log.js

@@ -27,33 +27,50 @@ const util = require('util');
 assert.ok(process.stdout.writable);
 assert.ok(process.stderr.writable);
 
-const stdout_write = global.process.stdout.write;
-const strings = [];
-global.process.stdout.write = function(string) {
-  strings.push(string);
+const runTests = () => {
+  const stdout_write = global.process.stdout.write;
+  const strings = [];
+  global.process.stdout.write = function(string) {
+    strings.push(string);
+  };
+  console._stderr = process.stdout;
+
+  const tests = [
+    {input: 'foo', output: 'foo'},
+    {input: undefined, output: 'undefined'},
+    {input: null, output: 'null'},
+    {input: false, output: 'false'},
+    {input: 42, output: '42'},
+    {input: function() {}, output: '[Function: input]'},
+    {input: parseInt('not a number', 10), output: 'NaN'},
+    {input: {answer: 42}, output: '{ answer: 42 }'},
+    {input: [1, 2, 3], output: '[ 1, 2, 3 ]'}
+  ];
+
+  // test util.log()
+  tests.forEach(function(test) {
+    util.log(test.input);
+    const result = strings.shift().trim();
+    const re = (/[0-9]{1,2} [A-Z][a-z]{2} [0-9]{2}:[0-9]{2}:[0-9]{2} - (.+)$/);
+    const match = re.exec(result);
+    assert.ok(match);
+    assert.strictEqual(match[1], test.output);
+  });
+
+  global.process.stdout.write = stdout_write;
 };
-console._stderr = process.stdout;
-
-const tests = [
-  {input: 'foo', output: 'foo'},
-  {input: undefined, output: 'undefined'},
-  {input: null, output: 'null'},
-  {input: false, output: 'false'},
-  {input: 42, output: '42'},
-  {input: function() {}, output: '[Function: input]'},
-  {input: parseInt('not a number', 10), output: 'NaN'},
-  {input: {answer: 42}, output: '{ answer: 42 }'},
-  {input: [1, 2, 3], output: '[ 1, 2, 3 ]'}
-];
-
-// test util.log()
-tests.forEach(function(test) {
-  util.log(test.input);
-  const result = strings.shift().trim();
-  const re = (/[0-9]{1,2} [A-Z][a-z]{2} [0-9]{2}:[0-9]{2}:[0-9]{2} - (.+)$/);
-  const match = re.exec(result);
-  assert.ok(match);
-  assert.strictEqual(match[1], test.output);
-});
-
-global.process.stdout.write = stdout_write;
+
+runTests();
+
+// run tests again with monkey-patched util.format()
+{
+  const saveFormat = util.format;
+  util.format = () => {
+    assert.fail('monkey-patched util.format() should not be invoked');
+  };
+
+  runTests();
+
+  // restore util.format to avoid side effects
+  util.format = saveFormat;
+}

test/sequential/test-util-debug-monkeypatched.js

@@ -0,0 +1,92 @@
+// Copyright Joyent, Inc. and other Node contributors.
+//
+// Permission is hereby granted, free of charge, to any person obtaining a
+// copy of this software and associated documentation files (the
+// "Software"), to deal in the Software without restriction, including
+// without limitation the rights to use, copy, modify, merge, publish,
+// distribute, sublicense, and/or sell copies of the Software, and to permit
+// persons to whom the Software is furnished to do so, subject to the
+// following conditions:
+//
+// The above copyright notice and this permission notice shall be included
+// in all copies or substantial portions of the Software.
+//
+// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS
+// OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
+// MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN
+// NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM,
+// DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR
+// OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE
+// USE OR OTHER DEALINGS IN THE SOFTWARE.
+
+'use strict';
+const common = require('../common');
+const assert = require('assert');
+
+if (process.argv[2] === 'child')
+  child();
+else
+  parent();
+
+function parent() {
+  test('foo,tud,bar', true);
+  test('foo,tud', true);
+  test('tud,bar', true);
+  test('tud', true);
+  test('foo,bar', false);
+  test('', false);
+}
+
+function test(environ, shouldWrite) {
+  let expectErr = '';
+  if (shouldWrite) {
+    expectErr = 'TUD %PID%: this { is: \'a\' } /debugging/\n' +
+                'TUD %PID%: number=1234 string=asdf obj={"foo":"bar"}\n';
+  }
+  const expectOut = 'ok\n';
+
+  const spawn = require('child_process').spawn;
+  const child = spawn(process.execPath, [__filename, 'child'], {
+    env: Object.assign(process.env, { NODE_DEBUG: environ })
+  });
+
+  expectErr = expectErr.split('%PID%').join(child.pid);
+
+  let err = '';
+  child.stderr.setEncoding('utf8');
+  child.stderr.on('data', (c) => {
+    err += c;
+  });
+
+  let out = '';
+  child.stdout.setEncoding('utf8');
+  child.stdout.on('data', (c) => {
+    out += c;
+  });
+
+  child.on('close', common.mustCall((c) => {
+    assert(!c);
+    assert.strictEqual(err, expectErr);
+    assert.strictEqual(out, expectOut);
+  }));
+}
+
+
+function child() {
+  const util = require('util');
+
+  // monkey-patch util.format() to confirm debuglog() will work correctly anyway
+  const saveFormat = util.format;
+  util.format = () => {
+    assert.fail('monkey-patched util.format() should not be invoked');
+  };
+
+  const debug = util.debuglog('tud');
+  debug('this', { is: 'a' }, /debugging/);
+  debug('number=%d string=%s obj=%j', 1234, 'asdf', { foo: 'bar' });
+
+  // restore util.format to avoid side effects
+  util.format = saveFormat;
+
+  console.log('ok');
+}