Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with HTTPS or Subversion.

Download ZIP
Browse files

v0.4: add 'src' call source location info support (the Yunong release)

  • Loading branch information...
commit e934baf74fe79e4af8f36e7a355a76048003cda7 1 parent 9786827
@trentm authored
View
2  AUTHORS.txt
@@ -0,0 +1,2 @@
+Trent Mick <trentm@gmail.com>
+Mark Cavage <mcavage@gmail.com>
View
12 CHANGES.md
@@ -1,8 +1,16 @@
# bunyan Changelog
-## bunyan 0.3.1 (not yet released)
+## bunyan 0.4.0 (not yet released)
+
+- Add `new Logger({src: true})` config option to have a 'src' attribute be
+ automatically added to log records with the log call source info. Example:
+
+ "src": {
+ "file": "/Users/trentm/tm/node-bunyan/examples/src.js",
+ "line": 20,
+ "func": "Wuzzle.woos"
+ },
-(nothing yet)
## bunyan 0.3.0
View
51 README.md
@@ -32,6 +32,16 @@ format version) are added for you.
$ node hi.js
{"service":"myapp","hostname":"banana.local","level":2,"msg":"hi","time":"2012-01-31T00:07:44.216Z","v":0}
+The full `log.{trace|debug|...|fatal}(...)` API is:
+
+ log.info(); // returns a boolean: is the "info" level enabled?
+ log.info("hi"); // log a simple string message
+ log.info("hi %s", bob, anotherVar); // uses `util.format` for msg formatting
+ log.info({foo: "bar"}, "hi"); // adds "foo" field to log record
+
+
+## bunyan tool
+
A `bunyan` tool is provided **for pretty-printing bunyan logs** and, eventually,
for filtering (e.g. `| bunyan -c 'level>3'`). This shows the default output
(which is fluid right now) and indented-JSON output. More output formats will
@@ -50,6 +60,9 @@ be added, including support for custom formats.
"v": 0
}
+
+## streams
+
By default, log output is to stdout (**stream**) and at the "info" level.
Explicitly that looks like:
@@ -73,6 +86,9 @@ streams at different levels**.
]
});
+
+## log.child
+
A `log.child(...)` is provided to **specialize a logger for a sub-component**.
The following will have log records from "Wuzzle" instances use exactly the
same config as its parent, plus include the "component" field.
@@ -111,12 +127,7 @@ See the changelog for node-bunyan 0.3.0 for details.
* * *
-Back to the `log.{trace|debug|...|fatal}(...)` API:
-
- log.info(); // returns a boolean: is the "info" level enabled?
- log.info("hi"); // log a simple string message
- log.info("hi %s", bob, anotherVar); // uses `util.format` for msg formatting
- log.info({foo: "bar"}, "hi"); // adds "foo" field to log record
+## serializers
Bunyan has a concept of **"serializers" to produce a JSON-able object from a
JavaScript object**, so your can easily do the following:
@@ -159,7 +170,32 @@ standard serializers you can use:
ugly message on stderr from Bunyan (along with the traceback) and the field
in your log record will be replaced with a short error message.*
+## src
+
+The **call source file, line and function** (if not at the global level) can
+be added to log records by using the `src: true` config option:
+
+ var log = new Logger({src: true, ...});
+
+This adds the call source info with the 'src' field, like this:
+
+ {
+ "service": "src-example",
+ "hostname": "banana.local",
+ "component": "wuzzle",
+ "level": 4,
+ "msg": "This wuzzle is woosey.",
+ "time": "2012-02-06T04:19:35.605Z",
+ "src": {
+ "file": "/Users/trentm/tm/node-bunyan/examples/src.js",
+ "line": 20,
+ "func": "Wuzzle.woos"
+ },
+ "v": 0
+ }
+**WARNING: Determining the call source info is slow. Never use this option
+in production.**
# Levels
@@ -245,6 +281,9 @@ Core fields:
[`Date.toISOString()`](https://developer.mozilla.org/en/JavaScript/Reference/Global_Objects/Date/toISOString).
- `msg`: Required. String.
Every `log.debug(...)` et al call must provide a log message.
+- `src`: Optional. Object giving log call source info. This is added
+ automatically by Bunyan if the "src: true" config option is given to the
+ Logger. Never use in production as this is really slow.
Go ahead and add more fields, and nest ones are fine (and recommended) as
View
46 TODO.md
@@ -1,14 +1,12 @@
-- `log.close` to close streams and shutdown and `this.closed`
- line/file: possible to get quickly with v8? Yunong asked.
-- what's the API for changing the logger/stream level(s)?
+ file/line/func (?)
+- Logger.setLevel()? How to change level for a given stream. Default all,
+ else, give an index... or type ... or support stream "names". Some positives
+ to stream names.
- bunyan cli: more layouts (http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/EnhancedPatternLayout.html)
Custom log formats (in config file? in '-f' arg) using printf or hogan.js
or whatever. Dap wants field width control for lining up. Hogan.js is
probably overkill for this.
-- bunyan cli: filter args a la json
-- bunyan cli: -c COND args a la json
-- mark wants pretty output for debug output
- - not sure if 'bunyan --pretty' or whatever would suffice
- ringBuffer stream
- syslog: Josh uses https://github.com/chrisdew/node-syslog
streams: [
@@ -20,8 +18,6 @@
syslog_pid: true, // syslog logopt "LOG_PID"
syslog_cons: false // syslog logopt "LOG_CONS"
}
-- Logger.setLevel()? How to change level for a given stream. Default all,
- else, give an index... or type ... or support stream "names".
- "canWrite" handling for full streams. Need to buffer a la log4js
- test file log with logadm rotation: does it handle that?
- test suite:
@@ -32,30 +28,24 @@
works *and* that an existing field in the parent is not *re-serialized*.
- a "rolling-file" stream: but specifically by time, e.g. hourly. (MarkC
requested)
+- (mark) instanceof-based serialization:
+ log.info(new Error("blah blah")) -> {err: ..., msg: ""}
+ perhaps at least default for Error. Then perhaps augment or replace
+ serializers with registerable instanceof's.
+ log = new Logger({
+ serializers
+ })
+
# someday/maybe
-- file/line fields automatic: "but it's fucking slow" (https://gist.github.com/1733234)
- function getFileAndLine() {
- var self = this;
- var saveLimit = Error.stackTraceLimit;
- var savePrepare = Error.prepareStackTrace;
- Error.stackTraceLimit = 1;
- Error.captureStackTrace(this, getFileAndLine);
- Error.prepareStackTrace = function(_, stack) {
- self.file = stack[0].getFileName();
- self.line = stack[0].getLineNumber();
- };
- this.stack;
- Error.stackTraceLimit = saveLimit;
- Error.prepareStackTrace = savePrepare;
- return {
- file: self.file,
- line: self.line
- }
- }
- Want some way to have file/line only at certain levesl and lazily.
+- bunyan cli: filter args a la json
+- bunyan cli: -c COND args a la json
+- bunyan "compact" or "light", '-l'? Something like. Or pehaps this (with
+ color) could be the default, with '-l' for long output.
+ 13:51.340 [src.js:20#Wuzzle.woos] WARN: This wuzzle is woosey.
+- `log.close` to close streams and shutdown and `this.closed`
- get Mark to show me dtrace provider stuff and consider adding for
logging, if helpful.
- add option to "streams" to take the raw object, not serialized.
View
20 bin/bunyan
@@ -5,7 +5,7 @@
// See <https://github.com/trentm/node-bunyan>.
//
-var VERSION = "0.3.1";
+var VERSION = "0.4.0";
var util = require('util');
var pathlib = require('path');
@@ -253,9 +253,9 @@ function handleLogLine(line, opts) {
switch (opts.outputMode) {
case OM_PAUL:
// Single-line msg:
- // [time] LEVEL: service[/component] on hostname: msg (extras...)
+ // [time] LEVEL: service[/component] on hostname (src): msg (extras...)
// Multi-line msg:
- // [time] LEVEL: service[/component] on hostname: (extras...)
+ // [time] LEVEL: service[/component] on hostname (src): (extras...)
// msg
// If 'req', show the request.
// If 'res', show the response.
@@ -266,8 +266,17 @@ function handleLogLine(line, opts) {
}
var levelStr = (upperNameFromLevel[rec.level]
|| "<unknown-level " + 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);
+ }
+ }
var extras = [];
- if (rec.request_id) extras.push(rec.request_id);
+ if (rec.req_id) extras.push("req_id=" + rec.req_id);
if (rec.latency) extras.push(rec.latency + "ms");
extras = (extras.length ? ' (' + extras.join(', ') + ')' : '');
var details = [];
@@ -304,11 +313,12 @@ function handleLogLine(line, opts) {
details.push(indent(rec.err.stack))
}
details = (details.length ? details.join('\n--\n') + '\n' : '');
- emit(format("[%s] %s: %s on %s:%s%s\n%s",
+ emit(format("[%s] %s: %s on %s%s:%s%s\n%s",
rec.time,
upperNameFromLevel[rec.level] || "<unknown-level " + rec.level + ">",
serviceStr,
rec.hostname || "<no-hostname>",
+ src,
onelineMsg,
extras,
details));
View
26 examples/src.js
@@ -0,0 +1,26 @@
+// Show the usage of `src: true` config option to get log call source info in
+// log records (the `src` field).
+
+var Logger = require('../lib/bunyan');
+
+var log = new Logger({service: "src-example", src: true});
+
+log.info("one");
+log.info("two");
+function doSomeFoo() {
+ log.info({foo:"bar"}, "three");
+}
+doSomeFoo();
+
+function Wuzzle(options) {
+ this.log = options.log;
+ this.log.info("creating a wuzzle")
+}
+Wuzzle.prototype.woos = function () {
+ this.log.warn("This wuzzle is woosey.")
+}
+
+var wuzzle = new Wuzzle({log: log.child({component: "wuzzle"})});
+wuzzle.woos();
+log.info("done with the wuzzle")
+
View
43 lib/bunyan.js
@@ -2,7 +2,7 @@
* Copyright 2012 (c) Trent Mick. All rights reserved.
*/
-var VERSION = "0.3.1";
+var VERSION = "0.4.0";
// Bunyan log format version. This becomes the 'v' field on all log records.
// `0` is until I release a version "1.0.0" of node-bunyan. Thereafter,
@@ -82,6 +82,32 @@ if (!format) {
}
+/**
+ * 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);
+ 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;
+}
+
+
+
//---- Levels
@@ -135,6 +161,8 @@ function resolveLevel(nameOrNum) {
* `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:
@@ -176,6 +204,7 @@ function Logger(options, _childOptions, _childSimple) {
this.level = parent.level;
this.streams = parent.streams;
this.serializers = parent.serializers;
+ this.src = parent.src;
this.fields = parent.fields;
var names = Object.keys(options);
for (var i = 0; i < names.length; i++) {
@@ -196,11 +225,13 @@ function Logger(options, _childOptions, _childSimple) {
this.streams.push(s);
}
this.serializers = objCopy(parent.serializers);
+ this.src = parent.src;
this.fields = objCopy(parent.fields);
} else {
this.level = Number.POSITIVE_INFINITY;
this.streams = [];
this.serializers = null;
+ this.src = false;
this.fields = {};
}
@@ -289,6 +320,9 @@ function Logger(options, _childOptions, _childSimple) {
if (options.serializers) {
addSerializers(options.serializers);
}
+ if (options.src) {
+ this.src = true;
+ }
xxx("Logger: ", self)
// Fields.
@@ -301,6 +335,7 @@ function Logger(options, _childOptions, _childSimple) {
delete fields.level;
delete fields.streams;
delete fields.serializers;
+ delete fields.src;
if (this.serializers) {
this._applySerializers(fields);
}
@@ -443,8 +478,12 @@ Logger.prototype._emit = function (rec) {
if (!obj.time) {
obj.time = (new Date());
}
+ // Get call source info
+ if (this.src && !obj.src) {
+ obj.src = getCaller3Info()
+ }
obj.v = LOG_VERSION;
-
+
xxx('_emit: stringify this:', obj);
var str = JSON.stringify(obj) + '\n';
this.streams.forEach(function(s) {
View
2  package.json
@@ -1,6 +1,6 @@
{
"name": "bunyan",
- "version": "0.3.1",
+ "version": "0.4.0",
"description": "a JSON Logger library for node.js servers",
"main": "./lib/bunyan.js",
"bin": {
View
37 tools/timesrc.js
@@ -0,0 +1,37 @@
+#!/usr/bin/env node
+/*
+ * Time 'src' fields (getting log call source info). This is expensive.
+ */
+
+console.log("Time adding 'src' field with call source info:");
+
+var ben = require('ben'); // npm install ben
+var Logger = require('../lib/bunyan');
+
+var records = [];
+function Collector() {
+}
+Collector.prototype.write = function(s) {
+ //records.push(s);
+}
+var collector = new Collector();
+
+var logwith = new Logger({
+ service: "with-src",
+ src: true,
+ stream: collector
+});
+
+var ms = ben(1e5, function () {
+ logwith.info("hi");
+});
+console.log(' - log.info with src: %dms per iteration', ms);
+
+var logwithout = new Logger({
+ service: "without-src",
+ stream: collector
+});
+var ms = ben(1e5, function () {
+ logwithout.info("hi");
+});
+console.log(' - log.info without src: %dms per iteration', ms);
Please sign in to comment.
Something went wrong with that request. Please try again.