From a111200a5a6f504c3dbef2c5f53d6b810a0a17b7 Mon Sep 17 00:00:00 2001 From: Trent Mick Date: Mon, 1 Apr 2013 17:21:01 -0700 Subject: [PATCH] make check --- Makefile | 2 +- bin/bunyan | 321 +++++++++++++++++++++------------------ examples/long-running.js | 3 +- lib/bunyan.js | 43 ++++-- test/buffer.test.js | 11 +- test/cli.test.js | 55 ++++--- test/serializers.test.js | 12 +- test/tap4nodeunit.js | 73 +++++---- 8 files changed, 297 insertions(+), 223 deletions(-) diff --git a/Makefile b/Makefile index 2309d2c..0fe54b6 100644 --- a/Makefile +++ b/Makefile @@ -108,7 +108,7 @@ test06: .PHONY: check-jsstyle check-jsstyle: $(JSSTYLE_FILES) - ./tools/jsstyle -o indent=4,doxygen,unparenthesized-return=0,blank-after-start-comment=0,leading-right-paren-ok $(JSSTYLE_FILES) + ./tools/jsstyle -o indent=4,doxygen,unparenthesized-return=0,blank-after-start-comment=0,leading-right-paren-ok=1 $(JSSTYLE_FILES) .PHONY: check check: check-jsstyle diff --git a/bin/bunyan b/bin/bunyan index 533bc2d..f7bbb1e 100755 --- a/bin/bunyan +++ b/bin/bunyan @@ -163,79 +163,82 @@ function objCopy(obj) { } function printHelp() { - console.log('Usage:'); - console.log(' bunyan [OPTIONS] [FILE ...]'); - console.log(' ... | bunyan [OPTIONS]'); - console.log(' bunyan [OPTIONS] -p PID'); - console.log(''); - console.log('Filter and pretty-print Bunyan log file content.'); - console.log(''); - console.log('General options:'); - console.log(' -h, --help print this help info and exit'); - console.log(' --version print version of this command and exit'); - console.log(''); - console.log('Dtrace options (only on dtrace-supporting platforms):'); - console.log(' -p PID Process bunyan:log-* probes from the process'); - console.log(' with the given PID. Can be used multiple times,'); - console.log(' or specify all processes with "*", or a set of'); - console.log(' processes whose command & args match a pattern'); - console.log(' with "-p NAME".'); - console.log(''); - console.log('Filtering options:'); - console.log(' -l, --level LEVEL'); - console.log(' Only show messages at or above the specified level.'); - console.log(' You can specify level *names* or numeric values.'); - console.log(' (See "Log Levels" below.)'); - console.log(' -c, --condition CONDITION'); - console.log(' Run each log message through the condition and'); - console.log(' only show those that return truish. E.g.:'); - console.log(' -c \'this.pid == 123\''); - console.log(' -c \'this.level == DEBUG\''); - console.log(' -c \'this.msg.indexOf("boom") != -1\''); - console.log(' "CONDITION" must be legal JS code. `this` holds'); - console.log(' the log record. The TRACE, DEBUG, ... FATAL values'); - console.log(' are defined to help with comparing `this.level`.'); - console.log(' --strict Suppress all but legal Bunyan JSON log lines. By default'); - console.log(' non-JSON, and non-Bunyan lines are passed through.'); - console.log(''); - console.log('Output options:'); - console.log(' --pager Pipe output into `less` (or $PAGER if set), if'); - console.log(' stdout is a TTY. This overrides $BUNYAN_NO_PAGER.'); - console.log(' Note: Paging is only supported on node >=0.8.'); - console.log(' --no-pager Do not pipe output into a pager.'); - console.log(' --color Colorize output. Defaults to try if output'); - console.log(' stream is a TTY.'); - console.log(' --no-color Force no coloring (e.g. terminal doesn\'t support it)'); - console.log(' -o, --output MODE'); - console.log(' Specify an output mode/format. One of'); - console.log(' long: (the default) pretty'); - console.log(' json: JSON output, 2-space indent'); - console.log(' json-N: JSON output, N-space indent, e.g. "json-4"'); - console.log(' bunyan: 0 indented JSON, bunyan\'s native format'); - console.log(' inspect: node.js `util.inspect` output'); - console.log(' short: like "long", but more concise'); - console.log(' -j shortcut for `-o json`'); - console.log(''); - console.log('Log Levels:'); - console.log(' Either numeric values or their associated strings are valid for the'); - console.log(' -l|--level argument. However, -c|--condition scripts will see a numeric'); - console.log(' "level" value, not a string.'); - console.log(''); + /* BEGIN JSSTYLED */ + var p = console.log; + p('Usage:'); + p(' bunyan [OPTIONS] [FILE ...]'); + p(' ... | bunyan [OPTIONS]'); + p(' bunyan [OPTIONS] -p PID'); + p(''); + p('Filter and pretty-print Bunyan log file content.'); + p(''); + p('General options:'); + p(' -h, --help print this help info and exit'); + p(' --version print version of this command and exit'); + p(''); + p('Dtrace options (only on dtrace-supporting platforms):'); + p(' -p PID Process bunyan:log-* probes from the process'); + p(' with the given PID. Can be used multiple times,'); + p(' or specify all processes with "*", or a set of'); + p(' processes whose command & args match a pattern'); + p(' with "-p NAME".'); + p(''); + p('Filtering options:'); + p(' -l, --level LEVEL'); + p(' Only show messages at or above the specified level.'); + p(' You can specify level *names* or numeric values.'); + p(' (See "Log Levels" below.)'); + p(' -c, --condition CONDITION'); + p(' Run each log message through the condition and'); + p(' only show those that return truish. E.g.:'); + p(' -c \'this.pid == 123\''); + p(' -c \'this.level == DEBUG\''); + p(' -c \'this.msg.indexOf("boom") != -1\''); + p(' "CONDITION" must be legal JS code. `this` holds'); + p(' the log record. The TRACE, DEBUG, ... FATAL values'); + p(' are defined to help with comparing `this.level`.'); + p(' --strict Suppress all but legal Bunyan JSON log lines. By default'); + p(' non-JSON, and non-Bunyan lines are passed through.'); + p(''); + p('Output options:'); + p(' --pager Pipe output into `less` (or $PAGER if set), if'); + p(' stdout is a TTY. This overrides $BUNYAN_NO_PAGER.'); + p(' Note: Paging is only supported on node >=0.8.'); + p(' --no-pager Do not pipe output into a pager.'); + p(' --color Colorize output. Defaults to try if output'); + p(' stream is a TTY.'); + p(' --no-color Force no coloring (e.g. terminal doesn\'t support it)'); + p(' -o, --output MODE'); + p(' Specify an output mode/format. One of'); + p(' long: (the default) pretty'); + p(' json: JSON output, 2-space indent'); + p(' json-N: JSON output, N-space indent, e.g. "json-4"'); + p(' bunyan: 0 indented JSON, bunyan\'s native format'); + p(' inspect: node.js `util.inspect` output'); + p(' short: like "long", but more concise'); + p(' -j shortcut for `-o json`'); + p(''); + p('Log Levels:'); + p(' Either numeric values or their associated strings are valid for the'); + p(' -l|--level argument. However, -c|--condition scripts will see a numeric'); + p(' "level" value, not a string.'); + p(''); Object.keys(levelFromName).forEach(function (name) { var n = name; while (n.length < 6) n += ' '; - console.log(' %s %d', n, levelFromName[name]); + p(' %s %d', n, levelFromName[name]); }); - console.log(''); - console.log('Environment Variables:'); - console.log(' BUNYAN_NO_COLOR Set to a non-empty value to force no output '); - console.log(' coloring. See "--no-color".'); - console.log(' BUNYAN_NO_PAGER Disable piping output to a pager. '); - console.log(' See "--no-pager".'); - console.log(''); - console.log('See for more complete docs.'); - console.log('Please report bugs to .'); + p(''); + p('Environment Variables:'); + p(' BUNYAN_NO_COLOR Set to a non-empty value to force no output '); + p(' coloring. See "--no-color".'); + p(' BUNYAN_NO_PAGER Disable piping output to a pager. '); + p(' See "--no-pager".'); + p(''); + p('See for more complete docs.'); + p('Please report bugs to .'); + /* END JSSTYLED */ } /* @@ -289,13 +292,14 @@ function emitNextRecord(opts, stylize) for (;;) { /* - * Take a first pass through the input streams to see if we have a record - * from all of them. If not, we'll pause any streams for which we do - * already have a record (to avoid consuming excess memory) and then wait - * until we have records from the others before emitting the next record. + * Take a first pass through the input streams to see if we have a + * record from all of them. If not, we'll pause any streams for + * which we do already have a record (to avoid consuming excess + * memory) and then wait until we have records from the others + * before emitting the next record. * - * As part of the same pass, we look for the earliest record we have not yet - * emitted. + * As part of the same pass, we look for the earliest record + * we have not yet emitted. */ minfile = undefined; ready = true; @@ -307,8 +311,10 @@ function emitNextRecord(opts, stylize) break; } - if (streams[ofile].records.length > 0 && (minfile === undefined || - streams[minfile].records[0].time > streams[ofile].records[0].time)) { + if (streams[ofile].records.length > 0 && + (minfile === undefined || + streams[minfile].records[0].time > + streams[ofile].records[0].time)) { minfile = ofile; } } @@ -333,8 +339,8 @@ function emitNextRecord(opts, stylize) } /* - * Emit the next record for 'minfile', and invoke ourselves again to make - * sure we emit as many records as we can right now. + * Emit the next record for 'minfile', and invoke ourselves again to + * make sure we emit as many records as we can right now. */ rec = streams[minfile].records.shift(); emitRecord(rec.rec, rec.line, opts, stylize); @@ -373,7 +379,9 @@ function parseArgv(argv) { var newArgs = []; var optTakesArg = {'d': true, 'o': true, 'c': true, 'l': true, 'p': true}; for (var i = 0; i < args.length; i++) { - if (args[i].charAt(0) === '-' && args[i].charAt(1) !== '-' && args[i].length > 2) { + if (args[i].charAt(0) === '-' && args[i].charAt(1) !== '-' && + args[i].length > 2) + { var splitOpts = args[i].slice(1).split(''); for (var j = 0; j < splitOpts.length; j++) { newArgs.push('-' + splitOpts[j]); @@ -454,8 +462,8 @@ function parseArgv(argv) { var pid = +(pidArg); if (!isNaN(pid) || pidArg === '*') { if (parsed.pidsType && parsed.pidsType !== 'num') { - throw new Error(format( - 'cannot mix PID name and number arguments: "%s"', pidArg)); + throw new Error(format('cannot mix PID name and ' + + 'number arguments: "%s"', pidArg)); } parsed.pidsType = 'num'; if (!parsed.pids) { @@ -464,8 +472,8 @@ function parseArgv(argv) { parsed.pids.push(isNaN(pid) ? pidArg : pid); } else { if (parsed.pidsType && parsed.pidsType !== 'name') { - throw new Error(format( - 'cannot mix PID name and number arguments: "%s"', pidArg)); + throw new Error(format('cannot mix PID name and ' + + 'number arguments: "%s"', pidArg)); } parsed.pidsType = 'name'; parsed.pids = pidArg; @@ -505,6 +513,7 @@ function parseArgv(argv) { script.runInNewContext(minValidRecord); } catch (condErr) { throw new Error(format( + /* JSSTYLED */ 'CONDITION code cannot safely filter a minimal Bunyan log record\n' + ' CONDITION script:\n' + '%s\n' @@ -654,7 +663,7 @@ function emitRecord(rec, line, opts, stylize) { /* jsl:fall-thru */ case OM_LONG: - // [time] LEVEL: name[/component]/pid on hostname (src): msg* (extras...) + // [time] LEVEL: name[/comp]/pid on hostname (src): msg* (extras...) // msg* // -- // long and multi-line extras @@ -670,8 +679,8 @@ function emitRecord(rec, line, opts, stylize) { delete rec.v; /* - * We assume the Date is formatted according to ISO8601, in which case we - * can safely chop off the date information. + * We assume the Date is formatted according to ISO8601, in which + * case we can safely chop off the date information. */ if (short && rec.time[10] == 'T') { var time = rec.time.substr(11); @@ -747,10 +756,11 @@ function emitRecord(rec, line, opts, stylize) { var s = format('%s %s HTTP/%s%s', req.method, req.url, req.httpVersion || '1.1', - (headers - ? '\n' + Object.keys(headers).map( - function (h) { return h + ': ' + headers[h]; }).join('\n') - : '') + (headers ? + '\n' + Object.keys(headers).map(function (h) { + return h + ': ' + headers[h]; + }).join('\n') : + '') ); delete req.url; delete req.method; @@ -762,13 +772,15 @@ function emitRecord(rec, line, opts, stylize) { delete req.body; } if (req.trailers && Object.keys(req.trailers) > 0) { - s += '\n' + Object.keys(req.trailers).map( - function (t) { return t + ': ' + req.trailers[t]; }).join('\n'); + s += '\n' + Object.keys(req.trailers).map(function (t) { + return t + ': ' + req.trailers[t]; + }).join('\n'); } delete req.trailers; details.push(indent(s)); - // E.g. for extra 'foo' field on 'req', add 'req.foo' at top-level. - // This *does* have the potential to stomp on a literal 'req.foo' key. + // E.g. for extra 'foo' field on 'req', add 'req.foo' at + // top-level. This *does* have the potential to stomp on a + // literal 'req.foo' key. Object.keys(req).forEach(function (k) { rec['req.' + k] = req[k]; }) @@ -793,21 +805,24 @@ function emitRecord(rec, line, opts, stylize) { client_req.url, client_req.httpVersion || '1.1', hostHeaderLine, - (headers - ? Object.keys(headers).map( - function (h) { return h + ': ' + headers[h]; }).join('\n') - : '')); + (headers ? + Object.keys(headers).map( + function (h) { + return h + ': ' + headers[h]; + }).join('\n') : + '')); delete client_req.method; delete client_req.url; delete client_req.httpVersion; if (client_req.body) { - s += '\n\n' + (typeof (client_req.body) === 'object' - ? JSON.stringify(client_req.body, null, 2) : client_req.body); + s += '\n\n' + (typeof (client_req.body) === 'object' ? + JSON.stringify(client_req.body, null, 2) : + client_req.body); delete client_req.body; } - // E.g. for extra 'foo' field on 'client_req', add 'client_req.foo' at - // top-level. This *does* have the potential to stomp on a literal - // 'client_req.foo' key. + // E.g. for extra 'foo' field on 'client_req', add + // 'client_req.foo' at top-level. This *does* have the potential + // to stomp on a literal 'client_req.foo' key. Object.keys(client_req).forEach(function (k) { rec['client_req.' + k] = client_req[k]; }) @@ -844,8 +859,9 @@ function emitRecord(rec, line, opts, stylize) { if (s) { details.push(indent(s)); } - // E.g. for extra 'foo' field on 'res', add 'res.foo' at top-level. - // This *does* have the potential to stomp on a literal 'res.foo' key. + // E.g. for extra 'foo' field on 'res', add 'res.foo' at + // top-level. This *does* have the potential to stomp on a + // literal 'res.foo' key. Object.keys(res).forEach(function (k) { rec['res.' + k] = res[k]; }); @@ -868,7 +884,8 @@ function emitRecord(rec, line, opts, stylize) { if (value.indexOf('\n') !== -1 || value.length > 50) { details.push(indent(key + ': ' + value)); } else if (!stringified && (value.indexOf(' ') != -1 || - value.length === 0)) { + value.length === 0)) + { extras.push(key + '=' + JSON.stringify(value)); } else { extras.push(key + '=' + value); @@ -912,11 +929,13 @@ function emitRecord(rec, line, opts, stylize) { break; case OM_SIMPLE: + /* JSSTYLED */ // if (!isValidRecord(rec)) { return emit(line + '\n'); } - emit(format('%s - %s\n', upperNameFromLevel[rec.level] || 'LVL' + rec.level, + emit(format('%s - %s\n', + upperNameFromLevel[rec.level] || 'LVL' + rec.level, rec.msg)); break; default: @@ -1023,10 +1042,15 @@ function processPids(opts, stylize, callback) { return cb(1); } var pids = stdout.trim().split('\n') - .map(function (line) { return line.trim().split(/\s+/)[0] }) - .filter(function (pid) { return Number(pid) !== process.pid }); + .map(function (line) { + return line.trim().split(/\s+/)[0] + }) + .filter(function (pid) { + return Number(pid) !== process.pid + }); if (pids.length === 0) { - warn('bunyan: error: no matching PIDs found for "%s"', opts.pids); + warn('bunyan: error: no matching PIDs found for "%s"', + opts.pids); return cb(2); } cb(null, pids); @@ -1035,8 +1059,8 @@ function processPids(opts, stylize, callback) { } else { var regex = opts.pids; if (regex && /[a-zA-Z0-9_]/.test(regex[0])) { - // 'foo' -> '[f]oo' trick to exclude the 'grep' PID from its own - // search. + // 'foo' -> '[f]oo' trick to exclude the 'grep' PID from its + // own search. regex = '[' + regex[0] + ']' + regex.slice(1); } exec(format('ps -A -o pid,command | grep \'%s\'', regex), @@ -1047,10 +1071,15 @@ function processPids(opts, stylize, callback) { return cb(1); } var pids = stdout.trim().split('\n') - .map(function (line) { return line.trim().split(/\s+/)[0] }) - .filter(function (pid) { return Number(pid) !== process.pid }); + .map(function (line) { + return line.trim().split(/\s+/)[0]; + }) + .filter(function (pid) { + return Number(pid) !== process.pid; + }); if (pids.length === 0) { - warn('bunyan: error: no matching PIDs found for "%s"', opts.pids); + warn('bunyan: error: no matching PIDs found for "%s"', + opts.pids); return cb(2); } cb(null, pids); @@ -1105,9 +1134,10 @@ function processPids(opts, stylize, callback) { if (nodeSpawnSupportsStdio) { dtrace.on('exit', finish); } else { - // Fallback (for < v0.8) to pipe the dtrace process' stderr to this stderr. - // Wait for all of (1) process 'exit', (2) stderr 'end', and (2) stdout - // 'end' before returning to ensure all stderr is flushed (issue #54). + // Fallback (for < v0.8) to pipe the dtrace process' stderr to + // this stderr. Wait for all of (1) process 'exit', (2) stderr + // 'end', and (2) stdout 'end' before returning to ensure all + // stderr is flushed (issue #54). var returnCode = null; var eventsRemaining = 3; function countdownToFinish(code) { @@ -1249,7 +1279,8 @@ function cleanupAndExit(code, signal) { stdout.end(); pager.on('exit', function (pagerCode) { if (_DEBUG) - warn('(bunyan: pager exit -> process.exit(%s))', pagerCode || code); + warn('(bunyan: pager exit -> process.exit(%s))', + pagerCode || code); process.exit(pagerCode || code); }); } else { @@ -1278,27 +1309,28 @@ process.on('uncaughtException', function (err) { var title = encodeURIComponent(format( 'Bunyan %s crashed: %s', getVersion(), String(err))); - console.error('* * *'); - console.error('* The Bunyan CLI crashed!'); - console.error('*'); + var e = console.error; + e('* * *'); + e('* The Bunyan CLI crashed!'); + e('*'); if (err.name === 'ReferenceError' && gOptsForUncaughtException.conditions) { - console.error('* A "ReferenceError" is often the result of given'); - console.error('* `-c CONDITION` code that doesn\'t guard against undefined'); - console.error('* values. If that is not the problem:'); - console.error('*'); + e('* A "ReferenceError" is often the result of given'); + e('* `-c CONDITION` code that doesn\'t guard against undefined'); + e('* values. If that is not the problem:'); + e('*'); } - console.error('* Please report this issue and include the details below:'); - console.error('*'); - console.error('* https://github.com/trentm/node-bunyan/issues/new?title=%s', title); - console.error('*'); - console.error('* * *'); - console.error('* node version:', process.version); - console.error('* bunyan version:', getVersion()); - console.error('* argv: %j', process.argv); - console.error('* log line: %j', currLine); - console.error('* stack:'); - console.error(_indent(err.stack)); - console.error('* * *'); + e('* Please report this issue and include the details below:'); + e('*'); + e('* https://github.com/trentm/node-bunyan/issues/new?title=%s', title); + e('*'); + e('* * *'); + e('* node version:', process.version); + e('* bunyan version:', getVersion()); + e('* argv: %j', process.argv); + e('* log line: %j', currLine); + e('* stack:'); + e(_indent(err.stack)); + e('* * *'); process.exit(1); }); @@ -1356,11 +1388,11 @@ function main(argv) { var argv = pagerCmd.split(/\s+/g); var env = objCopy(process.env); if (env.LESS === undefined) { - // git's default is LESS=FRSX. I don't like the 'S' here because lines - // are *typically* wide with bunyan output and scrolling horizontally - // is a royal pain. - // Note a bug in Mac's `less -F`, such that SIGWINCH can kill it. - // If that rears too much then I'll remove 'F' from here. + // git's default is LESS=FRSX. I don't like the 'S' here because + // lines are *typically* wide with bunyan output and scrolling + // horizontally is a royal pain. Note a bug in Mac's `less -F`, + // such that SIGWINCH can kill it. If that rears too much then + // I'll remove 'F' from here. env.LESS = 'FRX'; } if (_DEBUG) warn('(pager: argv=%j, env.LESS=%j)', argv, env.LESS); @@ -1387,7 +1419,8 @@ function main(argv) { if (err.code === 'EPIPE') { drainStdoutAndExit(0); } else if (err.toString() === 'Error: This socket is closed.') { - // Could get this if the pager closes its stdin, but hasn't exited yet. + // Could get this if the pager closes its stdin, but hasn't + // exited yet. drainStdoutAndExit(1); } else { warn(err); diff --git a/examples/long-running.js b/examples/long-running.js index aa858e0..dec13d1 100644 --- a/examples/long-running.js +++ b/examples/long-running.js @@ -31,7 +31,8 @@ function randchoice(array) { //---- mainline -var words = fs.readFileSync(__dirname + '/long-running.js', 'utf8').split(/\s+/); +var words = fs.readFileSync( + __dirname + '/long-running.js', 'utf8').split(/\s+/); var levels = ['trace', 'debug', 'info', 'warn', 'error', 'fatal']; var timeout; diff --git a/lib/bunyan.js b/lib/bunyan.js index d21a183..40dcb88 100644 --- a/lib/bunyan.js +++ b/lib/bunyan.js @@ -15,7 +15,8 @@ var LOG_VERSION = 0; var xxx = function xxx(s) { // internal dev/debug logging - var args = ['XX' + 'X: '+s].concat(Array.prototype.slice.call(arguments, 1)); + var args = ['XX' + 'X: '+s].concat( + Array.prototype.slice.call(arguments, 1)); console.error.apply(this, args); }; var xxx = function xxx() {}; // comment out to turn on debug logging @@ -238,7 +239,8 @@ function Logger(options, _childOptions, _childSimple) { parent = options; options = _childOptions; if (! parent instanceof Logger) { - throw new TypeError('invalid Logger creation: do not pass a second arg'); + throw new TypeError( + 'invalid Logger creation: do not pass a second arg'); } } if (!options) { @@ -250,7 +252,8 @@ function Logger(options, _childOptions, _childSimple) { } } else { if (options.name) { - throw new TypeError('invalid options.name: child cannot set logger name'); + throw new TypeError( + 'invalid options.name: child cannot set logger name'); } } if (options.stream && options.streams) { @@ -379,10 +382,11 @@ function Logger(options, _childOptions, _childSimple) { } break; case 'rotating-file': - assert.ok(!s.stream, '"rotating-file" stream should not give a "stream"'); + assert.ok(!s.stream, + '"rotating-file" stream should not give a "stream"'); assert.ok(s.path); - assert.ok(mv, - '"rotating-file" stream type is not supported: missing "mv" module'); + assert.ok(mv, '"rotating-file" stream type is not supported: ' + + 'missing "mv" module'); s.stream = new RotatingFileStream(s); if (!s.closeOnExit) { s.closeOnExit = true; @@ -408,7 +412,8 @@ function Logger(options, _childOptions, _childSimple) { var serializer = serializers[field]; if (typeof (serializer) !== 'function') { throw new TypeError(format( - 'invalid serializer for "%s" field: must be a function', field)); + 'invalid serializer for "%s" field: must be a function', + field)); } else { self.serializers[field] = serializer; } @@ -648,8 +653,9 @@ Logger.prototype._applySerializers = function (fields, excludeFields) { fields[name] = self.serializers[name](fields[name]); } catch (err) { _warn(format('bunyan: ERROR: This should never happen. ' - + 'This is a bug in or ' - + 'in this application. Exception from "%s" Logger serializer: %s', + + 'This is a bug in ' + + 'or in this application. Exception from "%s" Logger ' + + 'serializer: %s', name, err.stack || err)); fields[name] = format('(Error in Bunyan log "%s" serializer ' + 'broke field. See stderr for details.)', name); @@ -737,11 +743,13 @@ function mkLogEmitter(minLevel) { } else { msgArgs = Array.prototype.slice.call(args, 1); } - } else if (typeof (args[0]) === 'string') { // `log.(msg, ...)` + } else if (typeof (args[0]) === 'string') { + // `log.(msg, ...)` fields = null; msgArgs = Array.prototype.slice.call(args); } else if (Buffer.isBuffer(args[0])) { // `log.(buf, ...)` - // Almost certainly an error, show `inspect(buf)`. See bunyan issue #35. + // Almost certainly an error, show `inspect(buf)`. See bunyan + // issue #35. fields = null; msgArgs = Array.prototype.slice.call(args); msgArgs[0] = util.inspect(msgArgs[0]); @@ -986,7 +994,8 @@ RotatingFileStream.prototype._setupNextRot = function () { RotatingFileStream.prototype._nextRotTime = function _nextRotTime(first) { var _DEBUG = false; - if (_DEBUG) console.log('-- _nextRotTime: %s%s', this.periodNum, this.periodScope); + if (_DEBUG) + console.log('-- _nextRotTime: %s%s', this.periodNum, this.periodScope); var d = new Date(); if (_DEBUG) console.log(' now local: %s', d); @@ -1006,8 +1015,8 @@ RotatingFileStream.prototype._nextRotTime = function _nextRotTime(first) { rotAt = this.rotAt + this.periodNum * 60 * 60 * 1000; } else { // First time: top of the next hour. - rotAt = Date.UTC(d.getUTCFullYear(), d.getUTCMonth(), d.getUTCDate(), - d.getUTCHours() + 1); + rotAt = Date.UTC(d.getUTCFullYear(), d.getUTCMonth(), + d.getUTCDate(), d.getUTCHours() + 1); } break; case 'd': @@ -1015,7 +1024,8 @@ RotatingFileStream.prototype._nextRotTime = function _nextRotTime(first) { rotAt = this.rotAt + this.periodNum * 24 * 60 * 60 * 1000; } else { // First time: start of tomorrow (i.e. at the coming midnight) UTC. - rotAt = Date.UTC(d.getUTCFullYear(), d.getUTCMonth(), d.getUTCDate() + 1); + rotAt = Date.UTC(d.getUTCFullYear(), d.getUTCMonth(), + d.getUTCDate() + 1); } break; case 'w': @@ -1030,7 +1040,8 @@ RotatingFileStream.prototype._nextRotTime = function _nextRotTime(first) { break; case 'm': if (this.rotAt) { - rotAt = Date.UTC(d.getUTCFullYear(), d.getUTCMonth() + this.periodNum, 1); + rotAt = Date.UTC(d.getUTCFullYear(), + d.getUTCMonth() + this.periodNum, 1); } else { // First time: the start of the next month. rotAt = Date.UTC(d.getUTCFullYear(), d.getUTCMonth() + 1, 1); diff --git a/test/buffer.test.js b/test/buffer.test.js index 25c7ab8..53c6376 100644 --- a/test/buffer.test.js +++ b/test/buffer.test.js @@ -43,7 +43,12 @@ var log = new bunyan.createLogger({ test('log.info(BUFFER)', function (t) { var b = new Buffer('foo'); - ['trace', 'debug', 'info', 'warn', 'error', 'fatal'].forEach(function (lvl) { + ['trace', + 'debug', + 'info', + 'warn', + 'error', + 'fatal'].forEach(function (lvl) { log[lvl].call(log, b); var rec = catcher.records[catcher.records.length - 1]; t.equal(rec.msg, inspect(b), @@ -55,8 +60,8 @@ test('log.info(BUFFER)', function (t) { log[lvl].call(log, b, 'bar'); var rec = catcher.records[catcher.records.length - 1]; - t.equal(rec.msg, inspect(b) + ' bar', - format('log.%s(BUFFER, "bar") msg is inspect(BUFFER) + " bar"', lvl)); + t.equal(rec.msg, inspect(b) + ' bar', format( + 'log.%s(BUFFER, "bar") msg is inspect(BUFFER) + " bar"', lvl)); }); t.end(); diff --git a/test/cli.test.js b/test/cli.test.js index 2d26b81..d2ba55f 100644 --- a/test/cli.test.js +++ b/test/cli.test.js @@ -78,8 +78,8 @@ test('cat simple.log', function (t) { function (err, stdout, stderr) { t.ifError(err) t.equal(stdout, - '[2012-02-08T22:56:52.856Z] INFO: myservice/123 on example.com: ' - + 'My message\n'); + /* JSSTYLED */ + '[2012-02-08T22:56:52.856Z] INFO: myservice/123 on example.com: My message\n'); t.end(); } ); @@ -89,8 +89,8 @@ test('simple.log with color', function (t) { function (err, stdout, stderr) { t.ifError(err) t.equal(stdout, - '[2012-02-08T22:56:52.856Z] \u001b[36m INFO\u001b[39m: myservice/123 ' - + 'on example.com: \u001b[36mMy message\u001b[39m\n\u001b[0m'); + /* JSSTYLED */ + '[2012-02-08T22:56:52.856Z] \u001b[36m INFO\u001b[39m: myservice/123 on example.com: \u001b[36mMy message\u001b[39m\n\u001b[0m'); t.end(); }); }); @@ -110,7 +110,8 @@ test('extrafield.log with color', function (t) { function (err, stdout, stderr) { t.ifError(err) t.equal(stdout, - '[2012-02-08T22:56:52.856Z] \u001b[36m INFO\u001b[39m: myservice/123 ' + '[2012-02-08T22:56:52.856Z] \u001b[36m INFO\u001b[39m: ' + + 'myservice/123 ' + 'on example.com: \u001b[36mMy message\u001b[39m' + '\u001b[90m (extra=field)\u001b[39m\n\u001b[0m'); t.end(); @@ -151,8 +152,8 @@ test('simple.log doesnotexist1.log doesnotexist2.log', function (t) { t.ok(err) t.equal(err.code, 2) t.equal(stdout, - '[2012-02-08T22:56:52.856Z] INFO: myservice/123 on example.com: ' - + 'My message\n'); + /* JSSTYLED */ + '[2012-02-08T22:56:52.856Z] INFO: myservice/123 on example.com: My message\n'); // Note: node v0.6.10: // ENOENT, no such file or directory 'asdf.log' // but node v0.6.14: @@ -167,10 +168,12 @@ test('simple.log doesnotexist1.log doesnotexist2.log', function (t) { }); test('multiple logs', function (t) { - exec(_('%s %s/corpus/log1.log %s/corpus/log2.log', BUNYAN, __dirname, __dirname), - function (err, stdout, stderr) { + var cmd = _('%s %s/corpus/log1.log %s/corpus/log2.log', + BUNYAN, __dirname, __dirname); + exec(cmd, function (err, stdout, stderr) { t.ifError(err); t.equal(stdout, [ + /* BEGIN JSSTYLED */ '[2012-05-08T16:57:55.586Z] INFO: agent1/73267 on headnode: message\n', '[2012-05-08T16:58:55.586Z] INFO: agent2/73267 on headnode: message\n', '[2012-05-08T17:01:49.339Z] INFO: agent2/73267 on headnode: message\n', @@ -180,16 +183,19 @@ test('multiple logs', function (t) { '[2012-05-08T17:02:49.404Z] INFO: agent1/73267 on headnode: message\n', '[2012-05-08T17:02:57.404Z] INFO: agent2/73267 on headnode: message\n', '[2012-05-08T17:08:01.105Z] INFO: agent2/76156 on headnode: message\n', + /* END JSSTYLED */ ].join('')); t.end(); }); }); test('multiple logs, bunyan format', function (t) { - exec(_('%s -o bunyan %s/corpus/log1.log %s/corpus/log2.log', BUNYAN, __dirname, __dirname), - function (err, stdout, stderr) { + var cmd = _('%s -o bunyan %s/corpus/log1.log %s/corpus/log2.log', + BUNYAN, __dirname, __dirname); + exec(cmd, function (err, stdout, stderr) { t.ifError(err); t.equal(stdout, [ + /* BEGIN JSSTYLED */ '{"name":"agent1","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T16:57:55.586Z","v":0}', '{"name":"agent2","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T16:58:55.586Z","v":0}', '{"name":"agent2","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T17:01:49.339Z","v":0}', @@ -200,6 +206,7 @@ test('multiple logs, bunyan format', function (t) { '{"name":"agent2","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T17:02:57.404Z","v":0}', '{"name":"agent2","pid":76156,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T17:08:01.105Z","v":0}', '' + /* END JSSTYLED */ ].join('\n')); t.end(); }); @@ -210,20 +217,24 @@ test('log1.log.gz', function (t) { function (err, stdout, stderr) { t.ifError(err); t.equal(stdout, [ + /* BEGIN JSSTYLED */ '[2012-05-08T16:57:55.586Z] INFO: agent1/73267 on headnode: message\n', '[2012-05-08T17:02:49.339Z] INFO: agent1/73267 on headnode: message\n', '[2012-05-08T17:02:49.404Z] INFO: agent1/73267 on headnode: message\n', '[2012-05-08T17:02:49.404Z] INFO: agent1/73267 on headnode: message\n', + /* END JSSTYLED */ ].join('')); t.end(); }); }); test('mixed text and gzip logs', function (t) { - exec(_('%s %s/corpus/log1.log.gz %s/corpus/log2.log', BUNYAN, __dirname, __dirname), - function (err, stdout, stderr) { + var cmd = _('%s %s/corpus/log1.log.gz %s/corpus/log2.log', + BUNYAN, __dirname, __dirname); + exec(cmd, function (err, stdout, stderr) { t.ifError(err); t.equal(stdout, [ + /* BEGIN JSSTYLED */ '[2012-05-08T16:57:55.586Z] INFO: agent1/73267 on headnode: message\n', '[2012-05-08T16:58:55.586Z] INFO: agent2/73267 on headnode: message\n', '[2012-05-08T17:01:49.339Z] INFO: agent2/73267 on headnode: message\n', @@ -233,6 +244,7 @@ test('mixed text and gzip logs', function (t) { '[2012-05-08T17:02:49.404Z] INFO: agent1/73267 on headnode: message\n', '[2012-05-08T17:02:57.404Z] INFO: agent2/73267 on headnode: message\n', '[2012-05-08T17:08:01.105Z] INFO: agent2/76156 on headnode: message\n', + /* END JSSTYLED */ ].join('')); t.end(); }); @@ -240,6 +252,7 @@ test('mixed text and gzip logs', function (t) { test('--level 40', function (t) { expect = [ + /* BEGIN JSSTYLED */ '# levels\n', '[2012-02-08T22:56:53.856Z] WARN: myservice/123 on example.com: My message\n', '[2012-02-08T22:56:54.856Z] ERROR: myservice/123 on example.com: My message\n', @@ -251,6 +264,7 @@ test('--level 40', function (t) { '# bogus\n', 'not a JSON line\n', '{"hi": "there"}\n' + /* END JSSTYLED */ ].join(''); exec(_('%s -l 40 %s/corpus/all.log', BUNYAN, __dirname), function (err, stdout, stderr) { @@ -268,6 +282,7 @@ test('--level 40', function (t) { test('--condition "level === 10 && pid === 123"', function (t) { var expect = [ '# levels\n', + /* JSSTYLED */ '[2012-02-08T22:56:50.856Z] TRACE: myservice/123 on example.com: My message\n', '\n', '# extra fields\n', @@ -276,12 +291,15 @@ test('--condition "level === 10 && pid === 123"', function (t) { 'not a JSON line\n', '{"hi": "there"}\n' ].join(''); - exec(_('%s -c "level === 10 && pid === 123" %s/corpus/all.log', BUNYAN, __dirname), - function (err, stdout, stderr) { + var cmd = _('%s -c "level === 10 && pid === 123" %s/corpus/all.log', + BUNYAN, __dirname); + exec(cmd, function (err, stdout, stderr) { t.ifError(err); t.equal(stdout, expect); - exec(_('%s --condition "level === 10 && pid === 123" %s/corpus/all.log', BUNYAN, __dirname), - function (err, stdout, stderr) { + var cmd = _( + '%s --condition "level === 10 && pid === 123" %s/corpus/all.log', + BUNYAN, __dirname); + exec(cmd, function (err, stdout, stderr) { t.ifError(err); t.equal(stdout, expect); t.end(); @@ -294,6 +312,7 @@ test('--condition "level === 10 && pid === 123"', function (t) { test('multiple --conditions', function (t) { var expect = [ '# levels\n', + /* JSSTYLED */ '[2012-02-08T22:56:53.856Z] WARN: myservice/1 on example.com: My message\n', '\n', '# extra fields\n', @@ -318,6 +337,7 @@ test('multiple --conditions', function (t) { // field with no 'headers'. Ditto for the 'res' field. test('robust req handling', function (t) { var expect = [ + /* BEGIN JSSTYLED */ '[2012-08-08T10:25:47.636Z] DEBUG: amon-master/12859 on 9724a190-27b6-4fd8-830b-a574f839c67d: headAgentProbes respond (req_id=cce79d15-ffc2-487c-a4e4-e940bdaac31e, route=HeadAgentProbes, contentMD5=11FxOYiYfpMxmANj4kGJzg==)', '[2012-08-08T10:25:47.637Z] INFO: amon-master/12859 on 9724a190-27b6-4fd8-830b-a574f839c67d: HeadAgentProbes handled: 200 (req_id=cce79d15-ffc2-487c-a4e4-e940bdaac31e, audit=true, remoteAddress=10.2.207.2, remotePort=50394, latency=3, secure=false, _audit=true, req.version=*)', ' HEAD /agentprobes?agent=ccf92af9-0b24-46b6-ab60-65095fdd3037 HTTP/1.1', @@ -349,6 +369,7 @@ test('robust req handling', function (t) { ' "name": "HeadAgentProbes",', ' "version": false', ' }' + /* END JSSTYLED */ ].join('\n') + '\n'; exec(_('%s %s/corpus/withreq.log', BUNYAN, __dirname), function (err, stdout, stderr) { diff --git a/test/serializers.test.js b/test/serializers.test.js index fcfbab0..f7862eb 100644 --- a/test/serializers.test.js +++ b/test/serializers.test.js @@ -71,7 +71,8 @@ test('req serializer', function (t) { var lastRecord = records[records.length-1]; t.equal(lastRecord.req.method, 'GET'); t.equal(lastRecord.req.url, theReq.url); - t.equal(lastRecord.req.remoteAddress, theReq.connection.remoteAddress); + t.equal(lastRecord.req.remoteAddress, + theReq.connection.remoteAddress); t.equal(lastRecord.req.remotePort, theReq.connection.remotePort); server.close(); t.end(); @@ -238,12 +239,14 @@ test('err serializer: long stack', function (t) { topErr = new verror.WError(midErr, 'top err'); log.info(topErr, 'the error'); var lastRecord = records[records.length-1]; - t.equal(lastRecord.err.message, topErr.message, 'WError <- WError <- TypeError'); + t.equal(lastRecord.err.message, topErr.message, + 'WError <- WError <- TypeError'); t.equal(lastRecord.err.name, topErr.name, 'WError <- WError <- TypeError'); var expectedStack = (topErr.stack + '\nCaused by: ' + midErr.stack + '\nCaused by: ' + bottomErr.stack); - t.equal(lastRecord.err.stack, expectedStack, 'WError <- WError <- TypeError'); + t.equal(lastRecord.err.stack, expectedStack, + 'WError <- WError <- TypeError'); // WError <- WError <- WError bottomErr = new verror.WError('bottom err'); @@ -251,7 +254,8 @@ test('err serializer: long stack', function (t) { topErr = new verror.WError(midErr, 'top err'); log.info(topErr, 'the error'); var lastRecord = records[records.length-1]; - t.equal(lastRecord.err.message, topErr.message, 'WError <- WError <- WError'); + t.equal(lastRecord.err.message, topErr.message, + 'WError <- WError <- WError'); t.equal(lastRecord.err.name, topErr.name, 'WError <- WError <- WError'); var expectedStack = (topErr.stack + '\nCaused by: ' + midErr.stack diff --git a/test/tap4nodeunit.js b/test/tap4nodeunit.js index 49e1b45..5c46e4d 100644 --- a/test/tap4nodeunit.js +++ b/test/tap4nodeunit.js @@ -17,46 +17,45 @@ //---- Exports module.exports = { + after: function after(teardown) { + module.parent.exports.tearDown = function _teardown(callback) { + try { + teardown.call(this, callback); + } catch (e) { + console.error('after:\n' + e.stack); + process.exit(1); + } + }; + }, - after: function after(teardown) { - module.parent.exports.tearDown = function _teardown(callback) { - try { - teardown.call(this, callback); - } catch (e) { - console.error('after:\n' + e.stack); - process.exit(1); - } - }; - }, + before: function before(setup) { + module.parent.exports.setUp = function _setup(callback) { + try { + setup.call(this, callback); + } catch (e) { + console.error('before:\n' + e.stack); + process.exit(1); + } + }; + }, - before: function before(setup) { - module.parent.exports.setUp = function _setup(callback) { - try { - setup.call(this, callback); - } catch (e) { - console.error('before:\n' + e.stack); - process.exit(1); - } - }; - }, - - test: function test(name, tester) { - module.parent.exports[name] = function _(t) { - var _done = false; - t.end = function end() { - if (!_done) { - _done = true; - t.done(); - } - }; - t.notOk = function notOk(ok, message) { - return (t.ok(!ok, message)); - }; - t.error = t.ifError; - - tester.call(this, t); - }; + test: function test(name, tester) { + module.parent.exports[name] = function _(t) { + var _done = false; + t.end = function end() { + if (!_done) { + _done = true; + t.done(); } + }; + t.notOk = function notOk(ok, message) { + return (t.ok(!ok, message)); + }; + t.error = t.ifError; + + tester.call(this, t); + }; + } };