iamolegga / nestjs-pino

Platform agnostic logger for NestJS based on Pino with REQUEST CONTEXT IN EVERY LOG
MIT License
1.26k stars 98 forks source link

[QUESTION] PinoLogger: unable to assign extra fields out of request scope // trying to assign fields from AuthGuard #1020

Closed schealex closed 2 years ago

schealex commented 2 years ago

[x] I've read the docs of nestjs-pino

[x] I've read the docs of pino

[x] I couldn't find the same question about nestjs-pino

Question Hello guys, we require to extend our logs with user data which get set to the REQ object by using a nestjs auth guard. Sadly those are not getting into the logs. I'm now trying to set the fields specifically using the "assign" method. But as it seems (and which makes sense) it is not possible due to the auth guard not beeing request scoped. How can we get our request context based information into the logs in a uniform way (we need to provide this from a libary, ideally in form of a middleware) because we require this in a lot of different microservices. I've tried writing a request scoped middleware but it gives the same error:

import { Injectable, NestMiddleware } from '@nestjs/common';
import { Response, NextFunction } from 'express';
import { InjectPinoLogger, PinoLogger } from 'nestjs-pino';
import { UserRequest } from '@triluxds/tds-lp-nest-utilities';

@Injectable({ scope: Scope.REQUEST })
export class LoggerContextMiddleware implements NestMiddleware {
  constructor(
    @InjectPinoLogger(LoggerContextMiddleware.name)
    private readonly logger: PinoLogger,
  ) {}
  use(req: UserRequest, res: Response, next: NextFunction) {
    this.logger.assign({ userId: req.user?.userId });
    this.logger.assign({ customerId: req.user?.customerId });
    this.logger.assign({ clientId: req.user?.clientId });
    next();
  }
}

export class AppModule implements NestModule {
  configure(consumer: MiddlewareConsumer) {
    consumer.apply(LoggerContextMiddleware).forRoutes('*');
  }
}

Please mention other relevant information such as Node.js version and Operating System.

iamolegga commented 2 years ago

I believe this is a problem with middlewares order. Try to play with order of modules in imports of root module or other modules. Logger module should run before dependant modules. As nestjs has not guaranty of order of modules initialization you can open node_modules/nestjs-pino and add a breakpoint or log and check if lib's middleware runs before your middleware

schealex commented 2 years ago

maybe i've misread this error but doesn't that error say that the logger instance inside the middleware is not request scoped? I've debugged into the middleware and the req.user object is there and filled. it's just not able to execute the assign method on the this.logger instance

iamolegga commented 2 years ago

this error

which error?

you don't need any request scope, that's the main idea of usage of this library. please check the tests for logger assign.

also check if lifecycle order is correct https://docs.nestjs.com/faq/request-lifecycle, so you need:

  1. set req.user object and set this lib's middleware in any order
  2. assign extra fields to logger after step 1

As I understand you are using auth guard to build user field on request and using middleware to set extra fields, but auth guard goes after middleware, so in this case it will not work

schealex commented 2 years ago

i don't belive that is the problem here, check this out:

@Injectable()
export class LoggerContextMiddleware implements NestMiddleware {
  constructor(
    @InjectPinoLogger(LoggerContextMiddleware.name)
    private readonly logger: PinoLogger,
  ) {}
  use(req: UserRequest, res: Response, next: NextFunction) {
    this.logger.assign({ test: 'test' });
    // this.logger.assign({ userId: req.user?.userId });
    // this.logger.assign({ customerId: req.user?.customerId });
    // this.logger.assign({ clientId: req.user?.clientId });
    next();
  }
}

it still gives the "PinoLogger: unable to assign extra fields out of request scope" error even though it should only add a fixed value.

iamolegga commented 2 years ago

check the order of modules then.If you believe this is a bug feel free to open a bug report with minimal example

schealex commented 2 years ago

i've opened a bug report so I'm closing this question