support for 'raw' streams

CHANGES.md

@@ -1,6 +1,23 @@
 # bunyan Changelog
 
-## bunyan 0.8.1 (not yet released)
+## bunyan 0.9.0 (not yet released)
+
+- Add support for "raw" streams. This is a logging stream that is given
+  raw log record objects instead of a JSON-stringified string.
+
+        function Collector() {
+            this.records = [];
+        }
+        Collector.prototype.write = function (rec) {
+            this.records.push(rec);
+        }
+        var log = new Logger({
+            name: 'mylog',
+            stream: new Collector(),
+            raw: true
+        });
+
+  See "examples/raw-stream.js".
 
 - Add test/corpus/*.log files (accidentally excluded) so that test suite
   works(!).

README.md

@@ -420,7 +420,8 @@ In general streams are specified with the "streams" option:
     })
 
 For convenience, if there is only one stream, it can specified with the
-"stream" and "level" options (internal converted to a `Logger.streams`):
+"stream", "level" and "raw" options (internal converted to a
+`Logger.streams`):
 
     var log = new Logger({
       name: "foo",
@@ -439,6 +440,9 @@ If none are specified, the default is a stream on `process.stdout` at the
   file write stream.
 - `level`: The level at which logging to this stream is enabled. If not
   specified it defaults to INFO.
+- `raw`: A boolean indicating if the `write()` method of this stream should
+  be given the raw log record object instead of the JSON-stringified
+  string. See "examples/raw-stream.js".
 
 Supported stream types are:
 
@@ -467,16 +471,4 @@ MIT.
 
 # Future
 
-See "TODO.md", but basically:
-
-- Ring-buffer support for storing last N debug messages
-  (or whatever) in memory to support debugability without too much log load.
-
-- More `bunyan` output formats and filtering features.
-
-- Think about a bunyan dashboard that supports organizing and viewing logs
-  from multiple hosts and services.
-
-- Syslog support.
-
-- Some speed comparisons with others to get a feel for Bunyan's speed.
+See "TODO.md".

TODO.md

@@ -33,6 +33,12 @@
 
 # someday/maybe
 
+
+- More `bunyan` output formats and filtering features.
+- Think about a bunyan dashboard that supports organizing and viewing logs
+  from multiple hosts and services.
+- Syslog support.
+- Some speed comparisons with others to get a feel for Bunyan's speed.
 - remove "rm -rf tmp" when this fixed: <https://github.com/isaacs/npm/issues/2144>
 - what about promoting 'latency' field and making that easier?
 - `log.close` to close streams and shutdown and `this.closed`

examples/handle-fs-error.js

@@ -1,5 +1,5 @@
-// Example handling as fs error for a Bunyan-created
-// stream.
+// Example handling an fs error for a Bunyan-created
+// stream: we create a logger to a file that is read-only.
 
 var fs = require('fs');
 var path = require('path');

examples/raw-stream.js

@@ -0,0 +1,37 @@
+// Example of a "raw" stream in a Bunyan Logger. A raw stream is one to
+// which log record *objects* are written instead of the JSON-serialized
+// string.
+
+var Logger = require('../lib/bunyan');
+
+
+/**
+ * A raw Bunyan Logger stream object. It takes raw log records and writes
+ * them to stdout with an added "yo": "yo" field.
+ */
+function MyRawStream() {}
+MyRawStream.prototype.write = function (rec) {
+  if (typeof(rec) !== 'object') {
+    console.error('error: raw stream got a non-object record: %j', rec)
+  } else {
+    rec.yo = 'yo';
+    process.stdout.write(JSON.stringify(rec) + '\n');
+  }
+}
+
+
+// A Logger using the raw stream.
+var log = new Logger({
+  name: 'raw-example',
+  streams: [
+    {
+      level: "info",
+      stream: new MyRawStream(),
+      raw: true
+    },
+  ]
+});
+
+
+log.info('hi raw stream');
+log.info({foo: 'bar'}, 'added "foo" key');

lib/bunyan.js

@@ -310,6 +310,8 @@ function Logger(options, _childOptions, _childSimple) {
       self._level = s.level;
     }
 
+    s.raw = !!s.raw;
+
     switch (s.type) {
     case 'stream':
       if (!s.closeOnExit) {
@@ -360,7 +362,8 @@ function Logger(options, _childOptions, _childSimple) {
       type: 'stream',
       stream: options.stream,
       closeOnExit: false,
-      level: (options.level ? resolveLevel(options.level) : INFO)
+      level: (options.level ? resolveLevel(options.level) : INFO),
+      raw: (options.raw ? options.raw : false)
     });
   } else if (options.streams) {
     options.streams.forEach(addStream);
@@ -369,7 +372,8 @@ function Logger(options, _childOptions, _childSimple) {
       type: 'stream',
       stream: process.stdout,
       closeOnExit: false,
-      level: (options.level ? resolveLevel(options.level) : INFO)
+      level: (options.level ? resolveLevel(options.level) : INFO),
+      raw: (options.raw ? options.raw : false)
     });
   }
   if (options.serializers) {
@@ -617,6 +621,8 @@ Logger.prototype._mkRecord = function (fields, level, msgArgs) {
  * @param rec {log record}
  */
 Logger.prototype._emit = function (rec) {
+  var i;
+
   var obj = objCopy(rec[0]);
   var level = obj.level = rec[2];
   var recFields = rec[1];
@@ -639,34 +645,49 @@ Logger.prototype._emit = function (rec) {
   }
   obj.v = LOG_VERSION;
 
-  // Stringify the object. Attempt to warn/recover on error.
-  var str;
-  try {
-    str = JSON.stringify(obj) + '\n';
-  } catch (e) {
-    var src = ((obj.src && obj.src.file) ? obj.src : getCaller3Info());
-    var emsg = format('bunyan: ERROR: could not stringify log record from '
-      + '%s:%d: %s', src.file, src.line, e);
-    var eobj = objCopy(rec[0]);
-    eobj.bunyanMsg = emsg;
-    eobj.msg = obj.msg;
-    eobj.time = obj.time;
-    eobj.v = LOG_VERSION;
-    _warn(emsg, src.file, src.line);
-    try {
-      str = JSON.stringify(eobj) + '\n';
-    } catch (e2) {
-      str = JSON.stringify({bunyanMsg: emsg});
+  // Lazily determine if this Logger has non-"raw" streams. If there are
+  // any, then we need to stringify the log record.
+  if (this.haveNonRawStreams === undefined) {
+    this.haveNonRawStreams = false;
+    for (i = 0; i < this.streams.length; i++) {
+      if (!this.streams[i].raw) {
+        this.haveNonRawStreams = true;
+        break;
+      }
     }
   }
 
-  this.streams.forEach(function (s) {
-    if (s.level <= level) {
-      xxx('writing log rec "%s" to "%s" stream (%d <= %d): %s',
-        obj.msg, s.type, s.level, level, str);
-      s.stream.write(str);
+  // Stringify the object. Attempt to warn/recover on error.
+  var str;
+  if (this.haveNonRawStreams) {
+    try {
+      str = JSON.stringify(obj) + '\n';
+    } catch (e) {
+      var src = ((obj.src && obj.src.file) ? obj.src : getCaller3Info());
+      var emsg = format('bunyan: ERROR: could not stringify log record from '
+        + '%s:%d: %s', src.file, src.line, e);
+      var eobj = objCopy(rec[0]);
+      eobj.bunyanMsg = emsg;
+      eobj.msg = obj.msg;
+      eobj.time = obj.time;
+      eobj.v = LOG_VERSION;
+      _warn(emsg, src.file, src.line);
+      try {
+        str = JSON.stringify(eobj) + '\n';
+      } catch (e2) {
+        str = JSON.stringify({bunyanMsg: emsg});
+      }
     }
-  });
+  }
+
+  for (i = 0; i < this.streams.length; i++) {
+    var s = this.streams[i];
+    if (s.level <= level) {
+      xxx('writing log rec "%s" to "%s" stream (%s, %d <= %d): %j',
+        obj.msg, s.type, (s.raw ? 'raw' : 'not raw'), s.level, level, obj);
+      s.stream.write(s.raw ? obj : str);
+    }
+  };
 }
 
 

test/raw-stream.test.js

@@ -0,0 +1,127 @@
+/*
+ * Copyright (c) 2012 Trent Mick. All rights reserved.
+ *
+ * Test `raw: true` option on a Logger stream.
+ */
+
+var format = require('util').format;
+var test = require('tap').test;
+var Logger = require('../lib/bunyan');
+
+
+
+function CapturingStream(recs) {
+  this.recs = recs;
+}
+CapturingStream.prototype.write = function (rec) {
+  this.recs.push(rec);
+}
+
+
+test('raw stream', function (t) {
+  var recs = [];
+
+  var log = new Logger({
+    name: 'raw-stream-test',
+    streams: [{
+      stream: new CapturingStream(recs),
+      raw: true
+    }]
+  });
+  log.info('first');
+  log.info({two: 'deux'}, 'second');
+
+  t.equal(recs.length, 2);
+  t.equal(typeof(recs[0]), 'object', 'first rec is an object');
+  t.equal(recs[1].two, 'deux', '"two" field made it through');
+  t.end();
+});
+
+
+test('raw stream (short constructor)', function (t) {
+  var recs = [];
+
+  var log = new Logger({
+    name: 'raw-stream-test',
+    stream: new CapturingStream(recs),
+    raw: true
+  });
+  log.info('first');
+  log.info({two: 'deux'}, 'second');
+
+  t.equal(recs.length, 2);
+  t.equal(typeof(recs[0]), 'object', 'first rec is an object');
+  t.equal(recs[1].two, 'deux', '"two" field made it through');
+  t.end();
+});
+
+
+test('raw streams and regular streams can mix', function (t) {
+  var rawRecs = [];
+  var nonRawRecs = [];
+
+  var log = new Logger({
+    name: 'raw-stream-test',
+    streams: [
+      {
+        stream: new CapturingStream(rawRecs),
+        raw: true
+      },
+      {
+        stream: new CapturingStream(nonRawRecs)
+      }
+    ]
+  });
+  log.info('first');
+  log.info({two: 'deux'}, 'second');
+
+  t.equal(rawRecs.length, 2);
+  t.equal(typeof(rawRecs[0]), 'object', 'first rawRec is an object');
+  t.equal(rawRecs[1].two, 'deux', '"two" field made it through');
+
+  t.equal(nonRawRecs.length, 2);
+  t.equal(typeof(nonRawRecs[0]), 'string', 'first nonRawRec is a string');
+
+  t.end();
+});
+
+
+test('child adding a non-raw stream works', function (t) {
+  var parentRawRecs = [];
+  var rawRecs = [];
+  var nonRawRecs = [];
+
+  var logParent = new Logger({
+    name: 'raw-stream-test',
+    streams: [
+      {
+        stream: new CapturingStream(parentRawRecs),
+        raw: true
+      }
+    ]
+  });
+  var logChild = logParent.child({
+    child: true,
+    streams: [
+      {
+        stream: new CapturingStream(rawRecs),
+        raw: true
+      },
+      {
+        stream: new CapturingStream(nonRawRecs)
+      }
+    ]
+  });
+  logParent.info('first');
+  logChild.info({two: 'deux'}, 'second');
+
+  t.equal(rawRecs.length, 1,
+    format('rawRecs length should be 1 (is %d)', rawRecs.length));
+  t.equal(typeof(rawRecs[0]), 'object', 'rawRec entry is an object');
+  t.equal(rawRecs[0].two, 'deux', '"two" field made it through');
+
+  t.equal(nonRawRecs.length, 1);
+  t.equal(typeof(nonRawRecs[0]), 'string', 'first nonRawRec is a string');
+
+  t.end();
+});