TheThing
/
node-bunyan-lite
1
0
Fork 0
Code Issues Pull Requests Projects Releases 1 Wiki Activity

make check

master
Trent Mick 2013-04-01 17:21:01 -07:00
parent f616276dc6
commit a111200a5a
8 changed files with 297 additions and 223 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
Makefile
View File

@ -108,7 +108,7 @@ test06:
.PHONY: check-jsstyle
check-jsstyle: $(JSSTYLE_FILES)
./tools/jsstyle -o indent=4,doxygen,unparenthesized-return=0,blank-after-start-comment=0,leading-right-paren-ok $(JSSTYLE_FILES)
./tools/jsstyle -o indent=4,doxygen,unparenthesized-return=0,blank-after-start-comment=0,leading-right-paren-ok=1 $(JSSTYLE_FILES)
.PHONY: check
check: check-jsstyle

321
bin/bunyan
View File

@ -163,79 +163,82 @@ function objCopy(obj) {
}
function printHelp() {
console.log('Usage:');
console.log(' bunyan [OPTIONS] [FILE ...]');
console.log(' ... | bunyan [OPTIONS]');
console.log(' bunyan [OPTIONS] -p PID');
console.log('');
console.log('Filter and pretty-print Bunyan log file content.');
console.log('');
console.log('General options:');
console.log(' -h, --help print this help info and exit');
console.log(' --version print version of this command and exit');
console.log('');
console.log('Dtrace options (only on dtrace-supporting platforms):');
console.log(' -p PID Process bunyan:log-* probes from the process');
console.log(' with the given PID. Can be used multiple times,');
console.log(' or specify all processes with "*", or a set of');
console.log(' processes whose command & args match a pattern');
console.log(' with "-p NAME".');
console.log('');
console.log('Filtering options:');
console.log(' -l, --level LEVEL');
console.log(' Only show messages at or above the specified level.');
console.log(' You can specify level *names* or numeric values.');
console.log(' (See "Log Levels" below.)');
console.log(' -c, --condition CONDITION');
console.log(' Run each log message through the condition and');
console.log(' only show those that return truish. E.g.:');
console.log(' -c \'this.pid == 123\'');
console.log(' -c \'this.level == DEBUG\'');
console.log(' -c \'this.msg.indexOf("boom") != -1\'');
console.log(' "CONDITION" must be legal JS code. `this` holds');
console.log(' the log record. The TRACE, DEBUG, ... FATAL values');
console.log(' are defined to help with comparing `this.level`.');
console.log(' --strict Suppress all but legal Bunyan JSON log lines. By default');
console.log(' non-JSON, and non-Bunyan lines are passed through.');
console.log('');
console.log('Output options:');
console.log(' --pager Pipe output into `less` (or $PAGER if set), if');
console.log(' stdout is a TTY. This overrides $BUNYAN_NO_PAGER.');
console.log(' Note: Paging is only supported on node >=0.8.');
console.log(' --no-pager Do not pipe output into a pager.');
console.log(' --color Colorize output. Defaults to try if output');
console.log(' stream is a TTY.');
console.log(' --no-color Force no coloring (e.g. terminal doesn\'t support it)');
console.log(' -o, --output MODE');
console.log(' Specify an output mode/format. One of');
console.log(' long: (the default) pretty');
console.log(' json: JSON output, 2-space indent');
console.log(' json-N: JSON output, N-space indent, e.g. "json-4"');
console.log(' bunyan: 0 indented JSON, bunyan\'s native format');
console.log(' inspect: node.js `util.inspect` output');
console.log(' short: like "long", but more concise');
console.log(' -j shortcut for `-o json`');
console.log('');
console.log('Log Levels:');
console.log(' Either numeric values or their associated strings are valid for the');
console.log(' -l|--level argument. However, -c|--condition scripts will see a numeric');
console.log(' "level" value, not a string.');
console.log('');
/* BEGIN JSSTYLED */
var p = console.log;
p('Usage:');
p(' bunyan [OPTIONS] [FILE ...]');
p(' ... | bunyan [OPTIONS]');
p(' bunyan [OPTIONS] -p PID');
p('');
p('Filter and pretty-print Bunyan log file content.');
p('');
p('General options:');
p(' -h, --help print this help info and exit');
p(' --version print version of this command and exit');
p('');
p('Dtrace options (only on dtrace-supporting platforms):');
p(' -p PID Process bunyan:log-* probes from the process');
p(' with the given PID. Can be used multiple times,');
p(' or specify all processes with "*", or a set of');
p(' processes whose command & args match a pattern');
p(' with "-p NAME".');
p('');
p('Filtering options:');
p(' -l, --level LEVEL');
p(' Only show messages at or above the specified level.');
p(' You can specify level *names* or numeric values.');
p(' (See "Log Levels" below.)');
p(' -c, --condition CONDITION');
p(' Run each log message through the condition and');
p(' only show those that return truish. E.g.:');
p(' -c \'this.pid == 123\'');
p(' -c \'this.level == DEBUG\'');
p(' -c \'this.msg.indexOf("boom") != -1\'');
p(' "CONDITION" must be legal JS code. `this` holds');
p(' the log record. The TRACE, DEBUG, ... FATAL values');
p(' are defined to help with comparing `this.level`.');
p(' --strict Suppress all but legal Bunyan JSON log lines. By default');
p(' non-JSON, and non-Bunyan lines are passed through.');
p('');
p('Output options:');
p(' --pager Pipe output into `less` (or $PAGER if set), if');
p(' stdout is a TTY. This overrides $BUNYAN_NO_PAGER.');
p(' Note: Paging is only supported on node >=0.8.');
p(' --no-pager Do not pipe output into a pager.');
p(' --color Colorize output. Defaults to try if output');
p(' stream is a TTY.');
p(' --no-color Force no coloring (e.g. terminal doesn\'t support it)');
p(' -o, --output MODE');
p(' Specify an output mode/format. One of');
p(' long: (the default) pretty');
p(' json: JSON output, 2-space indent');
p(' json-N: JSON output, N-space indent, e.g. "json-4"');
p(' bunyan: 0 indented JSON, bunyan\'s native format');
p(' inspect: node.js `util.inspect` output');
p(' short: like "long", but more concise');
p(' -j shortcut for `-o json`');
p('');
p('Log Levels:');
p(' Either numeric values or their associated strings are valid for the');
p(' -l|--level argument. However, -c|--condition scripts will see a numeric');
p(' "level" value, not a string.');
p('');
Object.keys(levelFromName).forEach(function (name) {
var n = name;
while (n.length < 6)
n += ' ';
console.log(' %s %d', n, levelFromName[name]);
p(' %s %d', n, levelFromName[name]);
});
console.log('');
console.log('Environment Variables:');
console.log(' BUNYAN_NO_COLOR Set to a non-empty value to force no output ');
console.log(' coloring. See "--no-color".');
console.log(' BUNYAN_NO_PAGER Disable piping output to a pager. ');
console.log(' See "--no-pager".');
console.log('');
console.log('See <https://github.com/trentm/node-bunyan> for more complete docs.');
console.log('Please report bugs to <https://github.com/trentm/node-bunyan/issues>.');
p('');
p('Environment Variables:');
p(' BUNYAN_NO_COLOR Set to a non-empty value to force no output ');
p(' coloring. See "--no-color".');
p(' BUNYAN_NO_PAGER Disable piping output to a pager. ');
p(' See "--no-pager".');
p('');
p('See <https://github.com/trentm/node-bunyan> for more complete docs.');
p('Please report bugs to <https://github.com/trentm/node-bunyan/issues>.');
/* END JSSTYLED */
}
/*
@ -289,13 +292,14 @@ function emitNextRecord(opts, stylize)
for (;;) {
/*
* Take a first pass through the input streams to see if we have a record
* from all of them. If not, we'll pause any streams for which we do
* already have a record (to avoid consuming excess memory) and then wait
* until we have records from the others before emitting the next record.
* Take a first pass through the input streams to see if we have a
* record from all of them. If not, we'll pause any streams for
* which we do already have a record (to avoid consuming excess
* memory) and then wait until we have records from the others
* before emitting the next record.
*
* As part of the same pass, we look for the earliest record we have not yet
* emitted.
* As part of the same pass, we look for the earliest record
* we have not yet emitted.
*/
minfile = undefined;
ready = true;
@ -307,8 +311,10 @@ function emitNextRecord(opts, stylize)
break;
}
if (streams[ofile].records.length > 0 && (minfile === undefined ||
streams[minfile].records[0].time > streams[ofile].records[0].time)) {
if (streams[ofile].records.length > 0 &&
(minfile === undefined ||
streams[minfile].records[0].time >
streams[ofile].records[0].time)) {
minfile = ofile;
}
}
@ -333,8 +339,8 @@ function emitNextRecord(opts, stylize)
}
/*
* Emit the next record for 'minfile', and invoke ourselves again to make
* sure we emit as many records as we can right now.
* Emit the next record for 'minfile', and invoke ourselves again to
* make sure we emit as many records as we can right now.
*/
rec = streams[minfile].records.shift();
emitRecord(rec.rec, rec.line, opts, stylize);
@ -373,7 +379,9 @@ function parseArgv(argv) {
var newArgs = [];
var optTakesArg = {'d': true, 'o': true, 'c': true, 'l': true, 'p': true};
for (var i = 0; i < args.length; i++) {
if (args[i].charAt(0) === '-' && args[i].charAt(1) !== '-' && args[i].length > 2) {
if (args[i].charAt(0) === '-' && args[i].charAt(1) !== '-' &&
args[i].length > 2)
{
var splitOpts = args[i].slice(1).split('');
for (var j = 0; j < splitOpts.length; j++) {
newArgs.push('-' + splitOpts[j]);
@ -454,8 +462,8 @@ function parseArgv(argv) {
var pid = +(pidArg);
if (!isNaN(pid) || pidArg === '*') {
if (parsed.pidsType && parsed.pidsType !== 'num') {
throw new Error(format(
'cannot mix PID name and number arguments: "%s"', pidArg));
throw new Error(format('cannot mix PID name and '
+ 'number arguments: "%s"', pidArg));
}
parsed.pidsType = 'num';
if (!parsed.pids) {
@ -464,8 +472,8 @@ function parseArgv(argv) {
parsed.pids.push(isNaN(pid) ? pidArg : pid);
} else {
if (parsed.pidsType && parsed.pidsType !== 'name') {
throw new Error(format(
'cannot mix PID name and number arguments: "%s"', pidArg));
throw new Error(format('cannot mix PID name and '
+ 'number arguments: "%s"', pidArg));
}
parsed.pidsType = 'name';
parsed.pids = pidArg;
@ -505,6 +513,7 @@ function parseArgv(argv) {
script.runInNewContext(minValidRecord);
} catch (condErr) {
throw new Error(format(
/* JSSTYLED */
'CONDITION code cannot safely filter a minimal Bunyan log record\n'
+ ' CONDITION script:\n'
+ '%s\n'
@ -654,7 +663,7 @@ function emitRecord(rec, line, opts, stylize) {
/* jsl:fall-thru */
case OM_LONG:
// [time] LEVEL: name[/component]/pid on hostname (src): msg* (extras...)
// [time] LEVEL: name[/comp]/pid on hostname (src): msg* (extras...)
// msg*
// --
// long and multi-line extras
@ -670,8 +679,8 @@ function emitRecord(rec, line, opts, stylize) {
delete rec.v;
/*
* We assume the Date is formatted according to ISO8601, in which case we
* can safely chop off the date information.
* We assume the Date is formatted according to ISO8601, in which
* case we can safely chop off the date information.
*/
if (short && rec.time[10] == 'T') {
var time = rec.time.substr(11);
@ -747,10 +756,11 @@ function emitRecord(rec, line, opts, stylize) {
var s = format('%s %s HTTP/%s%s', req.method,
req.url,
req.httpVersion || '1.1',
(headers
? '\n' + Object.keys(headers).map(
function (h) { return h + ': ' + headers[h]; }).join('\n')
: '')
(headers ?
'\n' + Object.keys(headers).map(function (h) {
return h + ': ' + headers[h];
}).join('\n') :
'')
);
delete req.url;
delete req.method;
@ -762,13 +772,15 @@ function emitRecord(rec, line, opts, stylize) {
delete req.body;
}
if (req.trailers && Object.keys(req.trailers) > 0) {
s += '\n' + Object.keys(req.trailers).map(
function (t) { return t + ': ' + req.trailers[t]; }).join('\n');
s += '\n' + Object.keys(req.trailers).map(function (t) {
return t + ': ' + req.trailers[t];
}).join('\n');
}
delete req.trailers;
details.push(indent(s));
// E.g. for extra 'foo' field on 'req', add 'req.foo' at top-level.
// This *does* have the potential to stomp on a literal 'req.foo' key.
// E.g. for extra 'foo' field on 'req', add 'req.foo' at
// top-level. This *does* have the potential to stomp on a
// literal 'req.foo' key.
Object.keys(req).forEach(function (k) {
rec['req.' + k] = req[k];
})
@ -793,21 +805,24 @@ function emitRecord(rec, line, opts, stylize) {
client_req.url,
client_req.httpVersion || '1.1',
hostHeaderLine,
(headers
? Object.keys(headers).map(
function (h) { return h + ': ' + headers[h]; }).join('\n')
: ''));
(headers ?
Object.keys(headers).map(
function (h) {
return h + ': ' + headers[h];
}).join('\n') :
''));
delete client_req.method;
delete client_req.url;
delete client_req.httpVersion;
if (client_req.body) {
s += '\n\n' + (typeof (client_req.body) === 'object'
? JSON.stringify(client_req.body, null, 2) : client_req.body);
s += '\n\n' + (typeof (client_req.body) === 'object' ?
JSON.stringify(client_req.body, null, 2) :
client_req.body);
delete client_req.body;
}
// E.g. for extra 'foo' field on 'client_req', add 'client_req.foo' at
// top-level. This *does* have the potential to stomp on a literal
// 'client_req.foo' key.
// E.g. for extra 'foo' field on 'client_req', add
// 'client_req.foo' at top-level. This *does* have the potential
// to stomp on a literal 'client_req.foo' key.
Object.keys(client_req).forEach(function (k) {
rec['client_req.' + k] = client_req[k];
})
@ -844,8 +859,9 @@ function emitRecord(rec, line, opts, stylize) {
if (s) {
details.push(indent(s));
}
// E.g. for extra 'foo' field on 'res', add 'res.foo' at top-level.
// This *does* have the potential to stomp on a literal 'res.foo' key.
// E.g. for extra 'foo' field on 'res', add 'res.foo' at
// top-level. This *does* have the potential to stomp on a
// literal 'res.foo' key.
Object.keys(res).forEach(function (k) {
rec['res.' + k] = res[k];
});
@ -868,7 +884,8 @@ function emitRecord(rec, line, opts, stylize) {
if (value.indexOf('\n') !== -1 || value.length > 50) {
details.push(indent(key + ': ' + value));
} else if (!stringified && (value.indexOf(' ') != -1 ||
value.length === 0)) {
value.length === 0))
{
extras.push(key + '=' + JSON.stringify(value));
} else {
extras.push(key + '=' + value);
@ -912,11 +929,13 @@ function emitRecord(rec, line, opts, stylize) {
break;
case OM_SIMPLE:
/* JSSTYLED */
// <http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/SimpleLayout.html>
if (!isValidRecord(rec)) {
return emit(line + '\n');
}
emit(format('%s - %s\n', upperNameFromLevel[rec.level] || 'LVL' + rec.level,
emit(format('%s - %s\n',
upperNameFromLevel[rec.level] || 'LVL' + rec.level,
rec.msg));
break;
default:
@ -1023,10 +1042,15 @@ function processPids(opts, stylize, callback) {
return cb(1);
}
var pids = stdout.trim().split('\n')
.map(function (line) { return line.trim().split(/\s+/)[0] })
.filter(function (pid) { return Number(pid) !== process.pid });
.map(function (line) {
return line.trim().split(/\s+/)[0]
})
.filter(function (pid) {
return Number(pid) !== process.pid
});
if (pids.length === 0) {
warn('bunyan: error: no matching PIDs found for "%s"', opts.pids);
warn('bunyan: error: no matching PIDs found for "%s"',
opts.pids);
return cb(2);
}
cb(null, pids);
@ -1035,8 +1059,8 @@ function processPids(opts, stylize, callback) {
} else {
var regex = opts.pids;
if (regex && /[a-zA-Z0-9_]/.test(regex[0])) {
// 'foo' -> '[f]oo' trick to exclude the 'grep' PID from its own
// search.
// 'foo' -> '[f]oo' trick to exclude the 'grep' PID from its
// own search.
regex = '[' + regex[0] + ']' + regex.slice(1);
}
exec(format('ps -A -o pid,command | grep \'%s\'', regex),
@ -1047,10 +1071,15 @@ function processPids(opts, stylize, callback) {
return cb(1);
}
var pids = stdout.trim().split('\n')
.map(function (line) { return line.trim().split(/\s+/)[0] })
.filter(function (pid) { return Number(pid) !== process.pid });
.map(function (line) {
return line.trim().split(/\s+/)[0];
})
.filter(function (pid) {
return Number(pid) !== process.pid;
});
if (pids.length === 0) {
warn('bunyan: error: no matching PIDs found for "%s"', opts.pids);
warn('bunyan: error: no matching PIDs found for "%s"',
opts.pids);
return cb(2);
}
cb(null, pids);
@ -1105,9 +1134,10 @@ function processPids(opts, stylize, callback) {
if (nodeSpawnSupportsStdio) {
dtrace.on('exit', finish);
} else {
// Fallback (for < v0.8) to pipe the dtrace process' stderr to this stderr.
// Wait for all of (1) process 'exit', (2) stderr 'end', and (2) stdout
// 'end' before returning to ensure all stderr is flushed (issue #54).
// Fallback (for < v0.8) to pipe the dtrace process' stderr to
// this stderr. Wait for all of (1) process 'exit', (2) stderr
// 'end', and (2) stdout 'end' before returning to ensure all
// stderr is flushed (issue #54).
var returnCode = null;
var eventsRemaining = 3;
function countdownToFinish(code) {
@ -1249,7 +1279,8 @@ function cleanupAndExit(code, signal) {
stdout.end();
pager.on('exit', function (pagerCode) {
if (_DEBUG)
warn('(bunyan: pager exit -> process.exit(%s))', pagerCode || code);
warn('(bunyan: pager exit -> process.exit(%s))',
pagerCode || code);
process.exit(pagerCode || code);
});
} else {
@ -1278,27 +1309,28 @@ process.on('uncaughtException', function (err) {
var title = encodeURIComponent(format(
'Bunyan %s crashed: %s', getVersion(), String(err)));
console.error('* * *');
console.error('* The Bunyan CLI crashed!');
console.error('*');
var e = console.error;
e('* * *');
e('* The Bunyan CLI crashed!');
e('*');
if (err.name === 'ReferenceError' && gOptsForUncaughtException.conditions) {
console.error('* A "ReferenceError" is often the result of given');
console.error('* `-c CONDITION` code that doesn\'t guard against undefined');
console.error('* values. If that is not the problem:');
console.error('*');
e('* A "ReferenceError" is often the result of given');
e('* `-c CONDITION` code that doesn\'t guard against undefined');
e('* values. If that is not the problem:');
e('*');
}
console.error('* Please report this issue and include the details below:');
console.error('*');
console.error('* https://github.com/trentm/node-bunyan/issues/new?title=%s', title);
console.error('*');
console.error('* * *');
console.error('* node version:', process.version);
console.error('* bunyan version:', getVersion());
console.error('* argv: %j', process.argv);
console.error('* log line: %j', currLine);
console.error('* stack:');
console.error(_indent(err.stack));
console.error('* * *');
e('* Please report this issue and include the details below:');
e('*');
e('* https://github.com/trentm/node-bunyan/issues/new?title=%s', title);
e('*');
e('* * *');
e('* node version:', process.version);
e('* bunyan version:', getVersion());
e('* argv: %j', process.argv);
e('* log line: %j', currLine);
e('* stack:');
e(_indent(err.stack));
e('* * *');
process.exit(1);
});
@ -1356,11 +1388,11 @@ function main(argv) {
var argv = pagerCmd.split(/\s+/g);
var env = objCopy(process.env);
if (env.LESS === undefined) {
// git's default is LESS=FRSX. I don't like the 'S' here because lines
// are *typically* wide with bunyan output and scrolling horizontally
// is a royal pain.
// Note a bug in Mac's `less -F`, such that SIGWINCH can kill it.
// If that rears too much then I'll remove 'F' from here.
// git's default is LESS=FRSX. I don't like the 'S' here because
// lines are *typically* wide with bunyan output and scrolling
// horizontally is a royal pain. Note a bug in Mac's `less -F`,
// such that SIGWINCH can kill it. If that rears too much then
// I'll remove 'F' from here.
env.LESS = 'FRX';
}
if (_DEBUG) warn('(pager: argv=%j, env.LESS=%j)', argv, env.LESS);
@ -1387,7 +1419,8 @@ function main(argv) {
if (err.code === 'EPIPE') {
drainStdoutAndExit(0);
} else if (err.toString() === 'Error: This socket is closed.') {
// Could get this if the pager closes its stdin, but hasn't exited yet.
// Could get this if the pager closes its stdin, but hasn't
// exited yet.
drainStdoutAndExit(1);
} else {
warn(err);

3
examples/long-running.js
View File

@ -31,7 +31,8 @@ function randchoice(array) {
//---- mainline
var words = fs.readFileSync(__dirname + '/long-running.js', 'utf8').split(/\s+/);
var words = fs.readFileSync(
__dirname + '/long-running.js', 'utf8').split(/\s+/);
var levels = ['trace', 'debug', 'info', 'warn', 'error', 'fatal'];
var timeout;

43
lib/bunyan.js
View File

@ -15,7 +15,8 @@ var LOG_VERSION = 0;
var xxx = function xxx(s) { // internal dev/debug logging
var args = ['XX' + 'X: '+s].concat(Array.prototype.slice.call(arguments, 1));
var args = ['XX' + 'X: '+s].concat(
Array.prototype.slice.call(arguments, 1));
console.error.apply(this, args);
};
var xxx = function xxx() {}; // comment out to turn on debug logging
@ -238,7 +239,8 @@ function Logger(options, _childOptions, _childSimple) {
parent = options;
options = _childOptions;
if (! parent instanceof Logger) {
throw new TypeError('invalid Logger creation: do not pass a second arg');
throw new TypeError(
'invalid Logger creation: do not pass a second arg');
}
}
if (!options) {
@ -250,7 +252,8 @@ function Logger(options, _childOptions, _childSimple) {
}
} else {
if (options.name) {
throw new TypeError('invalid options.name: child cannot set logger name');
throw new TypeError(
'invalid options.name: child cannot set logger name');
}
}
if (options.stream && options.streams) {
@ -379,10 +382,11 @@ function Logger(options, _childOptions, _childSimple) {
}
break;
case 'rotating-file':
assert.ok(!s.stream, '"rotating-file" stream should not give a "stream"');
assert.ok(!s.stream,
'"rotating-file" stream should not give a "stream"');
assert.ok(s.path);
assert.ok(mv,
'"rotating-file" stream type is not supported: missing "mv" module');
assert.ok(mv, '"rotating-file" stream type is not supported: '
+ 'missing "mv" module');
s.stream = new RotatingFileStream(s);
if (!s.closeOnExit) {
s.closeOnExit = true;
@ -408,7 +412,8 @@ function Logger(options, _childOptions, _childSimple) {
var serializer = serializers[field];
if (typeof (serializer) !== 'function') {
throw new TypeError(format(
'invalid serializer for "%s" field: must be a function', field));
'invalid serializer for "%s" field: must be a function',
field));
} else {
self.serializers[field] = serializer;
}
@ -648,8 +653,9 @@ Logger.prototype._applySerializers = function (fields, excludeFields) {
fields[name] = self.serializers[name](fields[name]);
} catch (err) {
_warn(format('bunyan: ERROR: This should never happen. '
+ 'This is a bug in <https://github.com/trentm/node-bunyan> or '
+ 'in this application. Exception from "%s" Logger serializer: %s',
+ 'This is a bug in <https://github.com/trentm/node-bunyan> '
+ 'or in this application. Exception from "%s" Logger '
+ 'serializer: %s',
name, err.stack || err));
fields[name] = format('(Error in Bunyan log "%s" serializer '
+ 'broke field. See stderr for details.)', name);
@ -737,11 +743,13 @@ function mkLogEmitter(minLevel) {
} else {
msgArgs = Array.prototype.slice.call(args, 1);
}
} else if (typeof (args[0]) === 'string') { // `log.<level>(msg, ...)`
} else if (typeof (args[0]) === 'string') {
// `log.<level>(msg, ...)`
fields = null;
msgArgs = Array.prototype.slice.call(args);
} else if (Buffer.isBuffer(args[0])) { // `log.<level>(buf, ...)`
// Almost certainly an error, show `inspect(buf)`. See bunyan issue #35.
// Almost certainly an error, show `inspect(buf)`. See bunyan
// issue #35.
fields = null;
msgArgs = Array.prototype.slice.call(args);
msgArgs[0] = util.inspect(msgArgs[0]);
@ -986,7 +994,8 @@ RotatingFileStream.prototype._setupNextRot = function () {
RotatingFileStream.prototype._nextRotTime = function _nextRotTime(first) {
var _DEBUG = false;
if (_DEBUG) console.log('-- _nextRotTime: %s%s', this.periodNum, this.periodScope);
if (_DEBUG)
console.log('-- _nextRotTime: %s%s', this.periodNum, this.periodScope);
var d = new Date();
if (_DEBUG) console.log(' now local: %s', d);
@ -1006,8 +1015,8 @@ RotatingFileStream.prototype._nextRotTime = function _nextRotTime(first) {
rotAt = this.rotAt + this.periodNum * 60 * 60 * 1000;
} else {
// First time: top of the next hour.
rotAt = Date.UTC(d.getUTCFullYear(), d.getUTCMonth(), d.getUTCDate(),
d.getUTCHours() + 1);
rotAt = Date.UTC(d.getUTCFullYear(), d.getUTCMonth(),
d.getUTCDate(), d.getUTCHours() + 1);
}
break;
case 'd':
@ -1015,7 +1024,8 @@ RotatingFileStream.prototype._nextRotTime = function _nextRotTime(first) {
rotAt = this.rotAt + this.periodNum * 24 * 60 * 60 * 1000;
} else {
// First time: start of tomorrow (i.e. at the coming midnight) UTC.
rotAt = Date.UTC(d.getUTCFullYear(), d.getUTCMonth(), d.getUTCDate() + 1);
rotAt = Date.UTC(d.getUTCFullYear(), d.getUTCMonth(),
d.getUTCDate() + 1);
}
break;
case 'w':
@ -1030,7 +1040,8 @@ RotatingFileStream.prototype._nextRotTime = function _nextRotTime(first) {
break;
case 'm':
if (this.rotAt) {
rotAt = Date.UTC(d.getUTCFullYear(), d.getUTCMonth() + this.periodNum, 1);
rotAt = Date.UTC(d.getUTCFullYear(),
d.getUTCMonth() + this.periodNum, 1);
} else {
// First time: the start of the next month.
rotAt = Date.UTC(d.getUTCFullYear(), d.getUTCMonth() + 1, 1);

11
test/buffer.test.js
View File

@ -43,7 +43,12 @@ var log = new bunyan.createLogger({
test('log.info(BUFFER)', function (t) {
var b = new Buffer('foo');
['trace', 'debug', 'info', 'warn', 'error', 'fatal'].forEach(function (lvl) {
['trace',
'debug',
'info',
'warn',
'error',
'fatal'].forEach(function (lvl) {
log[lvl].call(log, b);
var rec = catcher.records[catcher.records.length - 1];
t.equal(rec.msg, inspect(b),
@ -55,8 +60,8 @@ test('log.info(BUFFER)', function (t) {
log[lvl].call(log, b, 'bar');
var rec = catcher.records[catcher.records.length - 1];
t.equal(rec.msg, inspect(b) + ' bar',
format('log.%s(BUFFER, "bar") msg is inspect(BUFFER) + " bar"', lvl));
t.equal(rec.msg, inspect(b) + ' bar', format(
'log.%s(BUFFER, "bar") msg is inspect(BUFFER) + " bar"', lvl));
});
t.end();

55
test/cli.test.js
View File

@ -78,8 +78,8 @@ test('cat simple.log', function (t) {
function (err, stdout, stderr) {
t.ifError(err)
t.equal(stdout,
'[2012-02-08T22:56:52.856Z] INFO: myservice/123 on example.com: '
+ 'My message\n');
/* JSSTYLED */
'[2012-02-08T22:56:52.856Z] INFO: myservice/123 on example.com: My message\n');
t.end();
}
);
@ -89,8 +89,8 @@ test('simple.log with color', function (t) {
function (err, stdout, stderr) {
t.ifError(err)
t.equal(stdout,
'[2012-02-08T22:56:52.856Z] \u001b[36m INFO\u001b[39m: myservice/123 '
+ 'on example.com: \u001b[36mMy message\u001b[39m\n\u001b[0m');
/* JSSTYLED */
'[2012-02-08T22:56:52.856Z] \u001b[36m INFO\u001b[39m: myservice/123 on example.com: \u001b[36mMy message\u001b[39m\n\u001b[0m');
t.end();
});
});
@ -110,7 +110,8 @@ test('extrafield.log with color', function (t) {
function (err, stdout, stderr) {
t.ifError(err)
t.equal(stdout,
'[2012-02-08T22:56:52.856Z] \u001b[36m INFO\u001b[39m: myservice/123 '
'[2012-02-08T22:56:52.856Z] \u001b[36m INFO\u001b[39m: '
+ 'myservice/123 '
+ 'on example.com: \u001b[36mMy message\u001b[39m'
+ '\u001b[90m (extra=field)\u001b[39m\n\u001b[0m');
t.end();
@ -151,8 +152,8 @@ test('simple.log doesnotexist1.log doesnotexist2.log', function (t) {
t.ok(err)
t.equal(err.code, 2)
t.equal(stdout,
'[2012-02-08T22:56:52.856Z] INFO: myservice/123 on example.com: '
+ 'My message\n');
/* JSSTYLED */
'[2012-02-08T22:56:52.856Z] INFO: myservice/123 on example.com: My message\n');
// Note: node v0.6.10:
// ENOENT, no such file or directory 'asdf.log'
// but node v0.6.14:
@ -167,10 +168,12 @@ test('simple.log doesnotexist1.log doesnotexist2.log', function (t) {
});
test('multiple logs', function (t) {
exec(_('%s %s/corpus/log1.log %s/corpus/log2.log', BUNYAN, __dirname, __dirname),
function (err, stdout, stderr) {
var cmd = _('%s %s/corpus/log1.log %s/corpus/log2.log',
BUNYAN, __dirname, __dirname);
exec(cmd, function (err, stdout, stderr) {
t.ifError(err);
t.equal(stdout, [
/* BEGIN JSSTYLED */
'[2012-05-08T16:57:55.586Z] INFO: agent1/73267 on headnode: message\n',
'[2012-05-08T16:58:55.586Z] INFO: agent2/73267 on headnode: message\n',
'[2012-05-08T17:01:49.339Z] INFO: agent2/73267 on headnode: message\n',
@ -180,16 +183,19 @@ test('multiple logs', function (t) {
'[2012-05-08T17:02:49.404Z] INFO: agent1/73267 on headnode: message\n',
'[2012-05-08T17:02:57.404Z] INFO: agent2/73267 on headnode: message\n',
'[2012-05-08T17:08:01.105Z] INFO: agent2/76156 on headnode: message\n',
/* END JSSTYLED */
].join(''));
t.end();
});
});
test('multiple logs, bunyan format', function (t) {
exec(_('%s -o bunyan %s/corpus/log1.log %s/corpus/log2.log', BUNYAN, __dirname, __dirname),
function (err, stdout, stderr) {
var cmd = _('%s -o bunyan %s/corpus/log1.log %s/corpus/log2.log',
BUNYAN, __dirname, __dirname);
exec(cmd, function (err, stdout, stderr) {
t.ifError(err);
t.equal(stdout, [
/* BEGIN JSSTYLED */
'{"name":"agent1","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T16:57:55.586Z","v":0}',
'{"name":"agent2","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T16:58:55.586Z","v":0}',
'{"name":"agent2","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T17:01:49.339Z","v":0}',
@ -200,6 +206,7 @@ test('multiple logs, bunyan format', function (t) {
'{"name":"agent2","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T17:02:57.404Z","v":0}',
'{"name":"agent2","pid":76156,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T17:08:01.105Z","v":0}',
''
/* END JSSTYLED */
].join('\n'));
t.end();
});
@ -210,20 +217,24 @@ test('log1.log.gz', function (t) {
function (err, stdout, stderr) {
t.ifError(err);
t.equal(stdout, [
/* BEGIN JSSTYLED */
'[2012-05-08T16:57:55.586Z] INFO: agent1/73267 on headnode: message\n',
'[2012-05-08T17:02:49.339Z] INFO: agent1/73267 on headnode: message\n',
'[2012-05-08T17:02:49.404Z] INFO: agent1/73267 on headnode: message\n',
'[2012-05-08T17:02:49.404Z] INFO: agent1/73267 on headnode: message\n',
/* END JSSTYLED */
].join(''));
t.end();
});
});
test('mixed text and gzip logs', function (t) {
exec(_('%s %s/corpus/log1.log.gz %s/corpus/log2.log', BUNYAN, __dirname, __dirname),
function (err, stdout, stderr) {
var cmd = _('%s %s/corpus/log1.log.gz %s/corpus/log2.log',
BUNYAN, __dirname, __dirname);
exec(cmd, function (err, stdout, stderr) {
t.ifError(err);
t.equal(stdout, [
/* BEGIN JSSTYLED */
'[2012-05-08T16:57:55.586Z] INFO: agent1/73267 on headnode: message\n',
'[2012-05-08T16:58:55.586Z] INFO: agent2/73267 on headnode: message\n',
'[2012-05-08T17:01:49.339Z] INFO: agent2/73267 on headnode: message\n',
@ -233,6 +244,7 @@ test('mixed text and gzip logs', function (t) {
'[2012-05-08T17:02:49.404Z] INFO: agent1/73267 on headnode: message\n',
'[2012-05-08T17:02:57.404Z] INFO: agent2/73267 on headnode: message\n',
'[2012-05-08T17:08:01.105Z] INFO: agent2/76156 on headnode: message\n',
/* END JSSTYLED */
].join(''));
t.end();
});
@ -240,6 +252,7 @@ test('mixed text and gzip logs', function (t) {
test('--level 40', function (t) {
expect = [
/* BEGIN JSSTYLED */
'# levels\n',
'[2012-02-08T22:56:53.856Z] WARN: myservice/123 on example.com: My message\n',
'[2012-02-08T22:56:54.856Z] ERROR: myservice/123 on example.com: My message\n',
@ -251,6 +264,7 @@ test('--level 40', function (t) {
'# bogus\n',
'not a JSON line\n',
'{"hi": "there"}\n'
/* END JSSTYLED */
].join('');
exec(_('%s -l 40 %s/corpus/all.log', BUNYAN, __dirname),
function (err, stdout, stderr) {
@ -268,6 +282,7 @@ test('--level 40', function (t) {
test('--condition "level === 10 && pid === 123"', function (t) {
var expect = [
'# levels\n',
/* JSSTYLED */
'[2012-02-08T22:56:50.856Z] TRACE: myservice/123 on example.com: My message\n',
'\n',
'# extra fields\n',
@ -276,12 +291,15 @@ test('--condition "level === 10 && pid === 123"', function (t) {
'not a JSON line\n',
'{"hi": "there"}\n'
].join('');
exec(_('%s -c "level === 10 && pid === 123" %s/corpus/all.log', BUNYAN, __dirname),
function (err, stdout, stderr) {
var cmd = _('%s -c "level === 10 && pid === 123" %s/corpus/all.log',
BUNYAN, __dirname);
exec(cmd, function (err, stdout, stderr) {
t.ifError(err);
t.equal(stdout, expect);
exec(_('%s --condition "level === 10 && pid === 123" %s/corpus/all.log', BUNYAN, __dirname),
function (err, stdout, stderr) {
var cmd = _(
'%s --condition "level === 10 && pid === 123" %s/corpus/all.log',
BUNYAN, __dirname);
exec(cmd, function (err, stdout, stderr) {
t.ifError(err);
t.equal(stdout, expect);
t.end();
@ -294,6 +312,7 @@ test('--condition "level === 10 && pid === 123"', function (t) {
test('multiple --conditions', function (t) {
var expect = [
'# levels\n',
/* JSSTYLED */
'[2012-02-08T22:56:53.856Z] WARN: myservice/1 on example.com: My message\n',
'\n',
'# extra fields\n',
@ -318,6 +337,7 @@ test('multiple --conditions', function (t) {
// field with no 'headers'. Ditto for the 'res' field.
test('robust req handling', function (t) {
var expect = [
/* BEGIN JSSTYLED */
'[2012-08-08T10:25:47.636Z] DEBUG: amon-master/12859 on 9724a190-27b6-4fd8-830b-a574f839c67d: headAgentProbes respond (req_id=cce79d15-ffc2-487c-a4e4-e940bdaac31e, route=HeadAgentProbes, contentMD5=11FxOYiYfpMxmANj4kGJzg==)',
'[2012-08-08T10:25:47.637Z] INFO: amon-master/12859 on 9724a190-27b6-4fd8-830b-a574f839c67d: HeadAgentProbes handled: 200 (req_id=cce79d15-ffc2-487c-a4e4-e940bdaac31e, audit=true, remoteAddress=10.2.207.2, remotePort=50394, latency=3, secure=false, _audit=true, req.version=*)',
' HEAD /agentprobes?agent=ccf92af9-0b24-46b6-ab60-65095fdd3037 HTTP/1.1',
@ -349,6 +369,7 @@ test('robust req handling', function (t) {
' "name": "HeadAgentProbes",',
' "version": false',
' }'
/* END JSSTYLED */
].join('\n') + '\n';
exec(_('%s %s/corpus/withreq.log', BUNYAN, __dirname),
function (err, stdout, stderr) {

12
test/serializers.test.js
View File

@ -71,7 +71,8 @@ test('req serializer', function (t) {
var lastRecord = records[records.length-1];
t.equal(lastRecord.req.method, 'GET');
t.equal(lastRecord.req.url, theReq.url);
t.equal(lastRecord.req.remoteAddress, theReq.connection.remoteAddress);
t.equal(lastRecord.req.remoteAddress,
theReq.connection.remoteAddress);
t.equal(lastRecord.req.remotePort, theReq.connection.remotePort);
server.close();
t.end();
@ -238,12 +239,14 @@ test('err serializer: long stack', function (t) {
topErr = new verror.WError(midErr, 'top err');
log.info(topErr, 'the error');
var lastRecord = records[records.length-1];
t.equal(lastRecord.err.message, topErr.message, 'WError <- WError <- TypeError');
t.equal(lastRecord.err.message, topErr.message,
'WError <- WError <- TypeError');
t.equal(lastRecord.err.name, topErr.name, 'WError <- WError <- TypeError');
var expectedStack = (topErr.stack
+ '\nCaused by: ' + midErr.stack
+ '\nCaused by: ' + bottomErr.stack);
t.equal(lastRecord.err.stack, expectedStack, 'WError <- WError <- TypeError');
t.equal(lastRecord.err.stack, expectedStack,
'WError <- WError <- TypeError');
// WError <- WError <- WError
bottomErr = new verror.WError('bottom err');
@ -251,7 +254,8 @@ test('err serializer: long stack', function (t) {
topErr = new verror.WError(midErr, 'top err');
log.info(topErr, 'the error');
var lastRecord = records[records.length-1];
t.equal(lastRecord.err.message, topErr.message, 'WError <- WError <- WError');
t.equal(lastRecord.err.message, topErr.message,
'WError <- WError <- WError');
t.equal(lastRecord.err.name, topErr.name, 'WError <- WError <- WError');
var expectedStack = (topErr.stack
+ '\nCaused by: ' + midErr.stack

73
test/tap4nodeunit.js
View File

@ -17,46 +17,45 @@
//---- Exports
module.exports = {
after: function after(teardown) {
module.parent.exports.tearDown = function _teardown(callback) {
try {
teardown.call(this, callback);
} catch (e) {
console.error('after:\n' + e.stack);
process.exit(1);
}
};
},
after: function after(teardown) {
module.parent.exports.tearDown = function _teardown(callback) {
try {
teardown.call(this, callback);
} catch (e) {
console.error('after:\n' + e.stack);
process.exit(1);
}
};
},
before: function before(setup) {
module.parent.exports.setUp = function _setup(callback) {
try {
setup.call(this, callback);
} catch (e) {
console.error('before:\n' + e.stack);
process.exit(1);
}
};
},
before: function before(setup) {
module.parent.exports.setUp = function _setup(callback) {
try {
setup.call(this, callback);
} catch (e) {
console.error('before:\n' + e.stack);
process.exit(1);
}
};
},
test: function test(name, tester) {
module.parent.exports[name] = function _(t) {
var _done = false;
t.end = function end() {
if (!_done) {
_done = true;
t.done();
}
};
t.notOk = function notOk(ok, message) {
return (t.ok(!ok, message));
};
t.error = t.ifError;
tester.call(this, t);
};
test: function test(name, tester) {
module.parent.exports[name] = function _(t) {
var _done = false;
t.end = function end() {
if (!_done) {
_done = true;
t.done();
}
};
t.notOk = function notOk(ok, message) {
return (t.ok(!ok, message));
};
t.error = t.ifError;
tester.call(this, t);
};
}
};