Security News
JSR Working Group Kicks Off with Ambitious Roadmap and Plans for Open Governance
At its inaugural meeting, the JSR Working Group outlined plans for an open governance model and a roadmap to enhance JavaScript package management.
Pino is a very low overhead Node.js logger, which is inspired by Bunyan. It is designed to be as minimal as possible and to perform logging tasks with a very small performance overhead. Pino provides a simple to use API for structured logging and can be easily integrated with different transports for log processing.
Basic Logging
This feature allows you to perform basic logging tasks, such as logging informational messages.
const pino = require('pino');
const logger = pino();
logger.info('Hello, this is an info message!');
Logging with Different Levels
Pino allows you to log messages with different severity levels, such as error, warn, and debug.
const logger = pino();
logger.error('This is an error message');
logger.warn('This is a warning message');
logger.debug('This is a debug message');
Child Loggers
You can create child loggers from a parent logger, which can inherit the configuration of the parent and can also have additional properties.
const parentLogger = pino();
const childLogger = parentLogger.child({ a: 'property' });
childLogger.info('Hello from child logger');
Custom Serializers
Pino allows you to define custom serializers for logging objects in a specific way.
const logger = pino({
serializers: {
req: (req) => ({ method: req.method, url: req.url })
}
});
logger.info({ req: requestObject }, 'Request log message');
Pretty Printing
For development purposes, Pino can be combined with the 'pino-pretty' module to format logs in a more readable way.
const pino = require('pino');
const pretty = require('pino-pretty');
const logger = pino(pretty());
logger.info('This will be pretty printed');
Winston is a multi-transport async logging library for Node.js. It is designed to be a simple and universal logging library with support for multiple transports. Compared to Pino, Winston is more feature-rich and configurable but can be heavier on performance.
Bunyan is a simple and fast JSON logging library for Node.js services. Like Pino, it is inspired by the Unix philosophy and focuses on structured logging. Bunyan is more similar to Pino in terms of philosophy, but Pino claims to be faster and more efficient.
Log4js is a logging framework for Node.js, which provides flexible configuration and supports multiple appenders. It is similar to the Log4j library for Java. Compared to Pino, Log4js offers more traditional logging features but may not be as performance-optimized.
Extremely fast node.js logger, inspired by Bunyan. It also includes a shell utility to pretty-print its log files.
npm install pino --save
'use strict'
var pino = require('./')()
pino.info('hello world')
pino.error('this is at error level')
pino.info('the answer is %d', 42)
pino.info({ obj: 42 }, 'hello world')
pino.info({ obj: 42, b: 2 }, 'hello world')
pino.info({ obj: { aa: 'bbb' } }, 'another')
setImmediate(function () {
pino.info('after setImmediate')
})
pino.error(new Error('an error'))
var child = pino.child({ a: 'property' })
child.info('hello child!')
var childsChild = child.child({ another: 'property' })
childsChild.info('hello baby..')
This produces:
{"pid":94473,"hostname":"MacBook-Pro-3.home","level":30,"msg":"hello world","time":1459529098958,"v":1}
{"pid":94473,"hostname":"MacBook-Pro-3.home","level":50,"msg":"this is at error level","time":1459529098959,"v":1}
{"pid":94473,"hostname":"MacBook-Pro-3.home","level":30,"msg":"the answer is 42","time":1459529098960,"v":1}
{"pid":94473,"hostname":"MacBook-Pro-3.home","level":30,"msg":"hello world","time":1459529098960,"obj":42,"v":1}
{"pid":94473,"hostname":"MacBook-Pro-3.home","level":30,"msg":"hello world","time":1459529098960,"obj":42,"b":2,"v":1}
{"pid":94473,"hostname":"MacBook-Pro-3.home","level":30,"msg":"another","time":1459529098960,"obj":{"aa":"bbb"},"v":1}
{"pid":94473,"hostname":"MacBook-Pro-3.home","level":50,"msg":"an error","time":1459529098961,"type":"Error","stack":"Error: an error\n at Object.<anonymous> (/Users/davidclements/z/nearForm/pino/example.js:14:12)\n at Module._compile (module.js:435:26)\n at Object.Module._extensions..js (module.js:442:10)\n at Module.load (module.js:356:32)\n at Function.Module._load (module.js:311:12)\n at Function.Module.runMain (module.js:467:10)\n at startup (node.js:136:18)\n at node.js:963:3","v":1}
{"pid":94473,"hostname":"MacBook-Pro-3.home","level":30,"msg":"hello child!","time":1459529098962,"a":"property","v":1}
{"pid":94473,"hostname":"MacBook-Pro-3.home","level":30,"msg":"hello baby..","time":1459529098962,"another":"property","a":"property","v":1}
{"pid":94473,"hostname":"MacBook-Pro-3.home","level":30,"msg":"after setImmediate","time":1459529098963,"v":1}
As far as we know, it is the fastest logger in town:
pino.info('hello world')
:
benchBunyan*10000: 1082.896ms
benchWinston*10000: 1707.665ms
benchBole*10000: 1574.295ms
benchPino*10000: 264.506ms
benchPinoExreme*10000: 105.391ms
pino.info({'hello': 'world'})
:
benchBunyanObj*10000: 1213.984ms
benchWinstonObj*10000: 1951.889ms
benchBoleObj*10000: 1717.641ms
benchPinoObj*10000: 322.118ms
benchPinoExtremeObj*10000: 142.215ms
pino.info(aBigDeeplyNestedObject)
:
benchBunyanDeepObj*10000: 6148.665ms
benchWinstonDeepObj*10000: 14726.129ms
benchBoleDeepObj*10000: 24450.814ms
benchPinoDeepObj*10000: 4296.618ms
benchPinoUnsafeDeepObj*10000: 3065.568ms
benchPinoExtremeDeepObj*10000: 4139.848ms
benchPinoUnsafeExtremeDeepObj*10000: 2948.078ms
pino.info('hello %s %j %d', 'world', {obj: true}, 4, {another: 'obj'})
:
benchBunyanInterpolateExtra*10000: 2665.294ms
benchWinstonInterpolateExtra*10000: 2455.395ms
benchBoleInterpolateExtra*10000: 3291.087ms
benchPinoInterpolateExtra*10000: 568.122ms
benchPinoExtremeInterpolateExtra*10000: 341.009ms
In multiple cases, pino is over 6x faster than alternatives.
To use the command line tool, we can install pino
globally:
npm install -g pino
Then we simply pipe a log file through pino
:
cat log | pino
There's also a transformer flag that converts Epoch timestamps to ISO timestamps.
cat log | pino -t
For instance, pino -t
will transform this:
{"pid":14139,"hostname":"MacBook-Pro-3.home","level":30,"msg":"hello world","time":1457537229339,"v":0}
Into this:
{"pid":14139,"hostname":"MacBook-Pro-3.home","level":30,"msg":"hello world","time":"2016-03-09T15:27:09.339Z","v":0}
pino()
logger.child()
logger.level
logger.fatal()
logger.error()
logger.warn()
logger.info()
logger.debug()
logger.trace()
pino.stdSerializers.req
pino.stdSerializers.res
pino.stdSerializers.err
Returns a new logger. Allowed options are:
safe
: avoid error causes by circular references in the object tree,
default true
name
: the name of the logger, default undefined
serializers
: an object containing functions for custom serialization of objects. These functions should return an JSONifiable object and they should never throwslowtime
: Outputs ISO time stamps ('2016-03-09T15:18:53.889Z'
) instead of Epoch time stamps (1457536759176
). WARNING: This option carries a 25% performance drop, we recommend using default Epoch timestamps and transforming logs after if required. The pino -t
command will do this for you (see CLI). default false
.extreme
: Enables extreme mode, yields an additional 60% performance (from 250ms down to 100ms per 10000 ops). There are trade-off's should be understood before usage. See Extreme mode explained. default false
stream
is a Writable stream, defaults to process.stdout
.
Example:
'use strict'
var pino = require('pino')
var logger = ({
name: 'myapp',
safe: true,
serializers: {
req: pino.stdSerializers.req
res: pino.stdSerializers.res
}
})
Creates a child logger, setting all key-value pairs in bindings
as
properties in the log lines. All serializers will be applied to the
given pair.
Example:
logger.child({ a: 'property' }).info('hello child!')
// generates
// {"pid":46497,"hostname":"MacBook-Pro-di-Matteo.local","level":30,"msg":"hello child!","time":1458124707120,"v":0,"a":"property"}
Child loggers use the same output stream as the parent and inherit the current log level of the parent at the time they are spawned.
From v2.x.x the log level of a child is mutable (whereas in v1.x.x it was immutable), and can be set independently of the parent.
For example
var logger = pino()
logger.level = 'error'
logger.info('nope') //does not log
var child = logger.child({foo: 'bar'})
child.info('nope again') //does not log
child.level = 'info'
child.info('hooray') //will log
logger.info('nope nope nope') //will not log, level is still set to error
Also from version 2.x.x we can spawn child loggers from child loggers, for instance
var logger = pino()
var child = logger.child({father: true})
var childChild = child.child({baby: true})
Child logger creation is fast:
benchBunyanCreation*10000: 1291.332ms
benchBoleCreation*10000: 1630.542ms
benchPinoCreation*10000: 352.330ms
benchPinoExtremeCreation*10000: 102.282ms
Logging through a child logger has little performance penalty:
benchBunyanChild*10000: 1343.933ms
benchBoleChild*10000: 1605.969ms
benchPinoChild*10000: 334.573ms
benchPinoExtremeChild*10000: 152.792ms
Spawning children from children has negligible overhead:
benchBunyanChildChild*10000: 1397.202ms
benchPinoChildChild*10000: 338.930ms
benchPinoExtremeChildChild*10000: 150.143ms
Set this property to the desired logging level.
In order of priority, available levels are:
Example: logger.level = 'info'
The logging level is a minimum level. For instance if logger.level
is 'info'
then all fatal
, error
, warn
, and info
logs will be enabled.
Log at 'fatal'
level the given msg
. If the first argument is an
object, all its properties will be included in the JSON line.
If more args follows msg
, these will be used to format msg
using
util.format
Log at 'error'
level the given msg
. If the first argument is an
object, all its properties will be included in the JSON line.
If more args follows msg
, these will be used to format msg
using
util.format
Log at 'warn'
level the given msg
. If the first argument is an
object, all its properties will be included in the JSON line.
If more args follows msg
, these will be used to format msg
using
util.format
Log at 'info'
level the given msg
. If the first argument is an
object, all its properties will be included in the JSON line.
If more args follows msg
, these will be used to format msg
using
util.format
Log at 'debug'
level the given msg
. If the first argument is an
object, all its properties will be included in the JSON line.
If more args follows msg
, these will be used to format msg
using
util.format
Log at 'trace'
level the given msg
. If the first argument is an
object, all its properties will be included in the JSON line.
If more args follows msg
, these will be used to format msg
using
util.format
Generates a JSONifiable object from the HTTP request
object passed to
the createServer
callback of Node's HTTP server.
It returns an object in the form:
{
pid: 93535,
hostname: 'your host',
level: 30,
msg: 'my request',
time: '2016-03-07T12:21:48.766Z',
v: 0,
req: {
method: 'GET',
url: '/',
headers: {
host: 'localhost:50201',
connection: 'close'
},
remoteAddress: '::ffff:127.0.0.1',
remotePort: 50202
}
}
Generates a JSONifiable object from the HTTP response
object passed to
the createServer
callback of Node's HTTP server.
It returns an object in the form:
{
pid: 93581,
hostname: 'myhost',
level: 30,
msg: 'my response',
time: '2016-03-07T12:23:18.041Z',
v: 0,
res: {
statusCode: 200,
header: 'HTTP/1.1 200 OK\r\nDate: Mon, 07 Mar 2016 12:23:18 GMT\r\nConnection: close\r\nContent-Length: 5\r\n\r\n'
}
}
Serializes an Error
object if passed in as an property.
{
"pid": 40510,
"hostname": "MBP-di-Matteo",
"level": 50,
"msg": "an error",
"time": 1459433282301,
"v": 1,
"type": "Error",
"stack": "Error: an error\n at Object.<anonymous> (/Users/matteo/Repositories/pino/example.js:16:7)\n at Module._compile (module.js:435:26)\n at Object.Module._extensions..js (module.js:442:10)\n at Module.load (module.js:356:32)\n at Function.Module._load (module.js:313:12)\n at Function.Module.runMain (module.js:467:10)\n at startup (node.js:136:18)\n at node.js:963:3"
}
In essence, Extreme mode enables extreme performance by buffering log messages and writing them in larger chunks.
This has a couple of important caveats:
logger.info
) and writes to a log file (or log stream)process.stdout
or process.stderr
, there is a slight possibility of lost logs or even partially written logs if the OS buffers don't have enough space, or something else is being written to the stream (or maybe some other reason we've not thought of)So in summary, only use extreme mode if you're doing an extreme amount of logging, and you're happy in some scenarios to lose the most recent logs.
We've got you covered:
npm install --save express-pino-logger
var app = require('express')()
var pino = require('express-pino-logger')()
app.use(pino)
app.get('/', function (req, res) {
req.log.info('something')
res.send('hello world')
})
app.listen(3000)
See the express-pino-logger readme for more info.
Use a separate tool for log rotation.
We recommend logrotate
Consider we output our logs to /var/log/myapp.log
like so:
> node server.js > /var/log/myapp.log
We would rotate our log files with logrotate, by adding the following to /etc/logrotate.d/myapp
:
/var/log/myapp.log {
su root
daily
rotate 7
delaycompress
compress
notifempty
missingok
copytruncate
}
Create a separate process and pipe to it.
For example:
var split = require('split2')
var pump = require('pump')
var through = require('through2')
var myTransport = through.obj(function (chunk, enc, cb) {
// do whatever you want here!
console.log(chunk)
cb()
}
pump(process.stdin, split2(JSON.parse), myTransport)
node my-app-which-logs-stuff-to-stdout.js | node my-transport-process.js
Using transports in the same process causes unnecessary load and slows down Node's single threaded event loop.
If you write a transport, let us know and we will add a link here!
There's some fine points to be aware of, which are a result of worthwhile trade-offs:
The logger functions (e.g. pino.info
) can take a maximum of 11 arguments.
If you need more than that to write a log entry, you're probably doing it wrong.
It's possible for naming conflicts to arise between child loggers and children of child loggers.
This isn't as bad as it sounds, even if you do use the same keys between parent and child loggers Pino resolves the conflict in the sanest way.
For example, consider the following:
var pino = require('pino')
var fs = require('fs')
pino(fs.createWriteStream('./my-log'))
.child({a: 'property'})
.child({a: 'prop'})
.info('howdy')
$ cat my-log
{"pid":95469,"hostname":"MacBook-Pro-3.home","level":30,"msg":"howdy","time":1459534114473,"a":"property","a":"prop","v":1}
Notice how there's two key's named a
in the JSON output. The sub-childs properties
appear after the parent child properties. This means if we run our logs through pino -t
(or convert them to objects in any other way) we'll end up with one a
property whose value corresponds to the lowest child in the hierarchy:
$ cat my-log | pino -t
{"pid":95469,"hostname":"MacBook-Pro-3.home","level":30,"msg":"howdy","time":"2016-04-01T18:08:34.473Z","a":"prop","v":1}
This equates to the same log output that Bunyan supplies.
One of Pino's performance tricks is to avoid building objects and stringifying them, so we're building strings instead. This is why duplicate keys between parents and children will end up in log output.
pino
objecthttps://www.npmjs.com/~matteo.collina
https://twitter.com/matteocollina
https://github.com/davidmarkclements
https://www.npmjs.com/~davidmarkclements
https://twitter.com/davidmarkclem
This project was kindly sponsored by nearForm.
MIT
FAQs
super fast, all natural json logger
We found that pino demonstrated a healthy version release cadence and project activity because the last version was released less than a year ago. It has 4 open source maintainers collaborating on the project.
Did you know?
Socket for GitHub automatically highlights issues in each pull request and monitors the health of all your open source dependencies. Discover the contents of your packages and block harmful activity before you install or update your dependencies.
Security News
At its inaugural meeting, the JSR Working Group outlined plans for an open governance model and a roadmap to enhance JavaScript package management.
Security News
Research
An advanced npm supply chain attack is leveraging Ethereum smart contracts for decentralized, persistent malware control, evading traditional defenses.
Security News
Research
Attackers are impersonating Sindre Sorhus on npm with a fake 'chalk-node' package containing a malicious backdoor to compromise developers' projects.