Skip to content

Latest commit

History

History
172 lines (132 loc) 路 5.21 KB

help.md

File metadata and controls

172 lines (132 loc) 路 5.21 KB

Help

Exit logging

When a Node process crashes from uncaught exception, exits due to a signal, or exits of it's own accord we may want to write some final logs 鈥撀爌articularly in cases of error.

Writing to a Node.js stream on exit is not necessarily guaranteed, and naively writing to an Extreme Mode logger on exit will definitely lead to lost logs.

To write logs in an exit handler, create the handler with pino.final:

process.on('uncaughtException', pino.final(logger, (err, finalLogger) => {
  finalLogger.error(err, 'uncaughtException')
  process.exit(1)
}))

process.on('unhandledRejection', pino.final(logger, (err, finalLogger) => {
  finalLogger.error(err, 'unhandledRejection')
  process.exit(1)
}))

The finalLogger is a special logger instance that will synchronously and reliably flush every log line. This is important in exit handlers, since no more asynchronous activity may be scheduled.

Log rotation

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
}

Reopening log files

In cases where a log rotation tool doesn't offer a copy-truncate capabilities, or where using them is deemed inappropriate pino.destination and pino.extreme destinations are able to reopen file paths after a file has been moved away.

One way to use this is to set up a SIGUSR2 or SIGHUP signal handler that reopens the log file destination.

const dest = pino.destination('/log/file') // pino.extreme will also work
const logger = require('pino')(dest)
process.on('SIGUSR2', () => dest.reopen())

The log rotation tool can then be configured to send this signal to the process after a log rotation has occurred.

Saving to multiple files

Let's assume we want to store all error messages to a separate log file.

Install pino-tee with:

npm i pino-tee -g

The following writes the log output of app.js to ./all-logs, while writing only warnings and errors to `./warn-log:

node app.js | pino-tee warn ./warn-logs > ./all-logs

Log Filtering

The Pino philosophy advocates common, pre-existing, system utilities.

Some recommendations in line with this philosophy are:

  1. Use grep:
    $ # View all "INFO" level logs
    $ node app.js | grep '"level":30'
  2. Use jq:
    $ # View all "ERROR" level logs
    $ node app.js | jq 'select(.level == 50)'

Transports and systemd

systemd makes it complicated to use pipes in services. One method for overcoming this challenge is to use a subshell:

ExecStart=/bin/sh -c '/path/to/node app.js | pino-transport'

How Pino handles duplicate keys

Duplicate keys are possibly when a child logger logs an object with a key that collides with a key in the child loggers bindings.

See the child logger duplicate keys caveat for information on this is handled.

Log levels as labels instead of numbers

Pino log lines are meant to be parseable. Thus, there isn't any built-in option to change the level from the integer value to the string name. However, there are a couple of options:

  1. If the only change desired is the name then a transport can be used. One such transport is pino-text-level-transport.
  2. Use a prettifier like pino-pretty to make the logs human friendly.

Pino with debug

The popular debug is used in many modules across the ecosystem.

The pino-debug module can capture calls to debug loggers and run them through pino instead. This results in a 10x (20x in extreme mode) performance improvement - event though pino-debug is logging additional data and wrapping it in JSON.

To quickly enable this install pino-debug and preload it with the -r flag, enabling any debug logs with the DEBUG environment variable:

$ npm i pino-debug
$ DEBUG=* node -r pino-debug app.js

pino-debug also offers fine grain control to map specific debug namespaces to pino log levels. See pino-debug for more.