This post covers some logging practices for the back-end (Node.js) apps.

• Avoid putting unique identifiers (e.g., user id) within the message. A unique id will produce a lot of different messages with the same context. Use it as a message parameter.

• Use the appropriate log level for the message. There are multiple log levels

  • info - app behavior, don't log every single step
  • error - app processing failure, something that needs to be fixed
  • debug - additional logs needed for troubleshooting
  • warning - something unexpected happened (e.g., third-party API fails)
  • fatal - app crash, needs to be fixed as soon as possible

Don't use the debug logs on production. Put log level as an environment variable.

• Stream logs to the standard output in JSON format so logging aggregators (Graylog, e.g.) can collect and adequately parse them

• Avoid logging any credentials, like passwords, auth tokens, etc.

• Put correlation ID as a message parameter for tracing related logs.

• Use a configurable logger like pino

const pino = require('pino');
const logger = pino({
  level: process.env.LOG_LEVEL || 'info',
  redact: {
    paths: ['token'],
    remove: true,
  },
});
logger.info({ someId: 'id' }, 'Started the app...');
const correlationId = request.headers['correlation-id'] || uuid.v4();
logger.debug({ data: 'some data useful for debugging', correlationId }, 'Sending the request...');

Boilerplate

Here is the link to the boilerplate I use for the development.

Logs are usually streamed to the standard output in JSON format so logging aggregators (Graylog, e.g.) can collect and adequately parse them.

The following example shows how bash script output can be formatted with the message, log levels, and timestamp. Error logs are streamed into a temporary file, formatted, and redirected to the standard output.

#!/usr/bin/env bash
declare -A log_levels=( [FATAL]=0 [ERROR]=3 [WARNING]=4 [INFO]=6 [DEBUG]=7)
json_logger() {
  log_level=$1
  message=$2
  level=${log_levels[$log_level]}
  timestamp=$(date --iso-8601=seconds)
  jq --raw-input --compact-output \
    '{
      "level": '$level',
      "timestamp": "'$timestamp'",
      "message": .
    }'
}
{
  set -e
  echo $? 1>&2
  echo "Finished"
} 2>/tmp/stderr.log | json_logger "INFO"
cat /tmp/stderr.log | json_logger "ERROR"