roarr

What is roarr?

Roarr is a lightweight and fast logger for Node.js applications. It is designed to be simple, performant, and easy to use, providing structured logging capabilities with minimal overhead.

What are roarr's main functionalities?

Basic Logging

Roarr allows you to create a logger instance and log messages with different severity levels. In this example, an info message is logged.

const Roarr = require('roarr');
const log = Roarr.child({ application: 'my-app' });
log.info('This is an info message');

Child Loggers

Roarr supports creating child loggers that inherit context from their parent loggers. This is useful for adding additional context to logs in different parts of your application.

const Roarr = require('roarr');
const parentLog = Roarr.child({ application: 'my-app' });
const childLog = parentLog.child({ module: 'my-module' });
childLog.debug('This is a debug message from my-module');

Structured Logging

Roarr supports structured logging, allowing you to log additional context as JSON objects. This makes it easier to analyze and search logs.

const Roarr = require('roarr');
const log = Roarr.child({ application: 'my-app' });
log.info({ userId: 123, action: 'login' }, 'User login event');

Log Level Filtering

Roarr allows you to filter logs by severity level using the ROARR_LOG environment variable. In this example, only debug and higher severity logs will be output.

process.env.ROARR_LOG = 'debug';
const Roarr = require('roarr');
const log = Roarr.child({ application: 'my-app' });
log.debug('This is a debug message');
log.info('This is an info message');

Other packages similar to roarr

winston

Winston is a versatile logging library for Node.js with support for multiple transports, log levels, and formats. It is more feature-rich compared to Roarr but also comes with more complexity and overhead.

pino

Pino is a fast and low-overhead logging library for Node.js, similar to Roarr in terms of performance. Pino offers more features out of the box, such as log rotation and serializers, but may be slightly more complex to set up.

bunyan

Bunyan is a JSON logging library for Node.js that provides structured logging and log levels. It is similar to Roarr in its focus on structured logging but includes additional features like log streams and serializers.

README

Roarr

JSON logger for Node.js and browser.

• Motivation
• Usage
  • Prepending context using the global state
  • Filtering logs
    • jq primer
• Log message format
• API
  • child
  • trace
  • debug
  • info
  • warn
  • error
  • fatal
• CLI program
• Transports
• Environment variables
• Conventions
  • Context property names
  • Using Roarr in an application
  • Using Roarr in modules
• Recipes
  • Logging errors
  • Using with Elasticsearch

Motivation

For a long time I have been a big fan of using debug. debug is simple to use, works in Node.js and browser, does not require configuration and it is fast. However, problems arise when you need to parse logs. Anything but one-line text messages cannot be parsed in a safe way.

To log structured data, I have been using Winston and Bunyan. These packages are great for application-level logging. I have preferred Bunyan because of the Bunyan CLI program used to pretty-print logs. However, these packages require program-level configuration – when constructing an instance of a logger, you need to define the transport and the log-level. This makes them unsuitable for use in code designed to be consumed by other applications.

Then there is pino. pino is fast JSON logger, it has CLI program equivalent to Bunyan, it decouples transports, and it has sane default configuration. Unfortunately, you still need to instantiate logger instance at the application-level. This makes it more suitable for application-level logging just like Winston and Bunyan.

I needed a logger that:

• Does not require initialisation.
• Produces structured data.
• Decouples transports.
• Has a CLI program.
• Works in Node.js and browser.
• Configurable using environment variables and global namespace.

In other words,

• a logger that I can use in an application code and in dependencies.
• a logger that allows to correlate logs between the main application code and the dependency code.
• a logger that works well with transports in external processes.

Roarr is this logger.

Usage

Roarr logging is disabled by default. To enable logging, you must start program with an environment variable ROARR_LOG set to true, e.g.

ROARR_LOG=true node ./index.js

import log from 'roarr';

log('foo');

log('bar %s', 'baz');

const debug = log.child({
  logLevel: 10
});

debug('qux');

debug({
  quuz: 'corge'
}, 'quux');

Produces output:

{"context":{},"message":"foo","sequence":0,"time":1506776210000,"version":"1.0.0"}
{"context":{},"message":"bar baz","sequence":1,"time":1506776210000,"version":"1.0.0"}
{"context":{"logLevel":10},"message":"qux","sequence":2,"time":1506776210000,"version":"1.0.0"}
{"context":{"logLevel":10,"quuz":"corge"},"sequence":3,"message":"quux","time":1506776210000,"version":"1.0.0"}

Prepending context using the global state

Prepending context using the global state will affect all roarr logs.

import log from 'roarr';

log('foo');

global.ROARR.prepend = {
  taskId: 1
};

log('bar');

global.ROARR.prepend = {};

log('baz');

Produces output:

{"context":{},"message":"foo","sequence":0,"time":1506776210000,"version":"1.0.0"}
{"context":{"taskId":1},"message":"bar","sequence":1,"time":1506776210000,"version":"1.0.0"}
{"context":{},"message":"baz","sequence":2,"time":1506776210000,"version":"1.0.0"}

Prepending context using the global state is useful when the desired result is to associate all logs with a specific context for a duration of an operation, e.g. to correlate the main process logs with the dependency logs.

import log from 'roarr';
import foo from 'foo';

const taskIds = [
  1,
  2,
  3
];

for (const taskId of taskIds) {
  global.ROARR = global.ROARR || {};
  global.ROARR.prepend = {
    taskId
  };

  log('starting task ID %d', taskId);

  // In this example, `foo` is an arbitrary third-party dependency that is using
  // roarr logger.
  foo(taskId);

  log('successfully completed task ID %d', taskId);

  global.ROARR.prepend = {};
}

Produces output:

{"context":{"taskId":1},"message":"starting task ID 1","sequence":0,"time":1506776210000,"version":"1.0.0"}
{"context":{"taskId":1},"message":"foo","sequence":1,"time":1506776210000,"version":"1.0.0"}
{"context":{"taskId":1},"message":"successfully completed task ID 1","sequence":2,"time":1506776210000,"version":"1.0.0"}
[...]

Filtering logs

Roarr is designed to print all or none logs (refer to the ROARR_LOG environment variable documentation).

To filter logs you need to use a JSON processor, e.g. jq.

jq primer

jq allows you to filter JSON messages using select(boolean_expression), e.g.

ROARR_LOG=true node ./index.js | jq 'select(.context.logLevel > 40)'

Combine it with roarr pretty-print to pretty-print a subset of the logs:

ROARR_LOG=true node ./index.js | jq -cM 'select(.context.logLevel > 40)'

(Notice the use of -cM parameters to disable JSON colarization and formatting.)

Log message format

Property name	Contents
context	Arbitrary, user-provided structured data. See context property names.
message	User-provided message formatted using printf.
sequence	An incremental ID.
time	Unix timestamp in milliseconds.
version	Roarr log message format version.

Example:

{
  "context": {
    "application": "task-runner",
    "hostname": "curiosity.local",
    "instanceId": "01BVBK4ZJQ182ZWF6FK4EC8FEY",
    "taskId": 1
  },
  "message": "starting task ID 1",
  "sequence": 0,
  "time": 1506776210000,
  "version": "1.0.0"
}

API

roarr package exports a function that accepts the following API:

export type LoggerType =
  (
    context: MessageContextType,
    message: string,
    c?: SprintfArgumentType,
    d?: SprintfArgumentType,
    e?: SprintfArgumentType,
    f?: SprintfArgumentType,
    g?: SprintfArgumentType,
    h?: SprintfArgumentType,
    i?: SprintfArgumentType,
    k?: SprintfArgumentType
  ) => void |
  (
    message: string,
    b?: SprintfArgumentType,
    c?: SprintfArgumentType,
    d?: SprintfArgumentType,
    e?: SprintfArgumentType,
    f?: SprintfArgumentType,
    g?: SprintfArgumentType,
    h?: SprintfArgumentType,
    i?: SprintfArgumentType,
    k?: SprintfArgumentType
  ) => void;

To put it into words:

• First parameter can be either a string (message) or an object.
  • If first parameter is an object (context), the second parameter must be a string (message).
• Arguments after the message parameter are used to enable printf message formatting.
  • Printf arguments must be of a primitive type (string | number | boolean | null).
  • There can be up to 9 printf arguments (or 8 if the first parameter is the context object).

Refer to the Usage documentation for common usage examples.

child

Creates a child logger appending the provided context object to the previous logger context.

type ChildType = (context: MessageContextType) => LoggerType;

trace

debug

info

warn

error

fatal

Convenience methods for logging a message with logLevel context property value set to the name of the convenience method, e.g.

import log from 'roarr';

log.trace('foo');
log.debug('foo');
log.info('foo');
log.warn('foo');
log.error('foo');
log.fatal('foo');

Produces output:

{"context":{"logLevel":10},"message":"foo","sequence":0,"time":1506776210000,"version":"1.0.0"}
{"context":{"logLevel":20},"message":"foo","sequence":1,"time":1506776210000,"version":"1.0.0"}
{"context":{"logLevel":30},"message":"foo","sequence":2,"time":1506776210000,"version":"1.0.0"}
{"context":{"logLevel":40},"message":"foo","sequence":3,"time":1506776210000,"version":"1.0.0"}
{"context":{"logLevel":50},"message":"foo","sequence":4,"time":1506776210000,"version":"1.0.0"}
{"context":{"logLevel":60},"message":"foo","sequence":5,"time":1506776210000,"version":"1.0.0"}

CLI program

Roarr comes with a CLI program used to pretty-print logs for development purposes.

To format the logs, pipe the program output to roarr pretty-print program, e.g.

$ npm install roarr -g
$ ROARR_LOG=true node index.js | roarr pretty-print

Provided that the index.js program produced an output such as:

{"context":{"package":"forward-proxy","namespace":"createHttpProxyServer","logLevel":30},"message":"Internal SSL Server running on localhost:62597","sequence":0,"time":1506803138704,"version":"1.0.0"}
{"context":{"package":"forward-proxy","namespace":"createRequestProcessor","logLevel":30},"message":"request start -> http://localhost:62595/","sequence":1,"time":1506803138741,"version":"1.0.0"}
{"context":{"package":"forward-proxy","namespace":"createLogInterceptor","logLevel":20,"headers":{"host":"localhost:62595","connection":"close"}},"message":"received request","sequence":2,"time":1506803138741,"version":"1.0.0"}
{"context":{"package":"forward-proxy","namespace":"createRequestProcessor","logLevel":30},"message":"request finished <- http://localhost:62595/","sequence":3,"time":1506803138749,"version":"1.0.0"}
{"context":{"package":"forward-proxy","namespace":"createLogInterceptor","logLevel":30,"method":"GET","requestHeaders":{"host":"localhost:62595","connection":"close"},"responseHeaders":{"date":"Sat, 30 Sep 2017 20:25:38 GMT","connection":"close","content-length":"7","x-forward-proxy-request-id":"2b746d92-1a8b-4f36-b3cc-5bff57dad94d","x-forward-proxy-cache-hit":"false"},"statusCode":200,"url":"http://localhost:62595/"},"message":"response","sequence":4,"time":1506803138755,"version":"1.0.0"}
{"context":{"package":"forward-proxy","namespace":"createLogInterceptor","logLevel":30,"method":"GET","requestHeaders":{"host":"localhost:62595","connection":"close"},"responseHeaders":{"date":"Sat, 30 Sep 2017 20:25:38 GMT","content-length":"7","x-forward-proxy-request-id":"2b746d92-1a8b-4f36-b3cc-5bff57dad94d","x-forward-proxy-cache-hit":"true"},"statusCode":200,"url":"http://localhost:62595/"},"message":"response","sequence":5,"time":1506803138762,"version":"1.0.0"}

roarr CLI program will format the output to look like this:

• @ prefixed value denotes the name of the package.
• # prefixed value denotes the namespace.

The roarr pretty-print CLI program is using the context property names suggested in the conventions to pretty-print the logs for the developer inspection purposes.

Explore other CLI commands and options using roarr --help.

Transports

A transport in most logging libraries is something that runs in-process to perform some operation with the finalised log line. For example, a transport might send the log line to a standard syslog server after processing the log line and reformatting it.

Roarr does not support in-process transports.

Roarr does not support in-process transports because Node processes are single threaded processes (ignoring some technical details). Given this restriction, Roarr purposefully offloads handling of the logs to external processes so that the threading capabilities of the OS can be used (or other CPUs).

Depending on your configuration, consider one of the following log transports:

• Beats for aggregating at a process level (written in Go).
• logagent for aggregating at a process level (written in JavaScript).
• Fluentd for aggregating logs at a container orchestration level (e.g. Kubernetes) (written in Ruby).

Environment variables

When running the script in a Node.js environment, use environment variables to control roarr behaviour.

Name	Type	Function	Default
ROARR_LOG	Boolean	Enables/ disables logging.	false
ROARR_STREAM	STDOUT, STDERR	Name of the stream where the logs will be written.	STDOUT

When using ROARR_STREAM=STDERR, use 3>&1 1>&2 2>&3 3>&- to pipe stderr output.

Conventions

Context property names

Roarr does not have reserved context property names. However, I encourage use of the following conventions:

Context property name	Use case
application	Name of the application (do not use in code intended for distribution; see package property instead).
hostname	Machine hostname. See roarr augment --append-hostname option.
instanceId	Unique instance ID. Used to distinguish log source in high-concurrency environments. See roarr augment --append-instance-id option.
logLevel	A numeric value indicating the log level. See API for the build-in loggers with a pre-set log-level.
namespace	Namespace within a package, e.g. function name. Treat the same way that you would construct namespaces when using the debug package.
package	Name of the package.

The roarr pretty-print CLI program is using the context property names suggested in the conventions to pretty-print the logs for the developer inspection purposes.

Log levels

The roarr pretty-print CLI program translates logLevel values to the following human-readable names:

logLevel	Human-readable name
10	TRACE
20	DEBUG
30	INFO
40	WARN
50	ERROR
60	FATAL

Using Roarr in an application

To avoid code duplication, you can use a singleton pattern to export a logger instance with predefined context properties (e.g. describing the application).

I recommend to create a file Logger.js in the project directory. Use this file to create an child instance of Roarr with context parameters describing the project and the initialisation instance, e.g.

/**
 * @file Example contents of a Logger.js file.
 */

import log from 'roarr';
import ulid from 'ulid';

// Instance ID is useful for correlating logs in high concurrency environment.
//
// See `roarr augment --append-instance-id` option as an alternative way to
// append instance ID to all logs.
const instanceId = ulid();

// The reason we are using `global.ROARR.prepend` as opposed to `roarr#child`
// is because we want this information to be prepended to all logs, including
// those of the "my-application" dependencies.
//
// Note: If you are adding logger to a package intended to be consumed by other
// packages, you must not set `global.ROARR.prepend`. Instead, use `roarr#child`.
global.ROARR.prepend = {
  ...global.ROARR.prepend,
  application: 'my-application',
  instanceId
};

const Logger = log.child({
  // .foo property is going to appear only in the logs that are created using
  // the current instance of a Roarr logger.
  foo: 'bar'
});

export default Logger;

Using Roarr in modules

If you are developing a code that is designed to be consumed by other applications/ modules, then you should avoid using global.ROARR (though, there are valid use cases). However, you should still start the project by defining a Logger.js file and use log.child instead.

/**
 * @file Example contents of a Logger.js file.
 */
import Roarr from 'roarr';

export default Roarr.child({
  domain: 'database',
  package: 'my-package'
});

Roarr does not have reserved context property names. However, I encourage use of the conventions. The roarr pretty-print CLI program is using the context property names suggested in the conventions to pretty-print the logs for the developer inspection purposes.

Recipes

Logging errors

This is not specific to Roarr – this suggestion applies to any kind of logging.

If you want to include an instance of Error in the context, you must serialize the error.

The least-error prone way to do this is to use an existing library, e.g. serialize-error.

Without using serialisation, your errors will be logged without the error name and stack trace.

Using with Elasticsearch

If you are using Elasticsearch, you will want to create an index template.

The following serves as the ground work for the index template. It includes the main Roarr log message properties (context, message, time) and the context properties suggested in the conventions.

{
  "mappings": {
    "log_message": {
      "_source": {
        "enabled": true
      },
      "dynamic": "strict",
      "properties": {
        "context": {
          "dynamic": true,
          "properties": {
            "application": {
              "type": "keyword"
            },
            "hostname": {
              "type": "keyword"
            },
            "instanceId": {
              "type": "keyword"
            },
            "logLevel": {
              "type": "integer"
            },
            "namespace": {
              "type": "text"
            },
            "package": {
              "type": "text"
            }
          }
        },
        "message": {
          "type": "text"
        },
        "time": {
          "format": "epoch_millis",
          "type": "date"
        }
      }
    }
  },
  "template": "logstash-*"
}