Announcing Pino V5.0.0
What is Pino?
If you’ve not heard of Pino before, it’s a low-overhead, newline-delimited-JSON logger with close compatibility to Bunyan. The idea behind Pino is to provide the lowest overhead JSON logging possible in order to keep Node’s event-loop as free as possible to handle the most critical work, such as request-handling.
For information on Pino, in general, see Pino – The fastest Node.js logger for production and The cost of logging article.
In this new major release of Pino, we’ve made several key improvements.
Redaction
In recent times there has been an increasing focus on keeping user data private. With the advent of GDPR the risk of leaking user data has significantly increased. The Pino team came to the conclusion that logging redaction should be a standard core feature.
After some research, we developed a low-overhead approach to redacting sensitive information and created a generic module, fast-redact which we then integrated into Pino v5.
This option can be particularly useful with Pino web framework loggers. For instance, given a Node core HTTP server using pino-http , any request cookie headers can be redacted from logs with the following:
const http = require('http')
const logger = require('pino-http')({
redact: ['headers.cookie']
})
http.createServer((req, res) => {
logger(req, res)
res.end('pino 5 y\'all!')
}).listen(3000)From Pino 5 redaction support is available in all official pino web loggers, including pino-http , express-pino-logger , hapi-pino , restify-pino-logger and koa-pino-logger .
The redact option also supports wildcards to allow for censoring the same namespace in multiple objects, or all the keys of an object. In the case of non-wildcard paths redaction adds around 1% overhead, and is thirty times faster than the Pino v4 redaction approach with pino-noir .
For more information on Pino 5 redaction see the Redact documentation .
Faster
Pino v5 introduces the pino.destination and pino.extreme methods as an alternative to using Node core streams as logging destinations.
These API’s are based on a module we created called sonic-boom which provides an interface similar to core streams but writes are twice as fast. sonic-boom only supports strings encoded as utf-8.
For writing to STDOUT pino.destination is used by default. We encourage pino.destination to be used instead of Node’s fs.writableStream when logging to a file. Nevertheless, log writes to Node core streams are still 35% faster in Pino 5 versus Pino 4.
The pino.extreme method replaces the Pino 4 extreme mode. While it’s significantly faster we can still only recommend this mode if potential log loss (e.g. during a power outage) is acceptable.
const pino = require('pino')
const stream = pino.destination('./my.log') // or pino.extreme('./my.log')
const logger = pino(stream) // or pino(opts, stream)Safer
Pino 5 offers API’s and strategies that allow for stronger guarantees that logs messages will be written to disk in edge case scenarios.
This is primarily thanks to Pino 5’s integration with sonic-boom which provides synchronous flushing capabilities. This is important in certain scenarios where asynchronous operations cannot be scheduled – namely in final tick scenarios. Final tick scenarios include during an unhandled promise rejection, uncaught exception or within the exit handler.
The new pino.final method supplies a special logger that always writes synchronously. This is important for log messages written during the final tick, since the process will have died before asynchronously scheduled operations would resolve.
For example, here’s a way to guarantee that log messages will be written out during an uncaught exception:
const pino = require('pino')
const logger = pino()
process.on('uncaughtException', pino.final(logger, (err, finalLogger) => {
finalLogger.error(err, 'uncaughtException')
process.exit(1)
}))For more information see the Exit Logging documentation .
Another way Pino 5 allows for safer logging is by providing a way to avoid the copy truncate approach of log rotation tools (such as logrotate ). Using copy truncate can lead to loss of messages written between copy and subsequent truncation. When using pino.destination (or pino.extreme ) a signal handler can be registered to instead reopen a file within the process, allowing log rotation tools to simply move the file and send the signal to the process. See Reopening Log Files documentation for more information. Here is the example in docs reported for convenience:
const pino = require('pino')
// write the process pid to a well known location for later
const fs = require('fs')
fs.writeFileSync('/var/run/myapp.pid', process.pid)</p><p>const dest = pino.destination('/log/file') // pino.extreme will also work
const logger = require('pino')(dest)
process.on('SIGHUP', () => dest.reopen())Then you can use the following logrotate.d configuration:
/var/log/myapp.log {
su root
daily
rotate 7
delaycompress
compress
notifempty
missingok
postrotate
kill -HUP `cat /var/run/myapp.pid`
endscript
}CLI
To decrease core maintenance overhead and subtract unnecessary install size the Pino CLI has been broken out in to an ecosystem module called pino-pretty .The Pino CLI is primarily a development tool, so it makes sense for it to be installed separately. In production we always recommend logging out JSON lines, and avoiding any prettification until later human processing.
Syntax Refresh, Refactor and API Clarity
One of the initial goals of the Pino logger was to discover, demonstrate and apply performance principles in Node.js. This goal has stayed with the project and has driven us to the decision to update Pino 5 syntax to more contemporary EcmaScript.
Over time, Pino’s code base took on an organic quality as patches were made. In the process of refreshing the syntax we performed an internal architecture audit which result an entire code base refactor.
Additionally we clarified the public API methods and options, removing undocumented methods and state properties.
We hope that this will encourage continued collaboration with the community, and showcase that performant code doesn’t haven’t to be obscure or only use ES3 code.
As part of this refactoring, we are dropping support for Node v4, which reached End-Of-Life in April 2018.
Ecosystem Integration API
As part of the refactor, all private property namespaces were converted to Symbols . This ensures a clear separation between private and public and avoids the non-ideal underscore-prefix convention.
However, third-party integration often requires access to state or the ability to override methods. There may be other ways to provide the same functionality, but overriding and state mutation will generally be the lowest impact on speed. To allow for ecosystem integration Pino 5 supplies the pino.symbols object, which contains all the symbols used for private state and methods. We think this is an interesting and novel pattern to use for integration and look forward to feedback.
Documentation
Finally, Pino 5 also sees a complete rewrite of the documentation. The API documentation has better structuring, help and advice documentation is easier to discover and the Pino website has undergone a minor design refresh.
Check it out at https://getpino.io .
Insight, imagination and expertly engineered solutions to accelerate and sustain progress.
Contact