bunyan - npm Package Compare versions

Comparing version 0.2.0 to 0.3.0

CHANGES.md

 # bunyan Changelog
 
+## bunyan 0.3.0
+
+- `log.child(options[, simple])` Added `simple` boolean arg. Set `true` to
+  assert that options only add fields (no config changes). Results in a 10x
+  speed increase in child creation. See "tools/timechild.js". On my Mac, 
+  "fast child" creation takes about 0.001ms. IOW, if your app is dishing
+  10,000 req/s, then creating a log child for each request will take
+  about 1% of the request time.
+- `log.clone` -> `log.child` to better reflect the relationship: streams and
+  serializers are inherited. Streams can't be removed as part of the child
+  creation. The child doesn't own the parent's streams (so can't close them).
+- Clean up Logger creation. The goal here was to ensure `log.child` usage
+  is fast. TODO: measure that.
+- Add `Logger.stdSerializers.err` serializer which is necessary to get good
+  Error object logging with node 0.6 (where core Error object properties
+  are non-enumerable).
+
+
 ## bunyan 0.2.0
@@ -4,0 +22,0 @@

examples/err.js

@@ -5,2 +5,3 @@ // Example logging an error:
 var Logger = require('../lib/bunyan');
+var util = require('util');
 
@@ -10,4 +11,3 @@ var log = new Logger({
   serializers: {
-    req: Logger.stdSerializers.req,
-    res: Logger.stdSerializers.res
+    err: Logger.stdSerializers.err,   // <--- use this
   }
@@ -30,2 +30,3 @@ });
     "stack": "TypeError: boom\n    at Object.<anonymous> (/Users/trentm/tm/node-bunyan/examples/err.js:15:9)\n    at Module._compile (module.js:411:26)\n    at Object..js (module.js:417:10)\n    at Module.load (module.js:343:31)\n    at Function._load (module.js:302:12)\n    at Array.0 (module.js:430:10)\n    at EventEmitter._tickCallback (node.js:126:26)",
+    "name": "TypeError",
     "message": "boom"
@@ -32,0 +33,0 @@ },

examples/hi.js

@@ -18,3 +18,3 @@ var Logger = require('../lib/bunyan');
 
-// Shows `log.clone(...)` to specialize a logger for a sub-component.
+// Shows `log.child(...)` to specialize a logger for a sub-component.
 console.log("\n\n")
@@ -31,5 +31,5 @@
 
-var wuzzle = new Wuzzle({log: log.clone({component: "wuzzle"})});
+var wuzzle = new Wuzzle({log: log.child({component: "wuzzle"})});
 wuzzle.woos();
 log.info("done with the wuzzle")
 

lib/bunyan.js

@@ -5,3 +5,3 @@ /*
 
-var VERSION = "0.2.0";
+var VERSION = "0.3.0";
 
@@ -32,7 +32,13 @@ // Bunyan log format version. This becomes the 'v' field on all log records.
 function objCopy(obj) {
-  var copy = {};
-  Object.keys(obj).forEach(function (k) {
-    copy[k] = obj[k];
-  });
-  return copy;
+  if (obj === null) {
+    return null;
+  } else if (Array.isArray(obj)) {
+    return obj.slice();
+  } else {
+    var copy = {};
+    Object.keys(obj).forEach(function (k) {
+      copy[k] = obj[k];
+    });
+    return copy;
+  }
 }
@@ -101,6 +107,10 @@
 
-function getLevel(nameOrNum) {
-  return (typeof(nameOrNum) === 'string'
+function resolveLevel(nameOrNum) {
+  var level = (typeof(nameOrNum) === 'string'
       ? levelFromName[nameOrNum]
       : nameOrNum);
+  if (! (TRACE <= level && level <= FATAL)) {
+    throw new Error('invalid level: ' + nameOrNum);
+  }
+  return level;
 }
@@ -116,125 +126,141 @@
  * @param options {Object} See documentation for full details. At minimum
- *    this must include a "service" string key.
- * @param _newCloneKeys {Array} Internal var. Should not be used externally.
- *    Array of new keys for this clone. This is necessary to assist with
- *    applying necessary serializers to the new keys.
+ *    this must include a "service" string key. Configuration keys:
+ *      - streams: specify the logger output streams. This is an array of
+ *        objects of the form:
+ *            {
+ *              "level": "info",          // optional, "info" default
+ *              "stream": process.stdout, // "stream" or "path" is required
+ *              "closeOnExit": false      // optional, default depends
+ *            }
+ *        See README.md for full details.
+ *      - `level`: set the level for a single output stream (cannot be used
+ *        with `streams`)
+ *      - `stream`: the output stream for a logger with just one, e.g.
+ *        `process.stdout` (cannot be used with `streams`)
+ *      - `serializers`: object mapping log record field names to
+ *        serializing functions. See README.md for details.
+ *    All other keys are log record fields.
+ *
+ * An alternative *internal* call signature is used for creating a child:
+ *    new Logger(<parent logger>, <child options>[, <child opts are simple>]);
+ *
+ * @param _childSimple (Boolean) An assertion that the given `_childOptions`
+ *    (a) only add fields (no config) and (b) no serialization handling is
+ *    required for them. IOW, this is a fast path for frequent child
+ *    creation.
  */
-function Logger(options, _newCloneKeys) {
+function Logger(options, _childOptions, _childSimple) {
   xxx('Logger start:', options)
   if (! this instanceof Logger) {
-    return new Logger(options);
+    return new Logger(options, _childOptions);
   }
   
-  var self = this;
+  // Input arg validation.
+  var parent;
+  if (_childOptions !== undefined) {
+    parent = options;
+    options = _childOptions;
+    if (! parent instanceof Logger) {
+      throw new TypeError('invalid Logger creation: do not pass a second arg');
+    }
+  }
   if (!options) {
     throw new TypeError('options (object) is required');
   }
-  if (options.stream && options.streams) {
-    throw new TypeError('can only have one of "stream" or "streams"');
+  if ((options.stream || options.level) && options.streams) {
+    throw new TypeError('cannot mix "streams" with "stream" or "level" options');
   }
-  if (_newCloneKeys && !Array.isArray(_newCloneKeys)) {
-    throw new TypeError('_newCloneKeys (Array) is an internal var');
-  }
   
-  // These are the default fields for log records (minus the attributes
-  // removed in this constructor). To allow storing raw log records
-  // (unrendered), `this.fields` must never be mutated. Create a copy for
-  // any changes.
-  this.fields = objCopy(options);
-  
-  // Extract and setup the configuration options (the remaining ones are
-  // log record fields).
-  var lowestLevel = Number.POSITIVE_INFINITY;
-  var level;
-  if (options.level) {
-    level = getLevel(options.level);
-    if (! (TRACE <= level && level <= FATAL)) {
-      throw new Error('invalid level: ' + options.level);
+  // Fast path for simple child creation.
+  if (parent && _childSimple) {
+    // Single to stream close handling that this child owns none of its
+    // streams.
+    this._isSimpleChild = true;
+
+    this.level = parent.level;
+    this.streams = parent.streams;
+    this.serializers = parent.serializers;
+    this.fields = parent.fields;
+    var names = Object.keys(options);
+    for (var i = 0; i < names.length; i++) {
+      var name = names[i];
+      this.fields[name] = options[name];
     }
-    delete this.fields.level;
-  } else {
-    level = INFO;
+    return;
   }
 
-  this.streams = [];
-  if (options.stream) {
-    this.streams.push({
-      type: "stream",
-      stream: options.stream,
-      closeOnExit: false,
-      level: level
-    });
-    if (level < lowestLevel) {
-      lowestLevel = level;
+  // Null values.
+  var self = this;
+  if (parent) {
+    this.level = parent.level;
+    this.streams = [];
+    for (var i = 0; i < parent.streams.length; i++) {
+      var s = objCopy(parent.streams[i]);
+      s.closeOnExit = false; // Don't own parent stream.
+      this.streams.push(s);
     }
-    delete this.fields.stream;
-  } else if (options.streams) {
-    options.streams.forEach(function (s) {
-      s = objCopy(s);
+    this.serializers = objCopy(parent.serializers);
+    this.fields = objCopy(parent.fields);
+  } else {
+    this.level = Number.POSITIVE_INFINITY;
+    this.streams = [];
+    this.serializers = null;
+    this.fields = {};
+  }
+  
+  // Helpers
+  function addStream(s) {
+    s = objCopy(s);
 
-      // Implicit 'type' from other args.
-      type = s.type;
-      if (!s.type) {
-        if (s.stream) {
-          s.type = "stream";
-        } else if (s.path) {
-          s.type = "file"
-        }
+    // Implicit 'type' from other args.
+    type = s.type;
+    if (!s.type) {
+      if (s.stream) {
+        s.type = "stream";
+      } else if (s.path) {
+        s.type = "file"
       }
+    }
 
-      if (s.level) {
-        s.level = getLevel(s.level);
-      } else {
-        s.level = level;
-      } 
-      if (s.level < lowestLevel) {
-        lowestLevel = s.level;
+    if (s.level) {
+      s.level = resolveLevel(s.level);
+    } else {
+      s.level = INFO;
+    }
+    if (s.level < self.level) {
+      self.level = s.level;
+    }
+
+    switch (s.type) {
+    case "stream":
+      if (!s.closeOnExit) {
+        s.closeOnExit = false;
       }
-
-      switch (s.type) {
-      case "stream":
+      break;
+    case "file":
+      if (!s.stream) {
+        s.stream = fs.createWriteStream(s.path,
+          {flags: 'a', encoding: 'utf8'});
         if (!s.closeOnExit) {
+          s.closeOnExit = true;
+        }
+      } else {
+        if (!s.closeOnExit) {
           s.closeOnExit = false;
         }
-        break;
-      case "file":
-        if (!s.stream) {
-          s.stream = fs.createWriteStream(s.path,
-            {flags: 'a', encoding: 'utf8'});
-          if (!s.closeOnExit) {
-            s.closeOnExit = true;
-          }
-        } else {
-          if (!s.closeOnExit) {
-            s.closeOnExit = false;
-          }
-        }
-        break;
-      default:
-        throw new TypeError('unknown stream type "' + s.type + '"');
       }
+      break;
+    default:
+      throw new TypeError('unknown stream type "' + s.type + '"');
+    }
 
-      self.streams.push(s);
-    });
-    delete this.fields.streams;
-  } else {
-    this.streams.push({
-      type: "stream",
-      stream: process.stdout,
-      closeOnExit: false,
-      level: level
-    });
-    if (level < lowestLevel) {
-      lowestLevel = level;
+    self.streams.push(s);
+  }
+
+  function addSerializers(serializers) {
+    if (!self.serializers) {
+      self.serializers = {};
     }
-  }
-  this.level = lowestLevel;
-  
-  delete this.fields.serializers;
-  if (!options.serializers) {
-    this.serializers = null;
-  } else {
-    this.serializers = {};
-    Object.keys(options.serializers).forEach(function (field) {
-      var serializer = options.serializers[field];
+    Object.keys(serializers).forEach(function (field) {
+      var serializer = serializers[field];
       if (typeof(serializer) !== "function") {
@@ -248,30 +274,45 @@ throw new TypeError(format(
   }
-  
+
+  // Handle *config* options.
+  if (options.stream) {
+    addStream({
+      type: "stream",
+      stream: options.stream,
+      closeOnExit: false,
+      level: (options.level ? resolveLevel(options.level) : INFO)
+    });
+  } else if (options.streams) {
+    options.streams.forEach(addStream);
+  } else if (!parent) {
+    addStream({
+      type: "stream",
+      stream: process.stdout,
+      closeOnExit: false,
+      level: (options.level ? resolveLevel(options.level) : INFO)
+    });
+  }
+  if (options.serializers) {
+    addSerializers(options.serializers);
+  }
   xxx("Logger: ", self)
   
-  // Apply serializers to initial fields.
+  // Fields.
+  // These are the default fields for log records (minus the attributes
+  // removed in this constructor). To allow storing raw log records
+  // (unrendered), `this.fields` must never be mutated. Create a copy for
+  // any changes.
+  var fields = objCopy(options);
+  delete fields.stream;
+  delete fields.level;
+  delete fields.streams;
+  delete fields.serializers;
   if (this.serializers) {
-    if (_newCloneKeys && _newCloneKeys.length > 0) {
-      // Note that this includes *config* vars send to `log.clone()` in
-      // addition to log record *fields*, so the impl. needs to handle that.
-      this._applySerializers(this.fields, _newCloneKeys);
-    } else {
-      this._applySerializers(this.fields);
-    }
+    this._applySerializers(fields);
   }
-  
-  // Automatic fields.
-  if (!this.fields.hostname) {
-    this.fields.hostname = os.hostname();
+  if (!fields.hostname) {
+    fields.hostname = os.hostname();
   }
-  
-  //XXX Turn this on or ditch it.
-  //process.on('exit', function () {
-  //  self.streams.forEach(function (s) {
-  //    if (s.closeOnExit) {
-  //      xxx("closing stream s:", s);
-  //      s.stream.end();
-  //    }
-  //  });
-  //});
+  Object.keys(fields).forEach(function (k) {
+    self.fields[k] = fields[k];
+  });
 }
@@ -281,4 +322,3 @@
 /**
- * Clone this logger to a new one, additionally adding the given config
- * options.
+ * Create a child logger, typically to add a few log record fields.
  *
@@ -288,3 +328,3 @@ * This can be useful when passing a logger to a sub-component, e.g. a
  *
- *    var wuzzleLog = log.clone({component: "wuzzle"})
+ *    var wuzzleLog = log.child({component: "wuzzle"})
  *    var wuzzle = new Wuzzle({..., log: wuzzleLog})
@@ -295,18 +335,41 @@ *
  *
- * @param options {Object} Optional. Set of options to apply to the clone.
- *    Supports the same set of options as the constructor.
+ * @param options {Object} Optional. Set of options to apply to the child.
+ *    All of the same options for a new Logger apply here. Notes:
+ *      - The parent's streams are inherited and cannot be removed in this
+ *        call.
+ *      - The parent's serializers are inherited, though can effectively be
+ *        overwritten by using duplicate keys.
+ * @param simple {Boolean} Optional. Set to true to assert that `options`
+ *    (a) only add fields (no config) and (b) no serialization handling is
+ *    required for them. IOW, this is a fast path for frequent child
+ *    creation. See "tools/timechild.js" for numbers.
  */
-Logger.prototype.clone = function (options) {
-  var cloneOptions = objCopy(this.fields);
-  cloneOptions.streams = this.streams;
-  if (options) {
-    var newCloneKeys = Object.keys(options);
-    newCloneKeys.forEach(function(k) {
-      cloneOptions[k] = options[k];
-    });
-  }
-  return new Logger(cloneOptions, newCloneKeys);
+Logger.prototype.child = function (options, simple) {
+  return new Logger(this, options || {}, simple);
 }
 
 
+///**
+// * Close this logger.
+// *
+// * This closes streams (that it owns, as per "endOnClose" attributes on
+// * streams), etc. Typically you **don't** need to bother calling this.
+// */
+//Logger.prototype.close = function () {
+//  if (this._closed) {
+//    return;
+//  }
+//  if (!this._isSimpleChild) {
+//    self.streams.forEach(function (s) {
+//      if (s.endOnClose) {
+//        xxx("closing stream s:", s);
+//        s.stream.end();
+//        s.endOnClose = false;
+//      }
+//    });
+//  }
+//  this._closed = true;
+//}
+
+
 /**
@@ -618,4 +681,20 @@ * Apply registered serializers to the appropriate keys in the given fields.
 
+// Serialize an Error object
+// (Core error properties are enumerable in node 0.4, not in 0.6).
+Logger.stdSerializers.err = function err(err) {
+  var obj = {
+    message: err.message,
+    name: err.name,
+    stack: err.stack
+  }
+  Object.keys(err).forEach(function (k) {
+    if (err[k] !== undefined) {
+      obj[k] = err[k];
+    }
+  });
+  return obj;
+};
 
 
+
 //---- Exports
@@ -622,0 +701,0 @@

package.json

 {
   "name": "bunyan",
-  "version": "0.2.0",
+  "version": "0.3.0",
   "description": "a JSON Logger library for node.js servers",
@@ -5,0 +5,0 @@ "main": "./lib/bunyan.js",

README.md

@@ -76,3 +76,3 @@ Bunyan -- a JSON Logger for node.js servers.
 
-A **`log.clone(...)`** is provided to specialize a logger for a sub-component.
+A **`log.child(...)`** is provided to specialize a logger for a sub-component.
 The following will have log records from "Wuzzle" instances use exactly the
@@ -93,3 +93,3 @@ same config as its parent, plus include the "component" field.
     
-    var wuzzle = new Wuzzle({log: log.clone({component: "wuzzle"})});
+    var wuzzle = new Wuzzle({log: log.child({component: "wuzzle"})});
     wuzzle.woos();
@@ -99,2 +99,16 @@ log.info("done with the wuzzle")
 
+An example and a hack: The [node-restify](https://github.com/mcavage/node-restify)
+framework integrates bunyan. One feature is that each restify request handler
+includes a `req.log` logger that is a:
+
+    log.child({req_id: <unique request id>}, true)
+
+Apps using restify can then use `req.log` and have all such log records
+include the unique request id (as "req_id"). Handy. *What is that `true`?* It
+is a small bunyan hack by which you can assert that you're just adding
+simple fields to the child logger. This makes `log.child` 10x faster and,
+hence, never a worry for slowing down HTTP request handling. See the
+changelog for node-bunyan 0.3.0 for details.
+
+
 Back to the `log.{trace|debug|...|fatal}(...)` API:
@@ -261,4 +275,4 @@
 - `err`: Object. A caught JS exception. Log that thing with
-  `log.error({err: err}, "oops")`! JS exceptions `JSON.stringify` quite
-  nicely so you don't need to do anything else. See "examples/err.js".
+  `log.error({err: err}, "oops")` and **use the `Logger.stdSerializers.err`**
+  serializer for it. See "examples/err.js".
 - `req_id`: String. A request identifier. Including this field in all logging
@@ -265,0 +279,0 @@ tied to handling a particular request to your server is strongly suggested.

TODO.md

@@ -1,10 +0,4 @@
-- expand set of fields: from dap
-    time, hostname
-    <https://github.com/Graylog2/graylog2-docs/wiki/GELF>
-    <http://journal.paul.querna.org/articles/2011/12/26/log-for-machines-in-json/>
-    require: facility and hostname
-    line/file: possible to get quickly with v8? Yunong asked.
-- fast clone: basically make it reasonable to clone per HTTP request.
-  Ditch mutability. Add another context (another entry in Log record tuple?)?
 - `log.close` to close streams and shutdown and `this.closed`
+- line/file: possible to get quickly with v8? Yunong asked.
+- what's the API for changing the logger/stream level(s)?
 - bunyan cli: more layouts (http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/EnhancedPatternLayout.html)
@@ -31,4 +25,2 @@ Custom log formats (in config file? in '-f' arg) using printf or hogan.js
   else, give an index... or type ... or support stream "names".
-- Logger.set to mutate config or `this.fields`
-- Logger.del to remove a field
 - "canWrite" handling for full streams. Need to buffer a la log4js
@@ -68,2 +60,4 @@ - test file log with logadm rotation: does it handle that?
     Want some way to have file/line only at certain levesl and lazily.
+- get Mark to show me dtrace provider stuff and consider adding for
+  logging, if helpful.
 - add option to "streams" to take the raw object, not serialized.
@@ -70,0 +64,0 @@ It would be a good hook for people with custom needs that Bunyan doesn't

New alerts

License Policy Violation

License

This package is not allowed per your license policy. Review the package's license to ensure compliance.

Found 1 instance in 1 package

Fixed alerts

License Policy Violation

License

This package is not allowed per your license policy. Review the package's license to ensure compliance.

Found 1 instance in 1 package

Improved metrics

Total package byte prevSize

216748

increased by2.86%

Number of package files

53

increased by1.92%

Lines of code

4490

increased by3.5%

Number of lines in readme file

331

increased by4.42%

No dependency changes