[QUESTION] Log context inside middlewares

[klutzer]

[ 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
Is there any way to get a working log context inside nestjs (or even raw express) middlewares? The code above just get the request id (from http-pino's genReqId) for the Response sent log, while Request received remains with no context information.

Already tried some workarounds but none of them is working properly. Maybe could be related to #803 (not sure)

export class LoggingMiddleware implements NestMiddleware<Request, Response> {
  private readonly logger = new Logger("HTTP");

  use(request: Request, response: Response, next: (error?: unknown) => void) {
    this.logger.debug("Request received", ...); // no request id here

    const originalSend = response.send;
    response.send = (rawBody: unknown): Response => {
      this.logger.debug("Response sent", ...); // request id present

      response.send = originalSend;
      return response.send(rawBody);
    };

    return next();
  }
}

This middleware is the first one loaded on nestjs request lifecycle. I can't use interceptor for that because I need to log request/response considering other application middlewares as well, and interceptors are executed after all middlewares. Any suggestions?

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

[iamolegga]

must be middlewares order. debug or just add console.log() in your middleware and bindLoggerMiddleware in node_modules/nestjs-pino/LoggerModule.js to check the order. When you will see that your middleware goes before logger's middleware move LoggerModule.forRoot() to make it run before your own middleware

[klutzer]

You were right @iamolegga, it was that. Thanks!

[iamolegga]

Yep, definitely this need to be added to FAQ

[hliang]

Hi, I'm facing a similar issue. Could you pls help me understand how to make it run before your own middleware?

// app.module.ts
@Module({
  imports: [
    CoreModule,
    CatsModule,
    LoggerModule.forRoot(
      {
        pinoHttp: {
          autoLogging: false,
          quietReqLogger: true,
        }
      }
    ),
  ],
})
export class AppModule {
  configure(consumer: MiddlewareConsumer) {
    consumer.apply(FoobarMiddleware).forRoutes("*");
  }
}

// main.ts
async function bootstrap() {
  const app = await NestFactory.create(AppModule, { bufferLogs: true });
  app.useLogger(app.get(Logger));
  app.useGlobalPipes(new ValidationPipe());

  await app.listen(3000);
  console.log(`Application is running on: ${await app.getUrl()}`);
}
bootstrap();

// foobar.middleware.ts
@Injectable()
export class FoobarMiddleware implements NestMiddleware {
  constructor(
    @InjectPinoLogger(FoobarMiddleware.name)
    private logger: PinoLogger,
) {
    console.log("foobar middleware constructor bindings", this.logger.logger?.bindings());
}

  use(req: any, res: any, next: () => void) {
    this.logger.info("We want to have reqId in this log.");  // <------ reqId is absent in the middleware logging
    next();
  }
}

[iamolegga]

move LoggerModule to the first place in imports array

[hliang]

I tried update the imports order in AppModule, but no luck.

@Module({
  imports: [
    LoggerModule.forRoot(  // <----- LoggerModule is the first in the imports array
      {
        pinoHttp: {
          autoLogging: false,
          quietReqLogger: true,
        }
      }
    ),
    CoreModule,
    CatsModule,
  ],
})
export class AppModule {
  configure(consumer: MiddlewareConsumer) {
    consumer.apply(FoobarMiddleware).forRoutes("*");
  }
}

Is any other change needed?
Here is a sample app: https://github.com/hliang/nest-sample-cats-app/tree/pino-log-middleware

[iamolegga]

move FoobarMiddleware middleware to a separate module and apply it there, import foobar module last. Nestjs has not guarantee for the middlewares order. If that won't help you can try this: https://github.com/iamolegga/nestjs-configure-after

[hliang]

That works! Thank you!
I moved the middleware into the CoreModule which is the first imports.

@Module({
  providers: [
   ...
  ],
})
export class CoreModule {
  configure(consumer: MiddlewareConsumer) {
    consumer.apply(FoobarMiddleware).forRoutes("*");  // <---- middleware moved to here (was in AppModule)
  }
}