- Notifications
You must be signed in to change notification settings - Fork519
a simple and fast JSON logging module for node.js services
License
trentm/node-bunyan
Folders and files
Name | Name | Last commit message | Last commit date | |
---|---|---|---|---|
Repository files navigation
Bunyan isa simple and fast JSON logging library for node.js services:
varbunyan=require('bunyan');varlog=bunyan.createLogger({name:"myapp"});log.info("hi");
andabunyan
CLI tool for nicely viewing those logs:
Manifesto: Server logs should be structured. JSON's a good format. Let's dothat. A log record is one line ofJSON.stringify
'd output. Let's alsospecify some common names for the requisite and common fields for a logrecord (see below).
- Current Status
- Installation
- Features
- Introduction
- Levels
- Log Record Fields
- Streams
- Runtime log snooping via DTrace
- Runtime environments
- Versioning
- License
- See Also
Stable. I do my best to follow semver: i.e. you should only need to worryabout code breaking for amajor version bump. Bunyan currently supports node0.10 and greater. Follow@trentmick for updates to Bunyan.
There is an email discussion listbunyan-logging@googlegroups.com,alsoas a forum in thebrowser.
Active branches:
- "1.x" is for 1.x maintenance work, if any. 1.x releases are still "latest" innpm.
- "master" is currently for coming Bunyan 2.x work. For now, 2.x releases arepublished to npm with the "beta" tag, meaning that
npm install bunyan
isstill 1.x for now. To install 2.x usenpm install bunyan@2
ornpm install bunyan@beta
.
npm install bunyan
Tip: Thebunyan
CLI tool is written to be compatible (within reason) withall versions of Bunyan logs. Therefore you might want tonpm install -g bunyan
to get the bunyan CLI on your PATH, then use local bunyan installs fornode.js library usage of bunyan in your apps.
Tip: Installing without optional dependencies can dramatically reducebunyan's install size.dtrace-provider is used for dtrace features,mv is used for RotatingFileStream, andmoment is used for local time.If you don't need these features, consider installing with the--no-optional
flag.
- elegantlog method API
- extensiblestreams system for controlling where log recordsgo (to a stream, to a file,log file rotation,etc.)
bunyan
CLI for pretty-printing and filtering of Bunyan logs- simple include of log call source location (file, line, function) with
src: true
- lightweight specialization of Logger instances with
log.child
- custom rendering of logged objects with"serializers"
- Runtime log snooping via DTrace support
- Support for a fewruntime environments: Node.js,Browserify,Webpack,NW.js.
Like most logging libraries you create a Logger instance and call methodsnamed after the logging levels:
// hi.jsvarbunyan=require('bunyan');varlog=bunyan.createLogger({name:'myapp'});log.info('hi');log.warn({lang:'fr'},'au revoir');
All loggers must provide a "name". This is somewhat akin to the log4j logger"name", but Bunyan doesn't do hierarchical logger names.
Bunyan log records are JSON. A few fields are added automatically:"pid", "hostname", "time" and "v".
$ node hi.js{"name":"myapp","hostname":"banana.local","pid":40161,"level":30,"msg":"hi","time":"2013-01-04T18:46:23.851Z","v":0}{"name":"myapp","hostname":"banana.local","pid":40161,"level":40,"lang":"fr","msg":"au revoir","time":"2013-01-04T18:46:23.853Z","v":0}
varbunyan=require('bunyan');varlog=bunyan.createLogger({name:<string>, // Required level:<levelnameornumber>, // Optional, see "Levels" section stream:<node.jsstream>, // Optional, see "Streams" section streams: [<bunyanstreams>, ...], // Optional, see "Streams" section serializers:<serializersmapping>, // Optional, see "Serializers" section src:<boolean>, // Optional, see "src" section // Any other fields are added to all log records as is. foo: 'bar', ...});
The example above shows two different ways to calllog.info(...)
. Thefull API is:
log.info();// Returns a boolean: is the "info" level enabled?// This is equivalent to `log.isInfoEnabled()` or// `log.isEnabledFor(INFO)` in log4j.log.info('hi');// Log a simple string message (or number).log.info('hi %s',bob,anotherVar);// Uses `util.format` for msg formatting.log.info({foo:'bar'},'hi');// The first field can optionally be a "fields" object, which// is merged into the log record.log.info(err);// Special case to log an `Error` instance to the record.// This adds an "err" field with exception details// (including the stack) and sets "msg" to the exception// message.log.info(err,'more on this: %s',more);// ... or you can specify the "msg".log.info({foo:'bar',err:err},'some msg about this error');// To pass in an Error *and* other fields, use the `err`// field name for the Error instance **and ensure your logger// has a `err` serializer.** One way to ensure the latter is:// var log = bunyan.createLogger({// ...,// serializers: bunyan.stdSerializers// });// See the "Serializers" section below for details.
Note that this impliesyou cannot blindly pass any object as the firstargument to log it because that object might include fields that collide withBunyan'score record fields. In other words,log.info(mywidget)
may not yield what you expect. Instead of a stringrepresentation ofmywidget
that other logging libraries may give you, Bunyanwill try to JSON-ify your object. It is a Bunyan best practice to always give afield name to included objects, e.g.:
log.info({widget:mywidget}, ...)
This will dove-tail withBunyan serializer support, discussedlater.
The same goes for all of Bunyan's log levels:log.trace
,log.debug
,log.info
,log.warn
,log.error
, andlog.fatal
. See thelevelssection below for details and suggestions.
Bunyan log output is a stream of JSON objects. This is great for processing,but not for reading directly. Abunyan
tool is providedforpretty-printing bunyan logs and forfiltering (e.g.| bunyan -c 'this.foo == "bar"'
). Using our example above:
$ node hi.js| ./node_modules/.bin/bunyan[2013-01-04T19:01:18.241Z] INFO: myapp/40208 on banana.local: hi[2013-01-04T19:01:18.242Z] WARN: myapp/40208 on banana.local: au revoir (lang=fr)
See the screenshot above for an example of the default coloring of renderedlog output. That example also shows the nice formatting automatically done forsome well-known log record fields (e.g.req
is formatted like an HTTP request,res
like an HTTP response,err
like an error stack trace).
One interesting feature isfiltering of log content, which can be usefulfor digging through large log files or for analysis. We can filter onlyrecords above a certain level:
$ node hi.js| bunyan -l warn[2013-01-04T19:08:37.182Z] WARN: myapp/40353 on banana.local: au revoir (lang=fr)
Or filter on the JSON fields in the records (e.g. only showing the Frenchrecords in our contrived example):
$ node hi.js| bunyan -c'this.lang == "fr"'[2013-01-04T19:08:26.411Z] WARN: myapp/40342 on banana.local: au revoir (lang=fr)
Seebunyan --help
for other facilities.
By default, log output is to stdout and at the "info" level. Explicitly thatlooks like:
varlog=bunyan.createLogger({name:'myapp',stream:process.stdout,level:'info'});
That is an abbreviated form for a single stream.You can define multiplestreams at different levels.
varlog=bunyan.createLogger({name:'myapp',streams:[{level:'info',stream:process.stdout// log INFO and above to stdout},{level:'error',path:'/var/tmp/myapp-error.log'// log ERROR and above to a file}]});
More on streams in theStreams section below.
Bunyan has a concept of a child logger tospecialize a logger for asub-component of your application, i.e. to create a new logger withadditional bound fields that will be included in its log records. A childlogger is created withlog.child(...)
.
In the following example, logging on a "Wuzzle" instance'sthis.log
willbe exactly as on the parent logger with the addition of thewidget_type
field:
varbunyan=require('bunyan');varlog=bunyan.createLogger({name:'myapp'});functionWuzzle(options){this.log=options.log.child({widget_type:'wuzzle'});this.log.info('creating a wuzzle')}Wuzzle.prototype.woos=function(){this.log.warn('This wuzzle is woosey.')}log.info('start');varwuzzle=newWuzzle({log:log});wuzzle.woos();log.info('done');
Running that looks like (raw):
$ node myapp.js{"name":"myapp","hostname":"myhost","pid":34572,"level":30,"msg":"start","time":"2013-01-04T07:47:25.814Z","v":0}{"name":"myapp","hostname":"myhost","pid":34572,"widget_type":"wuzzle","level":30,"msg":"creating a wuzzle","time":"2013-01-04T07:47:25.815Z","v":0}{"name":"myapp","hostname":"myhost","pid":34572,"widget_type":"wuzzle","level":40,"msg":"This wuzzle is woosey.","time":"2013-01-04T07:47:25.815Z","v":0}{"name":"myapp","hostname":"myhost","pid":34572,"level":30,"msg":"done","time":"2013-01-04T07:47:25.816Z","v":0}
And with thebunyan
CLI (using the "short" output mode):
$ node myapp.js| bunyan -o short07:46:42.707Z INFO myapp: start07:46:42.709Z INFO myapp: creating a wuzzle (widget_type=wuzzle)07:46:42.709Z WARN myapp: This wuzzle is woosey. (widget_type=wuzzle)07:46:42.709Z INFO myapp:done
A more practical example is in thenode-restify web framework.Restify uses Bunyan for its logging. One feature of its integration, is thatifserver.use(restify.requestLogger())
is used, each restify request handlerincludes areq.log
logger that is:
log.child({req_id:<uniquerequestid>},true)
Apps using restify can then usereq.log
and have all such log recordsinclude the unique request id (as "req_id"). Handy.
Bunyan has a concept of"serializer" functions to produce a JSON-able objectfrom a JavaScript object, so you can easily do the following:
log.info({req:<requestobject>},'something about handling this request');
and have thereq
entry in the log record be just a reasonable subset of<request object>
fields (or computed data about those fields).
A logger instance can have aserializers
mapping of log record field name("req" in this example) to a serializer function. When creating the log record,Bunyan will call the serializer function fortop-level fields of that name. Anexample:
functionreqSerializer(req){return{method:req.method,url:req.url,headers:req.headers};}varlog=bunyan.createLogger({name:'myapp',serializers:{req:reqSerializer}});
Typically serializers are added to a logger at creation time via:
varlog=bunyan.createLogger({name:'myapp',serializers:{foo:functionfooSerializer(foo){ ...}, ...}});// orvarlog=bunyan.createLogger({name:'myapp',serializers:bunyan.stdSerializers});
Serializers can also be added after creation via<logger>.addSerializers(...)
,e.g.:
varlog=bunyan.createLogger({name:'myapp'});log.addSerializers({req:reqSerializer});
A serializer function is passed unprotected objects that are passed to thelog.info
,log.debug
, etc. call. This means a poorly written serializerfunction can cause side-effects. Logging shouldn't do that. Here are a fewrules and best practices for serializer functions:
A serializer functionshould never throw. The bunyan librarydoesprotect somewhat from this: if the serializer throws an error, thenbunyan will (a) write an ugly message on stderr (along with the traceback),and (b) the field in the log record will be replaced with a short error message.For example:
bunyan: ERROR: Exception thrown from the "foo" Bunyan serializer. This should never happen. This is a bug in that serializer function.TypeError: Cannot read property 'not' of undefined at Object.fooSerializer [as foo] (/Users/trentm/tm/node-bunyan/bar.js:8:26) at /Users/trentm/tm/node-bunyan/lib/bunyan.js:873:50 at Array.forEach (native) at Logger._applySerializers (/Users/trentm/tm/node-bunyan/lib/bunyan.js:865:35) at mkRecord (/Users/trentm/tm/node-bunyan/lib/bunyan.js:978:17) at Logger.info (/Users/trentm/tm/node-bunyan/lib/bunyan.js:1044:19) at Object.<anonymous> (/Users/trentm/tm/node-bunyan/bar.js:13:5) at Module._compile (module.js:409:26) at Object.Module._extensions..js (module.js:416:10) at Module.load (module.js:343:32){"name":"bar","hostname":"danger0.local","pid":47411,"level":30,"foo":"(Error in Bunyan log \"foo\" serializer broke field. See stderr for details.)","msg":"one","time":"2017-03-08T02:53:51.173Z","v":0}
A serializer functionshould never mutate the given object. Doing so willchange the object in your application.
A serializer functionshould be defensive. In my experience, it is common toset a serializer in an app, say for field name "foo", and then accidentallyhave a log line that passes a "foo" that is undefined, or null, or of someunexpected type. A good start at defensiveness is to start with this:
functionfooSerializer(foo){// Guard against foo be null/undefined. Check that expected fields// are defined.if(!foo||!foo.bar)returnfoo;varobj={// Create the object to be logged.bar:foo.bar}returnobj;};
Bunyan includes a small set of "standard serializers", exported asbunyan.stdSerializers
. Their use is completely optional. An example usingall of them:
varlog=bunyan.createLogger({name:'myapp',serializers:bunyan.stdSerializers});
or particular ones:
varlog=bunyan.createLogger({name:'myapp',serializers:{err:bunyan.stdSerializers.err}});
Standard serializers are:
Field | Description |
---|---|
err | Used for serializing JavaScript error objects, including traversing an error's cause chain for error objects with a.cause() -- e.g. as fromverror. |
req | Common fields from a node.js HTTP request object. |
res | Common fields from a node.js HTTP response object. |
Note that thereq
andres
serializers intentionally do not include therequest/responsebody, as that can be prohibitively large. If helpful, therestify framework's audit logger pluginhas its own req/res serializers that include more information (optionallyincluding the body).
Thesource file, line and function of the log call site can be added tolog records by using thesrc: true
config option:
varlog=bunyan.createLogger({src:true, ...});
This adds the call source info with the 'src' field, like this:
{"name":"src-example","hostname":"banana.local","pid":123,"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 optionin production.
The log levels in bunyan are as follows. The level descriptions are bestpracticeopinions of the author.
- "fatal" (60): The service/app is going to stop or become unusable now.An operator should definitely look into this soon.
- "error" (50): Fatal for a particular request, but the service/app continuesservicing other requests. An operator should look at this soon(ish).
- "warn" (40): A note on something that should probably be looked at by anoperator eventually.
- "info" (30): Detail on regular operation.
- "debug" (20): Anything else, i.e. too verbose to be included in "info" level.
- "trace" (10): Logging from external libraries used by your app orverydetailed application logging.
Setting a logger instance (or one of its streams) to a particular level impliesthat all log recordsat that level and above are logged. E.g. a logger set tolevel "info" will log records at level info and above (warn, error, fatal).
While using log levelnames is preferred, the actual level values are integersinternally (10 for "trace", ..., 60 for "fatal"). Constants are defined forthe levels:bunyan.TRACE
...bunyan.FATAL
. The lowercase level names arealiases supported in the API, e.g.log.level("info")
. There is one exception:DTrace integration uses the level names. The fired DTrace probes are named'bunyan-$levelName'.
Here is the API for querying and changing levels on an existing logger.Recall that a logger instance has an array of output "streams":
log.level()->INFO// gets current level (lowest level of all streams)log.level(INFO)// set all streams to level INFOlog.level("info")// set all streams to level INFOlog.levels()->[DEBUG,INFO]// get array of levels of all streamslog.levels(0)->DEBUG// get level of stream at index 0log.levels("foo")// get level of stream with name "foo"log.levels(0,INFO)// set level of stream 0 to INFOlog.levels(0,"info")// can use "info" et al aliaseslog.levels("foo",WARN)// set stream named "foo" to WARN
Trent's biased suggestions for server apps: Use "debug" sparingly. Informationthat will be useful to debug errorspost mortem should usually be included in"info" messages if it's generally relevant or else with the corresponding"error" event. Don't rely on spewing mostly irrelevant debug messages all thetime and sifting through them when an error occurs.
Trent's biased suggestions for node.js libraries: IMHO, libraries should onlyever log attrace
-level. Fine control over log output should be up to theapp using a library. Having a library that spews log output at higher levelsgets in the way of a clear story in theapp logs.
This section will describerules for the Bunyan log format: field names,field meanings, required fields, etc. However, a Bunyan library doesn'tstrictly enforce all these rules while records are being emitted. For example,Bunyan will add atime
field with the correct format to your log records,but you can specify your own. It is the caller's responsibility to specifythe appropriate format.
The reason for the above leniency is because IMO logging a message shouldnever break your app. This leads to this rule of logging:a thrownexception fromlog.info(...)
or equivalent (other than for calling with theincorrect signature) is always a bug in Bunyan.
A typical Bunyan log record looks like this:
{"name":"myserver","hostname":"banana.local","pid":123,"req":{"method":"GET","url":"/path?q=1#anchor","headers":{"x-hi":"Mom","connection":"close"}},"level":3,"msg":"start request","time":"2012-02-03T19:02:46.178Z","v":0}
Pretty-printed:
{"name":"myserver","hostname":"banana.local","pid":123,"req":{"method":"GET","url":"/path?q=1#anchor","headers":{"x-hi":"Mom","connection":"close"},"remoteAddress":"120.0.0.1","remotePort":51244},"level":3,"msg":"start request","time":"2012-02-03T19:02:57.534Z","v":0}
v
: Required. Integer. Added by Bunyan. Cannot be overridden.This is the Bunyan log format version (require('bunyan').LOG_VERSION
).The log version is a single integer.0
is until I release a version"1.0.0" of node-bunyan. Thereafter, starting with1
, this will beincremented if there is any backward incompatible change to the log recordformat. Details will be in "CHANGES.md" (the change log).level
: Required. Integer. Added by Bunyan. Cannot be overridden.See the "Levels" section.name
: Required. String. Provided at Logger creation.You must specify a name for your logger when creating it. Typically thisis the name of the service/app using Bunyan for logging.hostname
: Required. String. Provided or determined at Logger creation.You can specify your hostname at Logger creation or it will be retrievedviaos.hostname()
.pid
: Required. Integer. Filled in automatically at Logger creation.time
: Required. String. Added by Bunyan. Can be overridden.The date and time of the event inISO 8601Extended Format format and in UTC,as fromDate.toISOString()
.msg
: Required. String.Everylog.debug(...)
et al call must provide a log message.src
: Optional. Object giving log call source info. This is addedautomatically by Bunyan if the "src: true" config option is given to theLogger. Never use in production as this is really slow.
Go ahead and add more fields, and nested ones are fine (and recommended) aswell. This is why we're using JSON. Some suggestions and best practicesfollow (feedback from actual users welcome).
err
: Object. A caught JS exception. Log that thing withlog.info(err)
to get:..."err":{"message":"boom","name":"TypeError","stack":"TypeError: boom\n at Object.<anonymous> ..."},"msg":"boom",...
Or use the
bunyan.stdSerializers.err
serializer in your Logger anddo thislog.error({err: err}, "oops")
. See "examples/err.js".req_id
: String. A request identifier. Including this field in all loggingtied to handling a particular request to your server is strongly suggested.This allows post analysis of logs to easily collate all related loggingfor a request. This really shines when you have a SOA with multiple servicesand you carry a single request ID from the top API down through all APIs(asnode-restify facilitateswith its 'Request-Id' header).req
: An HTTP server request. Bunyan providesbunyan.stdSerializers.req
to serialize a request with a suggested set of keys. Example:{"method":"GET","url":"/path?q=1#anchor","headers":{"x-hi":"Mom","connection":"close"},"remoteAddress":"120.0.0.1","remotePort":51244}
res
: An HTTP server response. Bunyan providesbunyan.stdSerializers.res
to serialize a response with a suggested set of keys. Example:{"statusCode":200,"header":"HTTP/1.1 200 OK\r\nContent-Type: text/plain\r\nConnection: keep-alive\r\nTransfer-Encoding: chunked\r\n\r\n"}
req.username
: Authenticated user (or for a 401, the user attempting toauth).- Some mechanism to calculate response latency. "restify" users will havean "X-Response-Time" header. A
latency
custom field would be fine. req.body
: If you know that request bodies are small (common in APIs,for example), then logging the request body is good.
A "stream" is Bunyan's name for where it outputs log messages (the equivalentto a log4j Appender). Ultimately Bunyan uses aWritable Streaminterface, but there are some additional attributes used to create andmanage the stream. A Bunyan Logger instance has one or more streams.In general streams are specified with the "streams" option:
varbunyan=require('bunyan');varlog=bunyan.createLogger({name:"foo",streams:[{stream:process.stderr,level:"debug"}, ...]});
For convenience, if there is only one stream, it can be specified with the"stream" and "level" options (internally converted to aLogger.streams
).
varlog=bunyan.createLogger({name:"foo",stream:process.stderr,level:"debug"});
Note that "file" streams do not support this shortcut (partly for historicalreasons and partly to not make it difficult to add a literal "path" fieldon log records).
If neither "streams" nor "stream" are specified, the default is a stream oftype "stream" emitting toprocess.stdout
at the "info" level.
After a bunyan instance has been initialized, you may add additional streams bycalling theaddStream
function.
varbunyan=require('bunyan');varlog=bunyan.createLogger('myLogger');log.addStream({name:"myNewStream",stream:process.stderr,level:"debug"});
A Bunyan logger instance can be made to re-emit "error" events from itsstreams. Bunyan does so by default fortype === "file"
streams, so you can do this:
varlog=bunyan.createLogger({name:'mylog',streams:[{path:LOG_PATH}]});log.on('error',function(err,stream){// Handle stream write or create error here.});
As of bunyan@1.7.0, thereemitErrorEvents
field can be used when adding astream to control whether "error" events are re-emitted on the Logger. Forexample:
var EventEmitter = require('events').EventEmitter;var util = require('util');function MyFlakyStream() {}util.inherits(MyFlakyStream, EventEmitter);MyFlakyStream.prototype.write = function (rec) { this.emit('error', new Error('boom'));}var log = bunyan.createLogger({ name: 'this-is-flaky', streams: [ { type: 'raw', stream: new MyFlakyStream(), reemitErrorEvents: true } ]});log.info('hi there');
The behaviour is as follows:
reemitErrorEvents
not specified:file
streams will re-emit error eventson the Logger instance.reemitErrorEvents: true
: error events will be re-emitted on the Loggerfor any stream with a.on()
function -- which includes file streams,process.stdout/stderr, and any object that inherits from EventEmitter.reemitErrorEvents: false
: error events will not be re-emitted for anystreams.
Note: "error" events arenot related to log records at the "error" levelas produced bylog.error(...)
. Seethe node.js docs on errorevents for details.
Atype === 'stream'
is a plain ol' node.jsWritableStream. A"stream" (the writable stream) field is required. E.g.:process.stdout
,process.stderr
.
varlog=bunyan.createLogger({name:'foo',streams:[{stream:process.stderr// `type: 'stream'` is implied}]});
Field | Required? | Default | Description |
---|---|---|---|
stream | Yes | - | A "Writable Stream", e.g. a std handle or an open file write stream. |
type | No | n/a | `type == 'stream'` is implied if the `stream` field is given. |
level | No | info | The level to which logging to this stream is enabled. If notspecified it defaults to "info". If specified this can be one of thelevel strings ("trace", "debug", ...) or constants (`bunyan.TRACE`,`bunyan.DEBUG`, ...). This serves as a severity threshold for that streamso logs of greater severity will also pass through (i.e. If level="warn",error and fatal will also pass through this stream). |
name | No | - | A name for this stream. This may be useful for usage of `log.level(NAME,LEVEL)`. See the [Levels section](#levels) for details. A stream "name" isn'tused for anything else. |
Atype === 'file'
stream requires a "path" field. Bunyan will open thisfile for appending. E.g.:
varlog=bunyan.createLogger({name:'foo',streams:[{path:'/var/log/foo.log',// `type: 'file'` is implied}]});
Field | Required? | Default | Description |
---|---|---|---|
path | Yes | - | A file path to which to log. |
type | No | n/a | `type == 'file'` is implied if the `path` field is given. |
level | No | info | The level to which logging to this stream is enabled. If notspecified it defaults to "info". If specified this can be one of thelevel strings ("trace", "debug", ...) or constants (`bunyan.TRACE`,`bunyan.DEBUG`, ...). This serves as a severity threshold for thatstream so logs of greater severity will also pass through (i.e. Iflevel="warn", error and fatal will also pass through this stream). |
name | No | - | A name for this stream. This may be useful for usage of `log.level(NAME,LEVEL)`. See the [Levels section](#levels) for details. A stream "name" isn'tused for anything else. |
WARNING on node 0.8 usage: Users of Bunyan'srotating-file
should (a) beusing at least bunyan 0.23.1 (with the fix forthisissue), and (b) should use atleast node 0.10 (node 0.8 does not support theunref()
method onsetTimeout(...)
needed for the mentioned fix). The symptom is that processtermination will hang for up to a full rotation period.
WARNING onclusterusage: Using Bunyan'srotating-file
stream with node.js's "cluster" modulecan result in unexpected file rotation. You must not have multiple processesin the cluster logging to the same file path. In other words, you must havea separate log file path for the master and each worker in the cluster.Alternatively, consider using a system file rotation facility such aslogrotate
on Linux orlogadm
on SmartOS/Illumos. Seethis comment on issue #117for details.
Atype === 'rotating-file'
is a file stream that handles file automaticrotation.
varlog=bunyan.createLogger({name:'foo',streams:[{type:'rotating-file',path:'/var/log/foo.log',period:'1d',// daily rotationcount:3// keep 3 back copies}]});
This will rotate '/var/log/foo.log' every day (at midnight) to:
/var/log/foo.log.0# yesterday/var/log/foo.log.1# 1 day ago/var/log/foo.log.2# 2 days ago
Currently, there is no support for providing a template for the rotatedfiles, or for rotating when the log reaches a threshold size.
Field | Required? | Default | Description |
---|---|---|---|
type | Yes | - | "rotating-file" |
path | Yes | - | A file path to which to log. Rotated files will be "$path.0","$path.1", ... |
period | No | 1d | The period at which to rotate. This is a string of the format"$number$scope" where "$scope" is one of "ms" (milliseconds -- only useful fortesting), "h" (hours), "d" (days), "w" (weeks), "m" (months), "y" (years). Orone of the following names can be used "hourly" (means 1h), "daily" (1d),"weekly" (1w), "monthly" (1m), "yearly" (1y). Rotation is done at the start ofthe scope: top of the hour (h), midnight (d), start of Sunday (w), start of the1st of the month (m), start of Jan 1st (y). |
count | No | 10 | The number of rotated files to keep. |
level | No | info | The level at which logging to this stream is enabled. If notspecified it defaults to "info". If specified this can be one of thelevel strings ("trace", "debug", ...) or constants (`bunyan.TRACE`,`bunyan.DEBUG`, ...). |
name | No | - | A name for this stream. This may be useful for usage of `log.level(NAME,LEVEL)`. See the [Levels section](#levels) for details. A stream "name" isn'tused for anything else. |
Note on log rotation: Often you may be using external log rotation utilitieslikelogrotate
on Linux orlogadm
on SmartOS/Illumos. In those cases, unlessyou are ensuring "copy and truncate" semantics (viacopytruncate
withlogrotate or-c
with logadm) then the fd for your 'file' stream will change.You can tell bunyan to reopen the file stream with code like this in yourapp:
varlog=bunyan.createLogger(...);...process.on('SIGUSR2',function(){log.reopenFileStreams();});
where you'd configure your log rotation to send SIGUSR2 (or some other signal)to your process. Any other mechanism to signal your app to runlog.reopenFileStreams()
would work as well.
raw
: Similar to a "stream" writable stream, except that the write methodis given raw log recordObjects instead of a JSON-stringified string.This can be useful for hooking on further processing to all Bunyan logging:pushing to an external service, a RingBuffer (see below), etc.
Bunyan comes with a special stream called a RingBuffer which keeps the last Nrecords in memory and doesnot write the data anywhere else. One commonstrategy is to log 'info' and higher to a normal log file but log all records(including 'trace') to a ringbuffer that you can access via a debugger, or yourown HTTP interface, or a post-mortem facility like MDB or node-panic.
To use a RingBuffer:
/* Create a ring buffer that stores the last 100 records. */varbunyan=require('bunyan');varringbuffer=newbunyan.RingBuffer({limit:100});varlog=bunyan.createLogger({name:'foo',streams:[{level:'info',stream:process.stdout},{level:'trace',type:'raw',// use 'raw' to get raw log record objectsstream:ringbuffer}]});log.info('hello world');console.log(ringbuffer.records);
This example emits:
[{name:'foo',hostname:'912d2b29',pid:50346,level:30,msg:'hello world',time:'2012-06-19T21:34:19.906Z',v:0}]
See theuser-maintained list in the Bunyanwiki.
On systems that support DTrace (e.g., illumos derivatives like SmartOS andOmniOS, FreeBSD, Mac), Bunyan will create a DTrace provider (bunyan
) thatmakes available the following probes:
log-tracelog-debuglog-infolog-warnlog-errorlog-fatal
Each of these probes has a single argument: the string that would bewritten to the log. Note that when a probe is enabled, it willfire whenever the corresponding function is called, even if the level ofthe log message is less than that of any stream.
Trace all log messages coming from any Bunyan module on the system.(The-x strsize=4k
is to raise dtrace's default 256 byte buffer sizebecause log messages are longer than typical dtrace probes.)
dtrace -x strsize=4k -qn'bunyan*:::log-*{printf("%d: %s: %s", pid, probefunc, copyinstr(arg0))}'
Trace all log messages coming from the "wuzzle" component:
dtrace -x strsize=4k -qn'bunyan*:::log-*/strstr(this->str = copyinstr(arg0), "\"component\":\"wuzzle\"") != NULL/{printf("%s", this->str)}'
Aggregate debug messages from process 1234, by message:
dtrace -x strsize=4k -n'bunyan1234:::log-debug{@[copyinstr(arg0)] = count()}'
Have the bunyan CLI pretty-print the traced logs:
dtrace -x strsize=4k -qn'bunyan1234:::log-*{printf("%s", copyinstr(arg0))}'| bunyan
A convenience handle has been made for this:
bunyan -p 1234
On systems that support thejstack
actionvia a node.js helper, get a stack backtrace for any debug message thatincludes the string "danger!":
dtrace -x strsize=4k -qn'log-debug/strstr(copyinstr(arg0), "danger!") != NULL/{printf("\n%s", copyinstr(arg0)); jstack()}'
Output of the above might be:
{"name":"foo","hostname":"763bf293-d65c-42d5-872b-4abe25d5c4c7.local","pid":12747,"level":20,"msg":"danger!","time":"2012-10-30T18:28:57.115Z","v":0} node`0x87e2010 DTraceProviderBindings.node`usdt_fire_probe+0x32 DTraceProviderBindings.node`_ZN4node11DTraceProbe5_fireEN2v85LocalINS1_5ValueEEE+0x32d DTraceProviderBindings.node`_ZN4node11DTraceProbe4FireERKN2v89ArgumentsE+0x77 << internal code >> (anon) as (anon) at /root/node-bunyan/lib/bunyan.js position 40484 << adaptor >> (anon) as doit at /root/my-prog.js position 360 (anon) as list.ontimeout at timers.js position 4960 << adaptor >> << internal >> << entry >> node`_ZN2v88internalL6InvokeEbNS0_6HandleINS0_10JSFunctionEEENS1_INS0_6ObjectEEEiPS5_Pb+0x101 node`_ZN2v88internal9Execution4CallENS0_6HandleINS0_6ObjectEEES4_iPS4_Pbb+0xcb node`_ZN2v88Function4CallENS_6HandleINS_6ObjectEEEiPNS1_INS_5ValueEEE+0xf0 node`_ZN4node12MakeCallbackEN2v86HandleINS0_6ObjectEEENS1_INS0_8FunctionEEEiPNS1_INS0_5ValueEEE+0x11f node`_ZN4node12MakeCallbackEN2v86HandleINS0_6ObjectEEENS1_INS0_6StringEEEiPNS1_INS0_5ValueEEE+0x66 node`_ZN4node9TimerWrap9OnTimeoutEP10uv_timer_si+0x63 node`uv__run_timers+0x66 node`uv__run+0x1b node`uv_run+0x17 node`_ZN4node5StartEiPPc+0x1d0 node`main+0x1b node`_start+0x83 node`0x87e2010 DTraceProviderBindings.node`usdt_fire_probe+0x32 DTraceProviderBindings.node`_ZN4node11DTraceProbe5_fireEN2v85LocalINS1_5ValueEEE+0x32d DTraceProviderBindings.node`_ZN4node11DTraceProbe4FireERKN2v89ArgumentsE+0x77 << internal code >> (anon) as (anon) at /root/node-bunyan/lib/bunyan.js position 40484 << adaptor >> (anon) as doit at /root/my-prog.js position 360 (anon) as list.ontimeout at timers.js position 4960 << adaptor >> << internal >> << entry >> node`_ZN2v88internalL6InvokeEbNS0_6HandleINS0_10JSFunctionEEENS1_INS0_6ObjectEEEiPS5_Pb+0x101 node`_ZN2v88internal9Execution4CallENS0_6HandleINS0_6ObjectEEES4_iPS4_Pbb+0xcb node`_ZN2v88Function4CallENS_6HandleINS_6ObjectEEEiPNS1_INS_5ValueEEE+0xf0 node`_ZN4node12MakeCallbackEN2v86HandleINS0_6ObjectEEENS1_INS0_8FunctionEEEiPNS1_INS0_5ValueEEE+0x11f node`_ZN4node12MakeCallbackEN2v86HandleINS0_6ObjectEEENS1_INS0_6StringEEEiPNS1_INS0_5ValueEEE+0x66 node`_ZN4node9TimerWrap9OnTimeoutEP10uv_timer_si+0x63 node`uv__run_timers+0x66 node`uv__run+0x1b node`uv_run+0x17 node`_ZN4node5StartEiPPc+0x1d0 node`main+0x1b node`_start+0x83
Node-bunyan supports running in a few runtime environments:
- Node.js
- Browserify: See theBrowserify section below.
- Webpack: See theWebpack section below.
- NW.js
Support for other runtime environments is welcome. If you have suggestions,fixes, or mentions that node-bunyan already works in some other JavaScriptruntime, please open anissueor a pull request.
The primary target is Node.js. It is the only environment in which Iregularly test. If you have suggestions for how to automate testing for otherenvironments, I'd appreciate feedback onthis automated testingissue.
As theBrowserify site says it "lets yourequire('modules')
in the browser by bundling up all of your dependencies."It is a build tool to run on your node.js script to bundle up your script andall its node.js dependencies into a single file that is runnable in thebrowser via:
<scriptsrc="play.browser.js"></script>
As of version 1.1.0, node-bunyan supports being run via Browserify. Thedefaultstream when running in the browser is one that emitsraw log records toconsole.log/info/warn/error
.
Here is a quick example showing you how you can get this working for yourscript.
Get browserify and bunyan installed in your module:
$ npm install browserify bunyan
An example script using Bunyan, "play.js":
varbunyan=require('bunyan');varlog=bunyan.createLogger({name:'play',level:'debug'});log.trace('this one does not emit');log.debug('hi on debug');// console.loglog.info('hi on info');// console.infolog.warn('hi on warn');// console.warnlog.error('hi on error');// console.error
Build this into a bundle to run in the browser, "play.browser.js":
$ ./node_modules/.bin/browserify play.js -o play.browser.js
Put that into an HTML file, "play.html":
<!DOCTYPE html><html><head><metacharset="utf-8"><scriptsrc="play.browser.js"></script></head><body><div>hi</div></body></html>
Open that in your browser and open your browser console:
$ open play.html
Here is what it looks like in Firefox's console:
For some, the raw log records might not be desired. To have a rendered log lineyou'll want to add your own stream, starting with something like this:
varbunyan=require('./lib/bunyan');functionMyRawStream(){}MyRawStream.prototype.write=function(rec){console.log('[%s] %s: %s',rec.time.toISOString(),bunyan.nameFromLevel[rec.level],rec.msg);}varlog=bunyan.createLogger({name:'play',streams:[{level:'info',stream:newMyRawStream(),type:'raw'}]});log.info('hi on info');
To include bunyan in your webpack bundle you need to tell webpack toignore the optional dependencies that are unavailable in browser environments.
Mark the following dependencies asexternals in your webpackconfiguration file to exclude them from the bundle:
module: { externals: ['dtrace-provider', 'fs', 'mv', 'os', 'source-map-support']}
All versions are<major>.<minor>.<patch>
which will be incremented forbreaking backward compat and major reworks, new features without breakingchange, and bug fixes, respectively. tl;dr:Semanticversioning.
MIT.
See theuser-maintained list of Bunyan-related software in the Bunyanwiki.
About
a simple and fast JSON logging module for node.js services