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

Merge branch 'master' of github.com:trentm/node-bunyan

Browse source
This commit is contained in:
Dave Pacheco 2012-06-19 14:42:10 -07:00
commit f8de9a35d5
22 changed files with 255 additions and 115 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

2
.gitignore vendored
View file

@ -1,4 +1,4 @@
/tmp
/npm-debug.log
/node_modules
*.log
!/test/corpus/*.log

17
CHANGES.md
View file

@ -1,6 +1,21 @@
# bunyan Changelog
## bunyan 0.7.1 (not yet released)
## bunyan 0.8.1 (not yet released)
- Add test/corpus/*.log files (accidentally excluded) so that test suite
works(!).
## bunyan 0.8.0
- [pull #21] Bunyan loggers now re-emit `fs.createWriteStream` error events.
By github.com/EvanOxfeld. See "examples/handle-fs-error.js" and
"test/error-event.js" for details.
var log = new Logger({name: 'mylog', streams: [{path: FILENAME}]});
log.on('error', function (err, stream) {
// Handle error writing to or creating FILENAME.
});
- jsstyle'ing (via `make check`)

4
Makefile
View file

@ -6,7 +6,7 @@ TAP := ./node_modules/.bin/tap
#---- Files
JSSTYLE_FILES := $(shell find lib test tools -name "*.js")
JSSTYLE_FILES := $(shell find lib test tools examples -name "*.js")
@ -18,7 +18,7 @@ all:
.PHONY: versioncheck
versioncheck:
[[ `cat package.json | json version` == `grep '^var VERSION' bin/bunyan | awk -F'"' '{print $$2}'` ]]
[[ `cat package.json | json version` == `grep '^var VERSION' lib/bunyan.js | awk -F'"' '{print $$2}'` ]]
[[ `cat package.json | json version` == `grep '^var VERSION' lib/bunyan.js | awk -F"'" '{print $$2}'` ]]
@echo Version check ok.
.PHONY: cutarelease

15
README.md
View file

@ -64,6 +64,14 @@ The full `log.{trace|debug|...|fatal}(...)` API is:
log.info(err, 'more on this: %s', more);
// ... or you can specify the "msg".
Note that this implies **you cannot pass any object as the first argument
to log it**. IOW, `log.info(myobject)` isn't going to work the way you
expect. Adding support for this API would necessitate (a) JSON-ifying safely
that given object (sometimes hard, and probably slow) and (b) putting all its
attribs under a top-level 'x' field name or something to avoid field name
collisions.
## bunyan tool
A `bunyan` tool is provided **for pretty-printing bunyan logs** and, eventually,
@ -443,6 +451,13 @@ Supported stream types are:
"level": "warn"
}
Bunyan re-emits error events from the created `WriteStream`. So you can
do this:
var log = new Logger({name: 'mylog', streams: [{path: LOG_PATH}]});
log.on('error', function (err, stream) {
// Handle stream write or create error here.
});
# License

7
TODO.md
View file

@ -1,4 +1,4 @@
- [Yuonong] buffered writes to increase speed:
- [Yunong] buffered writes to increase speed:
- I'd start with a tools/timeoutput.js for some numbers to compare
before/after. Sustained high output to a file.
- perhaps this would be a "buffered: true" option on the stream object
@ -20,9 +20,14 @@
as the basis for tools to consume bunyan logs. It can grow indep of node-bunyan
for generating the logs.
It would take a Bunyan log record object and be expected to emit it.
node-bunyan-reader
.createReadStream(path, [options]) ?
- document "well-known" keys from bunyan CLI p.o.v.. Add "client_req".
- bunyan tool: built in less usage (a la git?) so that I don't have to
go through this: `bunyan --color master.log | less -R`
- want `bunyan -f foo.log` a la `tail -f`

2
bin/bunyan
View file

@ -5,7 +5,7 @@
// See <https://github.com/trentm/node-bunyan>.
//
var VERSION = "0.7.1";
var VERSION = "0.8.1";
var util = require('util');
var pathlib = require('path');

68
examples/err.js
View file

@ -5,52 +5,54 @@ var Logger = require('../lib/bunyan');
var util = require('util');
var log = new Logger({
name: "myserver",
name: 'myserver',
serializers: {
err: Logger.stdSerializers.err, // <--- use this
}
});
try {
throw new TypeError("boom");
throw new TypeError('boom');
} catch (err) {
log.warn({err: err}, "operation went boom: %s", err) // <--- here
log.warn({err: err}, 'operation went boom: %s', err) // <--- here
}
log.info(new TypeError("how about this?")) // <--- alternatively this
log.info(new TypeError('how about this?')) // <--- alternatively this
try {
throw "boom string";
throw 'boom string';
} catch (err) {
log.error(err)
}
/*
$ node err.js | ../bin/bunyan -j
{
"name": "myserver",
"hostname": "banana.local",
"err": {
"stack": "TypeError: boom\n at Object.<anonymous> (/Users/trentm/tm/node-bunyan/examples/err.js:15:9)\n at Module._compile (module.js:411:26)\n at Object..js (module.js:417:10)\n at Module.load (module.js:343:31)\n at Function._load (module.js:302:12)\n at Array.0 (module.js:430:10)\n at EventEmitter._tickCallback (node.js:126:26)",
"name": "TypeError",
"message": "boom"
},
"level": 4,
"msg": "operation went boom: TypeError: boom",
"time": "2012-02-02T04:42:53.206Z",
"v": 0
}
$ node err.js | ../bin/bunyan
[2012-02-02T05:02:39.412Z] WARN: myserver on banana.local: operation went boom: TypeError: boom
TypeError: boom
at Object.<anonymous> (/Users/trentm/tm/node-bunyan/examples/err.js:15:9)
at Module._compile (module.js:411:26)
at Object..js (module.js:417:10)
at Module.load (module.js:343:31)
at Function._load (module.js:302:12)
at Array.0 (module.js:430:10)
at EventEmitter._tickCallback (node.js:126:26)
*/
/* BEGIN JSSTYLED */
/**
*
* $ node err.js | ../bin/bunyan -j
* {
* "name": "myserver",
* "hostname": "banana.local",
* "err": {
* "stack": "TypeError: boom\n at Object.<anonymous> (/Users/trentm/tm/node-bunyan/examples/err.js:15:9)\n at Module._compile (module.js:411:26)\n at Object..js (module.js:417:10)\n at Module.load (module.js:343:31)\n at Function._load (module.js:302:12)\n at Array.0 (module.js:430:10)\n at EventEmitter._tickCallback (node.js:126:26)",
* "name": "TypeError",
* "message": "boom"
* },
* "level": 4,
* "msg": "operation went boom: TypeError: boom",
* "time": "2012-02-02T04:42:53.206Z",
* "v": 0
* }
* $ node err.js | ../bin/bunyan
* [2012-02-02T05:02:39.412Z] WARN: myserver on banana.local: operation went boom: TypeError: boom
* TypeError: boom
* at Object.<anonymous> (/Users/trentm/tm/node-bunyan/examples/err.js:15:9)
* at Module._compile (module.js:411:26)
* at Object..js (module.js:417:10)
* at Module.load (module.js:343:31)
* at Function._load (module.js:302:12)
* at Array.0 (module.js:430:10)
* at EventEmitter._tickCallback (node.js:126:26)
*
*/
/* END JSSTYLED */

36
examples/handle-fs-error.js Normal file
View file

@ -0,0 +1,36 @@
// Example handling as fs error for a Bunyan-created
// stream.
var fs = require('fs');
var path = require('path');
var Logger = require('../lib/bunyan');
var FILENAME = 'handle-fs-error.log';
var S_IWUSR = 00200; // mask for owner write permission in stat mode
console.warn('- Log file is "%s".', FILENAME);
if (!path.existsSync(FILENAME)) {
console.warn('- Touch log file.');
fs.writeFileSync(FILENAME, 'touch\n');
}
if (fs.statSync(FILENAME).mode & S_IWUSR) {
console.warn('- Make log file read-only.');
fs.chmodSync(FILENAME, 0444);
}
console.warn('- Create logger.')
var log = new Logger({name: 'handle-fs-error', streams: [{path: FILENAME}]});
log.on('error', function (err) {
console.warn('- The logger emitted an error:', err);
});
console.warn('- Call log.info(...).')
log.info('info log message');
console.warn('- Called log.info(...).')
setTimeout(function () {
console.warn('- Call log.warn(...).')
log.warn('warn log message');
console.warn('- Called log.warn(...).')
}, 1000);

22
examples/hi.js
View file

@ -1,32 +1,32 @@
var Logger = require('../lib/bunyan');
// Basic usage.
var log = new Logger({name: "myapp", level: "info", src: true});
var log = new Logger({name: 'myapp', level: 'info', src: true});
// isInfoEnabled replacement
console.log("log.info() is:", log.info())
console.log('log.info() is:', log.info())
// `util.format`-based printf handling
log.info("hi");
log.info("hi", "trent");
log.info("hi %s there", true);
log.info('hi');
log.info('hi', 'trent');
log.info('hi %s there', true);
// First arg as an object adds fields to the log record.
log.info({foo:"bar", multiline:"one\ntwo\nthree"}, "hi %d", 1, "two", 3);
log.info({foo:'bar', multiline:'one\ntwo\nthree'}, 'hi %d', 1, 'two', 3);
// Shows `log.child(...)` to specialize a logger for a sub-component.
console.log("\n")
console.log('\n')
function Wuzzle(options) {
this.log = options.log;
this.log.info("creating a wuzzle")
this.log.info('creating a wuzzle')
}
Wuzzle.prototype.woos = function () {
this.log.warn("This wuzzle is woosey.")
this.log.warn('This wuzzle is woosey.')
}
var wuzzle = new Wuzzle({log: log.child({component: "wuzzle"})});
var wuzzle = new Wuzzle({log: log.child({component: 'wuzzle'})});
wuzzle.woos();
log.info("done with the wuzzle")
log.info('done with the wuzzle')

9
examples/level.js
View file

@ -37,11 +37,10 @@ try {
assert.ok(e.message.indexOf('name') !== -1)
}
log.trace("no one should see this")
log.debug("should see this once (on stdout)")
log.info("should see this twice")
log.trace('no one should see this')
log.debug('should see this once (on stdout)')
log.info('should see this twice')
log.levels('stdout', INFO)
log.debug("no one should see this either")
log.debug('no one should see this either')
log.level('trace')
log.trace('should see this twice as 4th and 5th emitted log messages')

16
examples/multi.js
View file

@ -1,20 +1,20 @@
var Logger = require('../lib/bunyan');
log = new Logger({
name: "amon",
name: 'amon',
streams: [
{
level: "info",
level: 'info',
stream: process.stdout,
},
{
level: "error",
path: "multi.log"
level: 'error',
path: 'multi.log'
}
]
});
log.debug("hi nobody on debug");
log.info("hi stdout on info");
log.error("hi both on error");
log.fatal("hi both on fatal");
log.debug('hi nobody on debug');
log.info('hi stdout on info');
log.error('hi both on error');
log.fatal('hi both on fatal');

56
examples/server.js
View file

@ -4,7 +4,7 @@ var http = require('http');
var Logger = require('../lib/bunyan');
var log = new Logger({
name: "myserver",
name: 'myserver',
serializers: {
req: Logger.stdSerializers.req,
res: Logger.stdSerializers.res
@ -12,13 +12,13 @@ var log = new Logger({
});
var server = http.createServer(function (req, res) {
log.info({req: req}, "start request"); // <-- this is the guy we're testing
log.info({req: req}, 'start request'); // <-- this is the guy we're testing
res.writeHead(200, {'Content-Type': 'text/plain'});
res.end('Hello World\n');
log.info({res: res}, "done response"); // <-- this is the guy we're testing
log.info({res: res}, 'done response'); // <-- this is the guy we're testing
});
server.listen(1337, "127.0.0.1", function () {
log.info("server listening");
server.listen(1337, '127.0.0.1', function () {
log.info('server listening');
var options = {
port: 1337,
hostname: '127.0.0.1',
@ -33,29 +33,31 @@ server.listen(1337, "127.0.0.1", function () {
process.exit();
})
});
req.write("hi from the client");
req.write('hi from the client');
req.end();
});
/*
$ node server.js
{"service":"myserver","hostname":"banana.local","level":3,"msg":"server listening","time":"2012-02-02T05:32:13.257Z","v":0}
{"service":"myserver","hostname":"banana.local","req":{"method":"GET","url":"/path?q=1#anchor","headers":{"x-hi":"Mom","connection":"close"}},"level":3,"msg":"start request","time":"2012-02-02T05:32:13.260Z","v":0}
{"service":"myserver","hostname":"banana.local","res":{"statusCode":200,"_hasBody":true,"_header":"HTTP/1.1 200 OK\r\nContent-Type: text/plain\r\nConnection: close\r\nTransfer-Encoding: chunked\r\n\r\n","_trailer":""},"level":3,"msg":"done response","time":"2012-02-02T05:32:13.261Z","v":0}
$ node server.js | ../bin/bunyan
[2012-02-02T05:32:16.006Z] INFO: myserver on banana.local: server listening
[2012-02-02T05:32:16.010Z] INFO: myserver on banana.local: start request
GET /path?q=1#anchor
x-hi: Mom
connection: close
[2012-02-02T05:32:16.011Z] INFO: myserver on banana.local: done response
HTTP/1.1 200 OK
Content-Type: text/plain
Connection: close
Transfer-Encoding: chunked
(body)
*/
/* BEGIN JSSTYLED */
/**
*
* $ node server.js
* {"service":"myserver","hostname":"banana.local","level":3,"msg":"server listening","time":"2012-02-02T05:32:13.257Z","v":0}
* {"service":"myserver","hostname":"banana.local","req":{"method":"GET","url":"/path?q=1#anchor","headers":{"x-hi":"Mom","connection":"close"}},"level":3,"msg":"start request","time":"2012-02-02T05:32:13.260Z","v":0}
* {"service":"myserver","hostname":"banana.local","res":{"statusCode":200,"_hasBody":true,"_header":"HTTP/1.1 200 OK\r\nContent-Type: text/plain\r\nConnection: close\r\nTransfer-Encoding: chunked\r\n\r\n","_trailer":""},"level":3,"msg":"done response","time":"2012-02-02T05:32:13.261Z","v":0}
*
* $ node server.js | ../bin/bunyan
* [2012-02-02T05:32:16.006Z] INFO: myserver on banana.local: server listening
* [2012-02-02T05:32:16.010Z] INFO: myserver on banana.local: start request
* GET /path?q=1#anchor
* x-hi: Mom
* connection: close
* [2012-02-02T05:32:16.011Z] INFO: myserver on banana.local: done response
* HTTP/1.1 200 OK
* Content-Type: text/plain
* Connection: close
* Transfer-Encoding: chunked
* (body)
*
*/
/* END JSSTYLED */

17
examples/src.js
View file

@ -3,24 +3,23 @@
var Logger = require('../lib/bunyan');
var log = new Logger({name: "src-example", src: true});
var log = new Logger({name: 'src-example', src: true});
log.info("one");
log.info("two");
log.info('one');
log.info('two');
function doSomeFoo() {
log.info({foo:"bar"}, "three");
log.info({foo:'bar'}, 'three');
}
doSomeFoo();
function Wuzzle(options) {
this.log = options.log;
this.log.info("creating a wuzzle")
this.log.info('creating a wuzzle')
}
Wuzzle.prototype.woos = function () {
this.log.warn("This wuzzle is woosey.")
this.log.warn('This wuzzle is woosey.')
}
var wuzzle = new Wuzzle({log: log.child({component: "wuzzle"})});
var wuzzle = new Wuzzle({log: log.child({component: 'wuzzle'})});
wuzzle.woos();
log.info("done with the wuzzle")
log.info('done with the wuzzle')

7
examples/unstringifyable.js
View file

@ -1,7 +1,7 @@
// See how bunyan behaves with an un-stringify-able object.
var Logger = require("../lib/bunyan");
var Logger = require('../lib/bunyan');
var log = new Logger({src: true, name: "foo"});
var log = new Logger({src: true, name: 'foo'});
// Make a circular object (cannot be JSON-ified).
var myobj = {
@ -9,5 +9,4 @@ var myobj = {
};
myobj.myobj = myobj;
log.info({obj: myobj}, "hi there"); // <--- here
log.info({obj: myobj}, 'hi there'); // <--- here

10
lib/bunyan.js
View file

@ -4,7 +4,7 @@
* The bunyan logging library for node.js.
*/
var VERSION = '0.7.1';
var VERSION = '0.8.1';
// 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,
@ -25,6 +25,7 @@ var os = require('os');
var fs = require('fs');
var util = require('util');
var assert = require('assert');
var EventEmitter = require('events').EventEmitter;
@ -239,6 +240,8 @@ function Logger(options, _childOptions, _childSimple) {
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
@ -317,6 +320,9 @@ function Logger(options, _childOptions, _childSimple) {
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;
}
@ -399,6 +405,8 @@ function Logger(options, _childOptions, _childSimple) {
});
}
util.inherits(Logger, EventEmitter);
/**
* Create a child logger, typically to add a few log record fields.

2
package.json
View file

@ -1,6 +1,6 @@
{
"name": "bunyan",
"version": "0.7.1",
"version": "0.8.1",
"description": "a JSON Logger library for node.js servers",
"author": "Trent Mick <trentm@gmail.com> (http://trentm.com)",
"main": "./lib/bunyan.js",

20
test/corpus/all.log Normal file
View file

@ -0,0 +1,20 @@
# levels
{"name":"myservice","pid":123,"hostname":"example.com","level":10,"msg":"My message","time":"2012-02-08T22:56:50.856Z","v":0}
{"name":"myservice","pid":123,"hostname":"example.com","level":20,"msg":"My message","time":"2012-02-08T22:56:51.856Z","v":0}
{"name":"myservice","pid":123,"hostname":"example.com","level":30,"msg":"My message","time":"2012-02-08T22:56:52.856Z","v":0}
{"name":"myservice","pid":123,"hostname":"example.com","level":40,"msg":"My message","time":"2012-02-08T22:56:53.856Z","v":0}
{"name":"myservice","pid":123,"hostname":"example.com","level":50,"msg":"My message","time":"2012-02-08T22:56:54.856Z","v":0}
{"name":"myservice","pid":123,"hostname":"example.com","level":55,"msg":"My message","time":"2012-02-08T22:56:55.856Z","v":0}
{"name":"myservice","pid":123,"hostname":"example.com","level":60,"msg":"My message","time":"2012-02-08T22:56:56.856Z","v":0}
# extra fields
{"name":"myservice","pid":123,"hostname":"example.com","level":30,"one":"short","msg":"My message","time":"2012-02-08T22:56:52.856Z","v":0}
{"name":"myservice","pid":123,"hostname":"example.com","level":30,"two":"short with space","msg":"My message","time":"2012-02-08T22:56:52.856Z","v":0}
{"name":"myservice","pid":123,"hostname":"example.com","level":30,"three":"multi\nline","msg":"My message","time":"2012-02-08T22:56:52.856Z","v":0}
{"name":"myservice","pid":123,"hostname":"example.com","level":30,"four":"over 50 chars long long long long long long long long long","msg":"My message","time":"2012-02-08T22:56:52.856Z","v":0}
{"name":"myservice","pid":123,"hostname":"example.com","level":30,"five":{"a": "json object"},"msg":"My message","time":"2012-02-08T22:56:52.856Z","v":0}
{"name":"myservice","pid":123,"hostname":"example.com","level":30,"six":["a", "json", "array"],"msg":"My message","time":"2012-02-08T22:56:52.856Z","v":0}
# bogus
not a JSON line
{"hi": "there"}

2
test/corpus/bogus.log Normal file
View file

@ -0,0 +1,2 @@
not a JSON line
{"hi": "there"}

1
test/corpus/extrafield.log Normal file
View file

@ -0,0 +1 @@
{"name":"myservice","pid":123,"hostname":"example.com","level":30,"extra":"field","msg":"My message","time":"2012-02-08T22:56:52.856Z","v":0}

1
test/corpus/simple.log Normal file
View file

@ -0,0 +1 @@
{"name":"myservice","pid":123,"hostname":"example.com","level":30,"msg":"My message","time":"2012-02-08T22:56:52.856Z","v":0}

24
test/error-event.test.js Normal file
View file

@ -0,0 +1,24 @@
/*
* Copyright (c) 2012 Trent Mick. All rights reserved.
*
* Test emission and handling of 'error' event in a logger with a 'path'
* stream.
*/
var test = require('tap').test;
var Logger = require('../lib/bunyan');
test('error event on log write', function (t) {
LOG_PATH = '/this/path/is/bogus.log'
var log = new Logger({name: 'error-event', streams: [{path: LOG_PATH}]});
t.plan(5);
log.on('error', function (err, stream) {
t.ok(err, 'got err in error event: ' + err);
t.equal(err.code, 'ENOENT', 'error code is ENOENT');
t.ok(stream, 'got a stream argument');
t.equal(stream.path, LOG_PATH);
t.equal(stream.type, 'file');
t.end();
});
log.info('info log message');
});

32
tools/cutarelease.py
View file

@ -13,7 +13,7 @@ Conventions:
- XXX
"""
__version_info__ = (1, 0, 6)
__version_info__ = (1, 0, 7)
__version__ = '.'.join(map(str, __version_info__))
import sys
@ -213,12 +213,23 @@ def cutarelease(project_name, version_files, dry_run=False):
ver_content = ver_content.replace(marker,
'"version": "%s"' % next_version)
elif ver_file_type == "javascript":
marker = 'var VERSION = "%s";' % version
if marker not in ver_content:
raise Error("couldn't find `%s' version marker in `%s' "
"content: can't prep for subsequent dev" % (marker, ver_file))
ver_content = ver_content.replace(marker,
'var VERSION = "%s";' % next_version)
candidates = [
("single", "var VERSION = '%s';" % version),
("double", 'var VERSION = "%s";' % version),
]
for quote_type, marker in candidates:
if marker in ver_content:
break
else:
raise Error("couldn't find any candidate version marker in "
"`%s' content: can't prep for subsequent dev: %r"
% (ver_file, candidates))
if quote_type == "single":
ver_content = ver_content.replace(marker,
"var VERSION = '%s';" % next_version)
else:
ver_content = ver_content.replace(marker,
'var VERSION = "%s";' % next_version)
elif ver_file_type == "python":
marker = "__version_info__ = %r" % (version_info,)
if marker not in ver_content:
@ -299,7 +310,8 @@ def _parse_version_file(version_file):
Supported version file types (i.e. types of files from which we know
how to parse the version string/number -- often by some convention):
- json: use the "version" key
- javascript: look for a `var VERSION = "1.2.3";`
- javascript: look for a `var VERSION = "1.2.3";` or
`var VERSION = '1.2.3';`
- python: Python script/module with `__version_info__ = (1, 2, 3)`
- version: a VERSION.txt or VERSION file where the whole contents are
the version string
@ -353,8 +365,8 @@ def _parse_version_file(version_file):
m = re.search(r'^__version_info__ = (.*?)$', content, re.M)
version_info = eval(m.group(1))
elif version_file_type == "javascript":
m = re.search(r'^var VERSION = "(.*?)";$', content, re.M)
version_info = _version_info_from_version(m.group(1))
m = re.search(r'^var VERSION = (\'|")(.*?)\1;$', content, re.M)
version_info = _version_info_from_version(m.group(2))
elif version_file_type == "version":
version_info = _version_info_from_version(content.strip())
else: