@revmob/logger NPM

Logger

A Techmob InnerSource library for logging. It encapsulates the pino library, adding the following features:

Support for continuation-local-storage to allow distributed logging.
Sane default configurations.

There is no support for custom transports, as this should not be a responsibility of the application.

Principles

1. Structured logging

The log format output is JSON.

2. Context-first

Instead of:

logger.info('Some message', context)

Use as:

logger.info(context, 'Some message')

3. Distributed logging ready

Example: generating a unique ID for a request — if it's not provided through the X-Request-ID header — and attaching it to the log context:

For each incomming request, the generated request-id is guaranteed to be unique by the uuid implementation. An alternative to uuid is cuid.

const uuid = require('uuid')
const express = require('express')
const logger = require('@revmob/logger').default()

const app = express()

app.use([
    (req, res, next) => {
        logger.ns.run(() => {
            const requestId = req.get('X-Request-ID') || uuid.v1()
            logger.ns.set('request-id', requestId)
            next()
        }) 
    }
])

logger.log('This is awesome!')

Outputs:

{ ... "request-id": "aaaaaaaa-bbbb-cccc-dddd-eeeeeeeeeeee", "msg": "This is awesome!", ...  }

The ns property holds an instance of a continuation-local-storage namespace. See the docs for more details.

Installation

npm install --save pino pino-noir @revmob/logger

Both pino and pino-noir are peer dependencies of @revmob/logger.

Usage

General usage

For most use cases, you want to have just one instance of the logger in your application:

// logger.js
const config = {
   // ...
}

const instance = require('@revmob/logger').default(config)

// or
import logger from '@revmob/logger'
const instance = logger(config)

Where config is an object containing configuration parameters accepted by pino. It can also be ommited,

Example:

const log = require('@revmob/logger').default()

log.trace('This entry will be shown')
log.debug('All entries with level above verbose will be shown')
log.info('I am shown')
log.warn('I am bigger than info')
log.error('Behold, I am the greatest!')
log.fatal('Poor child, I am the ultimate log!')

Output:

{"level":10,"time":1512596602556,"msg":"This entry will be shown","name":"main","pid":18886,"hostname":"henrique-All-Series","v":1}
{"level":20,"time":1512596602557,"msg":"All entries with level above verbose will be shown","name":"main","pid":18886,"hostname":"henrique-All-Series","v":1}
{"level":30,"time":1512596602558,"msg":"I am shown","name":"main","pid":18886,"hostname":"henrique-All-Series","v":1}
{"level":40,"time":1512596602558,"msg":"I am bigger than info","name":"main","pid":18886,"hostname":"henrique-All-Series","v":1}
{"level":50,"time":1512596602558,"msg":"Behold, I am the greatest!","name":"main","pid":18886,"hostname":"henrique-All-Series","v":1}
{"level":60,"time":1512596602558,"msg":"Poor child, I am the ultimate log!","name":"main","pid":18886,"hostname":"henrique-All-Series","v":1}

If we specify a level in the config, all logs bellow that threshold will not be displayed:

const log = require('@revmob/logger').default({
    level: 'warn'
})

Output:

{"level":40,"time":1512596602558,"msg":"I am bigger than info","name":"main","pid":18886,"hostname":"henrique-All-Series","v":1}
{"level":50,"time":1512596602558,"msg":"Behold, I am the greatest!","name":"main","pid":18886,"hostname":"henrique-All-Series","v":1}
{"level":60,"time":1512596602558,"msg":"Poor child, I am the ultimate log!","name":"main","pid":18886,"hostname":"henrique-All-Series","v":1}

Development time

JSON logs are not exactly friendly to human eyes. To aid this, use pino CLI in development to get a better output:

const log = require('@revmob/logger').default()

log.trace('This entry will be shown')
log.debug('All entries with level above verbose will be shown')
log.info('I am shown')
log.warn('I am bigger than info')
log.error('Behold, I am the greatest!')
log.fatal('Poor child, I am the ultimate log!')

log.info({ foo: 'bar' }, 'Hey, look! I have context')
log.info(new Error('I\'m an error'), 'Hey, look! I have an error context')

Running:

node app.js | npx pino pretty

Output:

Pretty Print

NOTICE: for npm@<5.2.0, npx is not available. Change the command after the pipe to $(npm bin)/pino pretty.

Forking

We can fork the logger to change some of its properties when needed:

const log = require('@revmob/logger').default()

log.trace('This entry will be shown')
log.debug('All entries with level above verbose will be shown')
log.info('I am shown')
log.warn('I am bigger than info')
log.error('Behold, I am the greatest!')
log.fatal('Poor child, I am the ultimate log!')

log.info({ foo: 'bar' }, 'Hey, look! I have context')
log.info(new Error('I\'m an error'), 'Hey, look! I have an error context')

const child = log.child({
  name: 'child',
  level: 'error'
})

child.trace('This entry will be shown')
child.debug('All entries with level above verbose will be shown')
child.info('I am shown')
child.warn('I am bigger than info')
console.log('\n\n-----------------------------------------------\n\n')
child.error('Behold, I am the greatest!')
child.fatal('Poor child, I am the ultimate log!')

Output:

Forking

Configuration

The config object is forwarded to pino.

The default config is:

({
  level,
  extreme,
  base: {
    name: 'main',
    pid: process.pid,
    hostname: hostname()
  },
  serializers: Object.assign(
    {
      req: req => ({
        id: req.id,
        method: req.method,
        url: req.url,
        body: req.body,
        headers: req.headers,
        remoteAddress: req.connection && req.connection.remoteAddress,
        remotePort: req.connection && req.connection.remotePort
      }),
      res: pino.stdSerializers.res,
      err: pino.stdSerializers.err
    },
    noir([
      'err.options.auth.*',
      'options.auth.*',
      'auth.*',
      'secret',
      'password',
      'pass'
    ], '****')
  )
})

We are free to patch this configuration.