bunyan、debug、log4js、loggly-jslogger、loglevel、morgan、pino 和 winston 是 Node.js 生态中主流的日志与调试工具,它们各自解决了不同层面的可观测性问题。winston 和 log4js 提供了高度可配置的传输机制和日志级别管理,适合复杂的企业级应用;pino 以极致的性能著称,专为高吞吐量的生产环境设计;bunyan 强制使用结构化 JSON 日志,便于机器解析;debug 专注于开发阶段的细粒度条件调试;loglevel 是最轻量的浏览器/Node 通用日志代理;morgan 专用于 HTTP 请求日志记录;而 loggly-jslogger 则是特定 SaaS 平台的专用客户端。这些工具共同构成了从开发调试到生产监控的完整日志解决方案。
在构建专业的 Node.js 应用时,日志系统不仅仅是打印几行文字,它是可观测性的基石。面对 bunyan、debug、log4js、loggly-jslogger、loglevel、morgan、pino 和 winston 这么多选择,开发者往往容易陷入困惑。本文将从架构师的角度,深入剖析这些库的核心机制、适用场景以及代码实现差异,帮助你做出最符合工程利益的选择。
日志的格式决定了后续处理的难度。现代微服务架构倾向于机器可读的结构化日志(JSON),而传统开发可能更习惯人类可读的文本。
pino 和 bunyan 是结构化日志的坚定拥护者。它们默认输出 JSON 对象,这使得日志可以轻松被 Logstash、Splunk 或 Datadog 解析。
// pino: 默认输出结构化 JSON
const pino = require('pino');
const logger = pino();
logger.info({ userId: 123, action: 'login' }, 'User logged in');
// 输出: {"level":30,"time":1678888888888,"pid":1234,"hostname":"local","userId":123,"action":"login","msg":"User logged in"}
// bunyan: 同样强制 JSON,但字段命名略有不同
const bunyan = require('bunyan');
const logger = bunyan.createLogger({ name: 'my-app' });
logger.info({ userId: 123, action: 'login' }, 'User logged in');
// 输出: {"name":"my-app","hostname":"local","pid":1234,"level":30,"msg":"User logged in","time":"2023-03-15T...","userId":123,"action":"login"}
相比之下,winston 和 log4js 更加灵活,允许你自定义格式。你可以选择文本格式以便开发人员直接阅读,也可以选择 JSON 格式用于生产环境。
// winston: 可配置格式,这里演示文本格式
const winston = require('winston');
const logger = winston.createLogger({
format: winston.format.combine(
winston.format.timestamp(),
winston.format.printf(({ level, message, timestamp }) => `${timestamp} [${level}]: ${message}`)
),
transports: [new winston.transports.Console()]
});
logger.info('User logged in');
// 输出: 2023-03-15T12:00:00.000Z [info]: User logged in
// log4js: 通过 layout 配置格式
const log4js = require('log4js');
log4js.configure({
appenders: { out: { type: 'stdout', layout: { type: 'pattern', pattern: '%d %p %m' } } },
categories: { default: { appenders: ['out'], level: 'info' } }
});
const logger = log4js.getLogger();
logger.info('User logged in');
// 输出: 2023-03-15 12:00:00 INFO User logged in
debug 和 loglevel 则专注于简单的文本输出,主要用于开发阶段的控制台交互,不具备原生的结构化数据支持。
// debug: 简单的命名空间文本日志
const debug = require('debug')('app:auth');
debug('User %s logged in', 'alice');
// 输出: app:auth User alice logged in
// loglevel: 基础文本日志
const log = require('loglevel');
log.info('User logged in');
// 输出: INFO: User logged in
morgan 专门用于 HTTP 访问日志,通常输出文本格式,但也可以配置为 JSON。
// morgan: HTTP 请求日志
const morgan = require('morgan');
// 使用预定义的 'combined' 格式 (文本)
app.use(morgan('combined'));
// 输出: ::1 - - [15/Mar/2023:12:00:00 +0000] "GET /api/users HTTP/1.1" 200 1234
在高并发场景下,日志写入不能阻塞主线程。这是 pino 脱颖而出的关键领域。
pino 采用了独特的异步写入机制。它将日志对象序列化为 JSON 字符串后,通过 worker 线程或进程异步写入目标,极大地减少了对事件循环的阻塞。
// pino: 内部自动处理异步写入,对主线程几乎无阻塞
const pino = require('pino');
// 即使在高负载下,这条日志也不会阻塞业务逻辑
const logger = pino({ level: 'info' });
logger.info({ data: largeObject }, 'Processing request');
winston 在 3.x 版本后也引入了异步传输的支持,但默认情况下往往是同步或基于流的处理,配置不当仍可能影响性能。
// winston: 需要显式配置或使用特定传输来实现最佳异步性能
const winston = require('winston');
const logger = winston.createLogger({
transports: [
new winston.transports.File({ filename: 'app.log' }) // 基于流的写入
]
});
logger.info('Processing request');
bunyan 的性能尚可,但由于其较老的架构设计,在极高吞吐量下不如 pino 高效。
// bunyan: 同步写入为主,高吞吐下可能有瓶颈
const bunyan = require('bunyan');
const logger = bunyan.createLogger({ name: 'my-app' });
logger.info('Processing request');
log4js 由于功能繁杂且历史包袱较重,性能通常是这几个通用库中最弱的,不适合对延迟极度敏感的核心链路。
// log4js: 功能丰富但性能开销相对较大
const log4js = require('log4js');
const logger = log4js.getLogger();
logger.info('Processing request');
在生产环境之外,开发阶段的日志控制同样重要。你不想看到所有库的日志,只想关注当前模块。
debug 是这一领域的王者。它允许你通过环境变量精确控制哪些命名空间的日志被显示,无需修改代码。
// debug: 通过环境变量控制
// 文件: auth.js
const debug = require('debug')('myapp:auth');
module.exports = () => debug('Auth function called');
// 终端运行: DEBUG=myapp:auth node app.js
// 只有 auth 模块的日志会显示,其他 debug 日志被静默
loglevel 提供了简单的日志级别切换,适合在浏览器或简单 Node 脚本中动态调整 verbosity。
// loglevel: 动态设置级别
const log = require('loglevel');
log.setLevel('warn'); // 只显示 warn 和 error
log.info('This will not show');
log.warn('This will show');
morgan 在开发阶段非常有用,可以实时看到 HTTP 请求的细节,帮助快速定位接口问题。
// morgan: 开发模式下的请求可视化
// 使用 'dev' 格式,带有颜色编码,适合终端查看
app.use(morgan('dev'));
// 输出: GET /api/users 200 15ms
日志生成后,需要发送到文件、远程服务器或监控平台。这就是 "Transports" 或 "Appenders" 发挥作用的地方。
winston 拥有最庞大的传输插件生态。你可以轻松将日志发送到 Syslog、MongoDB、Redis、HTTP 端点等。
// winston: 强大的多传输支持
const winston = require('winston');
const logger = winston.createLogger({
transports: [
new winston.transports.Console(),
new winston.transports.File({ filename: 'error.log', level: 'error' }),
// 假设安装了 winston-http 插件
// new WinstonHTTP({ host: 'log-server.com' })
]
});
logger.error('Something went wrong');
log4js 使用 "Appenders" 概念,同样支持文件轮转、邮件发送、Slack 通知等丰富功能,配置风格偏向传统 XML/JSON 配置块。
// log4js: 多 Appender 配置
const log4js = require('log4js');
log4js.configure({
appenders: {
file: { type: 'file', filename: 'app.log' },
console: { type: 'stdout' }
},
categories: {
default: { appenders: ['file', 'console'], level: 'info' }
}
});
pino 本身专注于生成日志,传输通常通过管道(pino-pretty)或单独的传输进程(pino-transport)处理,这种分离设计保持了核心库的轻量和高性能。
// pino: 使用传输模块
const pino = require('pino');
// 将日志通过管道发送给 pino-transport 处理
const logger = pino({
transport: {
target: 'pino-pretty', // 开发环境美化输出
options: { destination: 1 }
}
});
loggly-jslogger 是一个特例,它只专注于将日志发送到 Loggly 云平台,缺乏通用性,但如果你只用 Loggly,它是最直接的集成方式。
// loggly-jslogger: 专用发送
const Loggly = require('loggly-jslogger');
const logger = new Loggly.createLogger({
token: 'YOUR_TOKEN',
subdomain: 'your-subdomain'
});
logger.log('Sending directly to Loggly');
在选型时,库的维护状态至关重要。
bunyan: 虽然稳定且广泛使用,但其官方仓库的更新频率已显著降低。对于全新的大型项目,建议评估 pino 作为替代,以获得更好的长期支持和性能。loggly-jslogger: 仅作为特定 SaaS 的客户端存在。如果未来计划更换日志服务商,迁移成本较高。推荐做法是使用 winston 或 pino 配合 Loggly 的通用传输插件,以保持架构的灵活性。log4js: 仍在维护中,但其 API 风格较为陈旧。如果是新项目,除非有明确的迁移需求,否则 winston 或 pino 通常是更现代化的选择。| 特性 | pino | winston | bunyan | debug | log4js | morgan | loglevel | loggly-jslogger |
|---|---|---|---|---|---|---|---|---|
| 核心优势 | 极致性能,结构化 | 生态丰富,灵活 | 严格结构化 | 开发调试控制 | 传统 Appender 模式 | HTTP 请求日志 | 轻量,通用 | Loggly 专用 |
| 输出格式 | JSON (默认) | 可配置 | JSON (强制) | 文本 | 可配置 | 文本/JSON | 文本 | JSON (到云端) |
| 适用场景 | 高并发生产环境 | 通用企业级应用 | 结构化日志需求 | 开发阶段调试 | 传统迁移/复杂分发 | Web 服务器访问日志 | 前端/轻量库 | 仅 Loggly 用户 |
| 异步支持 | ⭐⭐⭐⭐⭐ (原生) | ⭐⭐⭐ (需配置) | ⭐⭐ | N/A | ⭐⭐ | N/A | N/A | N/A |
最终建议:
对于大多数现代 Node.js 后端服务,pino 是首选,因为它在性能和结构化日志之间取得了最佳平衡。如果你需要极其丰富的插件生态和经过时间考验的稳定性,winston 依然是可靠的伙伴。在开发阶段,务必搭配 debug 来处理细粒度的模块日志。对于 Express/Koa 应用,morgan 是记录访问日志的标准配置。尽量避免在新项目中直接使用 loggly-jslogger 或过度依赖 bunyan,除非有特定的遗留系统兼容需求。
如果你的团队严格遵循结构化日志规范,且主要需求是将日志直接导入 ELK 或类似的分析工具,bunyan 是一个成熟的选择。它强制输出 JSON 格式,消除了非结构化文本解析的麻烦,非常适合需要机器自动化处理日志的场景。不过,由于其社区活跃度近年来有所下降,在新项目中需权衡长期维护风险。
当你在开发过程中需要频繁开关特定模块的日志输出,而不想修改代码或重启服务时,debug 是最佳搭档。它通过环境变量控制日志显示,非常适合大型项目中隔离问题,避免控制台被无关信息淹没。它不是用来记录生产环境持久化日志的,而是专为开发调试设计的轻量级工具。
如果你需要从 Java 的 Log4j 迁移过来,或者习惯使用 Appender 模式将日志分发到文件、控制台、邮件等多种目标,log4js 提供了最熟悉的配置体验。它的功能非常全面,支持日志轮转和复杂的分类管理,适合对日志基础设施有传统要求的企业级应用。但相比现代库,其配置略显繁琐且性能开销较大。
仅当你的基础设施已经深度绑定 Loggly 平台,且需要直接在客户端或 Node 端发送日志到该特定服务时,才选择此包。它是一个专用客户端,不具备通用日志库的灵活性,无法轻松切换到其他后端。对于大多数需要自主掌控日志架构的项目,建议使用通用库配合传输插件代替。
如果你需要一个极轻量、零依赖的日志方案,且代码需要同时运行在浏览器和 Node.js 环境中,loglevel 是理想选择。它不提供复杂的传输功能,只负责日志级别的过滤和输出,非常适合嵌入到 SDK 或前端库中。当需要更高级功能时,它可以轻松与其他库组合使用。
当你的核心需求是记录 HTTP 请求的访问日志(如状态码、响应时间、URL),morgan 是 Express 和 Koa 生态中的标准中间件。它开箱即用,支持自定义格式,能迅速让你看清服务器的流量状况。它通常不单独使用,而是配合 winston 或 pino 将访问日志持久化到文件或远程服务。
在生产环境中,如果日志量巨大且对性能敏感(例如高并发 API 服务),pino 是目前性能最好的选择,其异步日志记录机制对主线程阻塞最小。它默认输出结构化 JSON,且拥有强大的生态插件支持各种传输目标。对于追求极致性能和现代化架构的新项目,pino 通常是首选推荐。
如果你需要一个社区最活跃、插件生态最丰富且经过长期验证的日志库,winston 是最稳妥的选择。它支持多种传输方式(Transports)和格式化处理,能够灵活适应从简单控制台输出到复杂分布式日志收集的各种场景。虽然性能略逊于 pino,但其稳定性和易用性使其成为许多大型项目的首选。
Bunyan is a simple and fast JSON logging library for node.js services:
var bunyan = require('bunyan');
var log = bunyan.createLogger({name: "myapp"});
log.info("hi");
and a bunyan CLI tool for nicely viewing those logs:

Manifesto: 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).
Solid core functionality is there. Joyent is using this for a number of production services. Bunyan supports node 0.10 and greater. Follow @trentmick for updates to Bunyan.
There is an email discussion list bunyan-logging@googlegroups.com, also as a forum in the browser.
npm install bunyan
Tip: The bunyan CLI tool is written to be compatible (within reason) with
all versions of Bunyan logs. Therefore you might want to npm install -g bunyan
to get the bunyan CLI on your PATH, then use local bunyan installs for
node.js library usage of bunyan in your apps.
Tip: Installing without optional dependencies can dramatically reduce
bunyan's install size. dtrace-provider is used for dtrace features,
mv is used for RotatingFileStream, and moment is used for local time.
If you don't need these features, consider installing with the
--no-optional flag.
bunyan CLI for pretty-printing and filtering of Bunyan logssrc: truelog.childLike most logging libraries you create a Logger instance and call methods named after the logging levels:
// hi.js
var bunyan = require('bunyan');
var log = 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}
var bunyan = require('bunyan');
var log = bunyan.createLogger({
name: <string>, // Required
level: <level name or number>, // Optional, see "Levels" section
stream: <node.js stream>, // Optional, see "Streams" section
streams: [<bunyan streams>, ...], // Optional, see "Streams" section
serializers: <serializers mapping>, // 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 call log.info(...). The
full 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.
Note that this implies you cannot blindly pass any object as the first
argument to log it because that object might include fields that collide with
Bunyan's core record fields. In other words,
log.info(mywidget) may not yield what you expect. Instead of a string
representation of mywidget that other logging libraries may give you, Bunyan
will try to JSON-ify your object. It is a Bunyan best practice to always give a
field name to included objects, e.g.:
log.info({widget: mywidget}, ...)
This will dove-tail with Bunyan serializer support, discussed later.
The same goes for all of Bunyan's log levels: log.trace, log.debug,
log.info, log.warn, log.error, and log.fatal. See the levels
section below for details and suggestions.
Bunyan log output is a stream of JSON objects. This is great for processing,
but not for reading directly. A bunyan tool is provided for
pretty-printing bunyan logs and for filtering (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 rendered
log output. That example also shows the nice formatting automatically done for
some 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 is filtering of log content, which can be useful for digging through large log files or for analysis. We can filter only records 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 French records 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)
See bunyan --help for other facilities.
By default, log output is to stdout and at the "info" level. Explicitly that looks like:
var log = bunyan.createLogger({
name: 'myapp',
stream: process.stdout,
level: 'info'
});
That is an abbreviated form for a single stream. You can define multiple streams at different levels.
var log = 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 the Streams section below.
Bunyan has a concept of a child logger to specialize a logger for a
sub-component of your application, i.e. to create a new logger with
additional bound fields that will be included in its log records. A child
logger is created with log.child(...).
In the following example, logging on a "Wuzzle" instance's this.log will
be exactly as on the parent logger with the addition of the widget_type
field:
var bunyan = require('bunyan');
var log = bunyan.createLogger({name: 'myapp'});
function Wuzzle(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');
var wuzzle = new Wuzzle({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 the bunyan CLI (using the "short" output mode):
$ node myapp.js | bunyan -o short
07:46:42.707Z INFO myapp: start
07: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 the
node-restify web framework.
Restify uses Bunyan for its logging. One feature of its integration, is that
if server.use(restify.requestLogger()) is used, each restify request handler
includes a req.log logger that is:
log.child({req_id: <unique request id>}, true)
Apps using restify can then use req.log and have all such log records
include the unique request id (as "req_id"). Handy.
Bunyan has a concept of "serializer" functions to produce a JSON-able object from a JavaScript object, so you can easily do the following:
log.info({req: <request object>}, 'something about handling this request');
and have the req 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 a serializers 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 for fields of that name.
An example:
function reqSerializer(req) {
return {
method: req.method,
url: req.url,
headers: req.headers
};
}
var log = bunyan.createLogger({
name: 'myapp',
serializers: {
req: reqSerializer
}
});
Typically serializers are added to a logger at creation time via
bunyan.createLogger({..., serializers: <serializers>}). However, serializers
can be added after creation via <logger>.addSerializers(...), e.g.:
var log = bunyan.createLogger({name: 'myapp'});
log.addSerializers({req: reqSerializer});
A serializer function is passed unprotected objects that are passed to the
log.info, log.debug, etc. call. This means a poorly written serializer
function can cause side-effects. Logging shouldn't do that. Here are a few
rules and best practices for serializer functions:
A serializer function should never throw. The bunyan library does protect somewhat from this: if the serializer throws an error, then bunyan 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 function should never mutate the given object. Doing so will change the object in your application.
A serializer function should be defensive. In my experience, it is common to set a serializer in an app, say for field name "foo", and then accidentally have a log line that passes a "foo" that is undefined, or null, or of some unexpected type. A good start at defensiveness is to start with this:
function fooSerializer(foo) {
// Guard against foo be null/undefined. Check that expected fields
// are defined.
if (!foo || !foo.bar)
return foo;
var obj = {
// Create the object to be logged.
bar: foo.bar
}
return obj;
};
Bunyan includes a small set of "standard serializers", exported as
bunyan.stdSerializers. Their use is completely optional. An example using
all of them:
var log = bunyan.createLogger({
name: 'myapp',
serializers: bunyan.stdSerializers
});
or particular ones:
var log = 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 from verror. |
| req | Common fields from a node.js HTTP request object. |
| res | Common fields from a node.js HTTP response object. |
Note that the req and res serializers intentionally do not include the
request/response body, as that can be prohibitively large. If helpful, the
restify framework's audit logger plugin
has its own req/res serializers that include more information (optionally
including the body).
The source file, line and function of the log call site can be added to
log records by using the src: true config option:
var log = 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 option in production.
The log levels in bunyan are as follows. The level descriptions are best practice opinions of the author.
Setting a logger instance (or one of its streams) to a particular level implies that all log records at that level and above are logged. E.g. a logger set to level "info" will log records at level info and above (warn, error, fatal).
While using log level names is preferred, the actual level values are integers
internally (10 for "trace", ..., 60 for "fatal"). Constants are defined for
the levels: bunyan.TRACE ... bunyan.FATAL. The lowercase level names are
aliases 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 INFO
log.level("info") // set all streams to level INFO
log.levels() -> [DEBUG, INFO] // get array of levels of all streams
log.levels(0) -> DEBUG // get level of stream at index 0
log.levels("foo") // get level of stream with name "foo"
log.levels(0, INFO) // set level of stream 0 to INFO
log.levels(0, "info") // can use "info" et al aliases
log.levels("foo", WARN) // set stream named "foo" to WARN
Trent's biased suggestions for server apps: Use "debug" 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.
Trent's biased suggestions for node.js libraries: IMHO, libraries should only
ever log at trace-level. Fine control over log output should be up to the
app using a library. Having a library that spews log output at higher levels
gets in the way of a clear story in the app logs.
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:
{"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 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 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 this
is 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 retrieved
via os.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 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.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 nested 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).
err: Object. A caught JS exception. Log that thing with log.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 and
do this log.error({err: err}, "oops"). 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 'Request-Id' header).
req: An HTTP server request. Bunyan provides bunyan.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 bunyan.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 to
auth).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 equivalent to a log4j Appender). Ultimately Bunyan uses a Writable Stream interface, but there are some additional attributes used to create and manage the stream. A Bunyan Logger instance has one or more streams. In general streams are specified with the "streams" option:
var bunyan = require('bunyan');
var log = 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 a Logger.streams).
var log = bunyan.createLogger({
name: "foo",
stream: process.stderr,
level: "debug"
});
Note that "file" streams do not support this shortcut (partly for historical reasons and partly to not make it difficult to add a literal "path" field on log records).
If neither "streams" nor "stream" are specified, the default is a stream of
type "stream" emitting to process.stdout at the "info" level.
After a bunyan instance has been initialized, you may add additional streams by
calling the addStream function.
var bunyan = require('bunyan');
var log = 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 its
streams. Bunyan does so by default for type === "file"
streams, so you can do this:
var log = 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, the reemitErrorEvents field can be used when adding a
stream to control whether "error" events are re-emitted on the Logger. For
example:
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 events
on the Logger instance.reemitErrorEvents: true: error events will be re-emitted on the Logger
for 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 any
streams.Note: "error" events are not related to log records at the "error" level
as produced by log.error(...). See the node.js docs on error
events for details.
streamA type === 'stream' is a plain ol' node.js Writable
Stream. A
"stream" (the writable stream) field is required. E.g.: process.stdout,
process.stderr.
var log = 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 not specified it defaults to "info". If specified this can be one of the level strings ("trace", "debug", ...) or constants (`bunyan.TRACE`, `bunyan.DEBUG`, ...). This serves as a severity threshold for that stream so 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](https://www.npmjs.com/package/bunyan#levels) for details. A stream "name" isn't used for anything else. |
fileA type === 'file' stream requires a "path" field. Bunyan will open this
file for appending. E.g.:
var log = 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 not specified it defaults to "info". If specified this can be one of the level strings ("trace", "debug", ...) or constants (`bunyan.TRACE`, `bunyan.DEBUG`, ...). This serves as a severity threshold for that stream so 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](https://www.npmjs.com/package/bunyan#levels) for details. A stream "name" isn't used for anything else. |
rotating-fileWARNING on node 0.8 usage: Users of Bunyan's rotating-file should (a) be
using at least bunyan 0.23.1 (with the fix for this
issue), and (b) should use at
least node 0.10 (node 0.8 does not support the unref() method on
setTimeout(...) needed for the mentioned fix). The symptom is that process
termination will hang for up to a full rotation period.
WARNING on cluster
usage: Using Bunyan's rotating-file stream with node.js's "cluster" module
can result in unexpected file rotation. You must not have multiple processes
in the cluster logging to the same file path. In other words, you must have
a separate log file path for the master and each worker in the cluster.
Alternatively, consider using a system file rotation facility such as
logrotate on Linux or logadm on SmartOS/Illumos. See
this comment on issue #117
for details.
A type === 'rotating-file' is a file stream that handles file automatic
rotation.
var log = bunyan.createLogger({
name: 'foo',
streams: [{
type: 'rotating-file',
path: '/var/log/foo.log',
period: '1d', // daily rotation
count: 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 rotated files, 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 for testing), "h" (hours), "d" (days), "w" (weeks), "m" (months), "y" (years). Or one of the following names can be used "hourly" (means 1h), "daily" (1d), "weekly" (1w), "monthly" (1m), "yearly" (1y). Rotation is done at the start of the scope: top of the hour (h), midnight (d), start of Sunday (w), start of the 1st 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 not specified it defaults to "info". If specified this can be one of the level 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](https://www.npmjs.com/package/bunyan#levels) for details. A stream "name" isn't used for anything else. |
Note on log rotation: Often you may be using external log rotation utilities
like logrotate on Linux or logadm on SmartOS/Illumos. In those cases, unless
you are ensuring "copy and truncate" semantics (via copytruncate with
logrotate 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 your
app:
var log = 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 run
log.reopenFileStreams() would work as well.
rawraw: Similar to a "stream" writable stream, except that the write method
is given raw log record Objects 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.raw + RingBuffer StreamBunyan comes with a special stream called a RingBuffer which keeps the last N records in memory and does not write the data anywhere else. One common strategy 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 your own 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. */
var bunyan = require('bunyan');
var ringbuffer = new bunyan.RingBuffer({ limit: 100 });
var log = bunyan.createLogger({
name: 'foo',
streams: [
{
level: 'info',
stream: process.stdout
},
{
level: 'trace',
type: 'raw', // use 'raw' to get raw log record objects
stream: 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 the user-maintained list in the Bunyan wiki.
On systems that support DTrace (e.g., illumos derivatives like SmartOS and
OmniOS, FreeBSD, Mac), Bunyan will create a DTrace provider (bunyan) that
makes available the following probes:
log-trace
log-debug
log-info
log-warn
log-error
log-fatal
Each of these probes has a single argument: the string that would be written to the log. Note that when a probe is enabled, it will fire whenever the corresponding function is called, even if the level of the 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 size
because 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 the
jstack action
via a node.js helper, get a stack backtrace for any debug message that
includes 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:
Support for other runtime environments is welcome. If you have suggestions, fixes, or mentions that node-bunyan already works in some other JavaScript runtime, please open an issue or a pull request.
The primary target is Node.js. It is the only environment in which I regularly test. If you have suggestions for how to automate testing for other environments, I'd appreciate feedback on this automated testing issue.
As the Browserify site says it "lets you
require('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 and
all its node.js dependencies into a single file that is runnable in the
browser via:
<script src="play.browser.js"></script>
As of version 1.1.0, node-bunyan supports being run via Browserify. The
default stream when running in the browser is one that emits
raw log records to console.log/info/warn/error.
Here is a quick example showing you how you can get this working for your script.
Get browserify and bunyan installed in your module:
$ npm install browserify bunyan
An example script using Bunyan, "play.js":
var bunyan = require('bunyan');
var log = bunyan.createLogger({name: 'play', level: 'debug'});
log.trace('this one does not emit');
log.debug('hi on debug'); // console.log
log.info('hi on info'); // console.info
log.warn('hi on warn'); // console.warn
log.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>
<meta charset="utf-8">
<script src="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 line you'll want to add your own stream, starting with something like this:
var bunyan = require('./lib/bunyan');
function MyRawStream() {}
MyRawStream.prototype.write = function (rec) {
console.log('[%s] %s: %s',
rec.time.toISOString(),
bunyan.nameFromLevel[rec.level],
rec.msg);
}
var log = bunyan.createLogger({
name: 'play',
streams: [
{
level: 'info',
stream: new MyRawStream(),
type: 'raw'
}
]
});
log.info('hi on info');
To include bunyan in your webpack bundle you need to tell webpack to ignore the optional dependencies that are unavailable in browser environments.
Mark the following dependencies as externals in your webpack configuration 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 for
breaking backward compat and major reworks, new features without breaking
change, and bug fixes, respectively. tl;dr: Semantic
versioning.
MIT.
See the user-maintained list of Bunyan-related software in the Bunyan wiki.