node-bunyan-lite/lib/bunyan.js

1229 lines
33 KiB
JavaScript
Raw Normal View History

2012-01-30 06:26:47 +00:00
/*
* Copyright (c) 2013 Trent Mick. All rights reserved.
*
* The bunyan logging library for node.js.
2012-01-30 06:26:47 +00:00
*/
2013-03-15 18:27:00 +00:00
var VERSION = '0.20.1';
2012-02-02 17:11:45 +00:00
2012-01-30 06:26:47 +00:00
// Bunyan log format version. This becomes the 'v' field on all log records.
2012-04-28 00:23:29 +00:00
// `0` is until I release a version '1.0.0' of node-bunyan. Thereafter,
2012-01-30 06:26:47 +00:00
// starting with `1`, this will be incremented if there is any backward
// incompatible change to the log record format. Details will be in
2012-04-28 00:23:29 +00:00
// 'CHANGES.md' (the change log).
var LOG_VERSION = 0;
2012-01-30 06:26:47 +00:00
2012-01-30 20:01:15 +00:00
var xxx = function xxx(s) { // internal dev/debug logging
var args = ['XX' + 'X: '+s].concat(Array.prototype.slice.call(arguments, 1));
2012-01-30 06:26:47 +00:00
console.error.apply(this, args);
};
var xxx = function xxx() {}; // comment out to turn on debug logging
2012-01-30 06:26:47 +00:00
2012-01-30 20:01:15 +00:00
var os = require('os');
2012-01-30 06:26:47 +00:00
var fs = require('fs');
var util = require('util');
var assert = require('assert');
try {
2012-11-02 20:36:46 +00:00
var dtrace = require('dtrace-provider');
} catch (e) {
dtrace = null;
}
2012-06-05 03:23:12 +00:00
var EventEmitter = require('events').EventEmitter;
2012-01-30 06:26:47 +00:00
// The 'mv' module is required for rotating-file stream support.
try {
var mv = require('mv');
} catch (e) {
mv = null;
}
2012-01-30 06:26:47 +00:00
//---- 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;
}
2012-01-30 06:26:47 +00:00
}
var format = util.format;
if (!format) {
// If node < 0.6, then use its `util.format`:
2012-01-30 06:26:47 +00:00
// <https://github.com/joyent/node/blob/master/lib/util.js#L22>:
var inspect = util.inspect;
var formatRegExp = /%[sdj%]/g;
format = function format(f) {
2012-04-28 00:31:46 +00:00
if (typeof (f) !== 'string') {
2012-01-30 06:26:47 +00:00
var objects = [];
for (var i = 0; i < arguments.length; i++) {
objects.push(inspect(arguments[i]));
}
return objects.join(' ');
}
2012-01-30 06:26:47 +00:00
var i = 1;
var args = arguments;
var len = args.length;
2012-04-28 00:23:29 +00:00
var str = String(f).replace(formatRegExp, function (x) {
if (i >= len)
return x;
2012-01-30 06:26:47 +00:00
switch (x) {
case '%s': return String(args[i++]);
case '%d': return Number(args[i++]);
2012-09-10 18:24:39 +00:00
case '%j': return JSON.stringify(args[i++], safeCycles());
2012-01-30 06:26:47 +00:00
case '%%': return '%';
default:
return x;
}
});
for (var x = args[i]; i < len; x = args[++i]) {
2012-04-28 00:31:46 +00:00
if (x === null || typeof (x) !== 'object') {
2012-01-30 06:26:47 +00:00
str += ' ' + x;
} else {
str += ' ' + inspect(x);
}
}
return str;
};
}
/**
* Gather some caller info 3 stack levels up.
* See <http://code.google.com/p/v8/wiki/JavaScriptStackTraceApi>.
*/
function getCaller3Info() {
var obj = {};
var saveLimit = Error.stackTraceLimit;
var savePrepare = Error.prepareStackTrace;
Error.stackTraceLimit = 3;
Error.captureStackTrace(this, getCaller3Info);
2012-04-28 00:23:29 +00:00
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;
}
/**
* Warn about an bunyan processing error.
*
* If file/line are given, this makes an attempt to warn on stderr only once.
*
* @param msg {String} Message with which to warn.
* @param file {String} Optional. File path relevant for the warning.
* @param line {String} Optional. Line number in `file` path relevant for
* the warning.
*/
function _warn(msg, file, line) {
assert.ok(msg);
var key;
if (file && line) {
key = file + ':' + line;
if (_warned[key]) {
return;
}
_warned[key] = true;
}
process.stderr.write(msg + '\n');
}
var _warned = {};
2012-01-30 06:26:47 +00:00
//---- Levels
var TRACE = 10;
var DEBUG = 20;
var INFO = 30;
var WARN = 40;
var ERROR = 50;
var FATAL = 60;
2012-01-30 06:26:47 +00:00
var levelFromName = {
'trace': TRACE,
2012-01-30 06:26:47 +00:00
'debug': DEBUG,
'info': INFO,
'warn': WARN,
'error': ERROR,
'fatal': FATAL
};
// Dtrace probes.
var dtp = undefined;
var probes = dtrace && {};
/**
* Resolve a level number, name (upper or lowercase) to a level number value.
*
* @api public
*/
function resolveLevel(nameOrNum) {
2012-04-28 00:23:29 +00:00
var level = (typeof (nameOrNum) === 'string'
? levelFromName[nameOrNum.toLowerCase()]
: nameOrNum);
if (! (TRACE <= level && level <= FATAL)) {
throw new Error('invalid level: ' + nameOrNum);
}
return level;
}
2012-01-30 06:26:47 +00:00
2012-01-30 06:26:47 +00:00
//---- Logger class
/**
* Create a Logger instance.
*
* @param options {Object} See documentation for full details. At minimum
2012-04-28 00:23:29 +00:00
* this must include a 'name' string key. Configuration keys:
* - `streams`: specify the logger output streams. This is an array of
* objects with these fields:
* - `type`: The stream type. See README.md for full details.
* Often this is implied by the other fields. Examples are
* "file", "stream" and "raw".
* - `level`: Defaults to "info".
* - `path` or `stream`: The specify the file path or writeable
* stream to which log records are written. E.g.
* `stream: process.stdout`.
* - `closeOnExit` (boolean): Optional. Default is true for a
* "file" stream when `path` is given, false otherwise.
* See README.md for full details.
* - `level`: set the level for a single output stream (cannot be used
* with `streams`)
* - `stream`: the output stream for a logger with just one, e.g.
* `process.stdout` (cannot be used with `streams`)
* - `serializers`: object mapping log record field names to
* serializing functions. See README.md for details.
* - `src`: Boolean (default false). Set true to enable 'src' automatic
* field with log call source info.
* All other keys are log record fields.
*
* An alternative *internal* call signature is used for creating a child:
* new Logger(<parent logger>, <child options>[, <child opts are simple>]);
*
* @param _childSimple (Boolean) An assertion that the given `_childOptions`
* (a) only add fields (no config) and (b) no serialization handling is
* required for them. IOW, this is a fast path for frequent child
* creation.
*/
function Logger(options, _childOptions, _childSimple) {
xxx('Logger start:', options)
2012-01-30 06:26:47 +00:00
if (! this instanceof Logger) {
return new Logger(options, _childOptions);
2012-01-30 06:26:47 +00:00
}
// 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');
}
}
2012-01-30 20:01:15 +00:00
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');
2012-01-30 20:01:15 +00:00
}
if (options.streams && !Array.isArray(options.streams)) {
throw new TypeError('invalid options.streams: must be an array')
}
2012-04-28 00:31:46 +00:00
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);
}
2012-01-30 06:26:47 +00:00
} else {
this._level = Number.POSITIVE_INFINITY;
this.streams = [];
this.serializers = null;
this.src = false;
this.fields = {};
2012-01-30 06:26:47 +00:00
}
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) {
2012-04-28 00:23:29 +00:00
s.type = 'stream';
} else if (s.path) {
2012-04-28 00:23:29 +00:00
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) {
2012-04-28 00:23:29 +00:00
case 'stream':
if (!s.closeOnExit) {
s.closeOnExit = false;
}
break;
2012-04-28 00:23:29 +00:00
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];
2012-04-28 00:23:29 +00:00
if (typeof (serializer) !== 'function') {
throw new TypeError(format(
'invalid serializer for "%s" field: must be a function', field));
} else {
self.serializers[field] = serializer;
}
});
}
// Handle *config* options (i.e. options that are not just plain data
// for log records).
if (options.stream) {
addStream({
2012-04-28 00:23:29 +00:00
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({
2012-04-28 00:23:29 +00:00
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;
}
2012-04-28 00:23:29 +00:00
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];
});
2012-01-30 20:01:15 +00:00
}
util.inherits(Logger, EventEmitter);
2012-01-30 20:01:15 +00:00
/**
* Create a child logger, typically to add a few log record fields.
2012-01-30 20:01:15 +00:00
*
* This can be useful when passing a logger to a sub-component, e.g. a
2012-04-28 00:23:29 +00:00
* 'wuzzle' component of your service:
2012-01-30 20:01:15 +00:00
*
2012-04-28 00:23:29 +00:00
* var wuzzleLog = log.child({component: 'wuzzle'})
2012-01-30 20:01:15 +00:00
* var wuzzle = new Wuzzle({..., log: wuzzleLog})
*
* Then log records from the wuzzle code will have the same structure as
2012-04-28 00:23:29 +00:00
* the app log, *plus the component='wuzzle' field*.
2012-01-30 20:01:15 +00:00
*
* @param options {Object} Optional. Set of options to apply to the child.
* All of the same options for a new Logger apply here. Notes:
* - The parent's streams are inherited and cannot be removed in this
* call. Any given `streams` are *added* to the set inherited from
* the parent.
* - The parent's serializers are inherited, though can effectively be
* overwritten by using duplicate keys.
* - Can use `level` to set the level of the streams inherited from
* the parent. The level for the parent is NOT affected.
* @param simple {Boolean} Optional. Set to true to assert that `options`
* (a) only add fields (no config) and (b) no serialization handling is
* required for them. IOW, this is a fast path for frequent child
2012-04-28 00:23:29 +00:00
* creation. See 'tools/timechild.js' for numbers.
2012-01-30 20:01:15 +00:00
*/
Logger.prototype.child = function (options, simple) {
return new Logger(this, options || {}, simple);
}
2012-04-28 00:31:46 +00:00
/* BEGIN JSSTYLED */
/**
* Close this logger.
*
* 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;
}
*/
/* END JSSTYLED */
/**
* Get/set the level of all streams on this logger.
*
* Get Usage:
* // Returns the current log level (lowest level of all its streams).
* log.level() -> INFO
*
* Set Usage:
* log.level(INFO) // set all streams to level INFO
2012-04-28 00:23:29 +00:00
* 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;
}
/**
* Get/set the level of a particular stream on this logger.
*
* Get Usage:
* // Returns an array of the levels of each stream.
* log.levels() -> [TRACE, INFO]
*
* // Returns a level of the identified stream.
* log.levels(0) -> TRACE // level of stream at index 0
2012-04-28 00:23:29 +00:00
* log.levels('foo') // level of stream with name 'foo'
*
* Set Usage:
* log.levels(0, INFO) // set level of stream 0 to INFO
2012-04-28 00:23:29 +00:00
* log.levels(0, 'info') // can use 'info' et al aliases
* log.levels('foo', WARN) // set stream named 'foo' to WARN
*
* Stream names: When streams are defined, they can optionally be given
* a name. For example,
* log = new Logger({
* streams: [
* {
2012-04-28 00:31:46 +00:00
* name: 'foo',
* path: '/var/log/my-service/foo.log'
* level: 'trace'
* },
* ...
*
* @param name {String|Number} The stream index or name.
2012-04-28 00:23:29 +00:00
* @param value {Number|String} The level value (INFO) or alias ('info').
* If not given, this is a 'get' operation.
* @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);
2012-04-28 00:31:46 +00:00
return this.streams.map(
function (s) { return s.level });
}
var stream;
2012-04-28 00:31:46 +00:00
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 (value === undefined) {
return stream.level;
} else {
var newLevel = resolveLevel(value);
stream.level = newLevel;
if (newLevel < this._level) {
this._level = newLevel;
}
}
}
/**
* Apply registered serializers to the appropriate keys in the given fields.
*
* Pre-condition: This is only called if there is at least one serializer.
*
* @param fields (Object) The log record fields.
* @param excludeFields (Object) Optional mapping of keys to `true` for
* keys to NOT apply a serializer.
*/
Logger.prototype._applySerializers = function (fields, excludeFields) {
var self = this;
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 <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);
}
});
2012-01-30 06:26:47 +00:00
}
/**
* A log record is a 4-tuple:
* [<default fields object>,
* <log record fields object>,
* <level integer>,
* <msg args array>]
* For Perf reasons, we only render this down to a single object when
* it is emitted.
*/
Logger.prototype._mkRecord = function (fields, level, msgArgs) {
var recFields = (fields ? objCopy(fields) : null);
return [this.fields, recFields, level, msgArgs];
}
2012-01-30 20:01:15 +00:00
/**
* Emit a log record.
*
* @param rec {log record}
* @param noemit {Boolean} Optional. Set to true to skip emission
* and just return the JSON string.
2012-01-30 20:01:15 +00:00
*/
Logger.prototype._emit = function (rec, noemit) {
2012-06-20 23:04:23 +00:00
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;
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;
2012-06-20 23:04:23 +00:00
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);
}
2012-06-20 23:04:23 +00:00
};
return str;
2012-01-30 06:26:47 +00:00
}
2012-10-24 16:04:57 +00:00
2012-01-30 20:40:57 +00:00
/**
2012-10-24 16:04:57 +00:00
* Build a log emitter function for level minLevel. I.e. this is the
* creator of `log.info`, `log.error`, etc.
2012-01-30 20:40:57 +00:00
*/
2012-10-24 16:04:57 +00:00
function mkLogEmitter(minLevel) {
return function () {
var log = this;
function mkRecord(args) {
var excludeFields;
if (args[0] instanceof Error) {
// `log.<level>(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.<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.
fields = null;
msgArgs = Array.prototype.slice.call(args);
msgArgs[0] = util.inspect(msgArgs[0]);
} else { // `log.<level>(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.<level>()`
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) ];
});
}
2012-01-30 20:40:57 +00:00
}
2012-10-24 16:04:57 +00:00
2012-01-30 20:40:57 +00:00
/**
* The functions below log a record at a specific level.
2012-01-30 20:40:57 +00:00
*
* Usages:
* log.<level>() -> boolean is-trace-enabled
* log.<level>(<Error> err, [<string> msg, ...])
* log.<level>(<string> msg, ...)
* log.<level>(<object> fields, <string> msg, ...)
2012-01-30 20:40:57 +00:00
*
2012-10-24 16:04:57 +00:00
* where <level> is the lowercase version of the log level. E.g.:
2012-01-30 20:40:57 +00:00
*
2012-10-24 16:04:57 +00:00
* log.info()
2012-01-30 20:40:57 +00:00
*
* @params fields {Object} Optional set of additional fields to log.
* @params msg {String} Log message. This can be followed by additional
* arguments that are handled like
* [util.format](http://nodejs.org/docs/latest/api/all.html#util.format).
*/
2012-10-24 16:04:57 +00:00
Logger.prototype.trace = mkLogEmitter(TRACE);
Logger.prototype.debug = mkLogEmitter(DEBUG);
Logger.prototype.info = mkLogEmitter(INFO);
Logger.prototype.warn = mkLogEmitter(WARN);
Logger.prototype.error = mkLogEmitter(ERROR);
Logger.prototype.fatal = mkLogEmitter(FATAL);
2012-01-30 20:40:57 +00:00
2012-01-30 20:01:15 +00:00
//---- Standard serializers
// A serializer is a function that serializes a JavaScript object to a
// JSON representation for logging. There is a standard set of presumed
// interesting objects in node.js-land.
Logger.stdSerializers = {};
// Serialize an HTTP request.
Logger.stdSerializers.req = function req(req) {
2012-08-08 05:34:46 +00:00
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
2012-06-21 21:58:42 +00:00
// make a custom serializer.
//if (Object.keys(trailers).length > 0) {
// obj.trailers = req.trailers;
//}
};
// Serialize an HTTP response.
Logger.stdSerializers.res = function res(res) {
2012-08-08 05:34:46 +00:00
if (!res || !res.statusCode)
return res;
return {
statusCode: res.statusCode,
header: res._header
}
};
/*
* This function dumps long stack traces for exceptions having a cause()
* method. The error classes from
* [verror](https://github.com/davepacheco/node-verror) and
* [restify v2.0](https://github.com/mcavage/node-restify) are examples.
*
* Based on `dumpException` in
* https://github.com/davepacheco/node-extsprintf/blob/master/lib/extsprintf.js
*/
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);
}
}
return (ret);
}
// Serialize an Error object
// (Core error properties are enumerable in node 0.4, not in 0.6).
2012-02-06 17:10:11 +00:00
var errSerializer = Logger.stdSerializers.err = function err(err) {
2012-08-08 05:34:46 +00:00
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;
};
2012-09-10 18:24:39 +00:00
// 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;
};
}
/**
* XXX
*/
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);
// Parse `options.period`.
if (options.period) {
// <number><scope> 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';
}
// TODO: template support for backup files
// template: <path to which to rotate>
// 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();
}
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());
}
RotatingFileStream.prototype._nextRotTime = function _nextRotTime(first) {
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;
}
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;
};
RotatingFileStream.prototype.rotate = function rotate() {
// 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;
}
n -= 1;
if (_DEBUG) console.log('rm %s', toDel);
fs.unlink(toDel, function (delErr) {
//XXX handle err other than not exists
moves();
});
}
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);
}
};
RotatingFileStream.prototype.end = function end(s) {
this.stream.end();
};
RotatingFileStream.prototype.destroy = function destroy(s) {
this.stream.destroy();
};
RotatingFileStream.prototype.destroySoon = function destroySoon(s) {
this.stream.destroySoon();
};
} /* if (mv) */
2012-06-19 21:36:02 +00:00
/**
* RingBuffer is a Writable Stream that just stores the last N records in
2012-06-19 21:36:02 +00:00
* memory.
*
* @param options {Object}, with the following fields:
*
* - limit: number of records to keep in memory
2012-06-19 21:36:02 +00:00
*/
function RingBuffer(options) {
this.limit = options && options.limit ? options.limit : 100;
this.writable = true;
this.records = [];
2012-06-19 21:36:02 +00:00
EventEmitter.call(this);
}
util.inherits(RingBuffer, EventEmitter);
2012-06-20 23:26:28 +00:00
RingBuffer.prototype.write = function (record) {
2012-06-19 21:36:02 +00:00
if (!this.writable)
throw (new Error('RingBuffer has been ended already'));
this.records.push(record);
2012-06-19 21:36:02 +00:00
if (this.records.length > this.limit)
this.records.shift();
2012-06-19 21:36:02 +00:00
return (true);
};
RingBuffer.prototype.end = function () {
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');
};
RingBuffer.prototype.destroySoon = function () {
this.destroy();
};
//---- Exports
2012-01-30 06:26:47 +00:00
module.exports = Logger;
module.exports.TRACE = TRACE;
module.exports.DEBUG = DEBUG;
module.exports.INFO = INFO;
module.exports.WARN = WARN;
module.exports.ERROR = ERROR;
module.exports.FATAL = FATAL;
module.exports.resolveLevel = resolveLevel;
2012-01-30 06:26:47 +00:00
module.exports.VERSION = VERSION;
module.exports.LOG_VERSION = LOG_VERSION;
module.exports.createLogger = function createLogger(options) {
return new Logger(options);
};
2012-06-19 21:36:02 +00:00
module.exports.RingBuffer = RingBuffer;
2012-10-24 17:54:18 +00:00
// Useful for custom `type == "raw"` streams that may do JSON stringification
// of log records themselves. Usage:
// var str = JSON.stringify(rec, bunyan.safeCycles());
module.exports.safeCycles = safeCycles;