From c5ba5c0147bae1a257d30fdcf48fd14be1a50af0 Mon Sep 17 00:00:00 2001 From: Trent Mick Date: Wed, 20 Jun 2012 16:04:23 -0700 Subject: [PATCH] support for 'raw' streams --- CHANGES.md | 19 +++++- README.md | 20 ++---- TODO.md | 6 ++ examples/handle-fs-error.js | 4 +- examples/raw-stream.js | 37 +++++++++++ lib/bunyan.js | 73 +++++++++++++-------- test/raw-stream.test.js | 127 ++++++++++++++++++++++++++++++++++++ 7 files changed, 243 insertions(+), 43 deletions(-) create mode 100644 examples/raw-stream.js create mode 100644 test/raw-stream.test.js diff --git a/CHANGES.md b/CHANGES.md index 1572251..60386ab 100644 --- a/CHANGES.md +++ b/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(!). diff --git a/README.md b/README.md index b8083b7..88890f6 100644 --- a/README.md +++ b/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". diff --git a/TODO.md b/TODO.md index 58d598f..f21f639 100644 --- a/TODO.md +++ b/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: - what about promoting 'latency' field and making that easier? - `log.close` to close streams and shutdown and `this.closed` diff --git a/examples/handle-fs-error.js b/examples/handle-fs-error.js index b0aa95b..af08056 100644 --- a/examples/handle-fs-error.js +++ b/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'); diff --git a/examples/raw-stream.js b/examples/raw-stream.js new file mode 100644 index 0000000..4470f36 --- /dev/null +++ b/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'); diff --git a/lib/bunyan.js b/lib/bunyan.js index 37dc4fd..ef7c921 100644 --- a/lib/bunyan.js +++ b/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); + } + }; } diff --git a/test/raw-stream.test.js b/test/raw-stream.test.js new file mode 100644 index 0000000..65d2fb3 --- /dev/null +++ b/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(); +});