momentjs: avoid for default fast path; make required only for local time

Make the default (long output format, UTC time) for the bunyan CLI a
fast path that doesn't use moment.js. Admittedly I haven't measured
percentage impact of `moment(rec.time).utc().format(...)` for
many bunyan records.

Also make moment dep *optional*. The bunyan CLI will error out without
the moment dep *only if local time is requested.*
This commit is contained in:
Trent Mick 2016-02-10 22:13:01 -08:00
parent 8df86bccf0
commit 6ff1f36abc
6 changed files with 72 additions and 47 deletions

View file

@ -28,3 +28,4 @@ Mark LeMerise (https://github.com/MarkLeMerise)
https://github.com/sometimesalready https://github.com/sometimesalready
Charly Koza (https://github.com/Cactusbone) Charly Koza (https://github.com/Cactusbone)
Thomas Heymann (https://github.com/cyberthom) Thomas Heymann (https://github.com/cyberthom)
David M. Lee (https://github.com/leedm777)

View file

@ -6,7 +6,12 @@ Known issues:
bug](https://github.com/TooTallNate/node-gyp/issues/65). bug](https://github.com/TooTallNate/node-gyp/issues/65).
## 1.5.2 (not yet released) ## 1.6.0 (not yet released)
- [pull #304, issue #245] Use [Moment.js][momentjs.com] library to handle
`bunyan` CLI time formatting in some cases, especially to fix display of
local time. It is now required for local time formatting (i.e. `bunyan -L`
or `bunyan --time local`). (By David M. Lee.)
- [pull #252] Fix errant `client_res={}` in `bunyan` CLI rendering, and avoid - [pull #252] Fix errant `client_res={}` in `bunyan` CLI rendering, and avoid
extra newlines in `client_req` rendering in some cases. (By Thomas Heymann.) extra newlines in `client_req` rendering in some cases. (By Thomas Heymann.)

View file

@ -1,7 +1,7 @@
#!/usr/bin/env node #!/usr/bin/env node
/** /**
* Copyright (c) 2015 Trent Mick. All rights reserved. * Copyright 2016 Trent Mick. All rights reserved.
* Copyright (c) 2015 Joyent Inc. All rights reserved. * Copyright 2016 Joyent Inc. All rights reserved.
* *
* bunyan -- filter and pretty-print Bunyan log files (line-delimited JSON) * bunyan -- filter and pretty-print Bunyan log files (line-delimited JSON)
* *
@ -11,7 +11,7 @@
* vim: expandtab:ts=4:sw=4 * vim: expandtab:ts=4:sw=4
*/ */
var VERSION = '1.5.2'; var VERSION = '1.6.0';
var p = console.log; var p = console.log;
var util = require('util'); var util = require('util');
@ -25,16 +25,20 @@ var child_process = require('child_process'),
exec = child_process.exec, exec = child_process.exec,
execFile = child_process.execFile; execFile = child_process.execFile;
var assert = require('assert'); var assert = require('assert');
try {
var moment = require('moment'); var moment = require('moment');
} catch (e) {
moment = null;
}
//---- globals and constants
var nodeSpawnSupportsStdio = ( var nodeSpawnSupportsStdio = (
Number(process.version.split('.')[0]) >= 0 || Number(process.version.split('.')[0]) >= 0 ||
Number(process.version.split('.')[1]) >= 8); Number(process.version.split('.')[1]) >= 8);
//---- globals and constants
// Internal debug logging via `console.warn`. // Internal debug logging via `console.warn`.
var _DEBUG = false; var _DEBUG = false;
@ -85,21 +89,19 @@ Object.keys(levelFromName).forEach(function (name) {
// Display time formats. // Display time formats.
TIME_UTC = 1; // the default, bunyan's native format var TIME_UTC = 1; // the default, bunyan's native format
TIME_LOCAL = 2; var TIME_LOCAL = 2;
// Timestamp formats. Timezone is added at format time // Timezone formats: output format -> momentjs format string
UTC_FORMATS = { var TIMEZONE_UTC_FORMATS = {
long: 'YYYY-MM-DD[T]HH:mm:ss.SSS[Z]', long: '[[]YYYY-MM-DD[T]HH:mm:ss.SSS[Z][]]',
short: 'HH:mm:ss.SSS[Z]' short: 'HH:mm:ss.SSS[Z]'
}; };
LOCAL_FORMATS = { var TIMEZONE_LOCAL_FORMATS = {
long: 'YYYY-MM-DD[T]HH:mm:ss.SSSZ', long: '[[]YYYY-MM-DD[T]HH:mm:ss.SSSZ[]]',
short: 'HH:mm:ss.SSS' short: 'HH:mm:ss.SSS'
}; };
var timezoneOffsetMs; // used for TIME_LOCAL display
// The current raw input line being processed. Used for `uncaughtException`. // The current raw input line being processed. Used for `uncaughtException`.
var currLine = null; var currLine = null;
@ -423,7 +425,7 @@ function parseArgv(argv) {
strict: false, strict: false,
pids: null, pids: null,
pidsType: null, pidsType: null,
timeFormat: null // one of the TIME_ constants timeFormat: TIME_UTC // one of the TIME_ constants
}; };
// Turn '-iH' into '-i -H', except for argument-accepting options. // Turn '-iH' into '-i -H', except for argument-accepting options.
@ -512,6 +514,10 @@ function parseArgv(argv) {
break; break;
case '-L': case '-L':
parsed.timeFormat = TIME_LOCAL; parsed.timeFormat = TIME_LOCAL;
if (!moment) {
throw new Error(
'could not find moment package required for "-L"');
}
break; break;
case '--time': case '--time':
var timeArg = args.shift(); var timeArg = args.shift();
@ -521,6 +527,10 @@ function parseArgv(argv) {
break break
case 'local': case 'local':
parsed.timeFormat = TIME_LOCAL; parsed.timeFormat = TIME_LOCAL;
if (!moment) {
throw new Error('could not find moment package '
+ 'required for "--time=local"');
}
break break
case undefined: case undefined:
throw new Error('missing argument to "--time"'); throw new Error('missing argument to "--time"');
@ -763,24 +773,30 @@ function emitRecord(rec, line, opts, stylize) {
delete rec.v; delete rec.v;
var time = moment(rec.time); // Time.
// default to UTC var time;
var zoneFormats; if (!short && opts.timeFormat === TIME_UTC) {
// Fast default path: We assume the raw `rec.time` is a UTC time
// in ISO 8601 format (per spec).
time = '[' + rec.time + ']';
} else if (!moment && opts.timeFormat === TIME_UTC) {
// Don't require momentjs install, as long as not using TIME_LOCAL.
time = rec.time.substr(11);
} else {
var tzFormat;
var moTime = moment(rec.time);
switch (opts.timeFormat) { switch (opts.timeFormat) {
case TIME_UTC:
tzFormat = TIMEZONE_UTC_FORMATS[short ? 'short' : 'long'];
moTime.utc();
break;
case TIME_LOCAL: case TIME_LOCAL:
zoneFormats = LOCAL_FORMATS; tzFormat = TIMEZONE_LOCAL_FORMATS[short ? 'short' : 'long'];
break; break;
default: default:
// default to UTC throw new Error('unexpected timeFormat: ' + opts.timeFormat);
zoneFormats = UTC_FORMATS; };
time.utc(); time = moTime.format(tzFormat);
break;
}
if (short) {
time = time.format(zoneFormats.short);
} else {
// Is there any way to put square brackets in a moment format?
time = '[' + time.format(zoneFormats.long) + ']';
} }
time = stylize(time, 'XXX'); time = stylize(time, 'XXX');
delete rec.time; delete rec.time;

View file

@ -8,7 +8,7 @@
* vim: expandtab:ts=4:sw=4 * vim: expandtab:ts=4:sw=4
*/ */
var VERSION = '1.5.2'; var VERSION = '1.6.0';
/* /*
* Bunyan log format version. This becomes the 'v' field on all log records. * Bunyan log format version. This becomes the 'v' field on all log records.

View file

@ -1,6 +1,6 @@
{ {
"name": "bunyan", "name": "bunyan",
"version": "1.5.2", "version": "1.6.0",
"description": "a JSON logging library for node.js services", "description": "a JSON logging library for node.js services",
"author": "Trent Mick <trentm@gmail.com> (http://trentm.com)", "author": "Trent Mick <trentm@gmail.com> (http://trentm.com)",
"main": "./lib/bunyan.js", "main": "./lib/bunyan.js",
@ -16,12 +16,14 @@
"keywords": ["log", "logging", "log4j", "json", "bunyan"], "keywords": ["log", "logging", "log4j", "json", "bunyan"],
"license": "MIT", "license": "MIT",
"// comment1": "'dtrace-provider' required for dtrace features", "// dtrace-provider": "required for dtrace features",
"// comment2": "'mv' required for RotatingFileStream", "// mv": "required for RotatingFileStream",
"// moment": "required for local time with CLI",
"optionalDependencies": { "optionalDependencies": {
"dtrace-provider": "~0.6", "dtrace-provider": "~0.6",
"mv": "~2", "mv": "~2",
"safe-json-stringify": "~1" "safe-json-stringify": "~1",
"moment": "^2.10.6"
}, },
"devDependencies": { "devDependencies": {
"nodeunit": "0.9", "nodeunit": "0.9",
@ -34,6 +36,5 @@
"test": "make test" "test": "make test"
}, },
"dependencies": { "dependencies": {
"moment": "^2.10.6"
} }
} }

View file

@ -86,7 +86,8 @@ test('cat simple.log', function (t) {
} }
); );
}); });
test('simple.log local long', function (t) {
test('time: simple.log local long', function (t) {
exec(_('%s -o long -L %s/corpus/simple.log', BUNYAN, __dirname), exec(_('%s -o long -L %s/corpus/simple.log', BUNYAN, __dirname),
function (err, stdout, stderr) { function (err, stdout, stderr) {
t.ifError(err) t.ifError(err)
@ -96,8 +97,8 @@ test('simple.log local long', function (t) {
t.end(); t.end();
}); });
}); });
test('simple.log utc long', function (t) { test('time: simple.log utc long', function (t) {
exec(_('%s -o long %s/corpus/simple.log', BUNYAN, __dirname), exec(_('%s -o long --time utc %s/corpus/simple.log', BUNYAN, __dirname),
function (err, stdout, stderr) { function (err, stdout, stderr) {
t.ifError(err) t.ifError(err)
t.equal(stdout, t.equal(stdout,
@ -106,7 +107,7 @@ test('simple.log utc long', function (t) {
t.end(); t.end();
}); });
}); });
test('simple.log local short', function (t) { test('time: simple.log local short', function (t) {
exec(_('%s -o short -L %s/corpus/simple.log', BUNYAN, __dirname), exec(_('%s -o short -L %s/corpus/simple.log', BUNYAN, __dirname),
function (err, stdout, stderr) { function (err, stdout, stderr) {
t.ifError(err) t.ifError(err)
@ -116,7 +117,7 @@ test('simple.log local short', function (t) {
t.end(); t.end();
}); });
}); });
test('simple.log utc short', function (t) { test('time: simple.log utc short', function (t) {
exec(_('%s -o short %s/corpus/simple.log', BUNYAN, __dirname), exec(_('%s -o short %s/corpus/simple.log', BUNYAN, __dirname),
function (err, stdout, stderr) { function (err, stdout, stderr) {
t.ifError(err) t.ifError(err)
@ -126,6 +127,7 @@ test('simple.log utc short', function (t) {
t.end(); t.end();
}); });
}); });
test('simple.log with color', function (t) { test('simple.log with color', function (t) {
exec(_('%s --color %s/corpus/simple.log', BUNYAN, __dirname), exec(_('%s --color %s/corpus/simple.log', BUNYAN, __dirname),
function (err, stdout, stderr) { function (err, stdout, stderr) {