cls-rtracer

cls-rtracer

Request Tracer - Express & Koa middlewares and Fastify & Hapi plugins for CLS-based request id generation, batteries included. An out-of-the-box solution for adding request ids into your logs. Check out this blog post that describes the rationale behind cls-rtracer.

Automatically generates a UUID V1 value as the id for each request and stores it in AsyncLocalStorage (CLS core API, see this blog post). Optionally, if the request contains X-Request-Id header, uses its value instead. Allows to obtain the generated request id anywhere in your routes later and use it for logging or any other purposes.

Tested and works fine with Express v4, Fastify v2 and v3, Koa v1 and v2, and Hapi v18.

Supported Node.js versions

As cls-rtracer v2 depends on AsyncLocalStorage API, it requires Node.js 12.17.0+, 13.14.0+, or 14.0.0+. If you happen to use an older Node.js version, you should use cls-rtracer v1 which is based on cls-hooked.

How to use it - Step 1

Install:

npm install --save cls-rtracer

Note for TypeScript users: typings are included.

How to use it - Step 2 (Common instructions)

Use the middleware (or plugin) provided by the library before the first middleware that needs to have access to request ids. Note that some middlewares, may cause CLS context (i.e. Async Hooks execution path) to get lost. To avoid such issues, you should use any third party middleware that does not need access to request ids before you use this middleware. See issue #20 as an example.

How to use it - Step 2 (Express users)

Use the middleware provided by the library:

const express = require('express')
const rTracer = require('cls-rtracer')

const app = express()
// any third party middleware that does not need access to request ids goes here
// ...

app.use(rTracer.expressMiddleware())
// optionally, you can override default middleware config:
// app.use(rTracer.expressMiddleware({
//   useHeader: true,
//   headerName: 'X-Your-Request-Header'
// }))

// all code in middlewares, starting from here, has access to request ids

Obtain request id in middlewares on the incoming request:

// an example middleware for a generic find entity endpoint
app.get('/api/v1/entity/{id}', (req, res, next) => {
  entityService.find(req.params.id)
    .then((entity) => {
      // you can obtain the request id here
      const requestId = rTracer.id()
      console.log(`requestId: ${requestId}`)
      
      res.json(entity)
    })
    .catch(next)
})

You can access the same request id from code that does not have access to the Express' req object.

// an imaginary entity-service.js
async function find (entityId) {
  // you can obtain the request id here
  const requestId = rTracer.id()
  // ...
}

How to use it - Step 2 (Fastify users)

Use the plugin provided by the library:

const fastify = require('fastify')()
const rTracer = require('cls-rtracer')

// any third party plugin that does not need access to request ids goes here
// ...

fastify.register(rTracer.fastifyPlugin)
// optionally, you can override default plugin config:
// fastify.register(rTracer.fastifyPlugin, {
//   useHeader: true,
//   headerName: 'X-Your-Request-Header'
// }))

// all code in plugins or handlers, starting from here, has access to request ids

Obtain request id in handlers on the incoming request:

// an example handler for a generic find entity endpoint
// router config is skipped for the sake of simplicity
app.get('/test', async (request, reply) => {
  const entity = await entityService.find(request.params.id)
  // you can obtain the request id here
  const requestId = rTracer.id()
  console.log(`requestId: ${requestId}`)

  reply.send(entity)
})

You can access the same request id from code that does not have access to the Fastify's request object.

// an imaginary entity-service.js
async function find (entityId) {
  // you can obtain the request id here
  const requestId = rTracer.id()
  // ...
}

Legacy Fastify middleware

There is a connect-style middleware available for Fastify v2, but it is deprecated and may be removed in one of upcoming releases. If you happen to use it in your application, you should migrate to the Fastify plugin.

fastify.use(rTracer.fastifyMiddleware())

How to use it - Step 2 (Koa users)

Use the middleware provided by the library:

const Koa = require('koa')
const rTracer = require('cls-rtracer')

const app = new Koa()
// any third party middleware that does not need access to request ids goes here
// ...

app.use(rTracer.koaMiddleware())
// optionally, you can override default middleware config:
// app.use(rTracer.koaMiddleware({
//   useHeader: true,
//   headerName: 'X-Your-Request-Header'
// }))

// all code in middlewares, starting from here, has access to request ids

Obtain request id in middlewares on the incoming request:

// an example middleware for a generic find entity endpoint
// router config is skipped for the sake of simplicity
app.use(async (ctx) => {
  const entity = await entityService.find(req.params.id)
  // you can obtain the request id here
  const requestId = rTracer.id()
  console.log(`requestId: ${requestId}`)

  ctx.body = entity
})

You can access the same request id from code that does not have access to the Koa's ctx object.

// an imaginary entity-service.js
async function find (entityId) {
  // you can obtain the request id here
  const requestId = rTracer.id()
  // ...
}

Koa v1 support

For Koa v1 use the koaV1Middleware(options) function.

How to use it - Step 2 (Hapi users)

Use the plugin provided by the library:

const Hapi = require('@hapi/hapi')
const rTracer = require('cls-rtracer')

const init = async () => {
  const server = Hapi.server({
    port: 3000,
    host: 'localhost'
  })
  // any third party plugin that does not need access to request ids goes here
  // ...

  await server.register({
    plugin: rTracer.hapiPlugin
  })

  // optionally, you can override default middleware config:
  //  await server.register({
  //    plugin: rTracer.hapiPlugin,
  //    options: {
  //      useHeader: true,
  //      headerName: 'X-Your-Request-Header'
  //    }
  //  })

  // all code in routes, starting from here, has access to request ids
}

init()

Obtain request id in route handlers on the incoming request:

// an example route for a generic find entity endpoint
server.route({
  method: 'GET',
  path: '/test',
  handler: async (request, h) => {
    const entity = await entityService.find(request.params.id)
    // you can obtain the request id here
    const requestId = rTracer.id()
    console.log(`requestId: ${requestId}`)

    return entity
  }
})

You can access the same request id from code that does not have access to the Hapi's request object.

// an imaginary entity-service.js
async function find (entityId) {
  // you can obtain the request id here
  const requestId = rTracer.id()
  // ...
}

Integration with loggers

The main use case for this library is request id generation and logging automation. You can integrate with any logger library in a single place and get request ids in logs across your application.

Without having request id, as a correlation value, in your logs, you will not be able to determine which log entries belong to code that handles the same request. You could generate request ids manually and store them in the Express' req object (or Fastify's request, or Koa's ctx), but then you will have to explicitly pass the object into all other modules on the route. And that's when cls-rtracer comes to the rescue!

Complete samples for Express, Fastify and Koa are available in /samples/ directory.

Winston

Here is how you can integrate cls-rtracer with winston, one of most popular logging libraries.

const { createLogger, format, transports } = require('winston')
const { combine, timestamp, printf } = format

// a custom format that outputs request id
const rTracerFormat = printf((info) => {
  const rid = rTracer.id()
  return rid
    ? `${info.timestamp} [request-id:${rid}]: ${info.message}`
    : `${info.timestamp}: ${info.message}`
})

const logger = createLogger({
  format: combine(
    timestamp(),
    rTracerFormat
  ),
  transports: [new transports.Console()]
})

Pino

This is how you can integrate cls-rtracer with pino logger.

// mixin function adds properties of the returned object to the logged JSON.
const logger = require('pino')({
    mixin () {
        return { requestId: rTracer.id() }
    }
})

Configuration

These are the available config options for the middleware/plugin functions. All config entries are optional.

{
  // Add request id to response header (default: false).
  // If set to true, the middleware/plugin will add request id to the specified
  // header. Use headerName option to specify header name.
  echoHeader: false,
  // Respect request header flag (default: false).
  // If set to true, the middleware/plugin will always use a value from
  // the specified header (if the value is present).
  useHeader: false,
  // Request/response header name, case insensitive (default: 'X-Request-Id').
  // Used if useHeader/echoHeader is set to true.
  headerName: 'X-Request-Id',
  // A custom function to generate your request ids (default: UUID v1).
  // The function will receive the intercepted request (as-is from the framework
  // being used) as its first argument. The returned id could be a usual string,
  // or a number, or any custom object, like in the example below.
  // Ignored if useHeader is set to true.
  requestIdFactory: (req) => ({
    id: 'Your request id',
    customHeader: req.headers['X-Custom-Header']
  }),
  // Use request id generated by Fastify instead of generating a new id.
  // Only available for the Fastify plugin.
  useFastifyRequestId: false,
}

Advanced features

If you need something different from the default UUID v1 for id generation, you should use the requestIdFactory function available in the middleware/plugin config. Note that this function allows storing any object as the id, not only primitive values or strings.

In certain situations you may want to have an id available outside of the request handler scope, say, in a code that acts as a background job. In this case you may use the runWithId() function:

const rTracer = require('cls-rtracer')

rTracer.runWithId(() => {
  console.log(rTracer.id()) // id is available here
  setInterval(() => {
    console.log(rTracer.id()) // and here
  }, 1000)
})

// you may override id by providing the 2nd argument
rTracer.runWithId(() => {
  // ...
}, 42) // 42 is the id override here

// async/await syntax is also supported, as `runWithId()`
// returns the result of `fn`
await rTracer.runWithId(myAsyncFn)

Troubleshooting

To avoid weird behavior:

• Make sure you use any third party middleware (or plugin) that does not need access to request ids before you use cls-rtracer. See this section.

Note: there is a small chance that you are using one of rare libraries that do not play nice with Async Hooks API. So, if you face the issue when the context (and thus, the request id) is lost at some point of async calls chain, please submit GitHub issue with a detailed description.

Performance impact

Note that this library has a certain performance impact on your application due to Async Hooks API usage. So, you need to decide if the benefit of being able to trace requests in logs without any boilerplate is more valuable for you than the disadvantage of performance impact.

The author of this library did some basic performance testing. See this tweet to see the results. The overhead also decreased in cls-rtracer v2 due to migration to the core API. See this tweet to learn more.

License

Licensed under MIT.