logger.js in passenger-6.0.13

- old
+ new

@@ -12,22 +12,55 @@
     config = require('./config'),
     common = require('./common'),
     exception = require('./exception'),
     Stream = require('stream').Stream;
 
+var formatRegExp = /%[sdj%]/g;
+
 //
 // ### function Logger (options)
 // #### @options {Object} Options for this instance.
 // Constructor function for the Logger object responsible
 // for persisting log messages and metadata to one or more transports.
 //
 var Logger = exports.Logger = function (options) {
   events.EventEmitter.call(this);
+  this.configure(options);
+};
+
+//
+// Inherit from `events.EventEmitter`.
+//
+util.inherits(Logger, events.EventEmitter);
+
+//
+// ### function configure (options)
+// This will wholesale reconfigure this instance by:
+// 1. Resetting all transports. Older transports will be removed implicitly.
+// 2. Set all other options including levels, colors, rewriters, filters,
+//    exceptionHandlers, etc.
+//
+Logger.prototype.configure = function (options) {
+  var self = this;
+
+  //
+  // If we have already been setup with transports
+  // then remove them before proceeding.
+  //
+  if (Array.isArray(this._names) && this._names.length) {
+    this.clear();
+  }
+
   options = options || {};
+  this.transports = {};
+  this._names     = [];
 
-  var self = this,
-      handleExceptions = false;
+  if (options.transports) {
+    options.transports.forEach(function (transport) {
+      self.add(transport, null, true);
+    });
+  }
 
   //
   // Set Levels and default logging level
   //
   this.padLevels = options.padLevels || false;
@@ -37,127 +70,144 @@
   }
 
   //
   // Hoist other options onto this instance.
   //
+  this.id          = options.id || null;
   this.level       = options.level || 'info';
   this.emitErrs    = options.emitErrs || false;
   this.stripColors = options.stripColors || false;
   this.exitOnError = typeof options.exitOnError !== 'undefined'
     ? options.exitOnError
     : true;
 
   //
-  // Setup other intelligent default settings.
+  // Setup internal state as empty Objects even though it is
+  // defined lazily later to ensure a strong existential API contract.
   //
-  this.transports        = {};
-  this.rewriters         = [];
-  this.filters           = [];
   this.exceptionHandlers = {};
   this.profilers         = {};
-  this._names            = [];
-  this._hnames           = [];
 
-  if (options.transports) {
-    options.transports.forEach(function (transport) {
-      self.add(transport, null, true);
+  ['rewriters', 'filters'].forEach(function (kind) {
+    self[kind] = Array.isArray(options[kind])
+      ? options[kind]
+      : [];
+  });
 
-      if (transport.handleExceptions) {
-        handleExceptions = true;
-      }
-    });
-  }
-
-  if (options.rewriters) {
-    options.rewriters.forEach(function (rewriter) {
-      self.addRewriter(rewriter);
-    });
-  }
-
   if (options.exceptionHandlers) {
-    handleExceptions = true;
-    options.exceptionHandlers.forEach(function (handler) {
-      self._hnames.push(handler.name);
-      self.exceptionHandlers[handler.name] = handler;
-    });
+    this.handleExceptions(options.exceptionHandlers);
   }
-
-  if (options.handleExceptions || handleExceptions) {
-    this.handleExceptions();
-  }
 };
 
 //
-// Inherit from `events.EventEmitter`.
-//
-util.inherits(Logger, events.EventEmitter);
-
-//
-// ### function extend (target)
-// #### @target {Object} Target to extend.
-// Extends the target object with a 'log' method
-// along with a method for each level in this instance.
-//
-Logger.prototype.extend = function (target) {
-  var self = this;
-  ['log', 'profile', 'startTimer'].concat(Object.keys(this.levels)).forEach(function (method) {
-    target[method] = function () {
-      return self[method].apply(self, arguments);
-    };
-  });
-
-  return this;
-};
-
-//
 // ### function log (level, msg, [meta], callback)
 // #### @level {string} Level at which to log the message.
 // #### @msg {string} Message to log
 // #### @meta {Object} **Optional** Additional metadata to attach
 // #### @callback {function} Continuation to respond to when complete.
 // Core logging method exposed to Winston. Metadata is optional.
 //
 Logger.prototype.log = function (level) {
-  var self = this,
-      args = Array.prototype.slice.call(arguments, 1);
+  var args = Array.prototype.slice.call(arguments, 1),
+      self = this,
+      transports;
 
-  while(args[args.length - 1] === null) {
+  while (args[args.length - 1] === null) {
     args.pop();
   }
 
-  var callback = typeof args[args.length - 1] === 'function' ? args.pop() : null,
-      meta     = typeof args[args.length - 1] === 'object' && Object.prototype.toString.call(args[args.length - 1]) !== '[object RegExp]' ? args.pop() : {},
-      msg      = util.format.apply(null, args);
+  //
+  // Determining what is `meta` and what are arguments for string interpolation
+  // turns out to be VERY tricky. e.g. in the cases like this:
+  //
+  //    logger.info('No interpolation symbols', 'ok', 'why', { meta: 'is-this' });
+  //
+  var callback  = typeof args[args.length - 1] === 'function'
+    ? args.pop()
+    : null;
 
-  // If we should pad for levels, do so
-  if (this.padLevels) {
-    msg = new Array(this.levelLength - level.length + 1).join(' ') + msg;
-  }
-
-  function onError (err) {
+  //
+  // Handle errors appropriately.
+  //
+  function onError(err) {
     if (callback) {
       callback(err);
     }
     else if (self.emitErrs) {
       self.emit('error', err);
     }
   }
 
-
-  if (Object.keys(this.transports).length === 0) {
+  if (this._names.length === 0) {
     return onError(new Error('Cannot log with no transports.'));
   }
   else if (typeof self.levels[level] === 'undefined') {
     return onError(new Error('Unknown log level: ' + level));
   }
 
+  //
+  // If there are no transports that match the level
+  // then be eager and return. This could potentially be calculated
+  // during `setLevels` for more performance gains.
+  //
+  var targets = this._names.filter(function (name) {
+    var transport = self.transports[name];
+    return (transport.level && self.levels[transport.level] >= self.levels[level])
+      || (!transport.level && self.levels[self.level] >= self.levels[level]);
+  });
+
+  if (!targets.length) {
+    if (callback) { callback(); }
+    return;
+  }
+
+  //
+  // Determining what is `meta` and what are arguments for string interpolation
+  // turns out to be VERY tricky. e.g. in the cases like this:
+  //
+  //    logger.info('No interpolation symbols', 'ok', 'why', { meta: 'is-this' });
+  //
+  var msg, meta = {}, validMeta = false;
+  var hasFormat = args && args[0] && args[0].match && args[0].match(formatRegExp) !== null;
+  var tokens = (hasFormat) ? args[0].match(formatRegExp) : [];
+  var ptokens = tokens.filter(function(t) { return t === '%%' });
+  if (((args.length - 1) - (tokens.length - ptokens.length)) > 0 || args.length === 1) {
+    // last arg is meta
+    meta = args[args.length - 1] || args;
+    var metaType = Object.prototype.toString.call(meta);
+    validMeta = metaType === '[object Object]' ||
+      metaType === '[object Error]' || metaType === '[object Array]';
+    meta = validMeta ? args.pop() : {};
+  }
+  msg = util.format.apply(null, args);
+
+  //
+  // Respond to the callback.
+  //
+  function finish(err) {
+    if (callback) {
+      if (err) return callback(err);
+      callback(null, level, msg, meta);
+    }
+
+    callback = null;
+    if (!err) {
+      self.emit('logged', level, msg, meta);
+    }
+  }
+
+  // If we should pad for levels, do so
+  if (this.padLevels) {
+    msg = new Array(this.levelLength - level.length + 1).join(' ') + msg;
+  }
+
   this.rewriters.forEach(function (rewriter) {
     meta = rewriter(level, msg, meta, self);
   });
 
   this.filters.forEach(function(filter) {
-    var filtered = filter(msg, meta, level, self);
+    var filtered = filter(level, msg, meta, self);
     if (typeof filtered === 'string')
       msg = filtered;
     else {
       msg = filtered.msg;
       meta = filtered.meta;
@@ -177,44 +227,25 @@
   }
 
   //
   // Log for each transport and emit 'logging' event
   //
-  function emit(name, next) {
+  function transportLog(name, next) {
     var transport = self.transports[name];
-    if ((transport.level && self.levels[transport.level] <= self.levels[level])
-      || (!transport.level && self.levels[self.level] <= self.levels[level])) {
-      transport.log(level, msg, meta, function (err) {
-        if (err) {
-          err.transport = transport;
-          cb(err);
-          return next();
-        }
-        self.emit('logging', transport, level, msg, meta);
-        next();
-      });
-    } else {
+    transport.log(level, msg, meta, function (err) {
+      if (err) {
+        err.transport = transport;
+        finish(err);
+        return next();
+      }
+
+      self.emit('logging', transport, level, msg, meta);
       next();
-    }
+    });
   }
 
-  //
-  // Respond to the callback
-  //
-  function cb(err) {
-    if (callback) {
-      if (err) return callback(err);
-      callback(null, level, msg, meta);
-    }
-    callback = null;
-    if (!err) {
-      self.emit('logged', level, msg, meta);
-    }
-  }
-
-  async.forEach(this._names, emit, cb);
-
+  async.forEach(targets, transportLog, finish);
   return this;
 };
 
 //
 // ### function query (options, callback)
@@ -255,11 +286,11 @@
 
   //
   // Helper function to accumulate the results from
   // `queryTransport` into the `results`.
   //
-  function addResults (transport, next) {
+  function addResults(transport, next) {
     queryTransport(transport, function (err, result) {
       //
       // queryTransport could potentially invoke the callback
       // multiple times since Transport code can be unpredictable.
       //
@@ -377,12 +408,13 @@
 
   this.emit('close');
 };
 
 //
-// ### function handleExceptions ()
-// Handles `uncaughtException` events for the current process
+// ### function handleExceptions ([tr0, tr1...] || tr0, tr1, ...)
+// Handles `uncaughtException` events for the current process by
+// ADDING any handlers passed in.
 //
 Logger.prototype.handleExceptions = function () {
   var args = Array.prototype.slice.call(arguments),
       handlers = [],
       self = this;
@@ -394,10 +426,11 @@
     else {
       handlers.push(a);
     }
   });
 
+  this.exceptionHandlers = this.exceptionHandlers || {};
   handlers.forEach(function (handler) {
     self.exceptionHandlers[handler.name] = handler;
   });
 
   this._hnames = Object.keys(self.exceptionHandlers);
@@ -449,11 +482,11 @@
 
   if (!instance.name && !instance.log) {
     throw new Error('Unknown transport with no log() method');
   }
   else if (this.transports[instance.name]) {
-    throw new Error('Transport already attached: ' + instance.name);
+    throw new Error('Transport already attached: ' + instance.name + ", assign a different name");
   }
 
   this.transports[instance.name] = instance;
   this._names = Object.keys(this.transports);
 
@@ -475,40 +508,17 @@
 
   return this;
 };
 
 //
-// ### function addRewriter (transport, [options])
-// #### @transport {Transport} Prototype of the Transport object to add.
-// #### @options {Object} **Optional** Options for the Transport to add.
-// #### @instance {Boolean} **Optional** Value indicating if `transport` is already instantiated.
-// Adds a transport of the specified type to this instance.
-//
-Logger.prototype.addRewriter = function (rewriter) {
-  this.rewriters.push(rewriter);
-}
-
-//
-// ### function addFilter (filter)
-// #### @filter {function} Filter function, called with the message and
-// optional metadata as the two arguments.
-// Expected to return either the filtered message or an object with properties:
-//   - msg = the filtered message string
-//   - meta = the filtered metadata object
-//
-Logger.prototype.addFilter = function (filter) {
-  this.filters.push(filter);
-}
-
-//
 // ### function clear ()
 // Remove all transports from this instance
 //
 Logger.prototype.clear = function () {
-  for (var name in this.transports) {
+  Object.keys(this.transports).forEach(function (name) {
     this.remove({ name: name });
-  }
+  }, this);
 };
 
 //
 // ### function remove (transport)
 // #### @transport {Transport|String} Transport or Name to remove.
@@ -535,30 +545,23 @@
     instance.removeListener('error', instance._onError);
   }
   return this;
 };
 
-var ProfileHandler = function (logger) {
-  this.logger = logger;
-
-  this.start = Date.now();
-
-  this.done = function (msg) {
-    var args, callback, meta;
-    args     = Array.prototype.slice.call(arguments);
-    callback = typeof args[args.length - 1] === 'function' ? args.pop() : null;
-    meta     = typeof args[args.length - 1] === 'object' ? args.pop() : {};
-
-    meta.durationMs = (Date.now()) - this.start;
-
-    return this.logger.info(msg, meta, callback);
-  }
-}
-
+//
+// ### function startTimer ()
+// Returns an object corresponding to a specific timing. When done
+// is called the timer will finish and log the duration. e.g.:
+//
+//    timer = winston.startTimer()
+//    setTimeout(function(){
+//      timer.done("Logging message");
+//    }, 1000);
+//
 Logger.prototype.startTimer = function () {
   return new ProfileHandler(this);
-}
+};
 
 //
 // ### function profile (id, [msg, meta, callback])
 // #### @id {string} Unique id of the profiler
 // #### @msg {string} **Optional** Message to log
@@ -696,6 +699,31 @@
 //
 Logger.prototype._onError = function (transport, err) {
   if (this.emitErrs) {
     this.emit('error', err, transport);
   }
+};
+
+//
+// ### @private ProfileHandler
+// Constructor function for the ProfileHandler instance used by
+// `Logger.prototype.startTimer`. When done is called the timer
+// will finish and log the duration.
+//
+function ProfileHandler(logger) {
+  this.logger = logger;
+  this.start = Date.now();
+}
+
+//
+// ### function done (msg)
+// Ends the current timer (i.e. ProfileHandler) instance and
+// logs the `msg` along with the duration since creation.
+//
+ProfileHandler.prototype.done = function (msg) {
+  var args     = Array.prototype.slice.call(arguments),
+      callback = typeof args[args.length - 1] === 'function' ? args.pop() : null,
+      meta     = typeof args[args.length - 1] === 'object' ? args.pop() : {};
+
+  meta.duration = (Date.now()) - this.start + 'ms';
+  return this.logger.info(msg, meta, callback);
 };