util: Add debuglog, deprecate console lookalikes

doc/api/util.markdown

@@ -2,9 +2,46 @@
 
     Stability: 5 - Locked
 
-These functions are in the module `'util'`. Use `require('util')` to access
-them.
+These functions are in the module `'util'`. Use `require('util')` to
+access them.
 
+The `util` module is primarily designed to support the needs of Node's
+internal APIs.  Many of these utilities are useful for your own
+programs.  If you find that these functions are lacking for your
+purposes, however, you are encouraged to write your own utilities.  We
+are not interested in any future additions to the `util` module that
+are unnecessary for Node's internal functionality.
+
+## util.debuglog(section)
+
+* `section` {String} The section of the program to be debugged
+* Returns: {Function} The logging function
+
+This is used to create a function which conditionally writes to stderr
+based on the existence of a `NODE_DEBUG` environment variable.  If the
+`section` name appears in that environment variable, then the returned
+function will be similar to `console.error()`.  If not, then the
+returned function is a no-op.
+
+For example:
+
+```javascript
+var debuglog = util.debuglog('foo');
+
+var bar = 123;
+debuglog('hello from foo [%d]', bar);
+```
+
+If this program is run with `NODE_DEBUG=foo` in the environment, then
+it will output something like:
+
+    FOO 3245: hello from foo [123]
+
+where `3245` is the process id.  If it is not run with that
+environment variable set, then it will not print anything.
+
+You may separate multiple `NODE_DEBUG` environment variables with a
+comma.  For example, `NODE_DEBUG=fs,net,tls`.
 
 ## util.format(format, [...])
 
@@ -37,35 +74,12 @@ Each argument is converted to a string with `util.inspect()`.
     util.format(1, 2, 3); // '1 2 3'
 
 
-## util.debug(string)
-
-A synchronous output function. Will block the process and
-output `string` immediately to `stderr`.
-
-    require('util').debug('message on stderr');
-
-## util.error([...])
-
-Same as `util.debug()` except this will output all arguments immediately to
-`stderr`.
-
-## util.puts([...])
-
-A synchronous output function. Will block the process and output all arguments
-to `stdout` with newlines after each argument.
-
-## util.print([...])
-
-A synchronous output function. Will block the process, cast each argument to a
-string then output to `stdout`. Does not place newlines after each argument.
-
 ## util.log(string)
 
 Output with timestamp on `stdout`.
 
     require('util').log('Timestamped message.');
 
-
 ## util.inspect(object, [options])
 
 Return a string representation of `object`, which is useful for debugging.
@@ -94,6 +108,8 @@ Example of inspecting all properties of the `util` object:
 
 ### Customizing `util.inspect` colors
 
+<!-- type=misc -->
+
 Color output (if enabled) of `util.inspect` is customizable globally
 via `util.inspect.styles` and `util.inspect.colors` objects.
 
@@ -116,6 +132,8 @@ There are also `bold`, `italic`, `underline` and `inverse` codes.
 
 ### Custom `inspect()` function on Objects
 
+<!-- type=misc -->
+
 Objects also may define their own `inspect(depth)` function which `util.inspect()`
 will invoke and use the result of when inspecting the object:
 
@@ -198,17 +216,6 @@ Returns `true` if the given "object" is an `Error`. `false` otherwise.
       // false
 
 
-## util.pump(readableStream, writableStream, [callback])
-
-    Stability: 0 - Deprecated: Use readableStream.pipe(writableStream)
-
-Read the data from `readableStream` and send it to the `writableStream`.
-When `writableStream.write(data)` returns `false` `readableStream` will be
-paused until the `drain` event occurs on the `writableStream`. `callback` gets
-an error as its only argument and is called when `writableStream` is closed or
-when an error occurs.
-
-
 ## util.inherits(constructor, superConstructor)
 
 Inherit the prototype methods from one
@@ -241,3 +248,35 @@ through the `constructor.super_` property.
         console.log('Received data: "' + data + '"');
     })
     stream.write("It works!"); // Received data: "It works!"
+
+
+## util.debug(string)
+
+    Stability: 0 - Deprecated: use console.error() instead.
+
+Deprecated predecessor of `console.error`.
+
+## util.error([...])
+
+    Stability: 0 - Deprecated: Use console.error() instead.
+
+Deprecated predecessor of `console.error`.
+
+## util.puts([...])
+
+    Stability: 0 - Deprecated: Use console.log() instead.
+
+Deprecated predecessor of `console.log`.
+
+## util.print([...])
+
+    Stability: 0 - Deprecated: Use `console.log` instead.
+
+Deprecated predecessor of `console.log`.
+
+
+## util.pump(readableStream, writableStream, [callback])
+
+    Stability: 0 - Deprecated: Use readableStream.pipe(writableStream)
+
+Deprecated predecessor of `stream.pipe()`.

lib/_http_client.js

@@ -205,7 +205,7 @@ function socketErrorListener(err) {
   var socket = this;
   var parser = socket.parser;
   var req = socket._httpMessage;
-  debug('HTTP SOCKET ERROR: ' + err.message + '\n' + err.stack);
+  debug('SOCKET ERROR:', err.message, err.stack);
 
   if (req) {
     req.emit('error', err);
@@ -325,7 +325,7 @@ function parserOnIncomingClient(res, shouldKeepAlive) {
   // to the content-length of the entity-body had the request
   // been a GET.
   var isHeadResponse = req.method == 'HEAD';
-  debug('AGENT isHeadResponse ' + isHeadResponse);
+  debug('AGENT isHeadResponse', isHeadResponse);
 
   if (res.statusCode == 100) {
     // restart the parser, as this is a continue message.

lib/_http_common.js

@@ -28,12 +28,7 @@ var readStart = incoming.readStart;
 var readStop = incoming.readStop;
 
 
-var debug;
-if (process.env.NODE_DEBUG && /http/.test(process.env.NODE_DEBUG)) {
-  debug = function(x) { console.error('HTTP: %s', x); };
-} else {
-  debug = function() { };
-}
+var debug = require('util').debuglog('http');
 exports.debug = debug;
 
 exports.CRLF = '\r\n';

lib/module.js

@@ -62,12 +62,7 @@ Module.wrap = NativeModule.wrap;
 
 var path = NativeModule.require('path');
 
-Module._debug = function() {};
-if (process.env.NODE_DEBUG && /module/.test(process.env.NODE_DEBUG)) {
-  Module._debug = function(x) {
-    console.error(x);
-  };
-}
+Module._debug = NativeModule.require('util').debuglog('module');
 
 
 // We use this alias for the preprocessor that filters it out

lib/net.js

@@ -51,20 +51,7 @@ function createHandle(fd) {
 }
 
 
-var debug;
-if (process.env.NODE_DEBUG && /net/.test(process.env.NODE_DEBUG)) {
-  var pid = process.pid;
-  debug = function(x) {
-    // if console is not set up yet, then skip this.
-    if (!console.error)
-      return;
-    console.error('NET: %d', pid,
-                  util.format.apply(util, arguments).slice(0, 500));
-  };
-} else {
-  debug = function() { };
-}
-
+var debug = util.debuglog('net');
 
 function isPipeName(s) {
   return typeof s === 'string' && toNumber(s) === false;

lib/timers.js

@@ -26,12 +26,7 @@ var assert = require('assert').ok;
 // Timeout values > TIMEOUT_MAX are set to 1.
 var TIMEOUT_MAX = 2147483647; // 2^31-1
 
-var debug;
-if (process.env.NODE_DEBUG && /timer/.test(process.env.NODE_DEBUG)) {
-  debug = function() { require('util').error.apply(this, arguments); };
-} else {
-  debug = function() { };
-}
+var debug = require('util').debuglog('timer');
 
 
 // IDLE TIMEOUTS
@@ -78,17 +73,17 @@ function listOnTimeout() {
   var msecs = this.msecs;
   var list = this;
 
-  debug('timeout callback ' + msecs);
+  debug('timeout callback %d', msecs);
 
   var now = Date.now();
-  debug('now: ' + now);
+  debug('now: %s', now);
 
   var first;
   while (first = L.peek(list)) {
     var diff = now - first._idleStart;
     if (diff < msecs) {
       list.start(msecs - diff, 0);
-      debug(msecs + ' list wait because diff is ' + diff);
+      debug('%d list wait because diff is %d', msecs, diff);
       return;
     } else {
       L.remove(first);
@@ -121,7 +116,7 @@ function listOnTimeout() {
     }
   }
 
-  debug(msecs + ' list empty');
+  debug('%d list empty', msecs);
   assert(L.isEmpty(list));
   list.close();
   delete lists[msecs];

lib/tls.js

@@ -52,13 +52,7 @@ exports.getCiphers = function() {
 };
 
 
-var debug;
-if (process.env.NODE_DEBUG && /tls/.test(process.env.NODE_DEBUG)) {
-  debug = function(a) { console.error('TLS:', a); };
-} else {
-  debug = function() { };
-}
-
+var debug = util.debuglog('tls');
 
 var Connection = null;
 try {
@@ -328,10 +322,10 @@ CryptoStream.prototype._write = function write(data, encoding, cb) {
     // Write current buffer now
     var written;
     if (this === this.pair.cleartext) {
-      debug('cleartext.write called with ' + data.length + ' bytes');
+      debug('cleartext.write called with %d bytes', data.length);
       written = this.pair.ssl.clearIn(data, 0, data.length);
     } else {
-      debug('encrypted.write called with ' + data.length + ' bytes');
+      debug('encrypted.write called with %d bytes', data.length);
       written = this.pair.ssl.encIn(data, 0, data.length);
     }
 
@@ -354,9 +348,9 @@ CryptoStream.prototype._write = function write(data, encoding, cb) {
     // Whole buffer was written
     if (written === data.length) {
       if (this === this.pair.cleartext) {
-        debug('cleartext.write succeed with ' + data.length + ' bytes');
+        debug('cleartext.write succeed with %d bytes', data.length);
       } else {
-        debug('encrypted.write succeed with ' + data.length + ' bytes');
+        debug('encrypted.write succeed with %d bytes', data.length);
       }
 
       return cb(null);
@@ -375,9 +369,9 @@ CryptoStream.prototype._write = function write(data, encoding, cb) {
   this._pendingCallback = cb;
 
   if (this === this.pair.cleartext) {
-    debug('cleartext.write queued with ' + data.length + ' bytes');
+    debug('cleartext.write queued with %d bytes', data.length);
   } else {
-    debug('encrypted.write queued with ' + data.length + ' bytes');
+    debug('encrypted.write queued with %d bytes', data.length);
   }
 };
 
@@ -404,10 +398,10 @@ CryptoStream.prototype._read = function read(size) {
 
   var out;
   if (this === this.pair.cleartext) {
-    debug('cleartext.read called with ' + size + ' bytes');
+    debug('cleartext.read called with %d bytes', size);
     out = this.pair.ssl.clearOut;
   } else {
-    debug('encrypted.read called with ' + size + ' bytes');
+    debug('encrypted.read called with %d bytes', size);
     out = this.pair.ssl.encOut;
   }
 
@@ -437,9 +431,9 @@ CryptoStream.prototype._read = function read(size) {
   assert(bytesRead >= 0);
 
   if (this === this.pair.cleartext) {
-    debug('cleartext.read succeed with ' + bytesRead + ' bytes');
+    debug('cleartext.read succeed with %d bytes', bytesRead);
   } else {
-    debug('encrypted.read succeed with ' + bytesRead + ' bytes');
+    debug('encrypted.read succeed with %d bytes', bytesRead);
   }
 
   // Try writing pending data