diff --git a/Makefile b/Makefile index 39296c4..2309d2c 100644 --- a/Makefile +++ b/Makefile @@ -108,7 +108,7 @@ test06: .PHONY: check-jsstyle check-jsstyle: $(JSSTYLE_FILES) - ./tools/jsstyle -o indent=2,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 $(JSSTYLE_FILES) .PHONY: check check: check-jsstyle diff --git a/bin/bunyan b/bin/bunyan index 5ad950b..533bc2d 100755 --- a/bin/bunyan +++ b/bin/bunyan @@ -14,14 +14,14 @@ var http = require('http'); var fs = require('fs'); var warn = console.warn; var child_process = require('child_process'), - spawn = child_process.spawn, - exec = child_process.exec, - execFile = child_process.execFile; + spawn = child_process.spawn, + exec = child_process.exec, + execFile = child_process.execFile; var assert = require('assert'); var nodeSpawnSupportsStdio = ( - Number(process.version.split('.')[0]) >= 0 || - Number(process.version.split('.')[1]) >= 8); + Number(process.version.split('.')[0]) >= 0 || + Number(process.version.split('.')[1]) >= 8); @@ -38,13 +38,13 @@ var OM_SIMPLE = 4; var OM_SHORT = 5; var OM_BUNYAN = 6; var OM_FROM_NAME = { - 'long': OM_LONG, - 'paul': OM_LONG, /* backward compat */ - 'json': OM_JSON, - 'inspect': OM_INSPECT, - 'simple': OM_SIMPLE, - 'short': OM_SHORT, - 'bunyan': OM_BUNYAN + 'long': OM_LONG, + 'paul': OM_LONG, /* backward compat */ + 'json': OM_JSON, + 'inspect': OM_INSPECT, + 'simple': OM_SIMPLE, + 'short': OM_SHORT, + 'bunyan': OM_BUNYAN }; @@ -57,22 +57,22 @@ var ERROR = 50; var FATAL = 60; var levelFromName = { - 'trace': TRACE, - 'debug': DEBUG, - 'info': INFO, - 'warn': WARN, - 'error': ERROR, - 'fatal': FATAL + 'trace': TRACE, + 'debug': DEBUG, + 'info': INFO, + 'warn': WARN, + 'error': ERROR, + 'fatal': FATAL }; var nameFromLevel = {}; var upperNameFromLevel = {}; var upperPaddedNameFromLevel = {}; Object.keys(levelFromName).forEach(function (name) { - var lvl = levelFromName[name]; - nameFromLevel[lvl] = name; - upperNameFromLevel[lvl] = name.toUpperCase(); - upperPaddedNameFromLevel[lvl] = ( - name.length === 4 ? ' ' : '') + name.toUpperCase(); + var lvl = levelFromName[name]; + nameFromLevel[lvl] = name; + upperNameFromLevel[lvl] = name.toUpperCase(); + upperPaddedNameFromLevel[lvl] = ( + name.length === 4 ? ' ' : '') + name.toUpperCase(); }); @@ -97,145 +97,145 @@ var stdout = process.stdout; //---- support functions function getVersion() { - return VERSION; + return VERSION; } var format = util.format; if (!format) { - /* BEGIN JSSTYLED */ - // If not node 0.6, then use its `util.format`: - // : - var inspect = util.inspect; - var formatRegExp = /%[sdj%]/g; - format = function format(f) { - if (typeof f !== 'string') { - var objects = []; - for (var i = 0; i < arguments.length; i++) { - objects.push(inspect(arguments[i])); - } - return objects.join(' '); - } + /* BEGIN JSSTYLED */ + // If not node 0.6, then use its `util.format`: + // : + var inspect = util.inspect; + var formatRegExp = /%[sdj%]/g; + format = function format(f) { + if (typeof f !== 'string') { + var objects = []; + for (var i = 0; i < arguments.length; i++) { + objects.push(inspect(arguments[i])); + } + return objects.join(' '); + } - var i = 1; - var args = arguments; - var len = args.length; - var str = String(f).replace(formatRegExp, function (x) { - if (i >= len) - return x; - switch (x) { - case '%s': return String(args[i++]); - case '%d': return Number(args[i++]); - case '%j': return JSON.stringify(args[i++]); - case '%%': return '%'; - default: - return x; - } - }); - for (var x = args[i]; i < len; x = args[++i]) { - if (x === null || typeof x !== 'object') { - str += ' ' + x; - } else { - str += ' ' + inspect(x); - } - } - return str; - }; - /* END JSSTYLED */ + var i = 1; + var args = arguments; + var len = args.length; + var str = String(f).replace(formatRegExp, function (x) { + if (i >= len) + return x; + switch (x) { + case '%s': return String(args[i++]); + case '%d': return Number(args[i++]); + case '%j': return JSON.stringify(args[i++]); + case '%%': return '%'; + default: + return x; + } + }); + for (var x = args[i]; i < len; x = args[++i]) { + if (x === null || typeof x !== 'object') { + str += ' ' + x; + } else { + str += ' ' + inspect(x); + } + } + return str; + }; + /* END JSSTYLED */ } function indent(s) { - return ' ' + s.split(/\r?\n/).join('\n '); + return ' ' + s.split(/\r?\n/).join('\n '); } function objCopy(obj) { - 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; - } + 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; + } } 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(''); - Object.keys(levelFromName).forEach(function (name) { - var n = name; - while (n.length < 6) - n += ' '; - console.log(' %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 .'); + 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(''); + Object.keys(levelFromName).forEach(function (name) { + var n = name; + while (n.length < 6) + n += ' '; + console.log(' %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 .'); } /* @@ -260,85 +260,85 @@ var streams = {}; function gotRecord(file, line, rec, opts, stylize) { - var time = new Date(rec.time); + var time = new Date(rec.time); - streams[file]['records'].push({ line: line, rec: rec, time: time }); - emitNextRecord(opts, stylize); + streams[file]['records'].push({ line: line, rec: rec, time: time }); + emitNextRecord(opts, stylize); } function filterRecord(rec, opts) { - if (opts.level && rec.level < opts.level) { - return false; - } - - if (opts.conditions) { - for (var i = 0; i < opts.conditions.length; i++) { - var pass = opts.conditions[i].runInNewContext(rec); - if (!pass) + if (opts.level && rec.level < opts.level) { return false; } - } - return true; + if (opts.conditions) { + for (var i = 0; i < opts.conditions.length; i++) { + var pass = opts.conditions[i].runInNewContext(rec); + if (!pass) + return false; + } + } + + return true; } function emitNextRecord(opts, stylize) { - var ofile, ready, minfile, rec; + var ofile, ready, minfile, rec; - 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. - * - * As part of the same pass, we look for the earliest record we have not yet - * emitted. - */ - minfile = undefined; - ready = true; - for (ofile in streams) { + 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. + * + * As part of the same pass, we look for the earliest record we have not yet + * emitted. + */ + minfile = undefined; + ready = true; + for (ofile in streams) { - if (streams[ofile].stream === null || - (!streams[ofile].done && streams[ofile].records.length === 0)) { - ready = false; - break; - } + if (streams[ofile].stream === null || + (!streams[ofile].done && streams[ofile].records.length === 0)) { + ready = false; + break; + } - if (streams[ofile].records.length > 0 && (minfile === undefined || - streams[minfile].records[0].time > streams[ofile].records[0].time)) { - minfile = ofile; - } - } - - if (!ready || minfile === undefined) { - for (ofile in streams) { - if (!streams[ofile].stream || streams[ofile].done) - continue; - - if (streams[ofile].records.length > 0) { - if (!streams[ofile].paused) { - streams[ofile].paused = true; - streams[ofile].stream.pause(); - } - } else if (streams[ofile].paused) { - streams[ofile].paused = false; - streams[ofile].stream.resume(); + if (streams[ofile].records.length > 0 && (minfile === undefined || + streams[minfile].records[0].time > streams[ofile].records[0].time)) { + minfile = ofile; + } } - } - return; + if (!ready || minfile === undefined) { + for (ofile in streams) { + if (!streams[ofile].stream || streams[ofile].done) + continue; + + if (streams[ofile].records.length > 0) { + if (!streams[ofile].paused) { + streams[ofile].paused = true; + streams[ofile].stream.pause(); + } + } else if (streams[ofile].paused) { + streams[ofile].paused = false; + streams[ofile].stream.resume(); + } + } + + return; + } + + /* + * 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); } - - /* - * 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); - } } /** @@ -354,188 +354,188 @@ function emitNextRecord(opts, stylize) * @throws {Error} If there is an error parsing argv. */ function parseArgv(argv) { - var parsed = { - args: [], - help: false, - color: null, - paginate: null, - outputMode: OM_LONG, - jsonIndent: 2, - level: null, - conditions: null, - strict: false, - pids: null, - pidsType: null - }; + var parsed = { + args: [], + help: false, + color: null, + paginate: null, + outputMode: OM_LONG, + jsonIndent: 2, + level: null, + conditions: null, + strict: false, + pids: null, + pidsType: null + }; - // Turn '-iH' into '-i -H', except for argument-accepting options. - var args = argv.slice(2); // drop ['node', 'scriptname'] - 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) { - var splitOpts = args[i].slice(1).split(''); - for (var j = 0; j < splitOpts.length; j++) { - newArgs.push('-' + splitOpts[j]); - if (optTakesArg[splitOpts[j]]) { - var optArg = splitOpts.slice(j+1).join(''); - if (optArg.length) { - newArgs.push(optArg); - } - break; - } - } - } else { - newArgs.push(args[i]); - } - } - args = newArgs; - - var condDefines = []; - Object.keys(upperNameFromLevel).forEach(function (lvl) { - condDefines.push( - format('Object.prototype.%s = %s;', upperNameFromLevel[lvl], lvl)); - }); - condDefines = condDefines.join('\n') + '\n'; - - var endOfOptions = false; - while (args.length > 0) { - var arg = args.shift(); - switch (arg) { - case '--': - endOfOptions = true; - break; - case '-h': // display help and exit - case '--help': - parsed.help = true; - break; - case '--version': - parsed.version = true; - break; - case '--strict': - parsed.strict = true; - break; - case '--color': - parsed.color = true; - break; - case '--no-color': - parsed.color = false; - break; - case '--pager': - parsed.paginate = true; - break; - case '--no-pager': - parsed.paginate = false; - break; - case '-o': - case '--output': - var name = args.shift(); - var idx = name.lastIndexOf('-'); - if (idx !== -1) { - var indentation = Number(name.slice(idx+1)); - if (! isNaN(indentation)) { - parsed.jsonIndent = indentation; - name = name.slice(0, idx); - } - } - parsed.outputMode = OM_FROM_NAME[name]; - if (parsed.outputMode === undefined) { - throw new Error('unknown output mode: "'+name+'"'); - } - break; - case '-j': // output with JSON.stringify - parsed.outputMode = OM_JSON; - break; - case '-p': - if (!parsed.pids) { - parsed.pids = []; - } - var pidArg = args.shift(); - 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)); - } - parsed.pidsType = 'num'; - if (!parsed.pids) { - parsed.pids = []; - } - parsed.pids.push(isNaN(pid) ? pidArg : pid); + // Turn '-iH' into '-i -H', except for argument-accepting options. + var args = argv.slice(2); // drop ['node', 'scriptname'] + 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) { + var splitOpts = args[i].slice(1).split(''); + for (var j = 0; j < splitOpts.length; j++) { + newArgs.push('-' + splitOpts[j]); + if (optTakesArg[splitOpts[j]]) { + var optArg = splitOpts.slice(j+1).join(''); + if (optArg.length) { + newArgs.push(optArg); + } + break; + } + } } else { - if (parsed.pidsType && parsed.pidsType !== 'name') { - throw new Error(format( - 'cannot mix PID name and number arguments: "%s"', pidArg)); - } - parsed.pidsType = 'name'; - parsed.pids = pidArg; + newArgs.push(args[i]); } - break; - case '-l': - case '--level': - var levelArg = args.shift(); - var level = +(levelArg); - if (isNaN(level)) { - level = +levelFromName[levelArg.toLowerCase()]; - } - if (isNaN(level)) { - throw new Error('unknown level value: "'+levelArg+'"'); - } - parsed.level = level; - break; - case '-c': - case '--condition': - var condition = args.shift(); - parsed.conditions = parsed.conditions || []; - var scriptName = 'bunyan-condition-'+parsed.conditions.length; - var code = condDefines + condition; - try { - var script = vm.createScript(code, scriptName); - } catch (compileErr) { - throw new Error(format('illegal CONDITION code: %s\n' - + ' CONDITION script:\n' - + '%s\n' - + ' Error:\n' - + '%s', - compileErr, indent(code), indent(compileErr.stack))); - } - - // Ensure this is a reasonably safe CONDITION. - try { - script.runInNewContext(minValidRecord); - } catch (condErr) { - throw new Error(format( - 'CONDITION code cannot safely filter a minimal Bunyan log record\n' - + ' CONDITION script:\n' - + '%s\n' - + ' Minimal Bunyan log record:\n' - + '%s\n' - + ' Filter error:\n' - + '%s', - indent(code), - indent(JSON.stringify(minValidRecord, null, 2)), - indent(condErr.stack) - )); - } - - parsed.conditions.push(script); - break; - default: // arguments - if (!endOfOptions && arg.length > 0 && arg[0] === '-') { - throw new Error('unknown option "'+arg+'"'); - } - parsed.args.push(arg); - break; } - } - //TODO: '--' handling and error on a first arg that looks like an option. + args = newArgs; - return parsed; + var condDefines = []; + Object.keys(upperNameFromLevel).forEach(function (lvl) { + condDefines.push( + format('Object.prototype.%s = %s;', upperNameFromLevel[lvl], lvl)); + }); + condDefines = condDefines.join('\n') + '\n'; + + var endOfOptions = false; + while (args.length > 0) { + var arg = args.shift(); + switch (arg) { + case '--': + endOfOptions = true; + break; + case '-h': // display help and exit + case '--help': + parsed.help = true; + break; + case '--version': + parsed.version = true; + break; + case '--strict': + parsed.strict = true; + break; + case '--color': + parsed.color = true; + break; + case '--no-color': + parsed.color = false; + break; + case '--pager': + parsed.paginate = true; + break; + case '--no-pager': + parsed.paginate = false; + break; + case '-o': + case '--output': + var name = args.shift(); + var idx = name.lastIndexOf('-'); + if (idx !== -1) { + var indentation = Number(name.slice(idx+1)); + if (! isNaN(indentation)) { + parsed.jsonIndent = indentation; + name = name.slice(0, idx); + } + } + parsed.outputMode = OM_FROM_NAME[name]; + if (parsed.outputMode === undefined) { + throw new Error('unknown output mode: "'+name+'"'); + } + break; + case '-j': // output with JSON.stringify + parsed.outputMode = OM_JSON; + break; + case '-p': + if (!parsed.pids) { + parsed.pids = []; + } + var pidArg = args.shift(); + 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)); + } + parsed.pidsType = 'num'; + if (!parsed.pids) { + parsed.pids = []; + } + 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)); + } + parsed.pidsType = 'name'; + parsed.pids = pidArg; + } + break; + case '-l': + case '--level': + var levelArg = args.shift(); + var level = +(levelArg); + if (isNaN(level)) { + level = +levelFromName[levelArg.toLowerCase()]; + } + if (isNaN(level)) { + throw new Error('unknown level value: "'+levelArg+'"'); + } + parsed.level = level; + break; + case '-c': + case '--condition': + var condition = args.shift(); + parsed.conditions = parsed.conditions || []; + var scriptName = 'bunyan-condition-'+parsed.conditions.length; + var code = condDefines + condition; + try { + var script = vm.createScript(code, scriptName); + } catch (compileErr) { + throw new Error(format('illegal CONDITION code: %s\n' + + ' CONDITION script:\n' + + '%s\n' + + ' Error:\n' + + '%s', + compileErr, indent(code), indent(compileErr.stack))); + } + + // Ensure this is a reasonably safe CONDITION. + try { + script.runInNewContext(minValidRecord); + } catch (condErr) { + throw new Error(format( + 'CONDITION code cannot safely filter a minimal Bunyan log record\n' + + ' CONDITION script:\n' + + '%s\n' + + ' Minimal Bunyan log record:\n' + + '%s\n' + + ' Filter error:\n' + + '%s', + indent(code), + indent(JSON.stringify(minValidRecord, null, 2)), + indent(condErr.stack) + )); + } + + parsed.conditions.push(script); + break; + default: // arguments + if (!endOfOptions && arg.length > 0 && arg[0] === '-') { + throw new Error('unknown option "'+arg+'"'); + } + parsed.args.push(arg); + break; + } + } + //TODO: '--' handling and error on a first arg that looks like an option. + + return parsed; } function isInteger(s) { - return (s.search(/^-?[0-9]+$/) == 0); + return (s.search(/^-?[0-9]+$/) == 0); } @@ -544,35 +544,35 @@ function isInteger(s) { // - Good: cyan, yellow (limited use), grey, bold, green, magenta, red // - Bad: blue (not visible on cmd.exe) var colors = { - 'bold' : [1, 22], - 'italic' : [3, 23], - 'underline' : [4, 24], - 'inverse' : [7, 27], - 'white' : [37, 39], - 'grey' : [90, 39], - 'black' : [30, 39], - 'blue' : [34, 39], - 'cyan' : [36, 39], - 'green' : [32, 39], - 'magenta' : [35, 39], - 'red' : [31, 39], - 'yellow' : [33, 39] + 'bold' : [1, 22], + 'italic' : [3, 23], + 'underline' : [4, 24], + 'inverse' : [7, 27], + 'white' : [37, 39], + 'grey' : [90, 39], + 'black' : [30, 39], + 'blue' : [34, 39], + 'cyan' : [36, 39], + 'green' : [32, 39], + 'magenta' : [35, 39], + 'red' : [31, 39], + 'yellow' : [33, 39] }; function stylizeWithColor(str, color) { - if (!str) - return ''; - var codes = colors[color]; - if (codes) { - return '\033[' + codes[0] + 'm' + str + - '\033[' + codes[1] + 'm'; - } else { - return str; - } + if (!str) + return ''; + var codes = colors[color]; + if (codes) { + return '\033[' + codes[0] + 'm' + str + + '\033[' + codes[1] + 'm'; + } else { + return str; + } } function stylizeWithoutColor(str, color) { - return str; + return str; } @@ -580,27 +580,27 @@ function stylizeWithoutColor(str, color) { * Is this a valid Bunyan log record. */ function isValidRecord(rec) { - if (rec.v == null || - rec.level == null || - rec.name == null || - rec.hostname == null || - rec.pid == null || - rec.time == null || - rec.msg == null) { - // Not valid Bunyan log. - return false; - } else { - return true; - } + if (rec.v == null || + rec.level == null || + rec.name == null || + rec.hostname == null || + rec.pid == null || + rec.time == null || + rec.msg == null) { + // Not valid Bunyan log. + return false; + } else { + return true; + } } var minValidRecord = { - v: 0, //TODO: get this from bunyan.LOG_VERSION - level: INFO, - name: 'name', - hostname: 'hostname', - pid: 123, - time: Date.now(), - msg: 'msg' + v: 0, //TODO: get this from bunyan.LOG_VERSION + level: INFO, + name: 'name', + hostname: 'hostname', + pid: 123, + time: Date.now(), + msg: 'msg' }; @@ -609,329 +609,329 @@ var minValidRecord = { * records) or enqueues it for emitting later when it's the next line to show. */ function handleLogLine(file, line, opts, stylize) { - currLine = line; // intentionally global + currLine = line; // intentionally global - // Emit non-JSON lines immediately. - var rec; - if (!line) { - if (!opts.strict) emit(line + '\n'); - return; - } else if (line[0] !== '{') { - if (!opts.strict) emit(line + '\n'); // not JSON - return; - } else { - try { - rec = JSON.parse(line); - } catch (e) { - if (!opts.strict) emit(line + '\n'); - return; + // Emit non-JSON lines immediately. + var rec; + if (!line) { + if (!opts.strict) emit(line + '\n'); + return; + } else if (line[0] !== '{') { + if (!opts.strict) emit(line + '\n'); // not JSON + return; + } else { + try { + rec = JSON.parse(line); + } catch (e) { + if (!opts.strict) emit(line + '\n'); + return; + } } - } - if (!isValidRecord(rec)) { - if (!opts.strict) emit(line + '\n'); - return; - } + if (!isValidRecord(rec)) { + if (!opts.strict) emit(line + '\n'); + return; + } - if (!filterRecord(rec, opts)) - return; + if (!filterRecord(rec, opts)) + return; - if (file === null) - return emitRecord(rec, line, opts, stylize); + if (file === null) + return emitRecord(rec, line, opts, stylize); - return gotRecord(file, line, rec, opts, stylize); + return gotRecord(file, line, rec, opts, stylize); } /** * Print out a single result, considering input options. */ function emitRecord(rec, line, opts, stylize) { - var short = false; + var short = false; - switch (opts.outputMode) { - case OM_SHORT: - short = true; - /* jsl:fall-thru */ + switch (opts.outputMode) { + case OM_SHORT: + short = true; + /* jsl:fall-thru */ - case OM_LONG: - // [time] LEVEL: name[/component]/pid on hostname (src): msg* (extras...) - // msg* - // -- - // long and multi-line extras - // ... - // If 'msg' is single-line, then it goes in the top line. - // If 'req', show the request. - // If 'res', show the response. - // If 'err' and 'err.stack' then show that. - if (!isValidRecord(rec)) { - return emit(line + '\n'); - } - - delete rec.v; - - /* - * 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); - time = stylize(time, 'XXX'); - } else { - var time = stylize('[' + rec.time + ']', 'XXX'); - } - - delete rec.time; - - var nameStr = rec.name; - delete rec.name; - - if (rec.component) { - nameStr += '/' + rec.component; - } - delete rec.component; - - if (!short) - nameStr += '/' + rec.pid; - delete rec.pid; - - var level = (upperPaddedNameFromLevel[rec.level] || 'LVL' + rec.level); - if (opts.color) { - var colorFromLevel = { - 10: 'grey', // TRACE - 20: 'grey', // DEBUG - 30: 'cyan', // INFO - 40: 'magenta', // WARN - 50: 'red', // ERROR - 60: 'inverse', // FATAL - }; - level = stylize(level, colorFromLevel[rec.level]); - } - delete rec.level; - - var src = ''; - if (rec.src && rec.src.file) { - var s = rec.src; - if (s.func) { - src = format(' (%s:%d in %s)', s.file, s.line, s.func); - } else { - src = format(' (%s:%d)', s.file, s.line); - } - src = stylize(src, 'green'); - } - delete rec.src; - - var hostname = rec.hostname; - delete rec.hostname; - - var extras = []; - var details = []; - - if (rec.req_id) { - extras.push('req_id=' + rec.req_id); - } - delete rec.req_id; - - var onelineMsg; - if (rec.msg.indexOf('\n') !== -1) { - onelineMsg = ''; - details.push(indent(stylize(rec.msg, 'cyan'))); - } else { - onelineMsg = ' ' + stylize(rec.msg, 'cyan'); - } - delete rec.msg; - - if (rec.req && typeof (rec.req) === 'object') { - var req = rec.req; - delete rec.req; - var headers = req.headers; - 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') - : '') - ); - delete req.url; - delete req.method; - delete req.httpVersion; - delete req.headers; - if (req.body) { - s += '\n\n' + (typeof (req.body) === 'object' - ? JSON.stringify(req.body, null, 2) : req.body); - 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'); - } - 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. - Object.keys(req).forEach(function (k) { - rec['req.' + k] = req[k]; - }) - } - - if (rec.client_req && typeof (rec.client_req) === 'object') { - var client_req = rec.client_req; - delete rec.client_req; - var headers = client_req.headers; - var hostHeaderLine = ''; - var s = ''; - if (client_req.address) { - hostHeaderLine = 'Host: ' + client_req.address; - if (client_req.port) - hostHeaderLine += ':' + client_req.port; - hostHeaderLine += '\n'; - } - delete client_req.headers; - delete client_req.address; - delete client_req.port; - s += format('%s %s HTTP/%s\n%s%s', client_req.method, - client_req.url, - client_req.httpVersion || '1.1', - hostHeaderLine, - (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); - 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. - Object.keys(client_req).forEach(function (k) { - rec['client_req.' + k] = client_req[k]; - }) - details.push(indent(s)); - } - - if (rec.res && typeof (rec.res) === 'object') { - var res = rec.res; - delete rec.res; - var s = ''; - if (res.header) { - s += res.header.trimRight(); - } else if (res.headers) { - if (res.statusCode) { - s += format('HTTP/1.1 %s %s\n', res.statusCode, - http.STATUS_CODES[res.statusCode]); + case OM_LONG: + // [time] LEVEL: name[/component]/pid on hostname (src): msg* (extras...) + // msg* + // -- + // long and multi-line extras + // ... + // If 'msg' is single-line, then it goes in the top line. + // If 'req', show the request. + // If 'res', show the response. + // If 'err' and 'err.stack' then show that. + if (!isValidRecord(rec)) { + return emit(line + '\n'); } - var headers = res.headers; - s += Object.keys(headers).map( - function (h) { return h + ': ' + headers[h]; }).join('\n'); - } - delete res.header; - delete res.headers; - delete res.statusCode; - if (res.body) { - s += '\n\n' + (typeof (res.body) === 'object' - ? JSON.stringify(res.body, null, 2) : res.body); - delete res.body; - } - if (res.trailer) { - s += '\n' + res.trailer; - } - delete res.trailer; - 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. - Object.keys(res).forEach(function (k) { - rec['res.' + k] = res[k]; - }); + + delete rec.v; + + /* + * 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); + time = stylize(time, 'XXX'); + } else { + var time = stylize('[' + rec.time + ']', 'XXX'); + } + + delete rec.time; + + var nameStr = rec.name; + delete rec.name; + + if (rec.component) { + nameStr += '/' + rec.component; + } + delete rec.component; + + if (!short) + nameStr += '/' + rec.pid; + delete rec.pid; + + var level = (upperPaddedNameFromLevel[rec.level] || 'LVL' + rec.level); + if (opts.color) { + var colorFromLevel = { + 10: 'grey', // TRACE + 20: 'grey', // DEBUG + 30: 'cyan', // INFO + 40: 'magenta', // WARN + 50: 'red', // ERROR + 60: 'inverse', // FATAL + }; + level = stylize(level, colorFromLevel[rec.level]); + } + delete rec.level; + + var src = ''; + if (rec.src && rec.src.file) { + var s = rec.src; + if (s.func) { + src = format(' (%s:%d in %s)', s.file, s.line, s.func); + } else { + src = format(' (%s:%d)', s.file, s.line); + } + src = stylize(src, 'green'); + } + delete rec.src; + + var hostname = rec.hostname; + delete rec.hostname; + + var extras = []; + var details = []; + + if (rec.req_id) { + extras.push('req_id=' + rec.req_id); + } + delete rec.req_id; + + var onelineMsg; + if (rec.msg.indexOf('\n') !== -1) { + onelineMsg = ''; + details.push(indent(stylize(rec.msg, 'cyan'))); + } else { + onelineMsg = ' ' + stylize(rec.msg, 'cyan'); + } + delete rec.msg; + + if (rec.req && typeof (rec.req) === 'object') { + var req = rec.req; + delete rec.req; + var headers = req.headers; + 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') + : '') + ); + delete req.url; + delete req.method; + delete req.httpVersion; + delete req.headers; + if (req.body) { + s += '\n\n' + (typeof (req.body) === 'object' + ? JSON.stringify(req.body, null, 2) : req.body); + 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'); + } + 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. + Object.keys(req).forEach(function (k) { + rec['req.' + k] = req[k]; + }) + } + + if (rec.client_req && typeof (rec.client_req) === 'object') { + var client_req = rec.client_req; + delete rec.client_req; + var headers = client_req.headers; + var hostHeaderLine = ''; + var s = ''; + if (client_req.address) { + hostHeaderLine = 'Host: ' + client_req.address; + if (client_req.port) + hostHeaderLine += ':' + client_req.port; + hostHeaderLine += '\n'; + } + delete client_req.headers; + delete client_req.address; + delete client_req.port; + s += format('%s %s HTTP/%s\n%s%s', client_req.method, + client_req.url, + client_req.httpVersion || '1.1', + hostHeaderLine, + (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); + 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. + Object.keys(client_req).forEach(function (k) { + rec['client_req.' + k] = client_req[k]; + }) + details.push(indent(s)); + } + + if (rec.res && typeof (rec.res) === 'object') { + var res = rec.res; + delete rec.res; + var s = ''; + if (res.header) { + s += res.header.trimRight(); + } else if (res.headers) { + if (res.statusCode) { + s += format('HTTP/1.1 %s %s\n', res.statusCode, + http.STATUS_CODES[res.statusCode]); + } + var headers = res.headers; + s += Object.keys(headers).map( + function (h) { return h + ': ' + headers[h]; }).join('\n'); + } + delete res.header; + delete res.headers; + delete res.statusCode; + if (res.body) { + s += '\n\n' + (typeof (res.body) === 'object' + ? JSON.stringify(res.body, null, 2) : res.body); + delete res.body; + } + if (res.trailer) { + s += '\n' + res.trailer; + } + delete res.trailer; + 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. + Object.keys(res).forEach(function (k) { + rec['res.' + k] = res[k]; + }); + } + + if (rec.err && rec.err.stack) { + details.push(indent(rec.err.stack)); + delete rec.err; + } + + var leftover = Object.keys(rec); + for (var i = 0; i < leftover.length; i++) { + var key = leftover[i]; + var value = rec[key]; + var stringified = false; + if (typeof (value) !== 'string') { + value = JSON.stringify(value, null, 2); + stringified = true; + } + if (value.indexOf('\n') !== -1 || value.length > 50) { + details.push(indent(key + ': ' + value)); + } else if (!stringified && (value.indexOf(' ') != -1 || + value.length === 0)) { + extras.push(key + '=' + JSON.stringify(value)); + } else { + extras.push(key + '=' + value); + } + } + + extras = stylize( + (extras.length ? ' (' + extras.join(', ') + ')' : ''), 'grey'); + details = stylize( + (details.length ? details.join('\n --\n') + '\n' : ''), 'grey'); + if (!short) + emit(format('%s %s: %s on %s%s:%s%s\n%s', + time, + level, + nameStr, + hostname || '', + src, + onelineMsg, + extras, + details)); + else + emit(format('%s %s %s:%s%s\n%s', + time, + level, + nameStr, + onelineMsg, + extras, + details)); + break; + + case OM_INSPECT: + emit(util.inspect(rec, false, Infinity, true) + '\n'); + break; + + case OM_BUNYAN: + emit(JSON.stringify(rec, null, 0) + '\n'); + break; + + case OM_JSON: + emit(JSON.stringify(rec, null, opts.jsonIndent) + '\n'); + break; + + case OM_SIMPLE: + // + if (!isValidRecord(rec)) { + return emit(line + '\n'); + } + emit(format('%s - %s\n', upperNameFromLevel[rec.level] || 'LVL' + rec.level, + rec.msg)); + break; + default: + throw new Error('unknown output mode: '+opts.outputMode); } - - if (rec.err && rec.err.stack) { - details.push(indent(rec.err.stack)); - delete rec.err; - } - - var leftover = Object.keys(rec); - for (var i = 0; i < leftover.length; i++) { - var key = leftover[i]; - var value = rec[key]; - var stringified = false; - if (typeof (value) !== 'string') { - value = JSON.stringify(value, null, 2); - stringified = true; - } - if (value.indexOf('\n') !== -1 || value.length > 50) { - details.push(indent(key + ': ' + value)); - } else if (!stringified && (value.indexOf(' ') != -1 || - value.length === 0)) { - extras.push(key + '=' + JSON.stringify(value)); - } else { - extras.push(key + '=' + value); - } - } - - extras = stylize( - (extras.length ? ' (' + extras.join(', ') + ')' : ''), 'grey'); - details = stylize( - (details.length ? details.join('\n --\n') + '\n' : ''), 'grey'); - if (!short) - emit(format('%s %s: %s on %s%s:%s%s\n%s', - time, - level, - nameStr, - hostname || '', - src, - onelineMsg, - extras, - details)); - else - emit(format('%s %s %s:%s%s\n%s', - time, - level, - nameStr, - onelineMsg, - extras, - details)); - break; - - case OM_INSPECT: - emit(util.inspect(rec, false, Infinity, true) + '\n'); - break; - - case OM_BUNYAN: - emit(JSON.stringify(rec, null, 0) + '\n'); - break; - - case OM_JSON: - emit(JSON.stringify(rec, null, opts.jsonIndent) + '\n'); - break; - - case OM_SIMPLE: - // - if (!isValidRecord(rec)) { - return emit(line + '\n'); - } - emit(format('%s - %s\n', upperNameFromLevel[rec.level] || 'LVL' + rec.level, - rec.msg)); - break; - default: - throw new Error('unknown output mode: '+opts.outputMode); - } } var stdoutFlushed = true; function emit(s) { - try { - stdoutFlushed = stdout.write(s); - } catch (e) { - // Handle any exceptions in stdout writing in `stdout.on('error', ...)`. - } + try { + stdoutFlushed = stdout.write(s); + } catch (e) { + // Handle any exceptions in stdout writing in `stdout.on('error', ...)`. + } } @@ -946,13 +946,13 @@ function emit(s) { * still be necessary in a shell pipeline. */ function drainStdoutAndExit(code) { - if (_DEBUG) warn('(drainStdoutAndExit(%d))', code); - stdout.on('drain', function () { - cleanupAndExit(code); - }); - if (stdoutFlushed) { - cleanupAndExit(code); - } + if (_DEBUG) warn('(drainStdoutAndExit(%d))', code); + stdout.on('drain', function () { + cleanupAndExit(code); + }); + if (stdoutFlushed) { + cleanupAndExit(code); + } } @@ -964,34 +964,34 @@ function drainStdoutAndExit(code) { * @param callback {Function} `function ()` */ function processStdin(opts, stylize, callback) { - var leftover = ''; // Left-over partial line from last chunk. - var stdin = process.stdin; - stdin.resume(); - stdin.setEncoding('utf8'); - stdin.on('data', function (chunk) { - var lines = chunk.split(/\r\n|\n/); - var length = lines.length; - if (length === 1) { - leftover += lines[0]; - return; - } + var leftover = ''; // Left-over partial line from last chunk. + var stdin = process.stdin; + stdin.resume(); + stdin.setEncoding('utf8'); + stdin.on('data', function (chunk) { + var lines = chunk.split(/\r\n|\n/); + var length = lines.length; + if (length === 1) { + leftover += lines[0]; + return; + } - if (length > 1) { - handleLogLine(null, leftover + lines[0], opts, stylize); - } - leftover = lines.pop(); - length -= 1; - for (var i = 1; i < length; i++) { - handleLogLine(null, lines[i], opts, stylize); - } - }); - stdin.on('end', function () { - if (leftover) { - handleLogLine(null, leftover, opts, stylize); - leftover = ''; - } - callback(); - }); + if (length > 1) { + handleLogLine(null, leftover + lines[0], opts, stylize); + } + leftover = lines.pop(); + length -= 1; + for (var i = 1; i < length; i++) { + handleLogLine(null, lines[i], opts, stylize); + } + }); + stdin.on('end', function () { + if (leftover) { + handleLogLine(null, leftover, opts, stylize); + leftover = ''; + } + callback(); + }); } @@ -1003,126 +1003,126 @@ function processStdin(opts, stylize, callback) { * @param callback {Function} `function (code)` */ function processPids(opts, stylize, callback) { - var leftover = ''; // Left-over partial line from last chunk. + var leftover = ''; // Left-over partial line from last chunk. - /** - * Get the PIDs to dtrace. - * - * @param cb {Function} `function (errCode, pids)` - */ - function getPids(cb) { - if (opts.pidsType === 'num') { - return cb(null, opts.pids); - } - if (process.platform === 'sunos') { - execFile('/bin/pgrep', ['-lf', opts.pids], - function (pidsErr, stdout, stderr) { - if (pidsErr) { - warn('bunyan: error getting PIDs for "%s": %s\n%s\n%s', - opts.pids, pidsErr.message, stdout, stderr); - 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 }); - if (pids.length === 0) { - warn('bunyan: error: no matching PIDs found for "%s"', opts.pids); - return cb(2); - } - cb(null, pids); + /** + * Get the PIDs to dtrace. + * + * @param cb {Function} `function (errCode, pids)` + */ + function getPids(cb) { + if (opts.pidsType === 'num') { + return cb(null, opts.pids); } - ); - } 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. - regex = '[' + regex[0] + ']' + regex.slice(1); - } - exec(format('ps -A -o pid,command | grep \'%s\'', regex), - function (pidsErr, stdout, stderr) { - if (pidsErr) { - warn('bunyan: error getting PIDs for "%s": %s\n%s\n%s', - opts.pids, pidsErr.message, stdout, stderr); - 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 }); - if (pids.length === 0) { - warn('bunyan: error: no matching PIDs found for "%s"', opts.pids); - return cb(2); - } - cb(null, pids); + if (process.platform === 'sunos') { + execFile('/bin/pgrep', ['-lf', opts.pids], + function (pidsErr, stdout, stderr) { + if (pidsErr) { + warn('bunyan: error getting PIDs for "%s": %s\n%s\n%s', + opts.pids, pidsErr.message, stdout, stderr); + 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 }); + if (pids.length === 0) { + warn('bunyan: error: no matching PIDs found for "%s"', opts.pids); + return cb(2); + } + cb(null, pids); + } + ); + } 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. + regex = '[' + regex[0] + ']' + regex.slice(1); + } + exec(format('ps -A -o pid,command | grep \'%s\'', regex), + function (pidsErr, stdout, stderr) { + if (pidsErr) { + warn('bunyan: error getting PIDs for "%s": %s\n%s\n%s', + opts.pids, pidsErr.message, stdout, stderr); + 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 }); + if (pids.length === 0) { + warn('bunyan: error: no matching PIDs found for "%s"', opts.pids); + return cb(2); + } + cb(null, pids); + } + ); } - ); - } - } - - getPids(function (errCode, pids) { - if (errCode) { - return callback(errCode); } - var probes = pids.map(function (pid) { - return format('bunyan%s:::log-*', pid); - }).join(','); - var argv = ['dtrace', '-Z', '-x', 'strsize=4k', '-qn', - format('%s{printf("%s", copyinstr(arg0))}', probes)]; - //console.log('dtrace argv: %s', argv); - var dtrace = spawn(argv[0], argv.slice(1), - // Share the stderr handle to have error output come - // straight through. Only supported in v0.8+. - {stdio: ['pipe', 'pipe', process.stderr]}); - child = dtrace; // intentionally global + getPids(function (errCode, pids) { + if (errCode) { + return callback(errCode); + } - function finish(code) { - if (leftover) { - handleLogLine(null, leftover, opts, stylize); - leftover = ''; - } - callback(returnCode); - } + var probes = pids.map(function (pid) { + return format('bunyan%s:::log-*', pid); + }).join(','); + var argv = ['dtrace', '-Z', '-x', 'strsize=4k', '-qn', + format('%s{printf("%s", copyinstr(arg0))}', probes)]; + //console.log('dtrace argv: %s', argv); + var dtrace = spawn(argv[0], argv.slice(1), + // Share the stderr handle to have error output come + // straight through. Only supported in v0.8+. + {stdio: ['pipe', 'pipe', process.stderr]}); + child = dtrace; // intentionally global - dtrace.stdout.setEncoding('utf8'); - dtrace.stdout.on('data', function (chunk) { - var lines = chunk.split(/\r\n|\n/); - var length = lines.length; - if (length === 1) { - leftover += lines[0]; - return; - } - if (length > 1) { - handleLogLine(null, leftover + lines[0], opts, stylize); - } - leftover = lines.pop(); - length -= 1; - for (var i = 1; i < length; i++) { - handleLogLine(null, lines[i], opts, stylize); - } + function finish(code) { + if (leftover) { + handleLogLine(null, leftover, opts, stylize); + leftover = ''; + } + callback(returnCode); + } + + dtrace.stdout.setEncoding('utf8'); + dtrace.stdout.on('data', function (chunk) { + var lines = chunk.split(/\r\n|\n/); + var length = lines.length; + if (length === 1) { + leftover += lines[0]; + return; + } + if (length > 1) { + handleLogLine(null, leftover + lines[0], opts, stylize); + } + leftover = lines.pop(); + length -= 1; + for (var i = 1; i < length; i++) { + handleLogLine(null, lines[i], opts, stylize); + } + }); + + 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). + var returnCode = null; + var eventsRemaining = 3; + function countdownToFinish(code) { + returnCode = code; + eventsRemaining--; + if (eventsRemaining == 0) { + finish(returnCode); + } + } + dtrace.stderr.pipe(process.stderr); + dtrace.stderr.on('end', countdownToFinish); + dtrace.stderr.on('end', countdownToFinish); + dtrace.on('exit', countdownToFinish); + } }); - - 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). - var returnCode = null; - var eventsRemaining = 3; - function countdownToFinish(code) { - returnCode = code; - eventsRemaining--; - if (eventsRemaining == 0) { - finish(returnCode); - } - } - dtrace.stderr.pipe(process.stderr); - dtrace.stderr.on('end', countdownToFinish); - dtrace.stderr.on('end', countdownToFinish); - dtrace.on('exit', countdownToFinish); - } - }); } @@ -1135,53 +1135,53 @@ function processPids(opts, stylize, callback) { * @param callback {Function} `function ()` */ function processFile(file, opts, stylize, callback) { - var stream = fs.createReadStream(file); - if (/\.gz$/.test(file)) { - stream = stream.pipe(require('zlib').createGunzip()); - } - // Manually decode streams - lazy load here as per node/lib/fs.js - var decoder = new (require('string_decoder').StringDecoder)('utf8'); - - streams[file].stream = stream; - - stream.on('error', function (err) { - streams[file].done = true; - callback(err); - }); - - var leftover = ''; // Left-over partial line from last chunk. - stream.on('data', function (data) { - var chunk = decoder.write(data); - if (!chunk.length) { - return; - } - var lines = chunk.split(/\r\n|\n/); - var length = lines.length; - if (length === 1) { - leftover += lines[0]; - return; + var stream = fs.createReadStream(file); + if (/\.gz$/.test(file)) { + stream = stream.pipe(require('zlib').createGunzip()); } + // Manually decode streams - lazy load here as per node/lib/fs.js + var decoder = new (require('string_decoder').StringDecoder)('utf8'); - if (length > 1) { - handleLogLine(file, leftover + lines[0], opts, stylize); - } - leftover = lines.pop(); - length -= 1; - for (var i = 1; i < length; i++) { - handleLogLine(file, lines[i], opts, stylize); - } - }); + streams[file].stream = stream; - stream.on('end', function () { - streams[file].done = true; - if (leftover) { - handleLogLine(file, leftover, opts, stylize); - leftover = ''; - } else { - emitNextRecord(opts, stylize); - } - callback(); - }); + stream.on('error', function (err) { + streams[file].done = true; + callback(err); + }); + + var leftover = ''; // Left-over partial line from last chunk. + stream.on('data', function (data) { + var chunk = decoder.write(data); + if (!chunk.length) { + return; + } + var lines = chunk.split(/\r\n|\n/); + var length = lines.length; + if (length === 1) { + leftover += lines[0]; + return; + } + + if (length > 1) { + handleLogLine(file, leftover + lines[0], opts, stylize); + } + leftover = lines.pop(); + length -= 1; + for (var i = 1; i < length; i++) { + handleLogLine(file, lines[i], opts, stylize); + } + }); + + stream.on('end', function () { + streams[file].done = true; + if (leftover) { + handleLogLine(file, leftover, opts, stylize); + leftover = ''; + } else { + emitNextRecord(opts, stylize); + } + callback(); + }); } @@ -1227,35 +1227,35 @@ function asyncForEach(arr, iterator, callback) { */ var cleanedUp = false; function cleanupAndExit(code, signal) { - // Guard one call. - if (cleanedUp) { - return; - } - cleanedUp = true; - if (_DEBUG) warn('(bunyan: cleanupAndExit)'); + // Guard one call. + if (cleanedUp) { + return; + } + cleanedUp = true; + if (_DEBUG) warn('(bunyan: cleanupAndExit)'); - // Clear possibly interrupted ANSI code (issue #59). - if (usingAnsiCodes) { - stdout.write('\033[0m'); - } + // Clear possibly interrupted ANSI code (issue #59). + if (usingAnsiCodes) { + stdout.write('\033[0m'); + } - // Kill possible dtrace child. - if (child) { - child.kill(signal); - } + // Kill possible dtrace child. + if (child) { + child.kill(signal); + } - if (pager) { - // Let pager know that output is done, then wait for pager to exit. - stdout.end(); - pager.on('exit', function (pagerCode) { - if (_DEBUG) - warn('(bunyan: pager exit -> process.exit(%s))', pagerCode || code); - process.exit(pagerCode || code); - }); - } else { - if (_DEBUG) warn('(bunyan: process.exit(%s))', code); - process.exit(code); - } + if (pager) { + // Let pager know that output is done, then wait for pager to exit. + stdout.end(); + pager.on('exit', function (pagerCode) { + if (_DEBUG) + warn('(bunyan: pager exit -> process.exit(%s))', pagerCode || code); + process.exit(pagerCode || code); + }); + } else { + if (_DEBUG) warn('(bunyan: process.exit(%s))', code); + process.exit(code); + } } @@ -1268,180 +1268,180 @@ process.on('SIGTERM', function () { cleanupAndExit(1, 'SIGTERM'); }); process.on('SIGHUP', function () { cleanupAndExit(1, 'SIGHUP'); }); process.on('uncaughtException', function (err) { - function _indent(s) { - var lines = s.split(/\r?\n/); - for (var i = 0; i < lines.length; i++) { - lines[i] = '* ' + lines[i]; + function _indent(s) { + var lines = s.split(/\r?\n/); + for (var i = 0; i < lines.length; i++) { + lines[i] = '* ' + lines[i]; + } + return lines.join('\n'); } - return lines.join('\n'); - } - var title = encodeURIComponent(format( - 'Bunyan %s crashed: %s', getVersion(), String(err))); - console.error('* * *'); - console.error('* The Bunyan CLI crashed!'); - console.error('*'); - 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:'); + var title = encodeURIComponent(format( + 'Bunyan %s crashed: %s', getVersion(), String(err))); + console.error('* * *'); + console.error('* The Bunyan CLI crashed!'); console.error('*'); - } - 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('* * *'); - process.exit(1); + 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('*'); + } + 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('* * *'); + process.exit(1); }); function main(argv) { - try { - var opts = parseArgv(argv); - } catch (e) { - warn('bunyan: error: %s', e.message); - return drainStdoutAndExit(1); - } - gOptsForUncaughtException = opts; // intentionally global - if (opts.help) { - printHelp(); - return; - } - if (opts.version) { - console.log('bunyan ' + getVersion()); - return; - } - if (opts.pid && opts.args.length > 0) { - warn('bunyan: error: can\'t use both "-p PID" (%s) and file (%s) args', - opts.pid, opts.args.join(' ')); - return drainStdoutAndExit(1); - } - if (opts.color === null) { - if (process.env.BUNYAN_NO_COLOR && - process.env.BUNYAN_NO_COLOR.length > 0) { - opts.color = false; - } else { - opts.color = process.stdout.isTTY; + try { + var opts = parseArgv(argv); + } catch (e) { + warn('bunyan: error: %s', e.message); + return drainStdoutAndExit(1); } - } - usingAnsiCodes = opts.color; // intentionally global - var stylize = (opts.color ? stylizeWithColor : stylizeWithoutColor); - - // Pager. - var nodeVer = process.versions.node.split('.').map(Number); - var paginate = ( - process.stdout.isTTY && - process.stdin.isTTY && - !opts.pids && // Don't page if following process output. - opts.args.length > 0 && // Don't page if no file args to process. - process.platform !== 'win32' && - nodeVer >= [0, 8, 0] && - (opts.paginate === true || - (opts.paginate !== false && - (!process.env.BUNYAN_NO_PAGER || - process.env.BUNYAN_NO_PAGER.length === 0)))); - if (paginate) { - var pagerCmd = process.env.PAGER || 'less'; - /* JSSTYLED */ - assert.ok(pagerCmd.indexOf('"') === -1 && pagerCmd.indexOf("'") === -1, - 'cannot parse PAGER quotes yet'); - 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. - env.LESS = 'FRX'; + gOptsForUncaughtException = opts; // intentionally global + if (opts.help) { + printHelp(); + return; } - if (_DEBUG) warn('(pager: argv=%j, env.LESS=%j)', argv, env.LESS); - // `pager` and `stdout` intentionally global. - pager = spawn(argv[0], argv.slice(1), - // Share the stderr handle to have error output come - // straight through. Only supported in v0.8+. - {env: env, stdio: ['pipe', 1, 2]}); - stdout = pager.stdin; - - // Early termination of the pager: just stop. - pager.on('exit', function (pagerCode) { - if (_DEBUG) warn('(bunyan: pager exit)'); - pager = null; - stdout.end() - stdout = process.stdout; - cleanupAndExit(pagerCode); - }); - } - - // Stdout error handling. (Couldn't setup until `stdout` was determined.) - stdout.on('error', function (err) { - if (_DEBUG) warn('(stdout error event: %s)', err); - 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. - drainStdoutAndExit(1); - } else { - warn(err); - drainStdoutAndExit(1); + if (opts.version) { + console.log('bunyan ' + getVersion()); + return; } - }); - - var retval = 0; - if (opts.pids) { - processPids(opts, stylize, function (code) { - cleanupAndExit(code); - }); - } else if (opts.args.length > 0) { - var files = opts.args; - files.forEach(function (file) { - streams[file] = { stream: null, records: [], done: false } - }); - asyncForEach(files, - function (file, next) { - processFile(file, opts, stylize, function (err) { - if (err) { - warn('bunyan: %s', err.message); - retval += 1; - } - next(); - }); - }, - function (err) { - if (err) { - warn('bunyan: unexpected error: %s', err.stack || err); - return drainStdoutAndExit(1); + if (opts.pid && opts.args.length > 0) { + warn('bunyan: error: can\'t use both "-p PID" (%s) and file (%s) args', + opts.pid, opts.args.join(' ')); + return drainStdoutAndExit(1); + } + if (opts.color === null) { + if (process.env.BUNYAN_NO_COLOR && + process.env.BUNYAN_NO_COLOR.length > 0) { + opts.color = false; + } else { + opts.color = process.stdout.isTTY; + } + } + usingAnsiCodes = opts.color; // intentionally global + var stylize = (opts.color ? stylizeWithColor : stylizeWithoutColor); + + // Pager. + var nodeVer = process.versions.node.split('.').map(Number); + var paginate = ( + process.stdout.isTTY && + process.stdin.isTTY && + !opts.pids && // Don't page if following process output. + opts.args.length > 0 && // Don't page if no file args to process. + process.platform !== 'win32' && + nodeVer >= [0, 8, 0] && + (opts.paginate === true || + (opts.paginate !== false && + (!process.env.BUNYAN_NO_PAGER || + process.env.BUNYAN_NO_PAGER.length === 0)))); + if (paginate) { + var pagerCmd = process.env.PAGER || 'less'; + /* JSSTYLED */ + assert.ok(pagerCmd.indexOf('"') === -1 && pagerCmd.indexOf("'") === -1, + 'cannot parse PAGER quotes yet'); + 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. + env.LESS = 'FRX'; + } + if (_DEBUG) warn('(pager: argv=%j, env.LESS=%j)', argv, env.LESS); + // `pager` and `stdout` intentionally global. + pager = spawn(argv[0], argv.slice(1), + // Share the stderr handle to have error output come + // straight through. Only supported in v0.8+. + {env: env, stdio: ['pipe', 1, 2]}); + stdout = pager.stdin; + + // Early termination of the pager: just stop. + pager.on('exit', function (pagerCode) { + if (_DEBUG) warn('(bunyan: pager exit)'); + pager = null; + stdout.end() + stdout = process.stdout; + cleanupAndExit(pagerCode); + }); + } + + // Stdout error handling. (Couldn't setup until `stdout` was determined.) + stdout.on('error', function (err) { + if (_DEBUG) warn('(stdout error event: %s)', err); + 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. + drainStdoutAndExit(1); + } else { + warn(err); + drainStdoutAndExit(1); } - cleanupAndExit(retval); - } - ); - } else { - processStdin(opts, stylize, function () { - cleanupAndExit(retval); }); - } + + var retval = 0; + if (opts.pids) { + processPids(opts, stylize, function (code) { + cleanupAndExit(code); + }); + } else if (opts.args.length > 0) { + var files = opts.args; + files.forEach(function (file) { + streams[file] = { stream: null, records: [], done: false } + }); + asyncForEach(files, + function (file, next) { + processFile(file, opts, stylize, function (err) { + if (err) { + warn('bunyan: %s', err.message); + retval += 1; + } + next(); + }); + }, + function (err) { + if (err) { + warn('bunyan: unexpected error: %s', err.stack || err); + return drainStdoutAndExit(1); + } + cleanupAndExit(retval); + } + ); + } else { + processStdin(opts, stylize, function () { + cleanupAndExit(retval); + }); + } } if (require.main === module) { - // HACK guard for . - // We override the `process.stdout.end` guard that core node.js puts in - // place. The real fix is that `.end()` shouldn't be called on stdout - // in node core. Node v0.6.9 fixes that. Only guard for v0.6.0..v0.6.8. - var nodeVer = process.versions.node.split('.').map(Number); - if ([0, 6, 0] <= nodeVer && nodeVer <= [0, 6, 8]) { - var stdout = process.stdout; - stdout.end = stdout.destroy = stdout.destroySoon = function () { - /* pass */ - }; - } + // HACK guard for . + // We override the `process.stdout.end` guard that core node.js puts in + // place. The real fix is that `.end()` shouldn't be called on stdout + // in node core. Node v0.6.9 fixes that. Only guard for v0.6.0..v0.6.8. + var nodeVer = process.versions.node.split('.').map(Number); + if ([0, 6, 0] <= nodeVer && nodeVer <= [0, 6, 8]) { + var stdout = process.stdout; + stdout.end = stdout.destroy = stdout.destroySoon = function () { + /* pass */ + }; + } - main(process.argv); + main(process.argv); } diff --git a/examples/err.js b/examples/err.js index 2eacc7f..b80527e 100644 --- a/examples/err.js +++ b/examples/err.js @@ -5,25 +5,25 @@ var Logger = require('../lib/bunyan'); var util = require('util'); var log = new Logger({ - name: 'myserver', - serializers: { - err: Logger.stdSerializers.err, // <--- use this - } + name: 'myserver', + serializers: { + err: Logger.stdSerializers.err, // <--- use this + } }); try { - throw new TypeError('boom'); + throw new TypeError('boom'); } catch (err) { - log.warn({err: err}, 'operation went boom: %s', err) // <--- here + log.warn({err: err}, 'operation went boom: %s', err) // <--- here } log.info(new TypeError('how about this?')) // <--- alternatively this try { - throw 'boom string'; + throw 'boom string'; } catch (err) { - log.error(err) + log.error(err) } /* BEGIN JSSTYLED */ diff --git a/examples/handle-fs-error.js b/examples/handle-fs-error.js index af08056..19e137a 100644 --- a/examples/handle-fs-error.js +++ b/examples/handle-fs-error.js @@ -10,19 +10,19 @@ var S_IWUSR = 00200; // mask for owner write permission in stat mode console.warn('- Log file is "%s".', FILENAME); if (!path.existsSync(FILENAME)) { - console.warn('- Touch log file.'); - fs.writeFileSync(FILENAME, 'touch\n'); + console.warn('- Touch log file.'); + fs.writeFileSync(FILENAME, 'touch\n'); } if (fs.statSync(FILENAME).mode & S_IWUSR) { - console.warn('- Make log file read-only.'); - fs.chmodSync(FILENAME, 0444); + console.warn('- Make log file read-only.'); + fs.chmodSync(FILENAME, 0444); } console.warn('- Create logger.') var log = new Logger({name: 'handle-fs-error', streams: [{path: FILENAME}]}); log.on('error', function (err) { - console.warn('- The logger emitted an error:', err); + console.warn('- The logger emitted an error:', err); }); console.warn('- Call log.info(...).') @@ -30,7 +30,7 @@ log.info('info log message'); console.warn('- Called log.info(...).') setTimeout(function () { - console.warn('- Call log.warn(...).') - log.warn('warn log message'); - console.warn('- Called log.warn(...).') + console.warn('- Call log.warn(...).') + log.warn('warn log message'); + console.warn('- Called log.warn(...).') }, 1000); diff --git a/examples/hi.js b/examples/hi.js index 0f5f21b..22a4a74 100644 --- a/examples/hi.js +++ b/examples/hi.js @@ -19,12 +19,12 @@ log.info({foo:'bar', multiline:'one\ntwo\nthree'}, 'hi %d', 1, 'two', 3); console.log('\n') function Wuzzle(options) { - this.log = options.log; - this.log.info('creating a wuzzle') + this.log = options.log; + this.log.info('creating a wuzzle') } Wuzzle.prototype.woos = function () { - this.log.warn('This wuzzle is woosey.') + this.log.warn('This wuzzle is woosey.') } var wuzzle = new Wuzzle({log: log.child({component: 'wuzzle'})}); diff --git a/examples/level.js b/examples/level.js index 80bb563..6a38cb2 100644 --- a/examples/level.js +++ b/examples/level.js @@ -3,25 +3,25 @@ // TODO: put this in a damn test suite var Logger = require('../lib/bunyan'), - DEBUG = Logger.DEBUG, - INFO = Logger.INFO, - WARN = Logger.WARN; + DEBUG = Logger.DEBUG, + INFO = Logger.INFO, + WARN = Logger.WARN; var assert = require('assert'); // Basic usage. var log = new Logger({ - name: 'example-level', - streams: [ - { - name: 'stdout', - stream: process.stdout, - level: 'debug' - }, - { - name: 'stderr', - stream: process.stderr - } - ] + name: 'example-level', + streams: [ + { + name: 'stdout', + stream: process.stdout, + level: 'debug' + }, + { + name: 'stderr', + stream: process.stderr + } + ] }); assert.equal(log.level(), DEBUG); @@ -32,9 +32,9 @@ assert.equal(log.levels(1), INFO); assert.equal(log.levels('stdout'), DEBUG) try { - log.levels('foo') + log.levels('foo') } catch (e) { - assert.ok(e.message.indexOf('name') !== -1) + assert.ok(e.message.indexOf('name') !== -1) } log.trace('no one should see this') diff --git a/examples/long-running.js b/examples/long-running.js index 5d5e8cb..aa858e0 100644 --- a/examples/long-running.js +++ b/examples/long-running.js @@ -21,11 +21,11 @@ var bunyan = require('../lib/bunyan'); function randint(n) { - return Math.floor(Math.random() * n); + return Math.floor(Math.random() * n); } function randchoice(array) { - return array[randint(array.length)]; + return array[randint(array.length)]; } @@ -40,18 +40,18 @@ var log = bunyan.createLogger({name: 'lr', level: 'debug'}); // We're logging to stdout. Let's exit gracefully on EPIPE. E.g. if piped // to `head` which will close after N lines. process.stdout.on('error', function (err) { - if (err.code === 'EPIPE') { - process.exit(0); - } + if (err.code === 'EPIPE') { + process.exit(0); + } }) function logOne() { - var level = randchoice(levels); - var msg = [randchoice(words), randchoice(words)].join(' '); - var delay = randint(300); - //console.warn('long-running about to log.%s(..., "%s")', level, msg) - log[level]({'word': randchoice(words), 'delay': delay}, msg); - timeout = setTimeout(logOne, delay); + var level = randchoice(levels); + var msg = [randchoice(words), randchoice(words)].join(' '); + var delay = randint(300); + //console.warn('long-running about to log.%s(..., "%s")', level, msg) + log[level]({'word': randchoice(words), 'delay': delay}, msg); + timeout = setTimeout(logOne, delay); } log.info('hi, this is the start'); diff --git a/examples/multi.js b/examples/multi.js index 81400ee..f3870da 100644 --- a/examples/multi.js +++ b/examples/multi.js @@ -1,16 +1,16 @@ var Logger = require('../lib/bunyan'); log = new Logger({ - name: 'amon', - streams: [ - { - level: 'info', - stream: process.stdout, - }, - { - level: 'error', - path: 'multi.log' - } - ] + name: 'amon', + streams: [ + { + level: 'info', + stream: process.stdout, + }, + { + level: 'error', + path: 'multi.log' + } + ] }); diff --git a/examples/raw-stream.js b/examples/raw-stream.js index 32b905b..f57f3cb 100644 --- a/examples/raw-stream.js +++ b/examples/raw-stream.js @@ -11,25 +11,25 @@ var Logger = require('../lib/bunyan'); */ 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'); - } + 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(), - type: 'raw' - }, - ] + name: 'raw-example', + streams: [ + { + level: 'info', + stream: new MyRawStream(), + type: 'raw' + }, + ] }); diff --git a/examples/ringbuffer.js b/examples/ringbuffer.js index 4ca76fd..bb307e4 100644 --- a/examples/ringbuffer.js +++ b/examples/ringbuffer.js @@ -2,12 +2,12 @@ var bunyan = require('..'); var ringbuffer = new bunyan.RingBuffer({ limit: 100 }); var log = new bunyan({ - name: 'foo', - streams: [ { - type: 'raw', - stream: ringbuffer, - level: 'debug' - } ] + name: 'foo', + streams: [ { + type: 'raw', + stream: ringbuffer, + level: 'debug' + } ] }); log.info('hello world'); diff --git a/examples/server.js b/examples/server.js index c8bdac1..209bf3b 100644 --- a/examples/server.js +++ b/examples/server.js @@ -4,37 +4,37 @@ var http = require('http'); var Logger = require('../lib/bunyan'); var log = new Logger({ - name: 'myserver', - serializers: { - req: Logger.stdSerializers.req, - res: Logger.stdSerializers.res - } + name: 'myserver', + serializers: { + req: Logger.stdSerializers.req, + res: Logger.stdSerializers.res + } }); var server = http.createServer(function (req, res) { - log.info({req: req}, 'start request'); // <-- this is the guy we're testing - res.writeHead(200, {'Content-Type': 'text/plain'}); - res.end('Hello World\n'); - log.info({res: res}, 'done response'); // <-- this is the guy we're testing + log.info({req: req}, 'start request'); // <-- this is the guy we're testing + res.writeHead(200, {'Content-Type': 'text/plain'}); + res.end('Hello World\n'); + log.info({res: res}, 'done response'); // <-- this is the guy we're testing }); server.listen(1337, '127.0.0.1', function () { - log.info('server listening'); - var options = { - port: 1337, - hostname: '127.0.0.1', - path: '/path?q=1#anchor', - headers: { - 'X-Hi': 'Mom' - } - }; - var req = http.request(options); - req.on('response', function (res) { - res.on('end', function () { - process.exit(); - }) - }); - req.write('hi from the client'); - req.end(); + log.info('server listening'); + var options = { + port: 1337, + hostname: '127.0.0.1', + path: '/path?q=1#anchor', + headers: { + 'X-Hi': 'Mom' + } + }; + var req = http.request(options); + req.on('response', function (res) { + res.on('end', function () { + process.exit(); + }) + }); + req.write('hi from the client'); + req.end(); }); diff --git a/examples/src.js b/examples/src.js index fe4ab50..e45e215 100644 --- a/examples/src.js +++ b/examples/src.js @@ -8,16 +8,16 @@ var log = new Logger({name: 'src-example', src: true}); log.info('one'); log.info('two'); function doSomeFoo() { - log.info({foo:'bar'}, 'three'); + log.info({foo:'bar'}, 'three'); } doSomeFoo(); function Wuzzle(options) { - this.log = options.log; - this.log.info('creating a wuzzle') + this.log = options.log; + this.log.info('creating a wuzzle') } Wuzzle.prototype.woos = function () { - this.log.warn('This wuzzle is woosey.') + this.log.warn('This wuzzle is woosey.') } var wuzzle = new Wuzzle({log: log.child({component: 'wuzzle'})}); diff --git a/examples/unstringifyable.js b/examples/unstringifyable.js index ddad545..5d7e94b 100644 --- a/examples/unstringifyable.js +++ b/examples/unstringifyable.js @@ -5,7 +5,7 @@ var log = new Logger({src: true, name: 'foo'}); // Make a circular object (cannot be JSON-ified). var myobj = { - foo: 'bar' + foo: 'bar' }; myobj.myobj = myobj; diff --git a/lib/bunyan.js b/lib/bunyan.js index 1ab6334..d21a183 100644 --- a/lib/bunyan.js +++ b/lib/bunyan.js @@ -15,8 +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)); - console.error.apply(this, args); + 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 @@ -26,17 +26,17 @@ var fs = require('fs'); var util = require('util'); var assert = require('assert'); try { - var dtrace = require('dtrace-provider'); + var dtrace = require('dtrace-provider'); } catch (e) { - dtrace = null; + dtrace = null; } var EventEmitter = require('events').EventEmitter; // The 'mv' module is required for rotating-file stream support. try { - var mv = require('mv'); + var mv = require('mv'); } catch (e) { - mv = null; + mv = null; } @@ -44,58 +44,58 @@ try { //---- Internal support stuff function objCopy(obj) { - 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; - } + 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; + } } var format = util.format; if (!format) { - // If node < 0.6, then use its `util.format`: - // : - var inspect = util.inspect; - var formatRegExp = /%[sdj%]/g; - format = function format(f) { - if (typeof (f) !== 'string') { - var objects = []; - for (var i = 0; i < arguments.length; i++) { - objects.push(inspect(arguments[i])); - } - return objects.join(' '); - } + // If node < 0.6, then use its `util.format`: + // : + var inspect = util.inspect; + var formatRegExp = /%[sdj%]/g; + format = function format(f) { + if (typeof (f) !== 'string') { + var objects = []; + for (var i = 0; i < arguments.length; i++) { + objects.push(inspect(arguments[i])); + } + return objects.join(' '); + } - var i = 1; - var args = arguments; - var len = args.length; - var str = String(f).replace(formatRegExp, function (x) { - if (i >= len) - return x; - switch (x) { - case '%s': return String(args[i++]); - case '%d': return Number(args[i++]); - case '%j': return JSON.stringify(args[i++], safeCycles()); - case '%%': return '%'; - default: - return x; - } - }); - for (var x = args[i]; i < len; x = args[++i]) { - if (x === null || typeof (x) !== 'object') { - str += ' ' + x; - } else { - str += ' ' + inspect(x); - } - } - return str; - }; + var i = 1; + var args = arguments; + var len = args.length; + var str = String(f).replace(formatRegExp, function (x) { + if (i >= len) + return x; + switch (x) { + case '%s': return String(args[i++]); + case '%d': return Number(args[i++]); + case '%j': return JSON.stringify(args[i++], safeCycles()); + case '%%': return '%'; + default: + return x; + } + }); + for (var x = args[i]; i < len; x = args[++i]) { + if (x === null || typeof (x) !== 'object') { + str += ' ' + x; + } else { + str += ' ' + inspect(x); + } + } + return str; + }; } @@ -104,23 +104,23 @@ if (!format) { * See . */ function getCaller3Info() { - var obj = {}; - var saveLimit = Error.stackTraceLimit; - var savePrepare = Error.prepareStackTrace; - Error.stackTraceLimit = 3; - Error.captureStackTrace(this, getCaller3Info); - Error.prepareStackTrace = function (_, stack) { - var caller = stack[2]; - obj.file = caller.getFileName(); - obj.line = caller.getLineNumber(); - var func = caller.getFunctionName(); - if (func) - obj.func = func; - }; - this.stack; - Error.stackTraceLimit = saveLimit; - Error.prepareStackTrace = savePrepare; - return obj; + var obj = {}; + var saveLimit = Error.stackTraceLimit; + var savePrepare = Error.prepareStackTrace; + Error.stackTraceLimit = 3; + Error.captureStackTrace(this, getCaller3Info); + Error.prepareStackTrace = function (_, stack) { + var caller = stack[2]; + obj.file = caller.getFileName(); + obj.line = caller.getLineNumber(); + var func = caller.getFunctionName(); + if (func) + obj.func = func; + }; + this.stack; + Error.stackTraceLimit = saveLimit; + Error.prepareStackTrace = savePrepare; + return obj; } @@ -135,16 +135,16 @@ function getCaller3Info() { * the warning. */ function _warn(msg, file, line) { - assert.ok(msg); - var key; - if (file && line) { - key = file + ':' + line; - if (_warned[key]) { - return; + assert.ok(msg); + var key; + if (file && line) { + key = file + ':' + line; + if (_warned[key]) { + return; + } + _warned[key] = true; } - _warned[key] = true; - } - process.stderr.write(msg + '\n'); + process.stderr.write(msg + '\n'); } var _warned = {}; @@ -160,12 +160,12 @@ var ERROR = 50; var FATAL = 60; var levelFromName = { - 'trace': TRACE, - 'debug': DEBUG, - 'info': INFO, - 'warn': WARN, - 'error': ERROR, - 'fatal': FATAL + 'trace': TRACE, + 'debug': DEBUG, + 'info': INFO, + 'warn': WARN, + 'error': ERROR, + 'fatal': FATAL }; // Dtrace probes. @@ -178,13 +178,13 @@ var probes = dtrace && {}; * @api public */ function resolveLevel(nameOrNum) { - var level = (typeof (nameOrNum) === 'string' - ? levelFromName[nameOrNum.toLowerCase()] - : nameOrNum); - if (! (TRACE <= level && level <= FATAL)) { - throw new Error('invalid level: ' + nameOrNum); - } - return level; + var level = (typeof (nameOrNum) === 'string' + ? levelFromName[nameOrNum.toLowerCase()] + : nameOrNum); + if (! (TRACE <= level && level <= FATAL)) { + throw new Error('invalid level: ' + nameOrNum); + } + return level; } @@ -227,246 +227,246 @@ function resolveLevel(nameOrNum) { * creation. */ function Logger(options, _childOptions, _childSimple) { - xxx('Logger start:', options) - if (! this instanceof Logger) { - return new Logger(options, _childOptions); - } - - // 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 (!parent) { - if (!options.name) { - throw new TypeError('options.name (string) is required'); - } - } else { - if (options.name) { - throw new TypeError('invalid options.name: child cannot set logger name'); - } - } - if (options.stream && options.streams) { - throw new TypeError('cannot mix "streams" and "stream" options'); - } - if (options.streams && !Array.isArray(options.streams)) { - throw new TypeError('invalid options.streams: must be an array') - } - if (options.serializers && (typeof (options.serializers) !== 'object' || - Array.isArray(options.serializers))) { - throw new TypeError('invalid options.serializers: must be an object') - } - - EventEmitter.call(this); - - // Fast path for simple child creation. - if (parent && _childSimple) { - // `_isSimpleChild` is a signal 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.src = parent.src; - var fields = this.fields = {}; - var parentFieldNames = Object.keys(parent.fields); - for (var i = 0; i < parentFieldNames.length; i++) { - var name = parentFieldNames[i]; - fields[name] = parent.fields[name]; - } - var names = Object.keys(options); - for (var i = 0; i < names.length; i++) { - var name = names[i]; - fields[name] = options[name]; - } - return; - } - - // 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); - } - this.serializers = objCopy(parent.serializers); - this.src = parent.src; - this.fields = objCopy(parent.fields); - if (options.level) { - this.level(options.level); - } - } else { - this._level = Number.POSITIVE_INFINITY; - this.streams = []; - this.serializers = null; - this.src = false; - this.fields = {}; - } - - if (!dtp && dtrace) { - dtp = dtrace.createDTraceProvider('bunyan'); - - for (var level in levelFromName) { - var probe; - - probes[levelFromName[level]] = probe = - dtp.addProbe('log-' + level, 'char *'); - - // Explicitly add a reference to dtp to prevent it from being GC'd - probe.dtp = dtp; + xxx('Logger start:', options) + if (! this instanceof Logger) { + return new Logger(options, _childOptions); } - dtp.enable(); - } - - // Helpers - function addStream(s) { - s = objCopy(s); - - // Implicit 'type' from other args. - var type = s.type; - if (!s.type) { - if (s.stream) { - s.type = 'stream'; - } else if (s.path) { - s.type = 'file' - } + // 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'); + } } - s.raw = (s.type === 'raw'); // PERF: Allow for faster check in `_emit`. - - if (s.level) { - s.level = resolveLevel(s.level); - } else if (options.level) { - s.level = resolveLevel(options.level); + if (!options) { + throw new TypeError('options (object) is required'); + } + if (!parent) { + if (!options.name) { + throw new TypeError('options.name (string) is required'); + } } else { - s.level = INFO; + if (options.name) { + throw new TypeError('invalid options.name: child cannot set logger name'); + } } - if (s.level < self._level) { - self._level = s.level; + if (options.stream && options.streams) { + throw new TypeError('cannot mix "streams" and "stream" options'); + } + if (options.streams && !Array.isArray(options.streams)) { + throw new TypeError('invalid options.streams: must be an array') + } + if (options.serializers && (typeof (options.serializers) !== 'object' || + Array.isArray(options.serializers))) { + throw new TypeError('invalid options.serializers: must be an object') } - switch (s.type) { - case 'stream': - if (!s.closeOnExit) { - s.closeOnExit = false; - } - break; - case 'file': - if (!s.stream) { - s.stream = fs.createWriteStream(s.path, - {flags: 'a', encoding: 'utf8'}); - s.stream.on('error', function (err) { - self.emit('error', err, s); + EventEmitter.call(this); + + // Fast path for simple child creation. + if (parent && _childSimple) { + // `_isSimpleChild` is a signal 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.src = parent.src; + var fields = this.fields = {}; + var parentFieldNames = Object.keys(parent.fields); + for (var i = 0; i < parentFieldNames.length; i++) { + var name = parentFieldNames[i]; + fields[name] = parent.fields[name]; + } + var names = Object.keys(options); + for (var i = 0; i < names.length; i++) { + var name = names[i]; + fields[name] = options[name]; + } + return; + } + + // 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); + } + this.serializers = objCopy(parent.serializers); + this.src = parent.src; + this.fields = objCopy(parent.fields); + if (options.level) { + this.level(options.level); + } + } else { + this._level = Number.POSITIVE_INFINITY; + this.streams = []; + this.serializers = null; + this.src = false; + this.fields = {}; + } + + if (!dtp && dtrace) { + dtp = dtrace.createDTraceProvider('bunyan'); + + for (var level in levelFromName) { + var probe; + + probes[levelFromName[level]] = probe = + dtp.addProbe('log-' + level, 'char *'); + + // Explicitly add a reference to dtp to prevent it from being GC'd + probe.dtp = dtp; + } + + dtp.enable(); + } + + // Helpers + function addStream(s) { + s = objCopy(s); + + // Implicit 'type' from other args. + var type = s.type; + if (!s.type) { + if (s.stream) { + s.type = 'stream'; + } else if (s.path) { + s.type = 'file' + } + } + s.raw = (s.type === 'raw'); // PERF: Allow for faster check in `_emit`. + + if (s.level) { + s.level = resolveLevel(s.level); + } else if (options.level) { + s.level = resolveLevel(options.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; + } + break; + case 'file': + if (!s.stream) { + s.stream = fs.createWriteStream(s.path, + {flags: 'a', encoding: 'utf8'}); + s.stream.on('error', function (err) { + self.emit('error', err, s); + }); + if (!s.closeOnExit) { + s.closeOnExit = true; + } + } else { + if (!s.closeOnExit) { + s.closeOnExit = false; + } + } + break; + case 'rotating-file': + 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'); + s.stream = new RotatingFileStream(s); + if (!s.closeOnExit) { + s.closeOnExit = true; + } + break; + case 'raw': + if (!s.closeOnExit) { + s.closeOnExit = false; + } + break; + default: + throw new TypeError('unknown stream type "' + s.type + '"'); + } + + self.streams.push(s); + } + + function addSerializers(serializers) { + if (!self.serializers) { + self.serializers = {}; + } + Object.keys(serializers).forEach(function (field) { + var serializer = serializers[field]; + if (typeof (serializer) !== 'function') { + throw new TypeError(format( + 'invalid serializer for "%s" field: must be a function', field)); + } else { + self.serializers[field] = serializer; + } }); - if (!s.closeOnExit) { - s.closeOnExit = true; - } - } else { - if (!s.closeOnExit) { - s.closeOnExit = false; - } - } - break; - case 'rotating-file': - 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'); - s.stream = new RotatingFileStream(s); - if (!s.closeOnExit) { - s.closeOnExit = true; - } - break; - case 'raw': - if (!s.closeOnExit) { - s.closeOnExit = false; - } - break; - default: - throw new TypeError('unknown stream type "' + s.type + '"'); } - self.streams.push(s); - } - - function addSerializers(serializers) { - if (!self.serializers) { - self.serializers = {}; + // Handle *config* options (i.e. options that are not just plain data + // for log records). + 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 && options.level) { + this.level(options.level); + } else if (!parent) { + addStream({ + type: 'stream', + stream: process.stdout, + closeOnExit: false, + level: (options.level ? resolveLevel(options.level) : INFO) + }); } - Object.keys(serializers).forEach(function (field) { - var serializer = serializers[field]; - if (typeof (serializer) !== 'function') { - throw new TypeError(format( - 'invalid serializer for "%s" field: must be a function', field)); - } else { - self.serializers[field] = serializer; - } - }); - } + if (options.serializers) { + addSerializers(options.serializers); + } + if (options.src) { + this.src = true; + } + xxx('Logger: ', self) - // Handle *config* options (i.e. options that are not just plain data - // for log records). - if (options.stream) { - addStream({ - type: 'stream', - stream: options.stream, - closeOnExit: false, - level: (options.level ? resolveLevel(options.level) : INFO) + // 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; + delete fields.src; + if (this.serializers) { + this._applySerializers(fields); + } + if (!fields.hostname) { + fields.hostname = os.hostname(); + } + if (!fields.pid) { + fields.pid = process.pid; + } + Object.keys(fields).forEach(function (k) { + self.fields[k] = fields[k]; }); - } else if (options.streams) { - options.streams.forEach(addStream); - } else if (parent && options.level) { - this.level(options.level); - } else if (!parent) { - addStream({ - type: 'stream', - stream: process.stdout, - closeOnExit: false, - level: (options.level ? resolveLevel(options.level) : INFO) - }); - } - if (options.serializers) { - addSerializers(options.serializers); - } - if (options.src) { - this.src = true; - } - xxx('Logger: ', self) - - // 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; - delete fields.src; - if (this.serializers) { - this._applySerializers(fields); - } - if (!fields.hostname) { - fields.hostname = os.hostname(); - } - if (!fields.pid) { - fields.pid = process.pid; - } - Object.keys(fields).forEach(function (k) { - self.fields[k] = fields[k]; - }); } util.inherits(Logger, EventEmitter); @@ -499,7 +499,7 @@ util.inherits(Logger, EventEmitter); * creation. See 'tools/timechild.js' for numbers. */ Logger.prototype.child = function (options, simple) { - return new Logger(this, options || {}, simple); + return new Logger(this, options || {}, simple); } @@ -510,19 +510,19 @@ Logger.prototype.child = function (options, simple) { * 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; + 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; } */ /* END JSSTYLED */ @@ -540,15 +540,15 @@ Logger.prototype.close = function () { * log.level('info') // can use 'info' et al aliases */ Logger.prototype.level = function level(value) { - if (value === undefined) { - return this._level; - } - var newLevel = resolveLevel(value); - var len = this.streams.length; - for (var i = 0; i < len; i++) { - this.streams[i].level = newLevel; - } - this._level = newLevel; + if (value === undefined) { + return this._level; + } + var newLevel = resolveLevel(value); + var len = this.streams.length; + for (var i = 0; i < len; i++) { + this.streams[i].level = newLevel; + } + this._level = newLevel; } @@ -585,39 +585,39 @@ Logger.prototype.level = function level(value) { * @throws {Error} If there is no stream with the given name. */ Logger.prototype.levels = function levels(name, value) { - if (name === undefined) { - assert.equal(value, undefined); - return this.streams.map( - function (s) { return s.level }); - } - var stream; - if (typeof (name) === 'number') { - stream = this.streams[name]; - if (stream === undefined) { - throw new Error('invalid stream index: ' + name); + if (name === undefined) { + assert.equal(value, undefined); + return this.streams.map( + function (s) { return s.level }); } - } else { - var len = this.streams.length; - for (var i = 0; i < len; i++) { - var s = this.streams[i]; - if (s.name === name) { - stream = s; - break; - } + var stream; + if (typeof (name) === 'number') { + stream = this.streams[name]; + if (stream === undefined) { + throw new Error('invalid stream index: ' + name); + } + } else { + var len = this.streams.length; + for (var i = 0; i < len; i++) { + var s = this.streams[i]; + if (s.name === name) { + stream = s; + break; + } + } + if (!stream) { + throw new Error(format('no stream with name "%s"', name)); + } } - if (!stream) { - throw new Error(format('no stream with name "%s"', name)); + if (value === undefined) { + return stream.level; + } else { + var newLevel = resolveLevel(value); + stream.level = newLevel; + if (newLevel < this._level) { + this._level = newLevel; + } } - } - if (value === undefined) { - return stream.level; - } else { - var newLevel = resolveLevel(value); - stream.level = newLevel; - if (newLevel < this._level) { - this._level = newLevel; - } - } } @@ -631,30 +631,30 @@ Logger.prototype.levels = function levels(name, value) { * keys to NOT apply a serializer. */ Logger.prototype._applySerializers = function (fields, excludeFields) { - var self = this; + var self = this; - xxx('_applySerializers: excludeFields', excludeFields); + xxx('_applySerializers: excludeFields', excludeFields); - // Check each serializer against these (presuming number of serializers - // is typically less than number of fields). - Object.keys(this.serializers).forEach(function (name) { - if (fields[name] === undefined || - (excludeFields && excludeFields[name])) - { - return; - } - xxx('_applySerializers; apply to "%s" key', name) - try { - 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', - name, err.stack || err)); - fields[name] = format('(Error in Bunyan log "%s" serializer ' - + 'broke field. See stderr for details.)', name); - } - }); + // Check each serializer against these (presuming number of serializers + // is typically less than number of fields). + Object.keys(this.serializers).forEach(function (name) { + if (fields[name] === undefined || + (excludeFields && excludeFields[name])) + { + return; + } + xxx('_applySerializers; apply to "%s" key', name) + try { + 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', + name, err.stack || err)); + fields[name] = format('(Error in Bunyan log "%s" serializer ' + + 'broke field. See stderr for details.)', name); + } + }); } @@ -668,8 +668,8 @@ Logger.prototype._applySerializers = function (fields, excludeFields) { * it is emitted. */ Logger.prototype._mkRecord = function (fields, level, msgArgs) { - var recFields = (fields ? objCopy(fields) : null); - return [this.fields, recFields, level, msgArgs]; + var recFields = (fields ? objCopy(fields) : null); + return [this.fields, recFields, level, msgArgs]; } @@ -681,40 +681,40 @@ Logger.prototype._mkRecord = function (fields, level, msgArgs) { * and just return the JSON string. */ Logger.prototype._emit = function (rec, noemit) { - var i; + var i; - // 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; + // 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; + } + } + } + + // Stringify the object. Attempt to warn/recover on error. + var str; + if (noemit || this.haveNonRawStreams) { + str = JSON.stringify(rec, safeCycles()) + '\n'; + } + + if (noemit) + return str; + + var level = rec.level; for (i = 0; i < this.streams.length; i++) { - if (!this.streams[i].raw) { - this.haveNonRawStreams = true; - break; - } - } - } + var s = this.streams[i]; + if (s.level <= level) { + xxx('writing log rec "%s" to "%s" stream (%d <= %d): %j', + rec.msg, s.type, s.level, level, rec); + s.stream.write(s.raw ? rec : str); + } + }; - // Stringify the object. Attempt to warn/recover on error. - var str; - if (noemit || this.haveNonRawStreams) { - str = JSON.stringify(rec, safeCycles()) + '\n'; - } - - if (noemit) return str; - - var level = rec.level; - 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 (%d <= %d): %j', - rec.msg, s.type, s.level, level, rec); - s.stream.write(s.raw ? rec : str); - } - }; - - return str; } @@ -723,76 +723,76 @@ Logger.prototype._emit = function (rec, noemit) { * creator of `log.info`, `log.error`, etc. */ function mkLogEmitter(minLevel) { - return function () { - var log = this; + return function () { + var log = this; - function mkRecord(args) { - var excludeFields; - if (args[0] instanceof Error) { - // `log.(err, ...)` - fields = {err: errSerializer(args[0])}; - excludeFields = {err: true}; - if (args.length === 1) { - msgArgs = [fields.err.message]; + function mkRecord(args) { + var excludeFields; + if (args[0] instanceof Error) { + // `log.(err, ...)` + fields = {err: errSerializer(args[0])}; + excludeFields = {err: true}; + if (args.length === 1) { + msgArgs = [fields.err.message]; + } else { + msgArgs = Array.prototype.slice.call(args, 1); + } + } 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. + fields = null; + msgArgs = Array.prototype.slice.call(args); + msgArgs[0] = util.inspect(msgArgs[0]); + } else { // `log.(fields, msg, ...)` + fields = args[0]; + msgArgs = Array.prototype.slice.call(args, 1); + } + + // Build up the record object. + var rec = objCopy(log.fields); + var level = rec.level = minLevel; + var recFields = (fields ? objCopy(fields) : null); + if (recFields) { + if (log.serializers) { + log._applySerializers(recFields, excludeFields); + } + Object.keys(recFields).forEach(function (k) { + rec[k] = recFields[k]; + }); + } + rec.msg = format.apply(log, msgArgs); + if (!rec.time) { + rec.time = (new Date()); + } + // Get call source info + if (log.src && !rec.src) { + rec.src = getCaller3Info() + } + rec.v = LOG_VERSION; + + return rec; + }; + + var fields = null; + var msgArgs = arguments; + var str = null; + var rec = null; + if (arguments.length === 0) { // `log.()` + return (this._level <= minLevel); + } else if (this._level > minLevel) { + /* pass through */ } else { - msgArgs = Array.prototype.slice.call(args, 1); + rec = mkRecord(msgArgs); + str = this._emit(rec); } - } 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. - fields = null; - msgArgs = Array.prototype.slice.call(args); - msgArgs[0] = util.inspect(msgArgs[0]); - } else { // `log.(fields, msg, ...)` - fields = args[0]; - msgArgs = Array.prototype.slice.call(args, 1); - } - - // Build up the record object. - var rec = objCopy(log.fields); - var level = rec.level = minLevel; - var recFields = (fields ? objCopy(fields) : null); - if (recFields) { - if (log.serializers) { - log._applySerializers(recFields, excludeFields); - } - Object.keys(recFields).forEach(function (k) { - rec[k] = recFields[k]; + probes && probes[minLevel].fire(function () { + return [ str || + (rec && log._emit(rec, true)) || + log._emit(mkRecord(msgArgs), true) ]; }); - } - rec.msg = format.apply(log, msgArgs); - if (!rec.time) { - rec.time = (new Date()); - } - // Get call source info - if (log.src && !rec.src) { - rec.src = getCaller3Info() - } - rec.v = LOG_VERSION; - - return rec; - }; - - var fields = null; - var msgArgs = arguments; - var str = null; - var rec = null; - if (arguments.length === 0) { // `log.()` - return (this._level <= minLevel); - } else if (this._level > minLevel) { - /* pass through */ - } else { - rec = mkRecord(msgArgs); - str = this._emit(rec); } - probes && probes[minLevel].fire(function () { - return [ str || - (rec && log._emit(rec, true)) || - log._emit(mkRecord(msgArgs), true) ]; - }); - } } @@ -832,30 +832,30 @@ Logger.stdSerializers = {}; // Serialize an HTTP request. Logger.stdSerializers.req = function req(req) { - if (!req || !req.connection) - return req; - return { - method: req.method, - url: req.url, - headers: req.headers, - remoteAddress: req.connection.remoteAddress, - remotePort: req.connection.remotePort - }; - // Trailers: Skipping for speed. If you need trailers in your app, then - // make a custom serializer. - //if (Object.keys(trailers).length > 0) { - // obj.trailers = req.trailers; - //} + if (!req || !req.connection) + return req; + return { + method: req.method, + url: req.url, + headers: req.headers, + remoteAddress: req.connection.remoteAddress, + remotePort: req.connection.remotePort + }; + // Trailers: Skipping for speed. If you need trailers in your app, then + // make a custom serializer. + //if (Object.keys(trailers).length > 0) { + // obj.trailers = req.trailers; + //} }; // Serialize an HTTP response. Logger.stdSerializers.res = function res(res) { - if (!res || !res.statusCode) - return res; - return { - statusCode: res.statusCode, - header: res._header - } + if (!res || !res.statusCode) + return res; + return { + statusCode: res.statusCode, + header: res._header + } }; @@ -870,46 +870,46 @@ Logger.stdSerializers.res = function res(res) { */ function getFullErrorStack(ex) { - var ret = ex.stack || ex.toString(); - if (ex.cause && typeof (ex.cause) === 'function') { - var cex = ex.cause(); - if (cex) { - ret += '\nCaused by: ' + getFullErrorStack(cex); + var ret = ex.stack || ex.toString(); + if (ex.cause && typeof (ex.cause) === 'function') { + var cex = ex.cause(); + if (cex) { + ret += '\nCaused by: ' + getFullErrorStack(cex); + } } - } - return (ret); + return (ret); } // Serialize an Error object // (Core error properties are enumerable in node 0.4, not in 0.6). var errSerializer = Logger.stdSerializers.err = function err(err) { - if (!err || !err.stack) - return err; - var obj = { - message: err.message, - name: err.name, - stack: getFullErrorStack(err), - code: err.code, - signal: err.signal - } - return obj; + if (!err || !err.stack) + return err; + var obj = { + message: err.message, + name: err.name, + stack: getFullErrorStack(err), + code: err.code, + signal: err.signal + } + return obj; }; // A JSON stringifier that handles cycles safely. // Usage: JSON.stringify(obj, safeCycles()) function safeCycles() { - var seen = []; - return function (key, val) { - if (!val || typeof (val) !== 'object') { - return val; - } - if (seen.indexOf(val) !== -1) { - return '[Circular]'; - } - seen.push(val); - return val; - }; + var seen = []; + return function (key, val) { + if (!val || typeof (val) !== 'object') { + return val; + } + if (seen.indexOf(val) !== -1) { + return '[Circular]'; + } + seen.push(val); + return val; + }; } @@ -919,238 +919,238 @@ function safeCycles() { if (mv) { function RotatingFileStream(options) { - this.path = options.path; - this.stream = fs.createWriteStream(this.path, - {flags: 'a', encoding: 'utf8'}); - this.count = (options.count == null ? 10 : options.count); - assert.ok(typeof (this.count) === 'number' && this.count >= 0); + this.path = options.path; + this.stream = fs.createWriteStream(this.path, + {flags: 'a', encoding: 'utf8'}); + this.count = (options.count == null ? 10 : options.count); + assert.ok(typeof (this.count) === 'number' && this.count >= 0); - // Parse `options.period`. - if (options.period) { - // where scope is: - // h hours (at the start of the hour) - // d days (at the start of the day, i.e. just after midnight) - // w weeks (at the start of Sunday) - // m months (on the first of the month) - // y years (at the start of Jan 1st) - // with special values 'hourly' (1h), 'daily' (1d), "weekly" (1w), - // 'monthly' (1m) and 'yearly' (1y) - var period = { - 'hourly': '1h', - 'daily': '1d', - 'weekly': '1w', - 'monthly': '1m', - 'yearly': '1y' - }[options.period] || options.period; - var m = /^([1-9][0-9]*)([hdwmy]|ms)$/.exec(period); - if (!m) { - throw new Error(format('invalid period: "%s"', options.period)); + // Parse `options.period`. + if (options.period) { + // where scope is: + // h hours (at the start of the hour) + // d days (at the start of the day, i.e. just after midnight) + // w weeks (at the start of Sunday) + // m months (on the first of the month) + // y years (at the start of Jan 1st) + // with special values 'hourly' (1h), 'daily' (1d), "weekly" (1w), + // 'monthly' (1m) and 'yearly' (1y) + var period = { + 'hourly': '1h', + 'daily': '1d', + 'weekly': '1w', + 'monthly': '1m', + 'yearly': '1y' + }[options.period] || options.period; + var m = /^([1-9][0-9]*)([hdwmy]|ms)$/.exec(period); + if (!m) { + throw new Error(format('invalid period: "%s"', options.period)); + } + this.periodNum = Number(m[1]); + this.periodScope = m[2]; + } else { + this.periodNum = 1; + this.periodScope = 'd'; } - this.periodNum = Number(m[1]); - this.periodScope = m[2]; - } else { - this.periodNum = 1; - this.periodScope = 'd'; - } - // TODO: template support for backup files - // template: - // default is %P.%n - // '/var/log/archive/foo.log' -> foo.log.%n - // '/var/log/archive/foo.log.%n' - // codes: - // XXX support strftime codes (per node version of those) - // or whatever module. Pick non-colliding for extra - // codes - // %P `path` base value - // %n integer number of rotated log (1,2,3,...) - // %d datetime in YYYY-MM-DD_HH-MM-SS - // XXX what should default date format be? - // prior art? Want to avoid ':' in - // filenames (illegal on Windows for one). + // TODO: template support for backup files + // template: + // default is %P.%n + // '/var/log/archive/foo.log' -> foo.log.%n + // '/var/log/archive/foo.log.%n' + // codes: + // XXX support strftime codes (per node version of those) + // or whatever module. Pick non-colliding for extra + // codes + // %P `path` base value + // %n integer number of rotated log (1,2,3,...) + // %d datetime in YYYY-MM-DD_HH-MM-SS + // XXX what should default date format be? + // prior art? Want to avoid ':' in + // filenames (illegal on Windows for one). - this.rotQueue = []; - this.rotating = false; - this._setupNextRot(); + this.rotQueue = []; + this.rotating = false; + this._setupNextRot(); } util.inherits(RotatingFileStream, EventEmitter); RotatingFileStream.prototype._setupNextRot = function () { - var self = this; - this.rotAt = this._nextRotTime(); - this.timeout = setTimeout( - function () { self.rotate(); }, - this.rotAt - Date.now()); + var self = this; + this.rotAt = this._nextRotTime(); + this.timeout = setTimeout( + function () { self.rotate(); }, + this.rotAt - Date.now()); } RotatingFileStream.prototype._nextRotTime = function _nextRotTime(first) { - var _DEBUG = false; - if (_DEBUG) console.log('-- _nextRotTime: %s%s', this.periodNum, this.periodScope); - var d = new Date(); + var _DEBUG = false; + if (_DEBUG) console.log('-- _nextRotTime: %s%s', this.periodNum, this.periodScope); + var d = new Date(); - if (_DEBUG) console.log(' now local: %s', d); - if (_DEBUG) console.log(' now utc: %s', d.toISOString()); - var rotAt; - switch (this.periodScope) { - case 'ms': - // Hidden millisecond period for debugging. - if (this.rotAt) { - rotAt = this.rotAt + this.periodNum; - } else { - rotAt = Date.now() + this.periodNum; + if (_DEBUG) console.log(' now local: %s', d); + if (_DEBUG) console.log(' now utc: %s', d.toISOString()); + var rotAt; + switch (this.periodScope) { + case 'ms': + // Hidden millisecond period for debugging. + if (this.rotAt) { + rotAt = this.rotAt + this.periodNum; + } else { + rotAt = Date.now() + this.periodNum; + } + break; + case 'h': + if (this.rotAt) { + 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); + } + break; + case 'd': + if (this.rotAt) { + 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); + } + break; + case 'w': + // Currently, always on Sunday morning at 00:00:00 (UTC). + if (this.rotAt) { + rotAt = this.rotAt + this.periodNum * 7 * 24 * 60 * 60 * 1000; + } else { + // First time: this coming Sunday. + rotAt = Date.UTC(d.getUTCFullYear(), d.getUTCMonth(), + d.getUTCDate() + (7 - d.getUTCDay())); + } + break; + case 'm': + if (this.rotAt) { + 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); + } + break; + case 'y': + if (this.rotAt) { + rotAt = Date.UTC(d.getUTCFullYear() + this.periodNum, 0, 1); + } else { + // First time: the start of the next year. + rotAt = Date.UTC(d.getUTCFullYear() + 1, 0, 1); + } + break; + default: + assert.fail(format('invalid period scope: "%s"', this.periodScope)); } - break; - case 'h': - if (this.rotAt) { - 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); - } - break; - case 'd': - if (this.rotAt) { - 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); - } - break; - case 'w': - // Currently, always on Sunday morning at 00:00:00 (UTC). - if (this.rotAt) { - rotAt = this.rotAt + this.periodNum * 7 * 24 * 60 * 60 * 1000; - } else { - // First time: this coming Sunday. - rotAt = Date.UTC(d.getUTCFullYear(), d.getUTCMonth(), - d.getUTCDate() + (7 - d.getUTCDay())); - } - break; - case 'm': - if (this.rotAt) { - 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); - } - break; - case 'y': - if (this.rotAt) { - rotAt = Date.UTC(d.getUTCFullYear() + this.periodNum, 0, 1); - } else { - // First time: the start of the next year. - rotAt = Date.UTC(d.getUTCFullYear() + 1, 0, 1); - } - break; - default: - assert.fail(format('invalid period scope: "%s"', this.periodScope)); - } - if (_DEBUG) { - console.log(' **rotAt**: %s (utc: %s)', rotAt, - new Date(rotAt).toUTCString()); - var now = Date.now(); - console.log(' now: %s (%sms == %smin == %sh to go)', - now, - rotAt - now, - (rotAt-now)/1000/60, - (rotAt-now)/1000/60/60); - } - return rotAt; + if (_DEBUG) { + console.log(' **rotAt**: %s (utc: %s)', rotAt, + new Date(rotAt).toUTCString()); + var now = Date.now(); + console.log(' now: %s (%sms == %smin == %sh to go)', + now, + rotAt - now, + (rotAt-now)/1000/60, + (rotAt-now)/1000/60/60); + } + return rotAt; }; RotatingFileStream.prototype.rotate = function rotate() { - // XXX What about shutdown? - var self = this; - var _DEBUG = false; + // XXX What about shutdown? + var self = this; + var _DEBUG = false; - if (_DEBUG) console.log('-- [%s] rotating %s', new Date(), self.path); - if (self.rotating) { - throw new TypeError('cannot start a rotation when already rotating'); - } - self.rotating = true; - - self.stream.end(); // XXX can do moves sync after this? test at high rate - - function del() { - var toDel = self.path + '.' + String(n - 1); - if (n === 0) { - toDel = self.path; + if (_DEBUG) console.log('-- [%s] rotating %s', new Date(), self.path); + if (self.rotating) { + throw new TypeError('cannot start a rotation when already rotating'); } - n -= 1; - if (_DEBUG) console.log('rm %s', toDel); - fs.unlink(toDel, function (delErr) { - //XXX handle err other than not exists - moves(); - }); - } + self.rotating = true; - function moves() { - if (self.count === 0 || n < 0) { - return finish(); - } - var before = self.path; - var after = self.path + '.' + String(n); - if (n > 0) { - before += '.' + String(n - 1); - } - n -= 1; - fs.exists(before, function (exists) { - if (!exists) { - moves(); - } else { - if (_DEBUG) console.log('mv %s %s', before, after); - mv(before, after, function (mvErr) { - if (mvErr) { - self.emit('error', mvErr); - finish(); // XXX finish here? - } else { + self.stream.end(); // XXX can do moves sync after this? test at high rate + + function del() { + var toDel = self.path + '.' + String(n - 1); + if (n === 0) { + toDel = self.path; + } + n -= 1; + if (_DEBUG) console.log('rm %s', toDel); + fs.unlink(toDel, function (delErr) { + //XXX handle err other than not exists moves(); - } }); - } - }) - } - - function finish() { - if (_DEBUG) console.log('open %s', self.path); - self.stream = fs.createWriteStream(self.path, - {flags: 'a', encoding: 'utf8'}); - var q = self.rotQueue, len = q.length; - for (var i = 0; i < len; i++) { - self.stream.write(q[i]); } - self.rotQueue = []; - self.rotating = false; - self.emit('drain'); - self._setupNextRot(); - } - var n = this.count; - del(); + function moves() { + if (self.count === 0 || n < 0) { + return finish(); + } + var before = self.path; + var after = self.path + '.' + String(n); + if (n > 0) { + before += '.' + String(n - 1); + } + n -= 1; + fs.exists(before, function (exists) { + if (!exists) { + moves(); + } else { + if (_DEBUG) console.log('mv %s %s', before, after); + mv(before, after, function (mvErr) { + if (mvErr) { + self.emit('error', mvErr); + finish(); // XXX finish here? + } else { + moves(); + } + }); + } + }) + } + + function finish() { + if (_DEBUG) console.log('open %s', self.path); + self.stream = fs.createWriteStream(self.path, + {flags: 'a', encoding: 'utf8'}); + var q = self.rotQueue, len = q.length; + for (var i = 0; i < len; i++) { + self.stream.write(q[i]); + } + self.rotQueue = []; + self.rotating = false; + self.emit('drain'); + self._setupNextRot(); + } + + var n = this.count; + del(); }; RotatingFileStream.prototype.write = function write(s) { - if (this.rotating) { - this.rotQueue.push(s); - return false; - } else { - return this.stream.write(s); - } + if (this.rotating) { + this.rotQueue.push(s); + return false; + } else { + return this.stream.write(s); + } }; RotatingFileStream.prototype.end = function end(s) { - this.stream.end(); + this.stream.end(); }; RotatingFileStream.prototype.destroy = function destroy(s) { - this.stream.destroy(); + this.stream.destroy(); }; RotatingFileStream.prototype.destroySoon = function destroySoon(s) { - this.stream.destroySoon(); + this.stream.destroySoon(); }; } /* if (mv) */ @@ -1166,39 +1166,39 @@ RotatingFileStream.prototype.destroySoon = function destroySoon(s) { * - limit: number of records to keep in memory */ function RingBuffer(options) { - this.limit = options && options.limit ? options.limit : 100; - this.writable = true; - this.records = []; - EventEmitter.call(this); + this.limit = options && options.limit ? options.limit : 100; + this.writable = true; + this.records = []; + EventEmitter.call(this); } util.inherits(RingBuffer, EventEmitter); RingBuffer.prototype.write = function (record) { - if (!this.writable) - throw (new Error('RingBuffer has been ended already')); + if (!this.writable) + throw (new Error('RingBuffer has been ended already')); - this.records.push(record); + this.records.push(record); - if (this.records.length > this.limit) - this.records.shift(); + if (this.records.length > this.limit) + this.records.shift(); - return (true); + return (true); }; RingBuffer.prototype.end = function () { - if (arguments.length > 0) - this.write.apply(this, Array.prototype.slice.call(arguments)); - this.writable = false; + if (arguments.length > 0) + this.write.apply(this, Array.prototype.slice.call(arguments)); + this.writable = false; }; RingBuffer.prototype.destroy = function () { - this.writable = false; - this.emit('close'); + this.writable = false; + this.emit('close'); }; RingBuffer.prototype.destroySoon = function () { - this.destroy(); + this.destroy(); }; @@ -1218,7 +1218,7 @@ module.exports.VERSION = VERSION; module.exports.LOG_VERSION = LOG_VERSION; module.exports.createLogger = function createLogger(options) { - return new Logger(options); + return new Logger(options); }; module.exports.RingBuffer = RingBuffer; diff --git a/test/buffer.test.js b/test/buffer.test.js index 5bc656a..25c7ab8 100644 --- a/test/buffer.test.js +++ b/test/buffer.test.js @@ -6,13 +6,13 @@ */ var util = require('util'), - inspect = util.inspect, - format = util.format; + inspect = util.inspect, + format = util.format; var bunyan = require('../lib/bunyan'); // node-tap API if (require.cache[__dirname + '/tap4nodeunit.js']) - delete require.cache[__dirname + '/tap4nodeunit.js']; + delete require.cache[__dirname + '/tap4nodeunit.js']; var tap4nodeunit = require('./tap4nodeunit.js'); var after = tap4nodeunit.after; var before = tap4nodeunit.before; @@ -21,45 +21,45 @@ var test = tap4nodeunit.test; function Catcher() { - this.records = []; + this.records = []; } Catcher.prototype.write = function (record) { - this.records.push(record); + this.records.push(record); } var catcher = new Catcher(); var log = new bunyan.createLogger({ - name: 'buffer.test', - streams: [ - { - type: 'raw', - stream: catcher, - level: 'trace' - } - ] + name: 'buffer.test', + streams: [ + { + type: 'raw', + stream: catcher, + level: 'trace' + } + ] }); test('log.info(BUFFER)', function (t) { - var b = new Buffer('foo'); + var b = new Buffer('foo'); - ['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), - format('log.%s msg is inspect(BUFFER)', lvl)); - t.ok(rec['0'] === undefined, - 'no "0" array index key in record: ' + inspect(rec['0'])); - t.ok(rec['parent'] === undefined, - 'no "parent" array index key in record: ' + inspect(rec['parent'])); + ['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), + format('log.%s msg is inspect(BUFFER)', lvl)); + t.ok(rec['0'] === undefined, + 'no "0" array index key in record: ' + inspect(rec['0'])); + t.ok(rec['parent'] === undefined, + 'no "parent" array index key in record: ' + inspect(rec['parent'])); - 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)); - }); + 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.end(); + t.end(); }); diff --git a/test/child-behaviour.test.js b/test/child-behaviour.test.js index 1109b3e..f29ec7a 100644 --- a/test/child-behaviour.test.js +++ b/test/child-behaviour.test.js @@ -8,7 +8,7 @@ var bunyan = require('../lib/bunyan'); // node-tap API if (require.cache[__dirname + '/tap4nodeunit.js']) - delete require.cache[__dirname + '/tap4nodeunit.js']; + delete require.cache[__dirname + '/tap4nodeunit.js']; var tap4nodeunit = require('./tap4nodeunit.js'); var after = tap4nodeunit.after; var before = tap4nodeunit.before; @@ -17,120 +17,120 @@ var test = tap4nodeunit.test; function CapturingStream(recs) { - this.recs = recs || []; + this.recs = recs || []; } CapturingStream.prototype.write = function (rec) { - this.recs.push(rec); + this.recs.push(rec); } test('child can add stream', function (t) { - var dadStream = new CapturingStream(); - var dad = bunyan.createLogger({ - name: 'surname', - streams: [ { - type: 'raw', - stream: dadStream, - level: 'info' - } ] - }); + var dadStream = new CapturingStream(); + var dad = bunyan.createLogger({ + name: 'surname', + streams: [ { + type: 'raw', + stream: dadStream, + level: 'info' + } ] + }); - var sonStream = new CapturingStream(); - var son = dad.child({ - component: 'son', - streams: [ { - type: 'raw', - stream: sonStream, - level: 'debug' - } ] - }); + var sonStream = new CapturingStream(); + var son = dad.child({ + component: 'son', + streams: [ { + type: 'raw', + stream: sonStream, + level: 'debug' + } ] + }); - dad.info('info from dad'); - dad.debug('debug from dad'); - son.debug('debug from son'); + dad.info('info from dad'); + dad.debug('debug from dad'); + son.debug('debug from son'); - var rec; - t.equal(dadStream.recs.length, 1); - rec = dadStream.recs[0]; - t.equal(rec.msg, 'info from dad'); - t.equal(sonStream.recs.length, 1); - rec = sonStream.recs[0]; - t.equal(rec.msg, 'debug from son'); + var rec; + t.equal(dadStream.recs.length, 1); + rec = dadStream.recs[0]; + t.equal(rec.msg, 'info from dad'); + t.equal(sonStream.recs.length, 1); + rec = sonStream.recs[0]; + t.equal(rec.msg, 'debug from son'); - t.end(); + t.end(); }); test('child can set level of inherited streams', function (t) { - var dadStream = new CapturingStream(); - var dad = bunyan.createLogger({ - name: 'surname', - streams: [ { - type: 'raw', - stream: dadStream, - level: 'info' - } ] - }); + var dadStream = new CapturingStream(); + var dad = bunyan.createLogger({ + name: 'surname', + streams: [ { + type: 'raw', + stream: dadStream, + level: 'info' + } ] + }); - // Intention here is that the inherited `dadStream` logs at 'debug' level - // for the son. - var son = dad.child({ - component: 'son', - level: 'debug' - }); + // Intention here is that the inherited `dadStream` logs at 'debug' level + // for the son. + var son = dad.child({ + component: 'son', + level: 'debug' + }); - dad.info('info from dad'); - dad.debug('debug from dad'); - son.debug('debug from son'); + dad.info('info from dad'); + dad.debug('debug from dad'); + son.debug('debug from son'); - var rec; - t.equal(dadStream.recs.length, 2); - rec = dadStream.recs[0]; - t.equal(rec.msg, 'info from dad'); - rec = dadStream.recs[1]; - t.equal(rec.msg, 'debug from son'); + var rec; + t.equal(dadStream.recs.length, 2); + rec = dadStream.recs[0]; + t.equal(rec.msg, 'info from dad'); + rec = dadStream.recs[1]; + t.equal(rec.msg, 'debug from son'); - t.end(); + t.end(); }); test('child can set level of inherited streams and add streams', function (t) { - var dadStream = new CapturingStream(); - var dad = bunyan.createLogger({ - name: 'surname', - streams: [ { - type: 'raw', - stream: dadStream, - level: 'info' - } ] - }); + var dadStream = new CapturingStream(); + var dad = bunyan.createLogger({ + name: 'surname', + streams: [ { + type: 'raw', + stream: dadStream, + level: 'info' + } ] + }); - // Intention here is that the inherited `dadStream` logs at 'debug' level - // for the son. - var sonStream = new CapturingStream(); - var son = dad.child({ - component: 'son', - level: 'trace', - streams: [ { - type: 'raw', - stream: sonStream, - level: 'debug' - } ] - }); + // Intention here is that the inherited `dadStream` logs at 'debug' level + // for the son. + var sonStream = new CapturingStream(); + var son = dad.child({ + component: 'son', + level: 'trace', + streams: [ { + type: 'raw', + stream: sonStream, + level: 'debug' + } ] + }); - dad.info('info from dad'); - dad.trace('trace from dad'); - son.trace('trace from son'); - son.debug('debug from son'); + dad.info('info from dad'); + dad.trace('trace from dad'); + son.trace('trace from son'); + son.debug('debug from son'); - t.equal(dadStream.recs.length, 3); - t.equal(dadStream.recs[0].msg, 'info from dad'); - t.equal(dadStream.recs[1].msg, 'trace from son'); - t.equal(dadStream.recs[2].msg, 'debug from son'); + t.equal(dadStream.recs.length, 3); + t.equal(dadStream.recs[0].msg, 'info from dad'); + t.equal(dadStream.recs[1].msg, 'trace from son'); + t.equal(dadStream.recs[2].msg, 'debug from son'); - t.equal(sonStream.recs.length, 1); - t.equal(sonStream.recs[0].msg, 'debug from son'); + t.equal(sonStream.recs.length, 1); + t.equal(sonStream.recs[0].msg, 'debug from son'); - t.end(); + t.end(); }); diff --git a/test/cli.test.js b/test/cli.test.js index 619c176..2d26b81 100644 --- a/test/cli.test.js +++ b/test/cli.test.js @@ -11,7 +11,7 @@ var debug = console.warn; // node-tap API if (require.cache[__dirname + '/tap4nodeunit.js']) - delete require.cache[__dirname + '/tap4nodeunit.js']; + delete require.cache[__dirname + '/tap4nodeunit.js']; var tap4nodeunit = require('./tap4nodeunit.js'); var after = tap4nodeunit.after; var before = tap4nodeunit.before; @@ -31,285 +31,285 @@ var BUNYAN = path.resolve(__dirname, '../bin/bunyan'); //}); test('--version', function (t) { - var version = require('../package.json').version; - exec(BUNYAN + ' --version', function (err, stdout, stderr) { - t.ifError(err) - t.equal(stdout, 'bunyan ' + version + '\n'); - t.end(); - }); + var version = require('../package.json').version; + exec(BUNYAN + ' --version', function (err, stdout, stderr) { + t.ifError(err) + t.equal(stdout, 'bunyan ' + version + '\n'); + t.end(); + }); }); test('--help', function (t) { - exec(BUNYAN + ' --help', function (err, stdout, stderr) { - t.ifError(err) - t.ok(stdout.indexOf('General options:') !== -1); - t.end(); - }); + exec(BUNYAN + ' --help', function (err, stdout, stderr) { + t.ifError(err) + t.ok(stdout.indexOf('General options:') !== -1); + t.end(); + }); }); test('-h', function (t) { - exec(BUNYAN + ' -h', function (err, stdout, stderr) { - t.ifError(err) - t.ok(stdout.indexOf('General options:') !== -1); - t.end(); - }); + exec(BUNYAN + ' -h', function (err, stdout, stderr) { + t.ifError(err) + t.ok(stdout.indexOf('General options:') !== -1); + t.end(); + }); }); test('--bogus', function (t) { - exec(BUNYAN + ' --bogus', function (err, stdout, stderr) { - t.ok(err, 'should error out') - t.equal(err.code, 1, '... with exit code 1') - t.end(); - }); + exec(BUNYAN + ' --bogus', function (err, stdout, stderr) { + t.ok(err, 'should error out') + t.equal(err.code, 1, '... with exit code 1') + t.end(); + }); }); test('simple.log', function (t) { - exec(_('%s %s/corpus/simple.log', BUNYAN, __dirname), - 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'); - t.end(); - }); + exec(_('%s %s/corpus/simple.log', BUNYAN, __dirname), + 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'); + t.end(); + }); }); test('cat simple.log', function (t) { - exec(_('cat %s/corpus/simple.log | %s', __dirname, BUNYAN), - 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'); - t.end(); - } - ); + exec(_('cat %s/corpus/simple.log | %s', __dirname, BUNYAN), + 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'); + t.end(); + } + ); }); test('simple.log with color', function (t) { - exec(_('%s --color %s/corpus/simple.log', BUNYAN, __dirname), - 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'); - t.end(); - }); + exec(_('%s --color %s/corpus/simple.log', BUNYAN, __dirname), + 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'); + t.end(); + }); }); test('extrafield.log', function (t) { - exec(_('%s %s/corpus/extrafield.log', BUNYAN, __dirname), - function (err, stdout, stderr) { - t.ifError(err) - t.equal(stdout, - '[2012-02-08T22:56:52.856Z] INFO: myservice/123 on example.com: ' - + 'My message (extra=field)\n'); - t.end(); - }); + exec(_('%s %s/corpus/extrafield.log', BUNYAN, __dirname), + function (err, stdout, stderr) { + t.ifError(err) + t.equal(stdout, + '[2012-02-08T22:56:52.856Z] INFO: myservice/123 on example.com: ' + + 'My message (extra=field)\n'); + t.end(); + }); }); test('extrafield.log with color', function (t) { - exec(_('%s --color %s/corpus/extrafield.log', BUNYAN, __dirname), - 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' - + '\u001b[90m (extra=field)\u001b[39m\n\u001b[0m'); - t.end(); - }); + exec(_('%s --color %s/corpus/extrafield.log', BUNYAN, __dirname), + 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' + + '\u001b[90m (extra=field)\u001b[39m\n\u001b[0m'); + t.end(); + }); }); test('bogus.log', function (t) { - exec(_('%s %s/corpus/bogus.log', BUNYAN, __dirname), - function (err, stdout, stderr) { - t.ifError(err) - t.equal(stdout, 'not a JSON line\n{"hi": "there"}\n'); - t.end(); - }); + exec(_('%s %s/corpus/bogus.log', BUNYAN, __dirname), + function (err, stdout, stderr) { + t.ifError(err) + t.equal(stdout, 'not a JSON line\n{"hi": "there"}\n'); + t.end(); + }); }); test('bogus.log -j', function (t) { - exec(_('%s -j %s/corpus/bogus.log', BUNYAN, __dirname), - function (err, stdout, stderr) { - t.ifError(err) - t.equal(stdout, 'not a JSON line\n{"hi": "there"}\n'); - t.end(); - }); + exec(_('%s -j %s/corpus/bogus.log', BUNYAN, __dirname), + function (err, stdout, stderr) { + t.ifError(err) + t.equal(stdout, 'not a JSON line\n{"hi": "there"}\n'); + t.end(); + }); }); test('all.log', function (t) { - exec(_('%s %s/corpus/all.log', BUNYAN, __dirname), - function (err, stdout, stderr) { - // Just make sure don't blow up on this. - t.ifError(err) - t.end(); - }); + exec(_('%s %s/corpus/all.log', BUNYAN, __dirname), + function (err, stdout, stderr) { + // Just make sure don't blow up on this. + t.ifError(err) + t.end(); + }); }); test('simple.log doesnotexist1.log doesnotexist2.log', function (t) { - exec(_('%s %s/corpus/simple.log doesnotexist1.log doesnotexist2.log', - BUNYAN, __dirname), - function (err, stdout, stderr) { - 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'); - // Note: node v0.6.10: - // ENOENT, no such file or directory 'asdf.log' - // but node v0.6.14: - // ENOENT, open 'asdf.log' - // Somewhat annoying change. - t.equal(stderr, - 'bunyan: ENOENT, open \'doesnotexist1.log\'\nbunyan: ENOENT, ' - + 'open \'doesnotexist2.log\'\n'); - t.end(); - } - ); + exec(_('%s %s/corpus/simple.log doesnotexist1.log doesnotexist2.log', + BUNYAN, __dirname), + function (err, stdout, stderr) { + 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'); + // Note: node v0.6.10: + // ENOENT, no such file or directory 'asdf.log' + // but node v0.6.14: + // ENOENT, open 'asdf.log' + // Somewhat annoying change. + t.equal(stderr, + 'bunyan: ENOENT, open \'doesnotexist1.log\'\nbunyan: ENOENT, ' + + 'open \'doesnotexist2.log\'\n'); + t.end(); + } + ); }); test('multiple logs', function (t) { - exec(_('%s %s/corpus/log1.log %s/corpus/log2.log', BUNYAN, __dirname, __dirname), - function (err, stdout, stderr) { - t.ifError(err); - t.equal(stdout, [ - '[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', - '[2012-05-08T17:02:47.404Z] INFO: agent2/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', - '[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', - ].join('')); - t.end(); - }); + exec(_('%s %s/corpus/log1.log %s/corpus/log2.log', BUNYAN, __dirname, __dirname), + function (err, stdout, stderr) { + t.ifError(err); + t.equal(stdout, [ + '[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', + '[2012-05-08T17:02:47.404Z] INFO: agent2/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', + '[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', + ].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) { - t.ifError(err); - t.equal(stdout, [ - '{"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}', - '{"name":"agent2","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T17:02:47.404Z","v":0}', - '{"name":"agent1","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T17:02:49.339Z","v":0}', - '{"name":"agent1","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T17:02:49.404Z","v":0}', - '{"name":"agent1","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T17:02:49.404Z","v":0}', - '{"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}', - '' - ].join('\n')); - t.end(); - }); + exec(_('%s -o bunyan %s/corpus/log1.log %s/corpus/log2.log', BUNYAN, __dirname, __dirname), + function (err, stdout, stderr) { + t.ifError(err); + t.equal(stdout, [ + '{"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}', + '{"name":"agent2","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T17:02:47.404Z","v":0}', + '{"name":"agent1","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T17:02:49.339Z","v":0}', + '{"name":"agent1","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T17:02:49.404Z","v":0}', + '{"name":"agent1","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T17:02:49.404Z","v":0}', + '{"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}', + '' + ].join('\n')); + t.end(); + }); }); test('log1.log.gz', function (t) { - exec(_('%s %s/corpus/log1.log.gz', BUNYAN, __dirname), - function (err, stdout, stderr) { - t.ifError(err); - t.equal(stdout, [ - '[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', - ].join('')); - t.end(); - }); + exec(_('%s %s/corpus/log1.log.gz', BUNYAN, __dirname), + function (err, stdout, stderr) { + t.ifError(err); + t.equal(stdout, [ + '[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', + ].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) { - t.ifError(err); - t.equal(stdout, [ - '[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', - '[2012-05-08T17:02:47.404Z] INFO: agent2/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', - '[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', - ].join('')); - t.end(); - }); + exec(_('%s %s/corpus/log1.log.gz %s/corpus/log2.log', BUNYAN, __dirname, __dirname), + function (err, stdout, stderr) { + t.ifError(err); + t.equal(stdout, [ + '[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', + '[2012-05-08T17:02:47.404Z] INFO: agent2/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', + '[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', + ].join('')); + t.end(); + }); }); test('--level 40', function (t) { - expect = [ - '# 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', - '[2012-02-08T22:56:55.856Z] LVL55: myservice/123 on example.com: My message\n', - '[2012-02-08T22:56:56.856Z] FATAL: myservice/123 on example.com: My message\n', - '\n', - '# extra fields\n', - '\n', - '# bogus\n', - 'not a JSON line\n', - '{"hi": "there"}\n' - ].join(''); - exec(_('%s -l 40 %s/corpus/all.log', BUNYAN, __dirname), - function (err, stdout, stderr) { - t.ifError(err); - t.equal(stdout, expect); - exec(_('%s --level 40 %s/corpus/all.log', BUNYAN, __dirname), - function (err, stdout, stderr) { - t.ifError(err); - t.equal(stdout, expect); - t.end(); + expect = [ + '# 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', + '[2012-02-08T22:56:55.856Z] LVL55: myservice/123 on example.com: My message\n', + '[2012-02-08T22:56:56.856Z] FATAL: myservice/123 on example.com: My message\n', + '\n', + '# extra fields\n', + '\n', + '# bogus\n', + 'not a JSON line\n', + '{"hi": "there"}\n' + ].join(''); + exec(_('%s -l 40 %s/corpus/all.log', BUNYAN, __dirname), + function (err, stdout, stderr) { + t.ifError(err); + t.equal(stdout, expect); + exec(_('%s --level 40 %s/corpus/all.log', BUNYAN, __dirname), + function (err, stdout, stderr) { + t.ifError(err); + t.equal(stdout, expect); + t.end(); + }); }); - }); }); test('--condition "level === 10 && pid === 123"', function (t) { - var expect = [ - '# levels\n', - '[2012-02-08T22:56:50.856Z] TRACE: myservice/123 on example.com: My message\n', - '\n', - '# extra fields\n', - '\n', - '# bogus\n', - '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) { - t.ifError(err); - t.equal(stdout, expect); - exec(_('%s --condition "level === 10 && pid === 123" %s/corpus/all.log', BUNYAN, __dirname), - function (err, stdout, stderr) { - t.ifError(err); - t.equal(stdout, expect); - t.end(); + var expect = [ + '# levels\n', + '[2012-02-08T22:56:50.856Z] TRACE: myservice/123 on example.com: My message\n', + '\n', + '# extra fields\n', + '\n', + '# bogus\n', + '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) { + t.ifError(err); + t.equal(stdout, expect); + exec(_('%s --condition "level === 10 && pid === 123" %s/corpus/all.log', BUNYAN, __dirname), + function (err, stdout, stderr) { + t.ifError(err); + t.equal(stdout, expect); + t.end(); + }); }); - }); }); // multiple // not sure if this is a bug or a feature. let's call it a feature! test('multiple --conditions', function (t) { - var expect = [ - '# levels\n', - '[2012-02-08T22:56:53.856Z] WARN: myservice/1 on example.com: My message\n', - '\n', - '# extra fields\n', - '\n', - '# bogus\n', - 'not a JSON line\n', - '{"hi": "there"}\n' - ].join(''); - exec(_('%s %s/corpus/all.log ' + - '-c "if (level === 40) pid = 1; true" ' + - '-c "pid === 1"', BUNYAN, __dirname), - function (err, stdout, stderr) { - t.ifError(err); - t.equal(stdout, expect); - t.end(); - }); + var expect = [ + '# levels\n', + '[2012-02-08T22:56:53.856Z] WARN: myservice/1 on example.com: My message\n', + '\n', + '# extra fields\n', + '\n', + '# bogus\n', + 'not a JSON line\n', + '{"hi": "there"}\n' + ].join(''); + exec(_('%s %s/corpus/all.log ' + + '-c "if (level === 40) pid = 1; true" ' + + '-c "pid === 1"', BUNYAN, __dirname), + function (err, stdout, stderr) { + t.ifError(err); + t.equal(stdout, expect); + t.end(); + }); }); // https://github.com/trentm/node-bunyan/issues/30 @@ -317,43 +317,43 @@ test('multiple --conditions', function (t) { // One of the records in corpus/withreq.log has a 'req' // field with no 'headers'. Ditto for the 'res' field. test('robust req handling', function (t) { - var expect = [ - '[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', - ' accept: application/json', - ' content-type: application/json', - ' host: 10.2.207.16', - ' connection: keep-alive', - ' --', - ' HTTP/1.1 200 OK', - ' content-md5: 11FxOYiYfpMxmANj4kGJzg==', - ' access-control-allow-origin: *', - ' access-control-allow-headers: Accept, Accept-Version, Content-Length, Content-MD5, Content-Type, Date, X-Api-Version', - ' access-control-allow-methods: HEAD', - ' access-control-expose-headers: X-Api-Version, X-Request-Id, X-Response-Time', - ' connection: Keep-Alive', - ' date: Wed, 08 Aug 2012 10:25:47 GMT', - ' server: Amon Master/1.0.0', - ' x-request-id: cce79d15-ffc2-487c-a4e4-e940bdaac31e', - ' x-response-time: 3', - ' --', - ' route: {', - ' "name": "HeadAgentProbes",', - ' "version": false', - ' }', - '[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', - ' --', - ' route: {', - ' "name": "HeadAgentProbes",', - ' "version": false', - ' }' - ].join('\n') + '\n'; - exec(_('%s %s/corpus/withreq.log', BUNYAN, __dirname), - function (err, stdout, stderr) { - t.ifError(err); - t.equal(stdout, expect); - t.end(); - }); + var expect = [ + '[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', + ' accept: application/json', + ' content-type: application/json', + ' host: 10.2.207.16', + ' connection: keep-alive', + ' --', + ' HTTP/1.1 200 OK', + ' content-md5: 11FxOYiYfpMxmANj4kGJzg==', + ' access-control-allow-origin: *', + ' access-control-allow-headers: Accept, Accept-Version, Content-Length, Content-MD5, Content-Type, Date, X-Api-Version', + ' access-control-allow-methods: HEAD', + ' access-control-expose-headers: X-Api-Version, X-Request-Id, X-Response-Time', + ' connection: Keep-Alive', + ' date: Wed, 08 Aug 2012 10:25:47 GMT', + ' server: Amon Master/1.0.0', + ' x-request-id: cce79d15-ffc2-487c-a4e4-e940bdaac31e', + ' x-response-time: 3', + ' --', + ' route: {', + ' "name": "HeadAgentProbes",', + ' "version": false', + ' }', + '[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', + ' --', + ' route: {', + ' "name": "HeadAgentProbes",', + ' "version": false', + ' }' + ].join('\n') + '\n'; + exec(_('%s %s/corpus/withreq.log', BUNYAN, __dirname), + function (err, stdout, stderr) { + t.ifError(err); + t.equal(stdout, expect); + t.end(); + }); }); diff --git a/test/ctor.test.js b/test/ctor.test.js index 685f418..a09749d 100644 --- a/test/ctor.test.js +++ b/test/ctor.test.js @@ -5,11 +5,11 @@ */ var bunyan = require('../lib/bunyan'), - Logger = bunyan; + Logger = bunyan; // node-tap API if (require.cache[__dirname + '/tap4nodeunit.js']) - delete require.cache[__dirname + '/tap4nodeunit.js']; + delete require.cache[__dirname + '/tap4nodeunit.js']; var tap4nodeunit = require('./tap4nodeunit.js'); var after = tap4nodeunit.after; var before = tap4nodeunit.before; @@ -18,109 +18,109 @@ var test = tap4nodeunit.test; test('ensure Logger creation options', function (t) { - t.throws(function () { new Logger(); }, - 'options (object) is required', - 'no options should throw'); + t.throws(function () { new Logger(); }, + 'options (object) is required', + 'no options should throw'); - t.throws(function () { new Logger({}); }, - 'options.name (string) is required', - 'no options.name should throw'); + t.throws(function () { new Logger({}); }, + 'options.name (string) is required', + 'no options.name should throw'); - t.doesNotThrow(function () { new Logger({name: 'foo'}); }, - 'just options.name should be sufficient'); + t.doesNotThrow(function () { new Logger({name: 'foo'}); }, + 'just options.name should be sufficient'); - var options = {name: 'foo', stream: process.stdout, streams: []}; - t.throws(function () { new Logger(options); }, - 'cannot use "stream" and "streams"'); + var options = {name: 'foo', stream: process.stdout, streams: []}; + t.throws(function () { new Logger(options); }, + 'cannot use "stream" and "streams"'); - // https://github.com/trentm/node-bunyan/issues/3 - options = {name: 'foo', streams: {}}; - t.throws(function () { new Logger(options); }, - 'invalid options.streams: must be an array', - '"streams" must be an array'); + // https://github.com/trentm/node-bunyan/issues/3 + options = {name: 'foo', streams: {}}; + t.throws(function () { new Logger(options); }, + 'invalid options.streams: must be an array', + '"streams" must be an array'); - options = {name: 'foo', serializers: 'a string'}; - t.throws(function () { new Logger(options); }, - 'invalid options.serializers: must be an object', - '"serializers" cannot be a string'); + options = {name: 'foo', serializers: 'a string'}; + t.throws(function () { new Logger(options); }, + 'invalid options.serializers: must be an object', + '"serializers" cannot be a string'); - options = {name: 'foo', serializers: [1, 2, 3]}; - t.throws(function () { new Logger(options); }, - 'invalid options.serializers: must be an object', - '"serializers" cannot be an array'); + options = {name: 'foo', serializers: [1, 2, 3]}; + t.throws(function () { new Logger(options); }, + 'invalid options.serializers: must be an object', + '"serializers" cannot be an array'); - t.end(); + t.end(); }); test('ensure Logger creation options (createLogger)', function (t) { - t.throws(function () { bunyan.createLogger(); }, - 'options (object) is required', - 'no options should throw'); + t.throws(function () { bunyan.createLogger(); }, + 'options (object) is required', + 'no options should throw'); - t.throws(function () { bunyan.createLogger({}); }, - 'options.name (string) is required', - 'no options.name should throw'); + t.throws(function () { bunyan.createLogger({}); }, + 'options.name (string) is required', + 'no options.name should throw'); - t.doesNotThrow(function () { bunyan.createLogger({name: 'foo'}); }, - 'just options.name should be sufficient'); + t.doesNotThrow(function () { bunyan.createLogger({name: 'foo'}); }, + 'just options.name should be sufficient'); - var options = {name: 'foo', stream: process.stdout, streams: []}; - t.throws(function () { bunyan.createLogger(options); }, - 'cannot use "stream" and "streams"'); + var options = {name: 'foo', stream: process.stdout, streams: []}; + t.throws(function () { bunyan.createLogger(options); }, + 'cannot use "stream" and "streams"'); - // https://github.com/trentm/node-bunyan/issues/3 - options = {name: 'foo', streams: {}}; - t.throws(function () { bunyan.createLogger(options); }, - 'invalid options.streams: must be an array', - '"streams" must be an array'); + // https://github.com/trentm/node-bunyan/issues/3 + options = {name: 'foo', streams: {}}; + t.throws(function () { bunyan.createLogger(options); }, + 'invalid options.streams: must be an array', + '"streams" must be an array'); - options = {name: 'foo', serializers: 'a string'}; - t.throws(function () { bunyan.createLogger(options); }, - 'invalid options.serializers: must be an object', - '"serializers" cannot be a string'); + options = {name: 'foo', serializers: 'a string'}; + t.throws(function () { bunyan.createLogger(options); }, + 'invalid options.serializers: must be an object', + '"serializers" cannot be a string'); - options = {name: 'foo', serializers: [1, 2, 3]}; - t.throws(function () { bunyan.createLogger(options); }, - 'invalid options.serializers: must be an object', - '"serializers" cannot be an array'); + options = {name: 'foo', serializers: [1, 2, 3]}; + t.throws(function () { bunyan.createLogger(options); }, + 'invalid options.serializers: must be an object', + '"serializers" cannot be an array'); - t.end(); + t.end(); }); test('ensure Logger child() options', function (t) { - var log = new Logger({name: 'foo'}); + var log = new Logger({name: 'foo'}); - t.doesNotThrow(function () { log.child(); }, - 'no options should be fine'); + t.doesNotThrow(function () { log.child(); }, + 'no options should be fine'); - t.doesNotThrow(function () { log.child({}); }, - 'empty options should be fine too'); + t.doesNotThrow(function () { log.child({}); }, + 'empty options should be fine too'); - t.throws(function () { log.child({name: 'foo'}); }, - 'invalid options.name: child cannot set logger name', - 'child cannot change name'); + t.throws(function () { log.child({name: 'foo'}); }, + 'invalid options.name: child cannot set logger name', + 'child cannot change name'); - var options = {stream: process.stdout, streams: []}; - t.throws(function () { log.child(options); }, - 'cannot use "stream" and "streams"'); + var options = {stream: process.stdout, streams: []}; + t.throws(function () { log.child(options); }, + 'cannot use "stream" and "streams"'); - // https://github.com/trentm/node-bunyan/issues/3 - options = {streams: {}}; - t.throws(function () { log.child(options); }, - 'invalid options.streams: must be an array', - '"streams" must be an array'); + // https://github.com/trentm/node-bunyan/issues/3 + options = {streams: {}}; + t.throws(function () { log.child(options); }, + 'invalid options.streams: must be an array', + '"streams" must be an array'); - options = {serializers: 'a string'}; - t.throws(function () { log.child(options); }, - 'invalid options.serializers: must be an object', - '"serializers" cannot be a string'); + options = {serializers: 'a string'}; + t.throws(function () { log.child(options); }, + 'invalid options.serializers: must be an object', + '"serializers" cannot be a string'); - options = {serializers: [1, 2, 3]}; - t.throws(function () { log.child(options); }, - 'invalid options.serializers: must be an object', - '"serializers" cannot be an array'); + options = {serializers: [1, 2, 3]}; + t.throws(function () { log.child(options); }, + 'invalid options.serializers: must be an object', + '"serializers" cannot be an array'); - t.end(); + t.end(); }); diff --git a/test/cycles.test.js b/test/cycles.test.js index 1ec4bdb..3f1cda6 100644 --- a/test/cycles.test.js +++ b/test/cycles.test.js @@ -8,7 +8,7 @@ var Logger = require('../lib/bunyan.js'); // node-tap API if (require.cache[__dirname + '/tap4nodeunit.js']) - delete require.cache[__dirname + '/tap4nodeunit.js']; + delete require.cache[__dirname + '/tap4nodeunit.js']; var tap4nodeunit = require('./tap4nodeunit.js'); var after = tap4nodeunit.after; var before = tap4nodeunit.before; @@ -20,71 +20,71 @@ var outstr = new Stream; outstr.writable = true; var output = []; outstr.write = function (c) { - output.push(JSON.parse(c + '')); + output.push(JSON.parse(c + '')); }; outstr.end = function (c) { - if (c) this.write(c); - this.emit('end'); + if (c) this.write(c); + this.emit('end'); }; // these are lacking a few fields that will probably never match var expect = - [ - { - 'name': 'blammo', - 'level': 30, - 'msg': 'bango { bang: \'boom\', KABOOM: [Circular] }', - 'v': 0 - }, - { - 'name': 'blammo', - 'level': 30, - 'msg': 'kaboom { bang: \'boom\', KABOOM: [Circular] }', - 'v': 0 - }, - { - 'name': 'blammo', - 'level': 30, - 'bang': 'boom', - 'KABOOM': { - 'bang': 'boom', - 'KABOOM': '[Circular]' - }, - 'msg': '', - 'v': 0 - } - ]; + [ + { + 'name': 'blammo', + 'level': 30, + 'msg': 'bango { bang: \'boom\', KABOOM: [Circular] }', + 'v': 0 + }, + { + 'name': 'blammo', + 'level': 30, + 'msg': 'kaboom { bang: \'boom\', KABOOM: [Circular] }', + 'v': 0 + }, + { + 'name': 'blammo', + 'level': 30, + 'bang': 'boom', + 'KABOOM': { + 'bang': 'boom', + 'KABOOM': '[Circular]' + }, + 'msg': '', + 'v': 0 + } + ]; var log = new Logger({ - name: 'blammo', - streams: [ - { - type: 'stream', - level: 'info', - stream: outstr - } - ] + name: 'blammo', + streams: [ + { + type: 'stream', + level: 'info', + stream: outstr + } + ] }); test('cycles', function (t) { - outstr.on('end', function () { - output.forEach(function (o, i) { - // Drop variable parts for comparison. - delete o.hostname; - delete o.pid; - delete o.time; - // Hack object/dict comparison: JSONify. - t.equal(JSON.stringify(o), JSON.stringify(expect[i]), - 'log item ' + i + ' matches'); + outstr.on('end', function () { + output.forEach(function (o, i) { + // Drop variable parts for comparison. + delete o.hostname; + delete o.pid; + delete o.time; + // Hack object/dict comparison: JSONify. + t.equal(JSON.stringify(o), JSON.stringify(expect[i]), + 'log item ' + i + ' matches'); + }); + t.end(); }); - t.end(); - }); - var obj = { bang: 'boom' }; - obj.KABOOM = obj; - log.info('bango', obj); - log.info('kaboom', obj.KABOOM); - log.info(obj); - outstr.end(); - t.ok('did not throw'); + var obj = { bang: 'boom' }; + obj.KABOOM = obj; + log.info('bango', obj); + log.info('kaboom', obj.KABOOM); + log.info(obj); + outstr.end(); + t.ok('did not throw'); }); diff --git a/test/dtrace.test.js b/test/dtrace.test.js index 0f90ac2..82c1485 100644 --- a/test/dtrace.test.js +++ b/test/dtrace.test.js @@ -11,7 +11,7 @@ var bunyan = require('../lib/bunyan'); // node-tap API if (require.cache[__dirname + '/tap4nodeunit.js']) - delete require.cache[__dirname + '/tap4nodeunit.js']; + delete require.cache[__dirname + '/tap4nodeunit.js']; var tap4nodeunit = require('./tap4nodeunit.js'); var after = tap4nodeunit.after; var before = tap4nodeunit.before; @@ -22,55 +22,55 @@ var test = tap4nodeunit.test; var dtracePlats = ['sunos', 'darwin', 'freebsd']; var runDtraceTests = true; try { - require('dtrace-provider') + require('dtrace-provider') } catch (e) { - console.log('# skip dtrace tests: no dtrace-provider module'); - runDtraceTests = false; + console.log('# skip dtrace tests: no dtrace-provider module'); + runDtraceTests = false; } if (!runDtraceTests) { - /* pass through */ + /* pass through */ } else if (dtracePlats.indexOf(process.platform) === -1) { - console.log('# skip dtrace tests: not on a platform with dtrace'); - runDtraceTests = false; + console.log('# skip dtrace tests: not on a platform with dtrace'); + runDtraceTests = false; } else if (process.env.SKIP_DTRACE) { - console.log('# skip dtrace tests: SKIP_DTRACE envvar set'); - runDtraceTests = false; + console.log('# skip dtrace tests: SKIP_DTRACE envvar set'); + runDtraceTests = false; } else if (process.getgid() !== 0) { - console.log('# skip dtrace tests: gid is not 0, run with `sudo`'); - runDtraceTests = false; + console.log('# skip dtrace tests: gid is not 0, run with `sudo`'); + runDtraceTests = false; } if (runDtraceTests) { test('basic dtrace', function (t) { - var argv = ['dtrace', '-Z', '-x', 'strsize=4k', '-qn', - 'bunyan$target:::log-*{printf("%s", copyinstr(arg0))}', - '-c', format('node %s/log-some.js', __dirname)]; - var dtrace = spawn(argv[0], argv.slice(1)); - //console.error('ARGV: %j', argv); + var argv = ['dtrace', '-Z', '-x', 'strsize=4k', '-qn', + 'bunyan$target:::log-*{printf("%s", copyinstr(arg0))}', + '-c', format('node %s/log-some.js', __dirname)]; + var dtrace = spawn(argv[0], argv.slice(1)); + //console.error('ARGV: %j', argv); - var traces = []; - dtrace.stdout.on('data', function (data) { - //console.error('DTRACE STDOUT:', data.toString()); - traces.push(data.toString()); - }); - dtrace.stderr.on('data', function (data) { - console.error('DTRACE STDERR:', data.toString()); - }); - dtrace.on('exit', function (code) { - t.notOk(code, 'dtrace exited cleanly'); - traces = traces.join('').split('\n') - .filter(function (t) { return t.trim().length }) - .map(function (t) { return JSON.parse(t) }); - t.equal(traces.length, 2, 'got 2 log records'); - if (traces.length) { - t.equal(traces[0].level, bunyan.DEBUG); - t.equal(traces[0].foo, 'bar'); - t.equal(traces[1].level, bunyan.TRACE); - t.equal(traces[1].msg, 'hi at trace'); - } - t.end(); - }); + var traces = []; + dtrace.stdout.on('data', function (data) { + //console.error('DTRACE STDOUT:', data.toString()); + traces.push(data.toString()); + }); + dtrace.stderr.on('data', function (data) { + console.error('DTRACE STDERR:', data.toString()); + }); + dtrace.on('exit', function (code) { + t.notOk(code, 'dtrace exited cleanly'); + traces = traces.join('').split('\n') + .filter(function (t) { return t.trim().length }) + .map(function (t) { return JSON.parse(t) }); + t.equal(traces.length, 2, 'got 2 log records'); + if (traces.length) { + t.equal(traces[0].level, bunyan.DEBUG); + t.equal(traces[0].foo, 'bar'); + t.equal(traces[1].level, bunyan.TRACE); + t.equal(traces[1].msg, 'hi at trace'); + } + t.end(); + }); }); diff --git a/test/error-event.test.js b/test/error-event.test.js index 4adf845..50616b3 100644 --- a/test/error-event.test.js +++ b/test/error-event.test.js @@ -9,7 +9,7 @@ var bunyan = require('../lib/bunyan'); // node-tap API if (require.cache[__dirname + '/tap4nodeunit.js']) - delete require.cache[__dirname + '/tap4nodeunit.js']; + delete require.cache[__dirname + '/tap4nodeunit.js']; var tap4nodeunit = require('./tap4nodeunit.js'); var after = tap4nodeunit.after; var before = tap4nodeunit.before; @@ -17,16 +17,16 @@ var test = tap4nodeunit.test; test('error event on log write', function (t) { - LOG_PATH = '/this/path/is/bogus.log' - var log = bunyan.createLogger( - {name: 'error-event', streams: [ {path: LOG_PATH} ]}); - log.on('error', function (err, stream) { - t.ok(err, 'got err in error event: ' + err); - t.equal(err.code, 'ENOENT', 'error code is ENOENT'); - t.ok(stream, 'got a stream argument'); - t.equal(stream.path, LOG_PATH); - t.equal(stream.type, 'file'); - t.end(); - }); - log.info('info log message'); + LOG_PATH = '/this/path/is/bogus.log' + var log = bunyan.createLogger( + {name: 'error-event', streams: [ {path: LOG_PATH} ]}); + log.on('error', function (err, stream) { + t.ok(err, 'got err in error event: ' + err); + t.equal(err.code, 'ENOENT', 'error code is ENOENT'); + t.ok(stream, 'got a stream argument'); + t.equal(stream.path, LOG_PATH); + t.equal(stream.type, 'file'); + t.end(); + }); + log.info('info log message'); }); diff --git a/test/log-some.js b/test/log-some.js index 2e3a893..4d0f042 100644 --- a/test/log-some.js +++ b/test/log-some.js @@ -5,8 +5,8 @@ var bunyan = require('../lib/bunyan'); var log = bunyan.createLogger({ - name: 'play', - serializers: bunyan.stdSerializers + name: 'play', + serializers: bunyan.stdSerializers }); log.debug({foo: 'bar'}, 'hi at debug') log.trace('hi at trace') diff --git a/test/log.test.js b/test/log.test.js index 5862374..77e013b 100644 --- a/test/log.test.js +++ b/test/log.test.js @@ -8,7 +8,7 @@ var bunyan = require('../lib/bunyan'); // node-tap API if (require.cache[__dirname + '/tap4nodeunit.js']) - delete require.cache[__dirname + '/tap4nodeunit.js']; + delete require.cache[__dirname + '/tap4nodeunit.js']; var tap4nodeunit = require('./tap4nodeunit.js'); var after = tap4nodeunit.after; var before = tap4nodeunit.before; @@ -16,45 +16,45 @@ var test = tap4nodeunit.test; var log1 = bunyan.createLogger({ - name: 'log1', - streams: [ - { - path: __dirname + '/log.test.log1.log', - level: 'info' - } - ] + name: 'log1', + streams: [ + { + path: __dirname + '/log.test.log1.log', + level: 'info' + } + ] }); var log2 = bunyan.createLogger({ - name: 'log2', - streams: [ - { - path: __dirname + '/log.test.log2a.log', - level: 'error' - }, - { - path: __dirname + '/log.test.log2b.log', - level: 'debug' - } - ] + name: 'log2', + streams: [ + { + path: __dirname + '/log.test.log2a.log', + level: 'error' + }, + { + path: __dirname + '/log.test.log2b.log', + level: 'debug' + } + ] }) test('log.LEVEL() -> boolean', function (t) { - t.equal(log1.trace(), false, 'log1.trace() is false') - t.equal(log1.debug(), false) - t.equal(log1.info(), true) - t.equal(log1.warn(), true) - t.equal(log1.error(), true) - t.equal(log1.fatal(), true) + t.equal(log1.trace(), false, 'log1.trace() is false') + t.equal(log1.debug(), false) + t.equal(log1.info(), true) + t.equal(log1.warn(), true) + t.equal(log1.error(), true) + t.equal(log1.fatal(), true) - // Level is the *lowest* level of all streams. - t.equal(log2.trace(), false) - t.equal(log2.debug(), true) - t.equal(log2.info(), true) - t.equal(log2.warn(), true) - t.equal(log2.error(), true) - t.equal(log2.fatal(), true) - t.end(); + // Level is the *lowest* level of all streams. + t.equal(log2.trace(), false) + t.equal(log2.debug(), true) + t.equal(log2.info(), true) + t.equal(log2.warn(), true) + t.equal(log2.error(), true) + t.equal(log2.fatal(), true) + t.end(); }); //TODO: diff --git a/test/other-api.test.js b/test/other-api.test.js index 29fc580..0d9304b 100644 --- a/test/other-api.test.js +++ b/test/other-api.test.js @@ -8,7 +8,7 @@ var bunyan = require('../lib/bunyan'); // node-tap API if (require.cache[__dirname + '/tap4nodeunit.js']) - delete require.cache[__dirname + '/tap4nodeunit.js']; + delete require.cache[__dirname + '/tap4nodeunit.js']; var tap4nodeunit = require('./tap4nodeunit.js'); var after = tap4nodeunit.after; var before = tap4nodeunit.before; @@ -16,27 +16,27 @@ var test = tap4nodeunit.test; test('bunyan.s', function (t) { - t.ok(bunyan.TRACE, 'TRACE'); - t.ok(bunyan.DEBUG, 'DEBUG'); - t.ok(bunyan.INFO, 'INFO'); - t.ok(bunyan.WARN, 'WARN'); - t.ok(bunyan.ERROR, 'ERROR'); - t.ok(bunyan.FATAL, 'FATAL'); - t.end(); + t.ok(bunyan.TRACE, 'TRACE'); + t.ok(bunyan.DEBUG, 'DEBUG'); + t.ok(bunyan.INFO, 'INFO'); + t.ok(bunyan.WARN, 'WARN'); + t.ok(bunyan.ERROR, 'ERROR'); + t.ok(bunyan.FATAL, 'FATAL'); + t.end(); }); test('bunyan.resolveLevel()', function (t) { - t.equal(bunyan.resolveLevel('trace'), bunyan.TRACE, 'TRACE'); - t.equal(bunyan.resolveLevel('TRACE'), bunyan.TRACE, 'TRACE'); - t.equal(bunyan.resolveLevel('debug'), bunyan.DEBUG, 'DEBUG'); - t.equal(bunyan.resolveLevel('DEBUG'), bunyan.DEBUG, 'DEBUG'); - t.equal(bunyan.resolveLevel('info'), bunyan.INFO, 'INFO'); - t.equal(bunyan.resolveLevel('INFO'), bunyan.INFO, 'INFO'); - t.equal(bunyan.resolveLevel('warn'), bunyan.WARN, 'WARN'); - t.equal(bunyan.resolveLevel('WARN'), bunyan.WARN, 'WARN'); - t.equal(bunyan.resolveLevel('error'), bunyan.ERROR, 'ERROR'); - t.equal(bunyan.resolveLevel('ERROR'), bunyan.ERROR, 'ERROR'); - t.equal(bunyan.resolveLevel('fatal'), bunyan.FATAL, 'FATAL'); - t.equal(bunyan.resolveLevel('FATAL'), bunyan.FATAL, 'FATAL'); - t.end(); + t.equal(bunyan.resolveLevel('trace'), bunyan.TRACE, 'TRACE'); + t.equal(bunyan.resolveLevel('TRACE'), bunyan.TRACE, 'TRACE'); + t.equal(bunyan.resolveLevel('debug'), bunyan.DEBUG, 'DEBUG'); + t.equal(bunyan.resolveLevel('DEBUG'), bunyan.DEBUG, 'DEBUG'); + t.equal(bunyan.resolveLevel('info'), bunyan.INFO, 'INFO'); + t.equal(bunyan.resolveLevel('INFO'), bunyan.INFO, 'INFO'); + t.equal(bunyan.resolveLevel('warn'), bunyan.WARN, 'WARN'); + t.equal(bunyan.resolveLevel('WARN'), bunyan.WARN, 'WARN'); + t.equal(bunyan.resolveLevel('error'), bunyan.ERROR, 'ERROR'); + t.equal(bunyan.resolveLevel('ERROR'), bunyan.ERROR, 'ERROR'); + t.equal(bunyan.resolveLevel('fatal'), bunyan.FATAL, 'FATAL'); + t.equal(bunyan.resolveLevel('FATAL'), bunyan.FATAL, 'FATAL'); + t.end(); }); diff --git a/test/raw-stream.test.js b/test/raw-stream.test.js index 21d5ad7..88432f3 100644 --- a/test/raw-stream.test.js +++ b/test/raw-stream.test.js @@ -9,7 +9,7 @@ var Logger = require('../lib/bunyan'); // node-tap API if (require.cache[__dirname + '/tap4nodeunit.js']) - delete require.cache[__dirname + '/tap4nodeunit.js']; + delete require.cache[__dirname + '/tap4nodeunit.js']; var tap4nodeunit = require('./tap4nodeunit.js'); var after = tap4nodeunit.after; var before = tap4nodeunit.before; @@ -17,101 +17,101 @@ var test = tap4nodeunit.test; function CapturingStream(recs) { - this.recs = recs; + this.recs = recs; } CapturingStream.prototype.write = function (rec) { - this.recs.push(rec); + this.recs.push(rec); } test('raw stream', function (t) { - var recs = []; + var recs = []; - var log = new Logger({ - name: 'raw-stream-test', - streams: [ - { - stream: new CapturingStream(recs), - type: 'raw' - } - ] - }); - log.info('first'); - log.info({two: 'deux'}, 'second'); + var log = new Logger({ + name: 'raw-stream-test', + streams: [ + { + stream: new CapturingStream(recs), + type: 'raw' + } + ] + }); + 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(); + 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 rawRecs = []; + var nonRawRecs = []; - var log = new Logger({ - name: 'raw-stream-test', - streams: [ - { - stream: new CapturingStream(rawRecs), - type: 'raw' - }, - { - stream: new CapturingStream(nonRawRecs) - } - ] - }); - log.info('first'); - log.info({two: 'deux'}, 'second'); + var log = new Logger({ + name: 'raw-stream-test', + streams: [ + { + stream: new CapturingStream(rawRecs), + type: 'raw' + }, + { + 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(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.equal(nonRawRecs.length, 2); + t.equal(typeof (nonRawRecs[0]), 'string', 'first nonRawRec is a string'); - t.end(); + t.end(); }); test('child adding a non-raw stream works', function (t) { - var parentRawRecs = []; - var rawRecs = []; - var nonRawRecs = []; + var parentRawRecs = []; + var rawRecs = []; + var nonRawRecs = []; - var logParent = new Logger({ - name: 'raw-stream-test', - streams: [ - { - stream: new CapturingStream(parentRawRecs), - type: 'raw' - } - ] - }); - var logChild = logParent.child({ - child: true, - streams: [ - { - stream: new CapturingStream(rawRecs), - type: 'raw' - }, - { - stream: new CapturingStream(nonRawRecs) - } - ] - }); - logParent.info('first'); - logChild.info({two: 'deux'}, 'second'); + var logParent = new Logger({ + name: 'raw-stream-test', + streams: [ + { + stream: new CapturingStream(parentRawRecs), + type: 'raw' + } + ] + }); + var logChild = logParent.child({ + child: true, + streams: [ + { + stream: new CapturingStream(rawRecs), + type: 'raw' + }, + { + 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(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.equal(nonRawRecs.length, 1); + t.equal(typeof (nonRawRecs[0]), 'string', 'first nonRawRec is a string'); - t.end(); + t.end(); }); diff --git a/test/ringbuffer.test.js b/test/ringbuffer.test.js index 1fd7329..79d193a 100644 --- a/test/ringbuffer.test.js +++ b/test/ringbuffer.test.js @@ -7,7 +7,7 @@ var ringbuffer = new Logger.RingBuffer({ 'limit': 5 }); // node-tap API if (require.cache[__dirname + '/tap4nodeunit.js']) - delete require.cache[__dirname + '/tap4nodeunit.js']; + delete require.cache[__dirname + '/tap4nodeunit.js']; var tap4nodeunit = require('./tap4nodeunit.js'); var after = tap4nodeunit.after; var before = tap4nodeunit.before; @@ -15,33 +15,33 @@ var test = tap4nodeunit.test; var log1 = new Logger({ - name: 'log1', - streams: [ - { - stream: ringbuffer, - type: 'raw', - level: 'info' - } - ] + name: 'log1', + streams: [ + { + stream: ringbuffer, + type: 'raw', + level: 'info' + } + ] }); test('ringbuffer', function (t) { - log1.info('hello'); - log1.trace('there'); - log1.error('android'); - t.equal(ringbuffer.records.length, 2); - t.equal(ringbuffer.records[0]['msg'], 'hello'); - t.equal(ringbuffer.records[1]['msg'], 'android'); - log1.error('one'); - log1.error('two'); - log1.error('three'); - t.equal(ringbuffer.records.length, 5); - log1.error('four'); - t.equal(ringbuffer.records.length, 5); - t.equal(ringbuffer.records[0]['msg'], 'android'); - t.equal(ringbuffer.records[1]['msg'], 'one'); - t.equal(ringbuffer.records[2]['msg'], 'two'); - t.equal(ringbuffer.records[3]['msg'], 'three'); - t.equal(ringbuffer.records[4]['msg'], 'four'); - t.end(); + log1.info('hello'); + log1.trace('there'); + log1.error('android'); + t.equal(ringbuffer.records.length, 2); + t.equal(ringbuffer.records[0]['msg'], 'hello'); + t.equal(ringbuffer.records[1]['msg'], 'android'); + log1.error('one'); + log1.error('two'); + log1.error('three'); + t.equal(ringbuffer.records.length, 5); + log1.error('four'); + t.equal(ringbuffer.records.length, 5); + t.equal(ringbuffer.records[0]['msg'], 'android'); + t.equal(ringbuffer.records[1]['msg'], 'one'); + t.equal(ringbuffer.records[2]['msg'], 'two'); + t.equal(ringbuffer.records[3]['msg'], 'three'); + t.equal(ringbuffer.records[4]['msg'], 'four'); + t.end(); }); diff --git a/test/serializers.test.js b/test/serializers.test.js index c58a7d3..fcfbab0 100644 --- a/test/serializers.test.js +++ b/test/serializers.test.js @@ -11,7 +11,7 @@ var verror = require('verror'); // node-tap API if (require.cache[__dirname + '/tap4nodeunit.js']) - delete require.cache[__dirname + '/tap4nodeunit.js']; + delete require.cache[__dirname + '/tap4nodeunit.js']; var tap4nodeunit = require('./tap4nodeunit.js'); var after = tap4nodeunit.after; var before = tap4nodeunit.before; @@ -19,246 +19,246 @@ var test = tap4nodeunit.test; function CapturingStream(recs) { - this.recs = recs; + this.recs = recs; } CapturingStream.prototype.write = function (rec) { - this.recs.push(rec); + this.recs.push(rec); } test('req serializer', function (t) { - var records = []; - var log = bunyan.createLogger({ - name: 'serializer-test', - streams: [ - { - stream: new CapturingStream(records), - type: 'raw' - } - ], - serializers: { - req: bunyan.stdSerializers.req - } - }); - - // None of these should blow up. - var bogusReqs = [ - undefined, - null, - {}, - 1, - 'string', - [1, 2, 3], - {'foo':'bar'} - ]; - for (var i = 0; i < bogusReqs.length; i++) { - log.info({req: bogusReqs[i]}, 'hi'); - t.equal(records[i].req, bogusReqs[i]); - } - - // Get http request and response objects to play with and test. - var theReq, theRes; - var server = http.createServer(function (req, res) { - theReq = req; - theRes = res; - res.writeHead(200, {'Content-Type': 'text/plain'}); - res.end('Hello World\n'); - }) - server.listen(8765, function () { - http.get({host: '127.0.0.1', port: 8765, path: '/'}, function (res) { - res.resume(); - log.info({req: theReq}, 'the request'); - 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.remotePort, theReq.connection.remotePort); - server.close(); - t.end(); - }).on('error', function (err) { - t.ok(false, 'error requesting to our test server: ' + err); - server.close(); - t.end(); + var records = []; + var log = bunyan.createLogger({ + name: 'serializer-test', + streams: [ + { + stream: new CapturingStream(records), + type: 'raw' + } + ], + serializers: { + req: bunyan.stdSerializers.req + } + }); + + // None of these should blow up. + var bogusReqs = [ + undefined, + null, + {}, + 1, + 'string', + [1, 2, 3], + {'foo':'bar'} + ]; + for (var i = 0; i < bogusReqs.length; i++) { + log.info({req: bogusReqs[i]}, 'hi'); + t.equal(records[i].req, bogusReqs[i]); + } + + // Get http request and response objects to play with and test. + var theReq, theRes; + var server = http.createServer(function (req, res) { + theReq = req; + theRes = res; + res.writeHead(200, {'Content-Type': 'text/plain'}); + res.end('Hello World\n'); + }) + server.listen(8765, function () { + http.get({host: '127.0.0.1', port: 8765, path: '/'}, function (res) { + res.resume(); + log.info({req: theReq}, 'the request'); + 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.remotePort, theReq.connection.remotePort); + server.close(); + t.end(); + }).on('error', function (err) { + t.ok(false, 'error requesting to our test server: ' + err); + server.close(); + t.end(); + }); }); - }); }); test('res serializer', function (t) { - var records = []; - var log = bunyan.createLogger({ - name: 'serializer-test', - streams: [ - { - stream: new CapturingStream(records), - type: 'raw' - } - ], - serializers: { - res: bunyan.stdSerializers.res - } - }); - - // None of these should blow up. - var bogusRess = [ - undefined, - null, - {}, - 1, - 'string', - [1, 2, 3], - {'foo':'bar'} - ]; - for (var i = 0; i < bogusRess.length; i++) { - log.info({res: bogusRess[i]}, 'hi'); - t.equal(records[i].res, bogusRess[i]); - } - - // Get http request and response objects to play with and test. - var theReq, theRes; - var server = http.createServer(function (req, res) { - theReq = req; - theRes = res; - res.writeHead(200, {'Content-Type': 'text/plain'}); - res.end('Hello World\n'); - }) - server.listen(8765, function () { - http.get({host: '127.0.0.1', port: 8765, path: '/'}, function (res) { - res.resume(); - log.info({res: theRes}, 'the response'); - var lastRecord = records[records.length-1]; - t.equal(lastRecord.res.statusCode, theRes.statusCode); - t.equal(lastRecord.res.header, theRes._header); - server.close(); - t.end(); - }).on('error', function (err) { - t.ok(false, 'error requesting to our test server: ' + err); - server.close(); - t.end(); + var records = []; + var log = bunyan.createLogger({ + name: 'serializer-test', + streams: [ + { + stream: new CapturingStream(records), + type: 'raw' + } + ], + serializers: { + res: bunyan.stdSerializers.res + } + }); + + // None of these should blow up. + var bogusRess = [ + undefined, + null, + {}, + 1, + 'string', + [1, 2, 3], + {'foo':'bar'} + ]; + for (var i = 0; i < bogusRess.length; i++) { + log.info({res: bogusRess[i]}, 'hi'); + t.equal(records[i].res, bogusRess[i]); + } + + // Get http request and response objects to play with and test. + var theReq, theRes; + var server = http.createServer(function (req, res) { + theReq = req; + theRes = res; + res.writeHead(200, {'Content-Type': 'text/plain'}); + res.end('Hello World\n'); + }) + server.listen(8765, function () { + http.get({host: '127.0.0.1', port: 8765, path: '/'}, function (res) { + res.resume(); + log.info({res: theRes}, 'the response'); + var lastRecord = records[records.length-1]; + t.equal(lastRecord.res.statusCode, theRes.statusCode); + t.equal(lastRecord.res.header, theRes._header); + server.close(); + t.end(); + }).on('error', function (err) { + t.ok(false, 'error requesting to our test server: ' + err); + server.close(); + t.end(); + }); }); - }); }); test('err serializer', function (t) { - var records = []; - var log = bunyan.createLogger({ - name: 'serializer-test', - streams: [ - { - stream: new CapturingStream(records), - type: 'raw' - } - ], - serializers: { - err: bunyan.stdSerializers.err + var records = []; + var log = bunyan.createLogger({ + name: 'serializer-test', + streams: [ + { + stream: new CapturingStream(records), + type: 'raw' + } + ], + serializers: { + err: bunyan.stdSerializers.err + } + }); + + // None of these should blow up. + var bogusErrs = [ + undefined, + null, + {}, + 1, + 'string', + [1, 2, 3], + {'foo':'bar'} + ]; + for (var i = 0; i < bogusErrs.length; i++) { + log.info({err: bogusErrs[i]}, 'hi'); + t.equal(records[i].err, bogusErrs[i]); } - }); - // None of these should blow up. - var bogusErrs = [ - undefined, - null, - {}, - 1, - 'string', - [1, 2, 3], - {'foo':'bar'} - ]; - for (var i = 0; i < bogusErrs.length; i++) { - log.info({err: bogusErrs[i]}, 'hi'); - t.equal(records[i].err, bogusErrs[i]); - } + var theErr = new TypeError('blah'); - var theErr = new TypeError('blah'); - - log.info(theErr, 'the error'); - var lastRecord = records[records.length-1]; - t.equal(lastRecord.err.message, theErr.message); - t.equal(lastRecord.err.name, theErr.name); - t.equal(lastRecord.err.stack, theErr.stack); - t.end(); + log.info(theErr, 'the error'); + var lastRecord = records[records.length-1]; + t.equal(lastRecord.err.message, theErr.message); + t.equal(lastRecord.err.name, theErr.name); + t.equal(lastRecord.err.stack, theErr.stack); + t.end(); }); test('err serializer: long stack', function (t) { - var records = []; - var log = bunyan.createLogger({ - name: 'serializer-test', - streams: [ { - stream: new CapturingStream(records), - type: 'raw' - } ], - serializers: { - err: bunyan.stdSerializers.err - } - }); + var records = []; + var log = bunyan.createLogger({ + name: 'serializer-test', + streams: [ { + stream: new CapturingStream(records), + type: 'raw' + } ], + serializers: { + err: bunyan.stdSerializers.err + } + }); - var topErr, midErr, bottomErr; + var topErr, midErr, bottomErr; - // Just a VError. - topErr = new verror.VError('top err'); - log.info(topErr, 'the error'); - var lastRecord = records[records.length-1]; - t.equal(lastRecord.err.message, topErr.message, 'Just a VError'); - t.equal(lastRecord.err.name, topErr.name, 'Just a VError'); - t.equal(lastRecord.err.stack, topErr.stack, 'Just a VError'); + // Just a VError. + topErr = new verror.VError('top err'); + log.info(topErr, 'the error'); + var lastRecord = records[records.length-1]; + t.equal(lastRecord.err.message, topErr.message, 'Just a VError'); + t.equal(lastRecord.err.name, topErr.name, 'Just a VError'); + t.equal(lastRecord.err.stack, topErr.stack, 'Just a VError'); - // Just a WError. - topErr = new verror.WError('top err'); - log.info(topErr, 'the error'); - var lastRecord = records[records.length-1]; - t.equal(lastRecord.err.message, topErr.message, 'Just a WError'); - t.equal(lastRecord.err.name, topErr.name, 'Just a WError'); - t.equal(lastRecord.err.stack, topErr.stack, 'Just a WError'); + // Just a WError. + topErr = new verror.WError('top err'); + log.info(topErr, 'the error'); + var lastRecord = records[records.length-1]; + t.equal(lastRecord.err.message, topErr.message, 'Just a WError'); + t.equal(lastRecord.err.name, topErr.name, 'Just a WError'); + t.equal(lastRecord.err.stack, topErr.stack, 'Just a WError'); - // WError <- TypeError - bottomErr = new TypeError('bottom err'); - topErr = new verror.WError(bottomErr, 'top err'); - log.info(topErr, 'the error'); - var lastRecord = records[records.length-1]; - t.equal(lastRecord.err.message, topErr.message, 'WError <- TypeError'); - t.equal(lastRecord.err.name, topErr.name, 'WError <- TypeError'); - var expectedStack = topErr.stack + '\nCaused by: ' + bottomErr.stack; - t.equal(lastRecord.err.stack, expectedStack, 'WError <- TypeError'); + // WError <- TypeError + bottomErr = new TypeError('bottom err'); + topErr = new verror.WError(bottomErr, 'top err'); + log.info(topErr, 'the error'); + var lastRecord = records[records.length-1]; + t.equal(lastRecord.err.message, topErr.message, 'WError <- TypeError'); + t.equal(lastRecord.err.name, topErr.name, 'WError <- TypeError'); + var expectedStack = topErr.stack + '\nCaused by: ' + bottomErr.stack; + t.equal(lastRecord.err.stack, expectedStack, 'WError <- TypeError'); - // WError <- WError - bottomErr = new verror.WError('bottom err'); - topErr = new verror.WError(bottomErr, 'top err'); - log.info(topErr, 'the error'); - var lastRecord = records[records.length-1]; - t.equal(lastRecord.err.message, topErr.message, 'WError <- WError'); - t.equal(lastRecord.err.name, topErr.name, 'WError <- WError'); - var expectedStack = topErr.stack + '\nCaused by: ' + bottomErr.stack; - t.equal(lastRecord.err.stack, expectedStack, 'WError <- WError'); + // WError <- WError + bottomErr = new verror.WError('bottom err'); + topErr = new verror.WError(bottomErr, 'top err'); + log.info(topErr, 'the error'); + var lastRecord = records[records.length-1]; + t.equal(lastRecord.err.message, topErr.message, 'WError <- WError'); + t.equal(lastRecord.err.name, topErr.name, 'WError <- WError'); + var expectedStack = topErr.stack + '\nCaused by: ' + bottomErr.stack; + t.equal(lastRecord.err.stack, expectedStack, 'WError <- WError'); - // WError <- WError <- TypeError - bottomErr = new TypeError('bottom err'); - midErr = new verror.WError(bottomErr, 'mid err'); - 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.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'); + // WError <- WError <- TypeError + bottomErr = new TypeError('bottom err'); + midErr = new verror.WError(bottomErr, 'mid err'); + 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.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'); - // WError <- WError <- WError - bottomErr = new verror.WError('bottom err'); - midErr = new verror.WError(bottomErr, 'mid err'); - 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.name, topErr.name, 'WError <- WError <- WError'); - var expectedStack = (topErr.stack - + '\nCaused by: ' + midErr.stack - + '\nCaused by: ' + bottomErr.stack); - t.equal(lastRecord.err.stack, expectedStack, 'WError <- WError <- WError'); + // WError <- WError <- WError + bottomErr = new verror.WError('bottom err'); + midErr = new verror.WError(bottomErr, 'mid err'); + 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.name, topErr.name, 'WError <- WError <- WError'); + var expectedStack = (topErr.stack + + '\nCaused by: ' + midErr.stack + + '\nCaused by: ' + bottomErr.stack); + t.equal(lastRecord.err.stack, expectedStack, 'WError <- WError <- WError'); - t.end(); + t.end(); }); @@ -266,28 +266,28 @@ test('err serializer: long stack', function (t) { // even if the log record doesn't have the associated key. That means // serializers that don't handle an `undefined` value will blow up. test('do not apply serializers if no record key', function (t) { - var records = []; - var log = bunyan.createLogger({ - name: 'serializer-test', - streams: [ { - stream: new CapturingStream(records), - type: 'raw' - } ], - serializers: { - err: bunyan.stdSerializers.err, - boom: function (value) { - throw new Error('boom'); - } - } - }); + var records = []; + var log = bunyan.createLogger({ + name: 'serializer-test', + streams: [ { + stream: new CapturingStream(records), + type: 'raw' + } ], + serializers: { + err: bunyan.stdSerializers.err, + boom: function (value) { + throw new Error('boom'); + } + } + }); - log.info({foo: 'bar'}, 'record one'); - log.info({err: new Error('record two err')}, 'record two'); + log.info({foo: 'bar'}, 'record one'); + log.info({err: new Error('record two err')}, 'record two'); - t.equal(records[0].boom, undefined); - t.equal(records[0].foo, 'bar'); - t.equal(records[1].boom, undefined); - t.equal(records[1].err.message, 'record two err'); + t.equal(records[0].boom, undefined); + t.equal(records[0].foo, 'bar'); + t.equal(records[1].boom, undefined); + t.equal(records[1].err.message, 'record two err'); - t.end(); + t.end(); }); diff --git a/test/tap4nodeunit.js b/test/tap4nodeunit.js index 6443be0..49e1b45 100644 --- a/test/tap4nodeunit.js +++ b/test/tap4nodeunit.js @@ -18,45 +18,45 @@ 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; + 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); - }; - } + tester.call(this, t); + }; + } }; diff --git a/tools/timechild.js b/tools/timechild.js index 8df5e0b..168f759 100755 --- a/tools/timechild.js +++ b/tools/timechild.js @@ -17,68 +17,68 @@ var ben = require('ben'); // npm install ben var Logger = require('../lib/bunyan'); var log = new Logger({ - name: 'svc', - streams: [ - { - path: __dirname + '/timechild.log' - }, - { - stream: process.stdout + name: 'svc', + streams: [ + { + path: __dirname + '/timechild.log' + }, + { + stream: process.stdout + } + ], + serializers: { + err: Logger.stdSerializers.err } - ], - serializers: { - err: Logger.stdSerializers.err - } }); console.log('Time `log.child`:'); var ms = ben(1e5, function () { - var child = log.child(); + var child = log.child(); }); console.log(' - adding no fields: %dms per iteration', ms); var ms = ben(1e5, function () { - var child = log.child({a:1}); + var child = log.child({a:1}); }); console.log(' - adding one field: %dms per iteration', ms); var ms = ben(1e5, function () { - var child = log.child({a:1, b:2}); + var child = log.child({a:1, b:2}); }); console.log(' - adding two fields: %dms per iteration', ms); function fooSerializer(obj) { - return {bar: obj.bar}; + return {bar: obj.bar}; } var ms = ben(1e5, function () { - var child = log.child({ - a: 1, - serializers: {foo: fooSerializer} - }); + var child = log.child({ + a: 1, + serializers: {foo: fooSerializer} + }); }); console.log(' - adding serializer and one field: %dms per iteration', ms); var ms = ben(1e5, function () { - var child = log.child({ - a: 1, - streams: [ {stream: process.stderr} ] - }); + var child = log.child({ + a: 1, + streams: [ {stream: process.stderr} ] + }); }); console.log(' - adding a (stderr) stream and one field: %dms per iteration', - ms); + ms); var ms = ben(1e6, function () { - var child = log.child({}, true); + var child = log.child({}, true); }); console.log(' - [fast] adding no fields: %dms per iteration', ms); var ms = ben(1e6, function () { - var child = log.child({a:1}, true); + var child = log.child({a:1}, true); }); console.log(' - [fast] adding one field: %dms per iteration', ms); var ms = ben(1e6, function () { - var child = log.child({a:1, b:2}, true); + var child = log.child({a:1, b:2}, true); }); console.log(' - [fast] adding two fields: %dms per iteration', ms); diff --git a/tools/timeguard.js b/tools/timeguard.js index 6d5b0f8..93ba09c 100755 --- a/tools/timeguard.js +++ b/tools/timeguard.js @@ -12,17 +12,17 @@ var records = []; function Collector() { } Collector.prototype.write = function (s) { - //records.push(s); + //records.push(s); } var collector = new Collector(); var log = new Logger({ - name: 'timeguard', - src: true, - stream: collector + name: 'timeguard', + src: true, + stream: collector }); var ms = ben(1e5, function () { - log.info('hi'); + log.info('hi'); }); console.log(' - log.info: %dms per iteration', ms); diff --git a/tools/timesrc.js b/tools/timesrc.js index 456d5db..b94bf9d 100755 --- a/tools/timesrc.js +++ b/tools/timesrc.js @@ -12,26 +12,26 @@ var records = []; function Collector() { } Collector.prototype.write = function (s) { - //records.push(s); + //records.push(s); } var collector = new Collector(); var logwith = new Logger({ - name: 'with-src', - src: true, - stream: collector + name: 'with-src', + src: true, + stream: collector }); var ms = ben(1e5, function () { - logwith.info('hi'); + logwith.info('hi'); }); console.log(' - log.info with src: %dms per iteration', ms); var logwithout = new Logger({ - name: 'without-src', - stream: collector + name: 'without-src', + stream: collector }); var ms = ben(1e5, function () { - logwithout.info('hi'); + logwithout.info('hi'); }); console.log(' - log.info without src: %dms per iteration', ms);