How to trace request id in Loopback 4?

Question

I am trying to trace each HTTP request in my REST API using Loopback 4 in order to log them in the controllers using log4js, just like this:

[2020-05-05T19:21:52.191] [INFO] [request-id:47e9a486-1243-1c07-3ac0-0acc9cce2c0e] user.controller.ts - starting request validation
[2020-05-05T19:21:52.191] [INFO] [request-id:1dc81e45-093a-8009-42d2-e545c3a10c9d] user.controller.ts - starting request validation
[2020-05-05T19:21:53.126] [INFO] [request-id:47e9a486-1243-1c07-3ac0-0acc9cce2c0e] user.controller.ts - request validation success
[2020-05-05T19:21:53.145] [ERROR] [request-id:1dc81e45-093a-8009-42d2-e545c3a10c9d] user.controller.ts - request validation failed

The main problem here is the [request-id:UUID] part, since Node.js sometimes mixes up the logs and I am not able to identify which of them belong to the same request. I have found some solutions for Express applications, but I could not find a way to make that work with Loopback 4 and log4js:

The solution might involve the use of the Sequence handler, but I could not figure out how to do it yet. Some hint of injecting the Request object: https://github.com/strongloop/loopback-next/issues/1881#issuecomment-431384142

score 1 · Answer 1 · answered May 07 '20 at 10:34

We did it using winston logger which was injected as a Logger Service into our sequence.ts. Here is the code for sequence.ts.

export class MySequence implements SequenceHandler {
  constructor(
    @inject(SequenceActions.FIND_ROUTE) protected findRoute: FindRoute,
    @inject(SequenceActions.PARSE_PARAMS) protected parseParams: ParseParams,
    @inject(SequenceActions.INVOKE_METHOD) protected invoke: InvokeMethod,
    @inject(SequenceActions.SEND) public send: Send,
    @inject(SequenceActions.REJECT) public reject: Reject,
    @inject(LOGGER.LOGGER_INJECT) public logger: ILogger,
    @inject(HelmetSecurityBindings.HELMET_SECURITY_ACTION)
    protected helmetAction: HelmetAction,
    @inject(RateLimitSecurityBindings.RATELIMIT_SECURITY_ACTION)
    protected rateLimitAction: RateLimitAction,
    @inject(AlivioBindings.i18n)
    protected i18n: i18nAPI,
  ) {}

  async handle(context: RequestContext) {
    const requestTime = Date.now();
    try {
      const {request, response} = context;
      this.logger.info(
        `Request ${request.method} ${
          request.url
        } started at ${requestTime.toString()}.
        Request Details
        Referer = ${request.headers.referer}
        User-Agent = ${request.headers['user-agent']}
        Remote Address = ${request.connection.remoteAddress}
        Remote Address (Proxy) = ${request.headers['x-forwarded-for']}`,
      );
      const route = this.findRoute(request);
      const args = await this.parseParams(request, route);

      await this.rateLimitAction(request, response);
      await this.helmetAction(request, response);

      request.body = args[args.length - 1];
      const result = await this.invoke(route, args);
      this.send(response, result);
    } catch (err) {
      this.logger.error(
        `Request ${context.request.method} ${
          context.request.url
        } errored out. Error :: ${JSON.stringify(err)} ${err}`,
      );

      this.reject(context, error);
    } finally {
      this.logger.info(
        `Request ${context.request.method} ${
          context.request.url
        } Completed in ${Date.now() - requestTime}ms`,
      );
    }
  }
}

You can use any logger as a provider here. You can create a wrapper provider over log4js and then do it like above. Hope this helps. Let me know if you want to see the provider code as well. I'll share that too.

Thanks, Samarpan. I have added some explanation on my answer. My main problem is to log the request identifier in the controllers classes avoiding they get mixed up. — Javier Escobar Espinoza, May 07 '20 at 13:59

How to trace request id in Loopback 4?

1 Answers1