Context-aware Logging in Node.js

Context-aware Logging in Node.js

Learn how to add crucial context to your log messages in Node.js. Let’s take a look at how we would go about attaching a request identifier to each log created by an Express.js application.

By themselves, log messages can only tell you so much. Learn how to add crucial context to your log messages in Node.js.

One of the most basic requirements of good application monitoring is to have robust logging to keep track of everything that’s going on. By themselves, however, the log messages can only tell us so much. Seeing a log message indicating that a video has been uploaded is informative, but usually we would also like to have some context for this “event.”

The bare minimum contextual information that should be included in each log message is a request identifier. Being able to group together all logs produced by a single request allows us to easily track its lifecycle and monitor its behavior at various stages. A context could also include the currently authenticated user’s ID and the place from which the log was sent, like UserService, among other things.

Basic methods for tracking requests, and why they’re not enough

Let’s take a look at how we would go about attaching a request identifier to each log created by an Express.js application.

The most straightforward approach would be to attach an ID to a request and use it everywhere, like so:

req.id = uuid.v4();

And then manually attach it to the log in a handler:

// handler
logger.log('This is a log from the handler for the request with id:', req.id)

At first it may seem a good solution, albeit a little bit tedious and repetetive.

Manually attaching req.id to each log would be repetitive, yes, but one could argue that it would be eventually replaced by an object that could then be easily formatted by the log method:

logger.log('This is a log from the handler for the request', { requestId: req.id })

By passing this “context” object as a second argument, we could then attach it to the log message automatically. However, the problem is more apparent when we try to log a message from a function that doesn’t have access to the request object:

app.use((req) => createUser())

function createUser() { logger.log('User created!', {}) }

The createUser function has no clue which request caused its execution.

The issue could be fixed by passing the “context” argument to the createUser function, but that wouldn’t solve anything. What if there was another function that was called by createUser? All the functions that had to log something would have to accept this “context” parameter, making the code a mess as a result.

Instead, a better solution would be for the logger to somehow know that this incoming log message was called by a handler dealing with a request with a given ID. By having this “context-aware” logger, we wouldn’t have to worry about passing this context object around and get all the necessary information directly in the logger.log method. The information could then be attached to each outgoing log message automatically.

Although many developers may not be familiar with this feature, Node allows us to track a “chain” of function calls, both synchronous and asynchronous, with the use of a feature called async hooks introduced back in Node 8.

Although you might assume the feature is mature since it’s been around for quite a while, it’s actually still considered experimental as of Node 15. There’s no need to worry, though — a library called cls-hooked has been around even longer than async hooks and has provided a consistent and stable API for creating and keeping track of asynchronous context that is propagated through a chain of function calls.

A chain of function calls is a fancy way of saying that there’s a function one(), which calls function two(), which then goes and calls a bunch of other functions. So it’s like a function call stack for both synchronous and asynchronous functions.

Let’s take a look at how to create and manage an asynchronous context with cls-hooked.

Using cls-hooked for context-aware logging in Node

In order to install the library, run:

npm install --save cls-hooked

Creating a namespace

A namespace is an object that provides an API for getting and setting values in the asynchronous context available in the current function chain.

Creating a namespace is as simple as writing:

const applicationNamespace = createNamespace('APP_NAMESPACE');

In order to make use of the asynchronous context in a chain of function calls, we have to explicitly run the “top” function in a context-aware callback, like so:

applicationNamespace.run(contextAwareFunction);

By using the .run() method we are saying that the namespace should create an empty context and supply it to the contextAwareFunction and all the function calls originating therefrom.

The usage of the get and set methods of the namespace is very intuitive, as you can see in the following example:

import { createNamespace } from 'cls-hooked';

const applicationNamespace = createNamespace('APP_NAMESPACE');

function deepContextAwareFunction() {
  console.log(applicationNamespace.get('TEST'));
}

function contextAwareFunction() {
  applicationNamespace.set('TEST', 150);

  deepContextAwareFunction();
}

applicationNamespace.run(() => contextAwareFunction());

The console.log method will yield 150, as expected.

Now that we know the library’s API, let’s try to integrate it into a real-world example with an Express application.

node express javascript programming developer

Bootstrap 5 Complete Course with Examples

Bootstrap 5 Tutorial - Bootstrap 5 Crash Course for Beginners

Nest.JS Tutorial for Beginners

Hello Vue 3: A First Look at Vue 3 and the Composition API

Building a simple Applications with Vue 3

Deno Crash Course: Explore Deno and Create a full REST API with Deno

How to Build a Real-time Chat App with Deno and WebSockets

Convert HTML to Markdown Online

HTML entity encoder decoder Online

Node.js Express Bulk Email Validation Checker in JavaScript

Node.js Express Bulk Email Validation Checker in Javascript Using bulk-email-verifier Library 2020. We will be building a bulk domain or website validator checker in node.js and express. For this we will be using a node.js library called as bulk-email-verifier.

Node.js Express Text Repeater Generator Online Tool in Javascript Full Tutorial 2020

Node.js Express Text Repeater Generator Online Tool in Javascript Full Tutorial 2020

Node.js Express PDF to HTML Files Converter Web Application Online in Javascript 2020

Node.js Express PDF to HTML Files Converter Web Application Online in Javascript 2020

Node.js Express Youtube Video URL Timestamp Link Generator in JavaScript Full Project 2020

Node.js Express Youtube Video URL Timestamp Link Generator in Javascript Full Project 2020

Top Node.js Development Companies and Expert NodeJS Developers

A thoroughly researched list of top NodeJS development companies with ratings & reviews to help hire the best Node.JS developers who provide development services and solutions across the world. List of Leading Node.js development Service Providers...