Arrange Act Assert

Jag Reehals thinking on things, mostly product development

Don't repeat yourself: Why you should use child loggers in Node.js

20 Feb 2023

Logging is an essential part of any application, providing insight into the what's happening behind the scenes. However, as your codebase grows, it can be challenging to keep track of all the different log statements and where they're coming from. This is where child loggers come in.

Child loggers are a feature of many of the Node.js logging libraries such as Pino, Bunyan and winston have that allow you to create a new logger that inherits the configuration of its parent logger.

This means you can create child loggers that are pre-configured with specific options, making it easier to log messages without repeating the same configuration over and over again.

In this blog post, we'll take a look at an example of how child loggers can help cut down on repetition in TypeScript and Pino.

In this example, we have a function handleRequest that handles an incoming HTTP request. We extract the x-request-id and x-user-id headers from the request and use them as context for our log statements.

import pino from 'pino';

const logger = pino({
  transport: {
    target: 'pino-pretty',
  },
});

function handleRequest(req, res) {
  const requestId = req.headers['x-request-id'];
  const userId = req.headers['x-user-id'];

  logger.info({ requestId, userId }, 'Handling request');

  logger.info({ requestId, userId }, 'Processing request');

  logger.info({ requestId, userId }, 'Finished handling request');

  res.send('Success');
}

const req = {
  headers: {
    'x-request-id': '123',
    'x-user-id': '456',
  },
};
const res = {
  send: (msg) => console.log(msg),
};
handleRequest(req, res);

As you can see the in the code above we're repeating the same details on every log line. This can make the code harder to read and maintain, and it also means that we have to remember to include the same details on every log line.

The log output looks like this:

[19:40:01.825] INFO (73183): Handling request
    requestId: "123"
    userId: "456"
[19:40:01.825] INFO (73183): Processing request
    requestId: "123"
    userId: "456"
[19:40:01.825] INFO (73183): Finished handling request
    requestId: "123"
    userId: "456"

Using Child Loggers to Simplify Logging

Using a child logger, we can simplify this code and make it easier to read and maintain. Here's an example of how we could refactor the code to use a child logger:

import pino from 'pino';

const logger = pino({
  prettyPrint: true,
});

function handleRequest(req, res) {
  const requestId = req.headers['x-request-id'];
  const userId = req.headers['x-user-id'];

  /*
  Next, we create a child logger using logger.child({ requestId, userId }).
  
  This child logger inherits all the settings of the parent logger,
  and also includes the requestId and userId as context.   
  */
  const childLogger = logger.child({ requestId, userId });

  /*
  We then use the child logger to log additional messages, which automatically
  include the context provided at creation time.
  */

  childLogger.info('Starting to handle request');

  childLogger.info('Processing request');

  childLogger.info('Finished handling request');

  res.send('Success');
}

The log output looks like this:

[19:40:01.263] INFO (73809): Starting to handle request
    requestId: "123"
    userId: "456"
[19:40:01.263] INFO (73809): Processing request
    requestId: "123"
    userId: "456"
[19:40:01.263] INFO (73809): Finished handling request
    requestId: "123"
    userId: "456"

As the code above shows using a child logger in this way provides several benefits over repeating the same details on every log line e.g.

logger.info({ requestId, userId }, 'Processing request');
// vs.
childLogger.info('Processing request');

First, it reduces the amount of code required to log context, making the code more concise and easier to read.

Second, it ensures that all log statements for a particular request include the same context, which can be helpful for debugging.

Finally, it allows you to easily add or remove context as needed without modifying all of your log statements.

Give them a try

If you're not already using child loggers in your code, give them a try! They can make a big difference in the readability and maintainability of your logging code.

Child loggers are not only the future of efficient logging, but they also remind us that even in code, children are the future.

Node.js logging