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 productionThe cost of logging article  and  The cost of logging video .

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:

Plain Text
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-httpexpress-pino-loggerhapi-pinorestify-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.

Plain Text
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:

Plain Text
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:

Plain Text
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:

Plain Text
/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