bunyan

What is bunyan?

The bunyan npm package is a simple and fast JSON logging library for node.js services. It provides a high-level abstraction around the process of logging and allows developers to create structured logs in JSON format. These logs are easy to read for humans and easy to parse for machines, making bunyan suitable for production debugging and monitoring.

What are bunyan's main functionalities?

Creating a Logger

This feature allows you to create a logger instance with a specified name. You can then use this instance to log messages at different levels, such as info, error, warn, etc.

const bunyan = require('bunyan');
const log = bunyan.createLogger({ name: 'myapp' });
log.info('Hello Bunyan');

Logging at Different Levels

Bunyan provides methods to log messages at various levels, which helps in filtering and categorizing logs based on their severity.

log.trace('This is a trace message');
log.debug('This is a debug message');
log.info('This is an info message');
log.warn('This is a warning message');
log.error('This is an error message');
log.fatal('This is a fatal message');

Adding Metadata to Logs

You can add additional metadata to your logs by passing an object as the first argument to any of the logging methods. This is useful for adding context to your logs.

log.info({user: 'john_doe'}, 'User logged in');

Stream Configuration

Bunyan allows you to configure multiple streams for your logs, directing them to different outputs, such as stdout or a file, and at different log levels.

const log = bunyan.createLogger({
  name: 'myapp',
  streams: [
    {
      level: 'info',
      stream: process.stdout
    },
    {
      level: 'error',
      path: '/var/log/myapp-error.log'
    }
  ]
});

Child Loggers

You can create child loggers from an existing logger instance. Child loggers inherit the streams and log level of the parent but can add additional metadata, which is useful for logging within specific components or modules.

const childLog = log.child({ component: 'mycomponent' });
childLog.info('Component initialized');

Other packages similar to bunyan

winston

Winston is a multi-transport async logging library for Node.js. Similar to bunyan, it supports multiple storage options for logs, such as files, databases, and third-party services. It differs in its support for custom transports, which allows for more flexibility in how logs are handled and stored.

pino

Pino is a very low-overhead Node.js logger, which focuses on performance. It provides similar JSON-based logging capabilities as bunyan but is designed to be faster in scenarios where logging performance is critical.

morgan

Morgan is an HTTP request logger middleware for Node.js, which is often used in Express.js applications. It differs from bunyan in that it's specifically tailored for logging HTTP requests and responses and is used as middleware in web applications rather than a general-purpose logging library.

log4js

Log4js is a logging framework for Node.js, which is inspired by the Java library log4j. It supports multiple appenders, categories, and layouts, making it a flexible choice for complex logging needs. It is more configurable than bunyan but may have a steeper learning curve due to its extensive features.

README

Bunyan -- a JSON Logger for node.js servers.

Server logs should be structured. JSON's a good format. Let's do that: a log record is one line of JSON.stringify'd output. Let's also specify some common names for the requisite and common fields for a log record (see below).

Also: log4j is way more than you need.

Current Status

Basic functionality there. Still a fair amount of planned work... most importantly the clarifying of required and suggested fields.

Currently supports node 0.4+, but I'll probably make the jump to node 0.6+ as a base soonish.

Usage

The usual. All loggers must provide a "service" name. This is somewhat akin to log4j logger "name", but Bunyan doesn't do hierarchical logger names.

$ cat hi.js
var Logger = require('bunyan');
var log = new Logger({service: "myapp"});
log.info("hi");

Log records are JSON. "hostname", "time" and "v" (the Bunyan log 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}

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 be added, including support for custom formats.

$ node hi.js | ./bin/bunyan  # CLI tool to filter/pretty-print JSON logs.
[2012-01-31T00:08:11.387Z] INFO: myapp on banana.local: hi

$ node hi.js | ./bin/bunyan -o json
{
  "service": "myapp",
  "hostname": "banana.local",
  "level": 2,
  "msg": "hi",
  "time": "2012-01-31T00:10:00.676Z",
  "v": 0
}

By default, log output is to stdout (stream) and at the "info" level. Explicitly that looks like:

var log = new Logger({service: "myapp", stream: process.stdout, 
  level: "info"});

That is an abbreviated form for a single stream. You can defined multiple streams at different levels.

var log = new Logger({
  service: "amon",
  streams: [
    {
      level: "info",
      stream: process.stdout, // log INFO and above to stdout
    },
    {
      level: "error",
      path: "tmp/error.log"   // log ERROR and above to a file
    }
  ]
});

A log.clone(...) 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.

var log = new Logger(...);

...

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.clone({component: "wuzzle"})});
wuzzle.woos();
log.info("done with the wuzzle")

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

Bunyan has a concept of "serializers" to produce a JSON-able object from a JavaScript object, so your can easily do the following:

log.info({req: <request object>}, "something about handling this request");

Association is by log record field name, "req" in this example, so this requires a registered serializer something like this:

function reqSerializer(req) {
  return {
    method: req.method,
    url: req.url,
    headers: req.headers
  }
}
var log = new Logger({
  ...
  serializers: {
    req: reqSerializer
  }
});

Or this:

var log = new Logger({
  ...
  serializers: {req: Logger.stdSerializers.req}
});

because Buyan includes a small set of standard serializers. To use all the standard serializers you can use:

var log = new Logger({
  ...
  serializers: Logger.stdSerializers
});

Note: Your own serializers should never throw, otherwise you'll get an 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.

Future

See "TODO.md", but basically:

• More std serializers. See TODO.md.

• Spec'ing and enforcing the fields (from dap's section in eng guide).

• Syslog support. Ring-buffer support for storing last N debug messages (or whatever) in memory to support debugability without too much log load.

• More bunyan output formats and filtering features.

• Think about a bunyan dashboard that supports organizing and viewing logs from multiple hosts and services.

Levels

• "fatal" (6): the service is going to stop or become unusable now
• "error" (5): fatal for a particular request, but the service continues servicing other requests
• "warn" (4): a note on something that should probably be looked at by an operator
• "info" (3): detail on regular operation
• "debug" (2): anything else, i.e. too verbose to be included in "info" level.
• "trace" (1): logging from external libraries used by your app

"debug" should be used sparingly. Information that will be useful to debug errors post 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 the time and sifting through them when an error occurs.

Integers are used for the actual level values (1 for "trace", ..., 6 for "fatal") and constants are defined for the (Logger.TRACE ... Logger.DEBUG). The lowercase level names are aliases supported in the API.

Log Record Fields

This section will describe rules for the Bunyan log format: field names, field meanings, required fields, etc. However, a Bunyan library doesn't strictly enforce all these rules while records are being emitted. For example, Bunyan will add a time field with the correct format to your log records, but you can specify your own. It is the caller's responsibility to specify the appropriate format.

The reason for the above leniency is because IMO logging a message should never break your app. This leads to this rule of logging: a thrown exception from log.info(...) or equivalent (other than for calling with the incorrect signature) is always a bug in Bunyan.

A typical Bunyan log record looks like this:

{"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-03T19:02:46.178Z","v":0}

Pretty-printed:

{
  "service": "myserver",
  "hostname": "banana.local",
  "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
}

Core fields:

• v: Required. Integer. Added by Bunion. Cannot be overriden. 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 with 1, this will be incremented if there is any backward incompatible change to the log record format. Details will be in "CHANGES.md" (the change log).
• level: Required. Integer. Added by Bunion. Cannot be overriden. See the "Levels" section.
• service: Required. String. Provided at Logger creation. You must specify a service name for your logger when creating it.
• hostname: Required. String. Provided or determined at Logger creation. You can specify your hostname at Logger creation or it will be retrieved vi os.hostname().
• time: Required. String. Added by Bunion. Can be overriden. The date and time of the event in ISO 8601 Extended Format format and in UTC, as from Date.toISOString().
• msg: Required. String. Every log.debug(...) et al call must provide a log message.

Go ahead and add more fields, and nest ones are fine (and recommended) as well. This is why we're using JSON. Some suggestions and best practices follow (feedback from actual users welcome).

Recommended/Best Practice Fields:

• err: Object. A caught JS exception. Log that thing with log.error({err: err}, "oops")! JS exceptions JSON.stringify quite nicely so you don't need to do anything else. See "examples/err.js".

• req_id: String. A request identifier. Including this field in all logging tied to handling a particular request to your server is strongly suggested. This allows post analysis of logs to easily collate all related logging for a request. This really shines when you have a SOA with multiple services and you carry a single request ID from the top API down through all APIs (as node-restify facilitates with its 'X-Request-Id' header).

• req: An HTTP server request. Bunyan provides Logger.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 provides Logger.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"
    }
  

Other fields to consider:

• req.username: Authenticated user (or for a 401, the user attempting to auth).
• Some mechanism to calculate response latency. "restify" users will have a "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.

Streams

A "stream" is Bunyan's name for an output for log messages. It expects a Writable Stream interface. See above for some examples of specifying streams. Supported streams are:

• A writable "stream". Often this is one of the std handles (process.stdout or process.stderr), but it can be anything you want supporting the node writable stream interface, e.g. fs.createWriteStream.
• A file. Will append to the given "path".

License

MIT.

Changelog

0.2.0

• Spec'ing core/recommended log record fields.
• Add LOG_VERSION to exports.
• Improvements to request/response serializations.