Skip to content

Platform agnostic logger for NestJS based on Pino with REQUEST CONTEXT IN EVERY LOG

License

Notifications You must be signed in to change notification settings

zimiovid/nestjs-pino

 
 

Repository files navigation

NestJS-Pino logo

NestJS-Pino

npm Travis (.org) Coverage Status Snyk Vulnerabilities for npm package David Dependabot Supported platforms: Express & Fastify

✨✨✨ Platform agnostic logger for NestJS based on Pino with REQUEST CONTEXT IN EVERY LOG ✨✨✨

Example

Import module with LoggerModule.forRoot(...) or LoggerModule.forRootAsync(...):

import { LoggerModule } from "nestjs-pino";

@Module({
  imports: [LoggerModule.forRoot()],
  controllers: [AppController],
  providers: [MyService]
})
class MyModule {}

In controller let's use Logger - class with the same API as built-in NestJS logger:

import { Logger } from "nestjs-pino";

@Controller()
export class AppController {
  constructor(
    private readonly myService: MyService,
    private readonly logger: Logger
  ) {}

  @Get()
  getHello(): string {
    // pass message
    this.logger.log("getHello()");

    // also we can pass context
    this.logger.log("getHello()", AppController.name);

    return `Hello ${this.myService.getWorld()}`;
  }
}

Let's compare it to another one logger - PinoLogger, it has same logging API as pino instance.

For example in service it will be used instead of previous one:

import { PinoLogger } from "nestjs-pino";

@Injectable()
export class MyService {
  constructor(private readonly logger: PinoLogger) {}

  getWorld(...params: any[]) {
    this.logger.info({ context: MyService.name }, "getWorld(%o)", params);
    return "World!";
  }
}

Also context can be set just once in constructor instead of every call:

import { PinoLogger } from "nestjs-pino";

@Injectable()
export class MyService {
  constructor(private readonly logger: PinoLogger) {
    logger.setContext(MyService.name);
  }

  getWorld(...params: any[]) {
    this.logger.info("getWorld(%o)", params);
    return "World!";
  }
}

Also context can be set at injection via decorator @InjectPinoLogger(...):

import { PinoLogger, InjectPinoLogger } from "nestjs-pino";

@Injectable()
export class MyService {
  constructor(
    @InjectPinoLogger(MyService.name) private readonly logger: PinoLogger
  ) {}

  getWorld(...params: any[]) {
    this.logger.info("getWorld(%o)", params);
    return "World!";
  }
}

And also Logger can be set as app logger, as it is compatible with built-in NestJS logger:

import { Logger } from "nestjs-pino";

const app = await NestFactory.create(AppModule, { logger: false });
app.useLogger(app.get(Logger));

Output:

// Logs by app itself
{"level":30,"time":1570470154387,"pid":17383,"hostname":"my-host","context":"RoutesResolver","msg":"AppController {/}: true","v":1}
{"level":30,"time":1570470154391,"pid":17383,"hostname":"my-host","context":"RouterExplorer","msg":"Mapped {/, GET} route true","v":1}
{"level":30,"time":1570470154405,"pid":17383,"hostname":"my-host","context":"NestApplication","msg":"Nest application successfully started true","v":1}

// Logs by injected Logger and PinoLogger in Services/Controllers
// Every log has it's request data and unique `req.id` (per process)
{"level":30,"time":1570470161805,"pid":17383,"hostname":"my-host","req":{"id":1,"method":"GET","url":"/","headers":{...},"remoteAddress":"::1","remotePort":53957},"context":"AppController","msg":"getHello()","v":1}
{"level":30,"time":1570470161805,"pid":17383,"hostname":"my-host","req":{"id":1,"method":"GET","url":"/","headers":{...},"remoteAddress":"::1","remotePort":53957},"context":"MyService","msg":"getWorld([])","v":1}

// Automatic logs of every request/response
{"level":30,"time":1570470161819,"pid":17383,"hostname":"my-host","req":{"id":1,"method":"GET","url":"/","headers":{...},"remoteAddress":"::1","remotePort":53957},"res":{"statusCode":304,"headers":{...}},"responseTime":15,"msg":"request completed","v":1}

Comparison with others

There are other Nestjs loggers. The key purposes of this module are:

  • to be compatible with built-in LoggerService
  • to log with JSON (thanks to pino - super fast logger) (why JSON?)
  • to log every request/response automatically (thanks to pino-http)
  • to bind request data to the logs automatically from any service on any application layer without passing request context
  • to have another one alternative PinoLogger for experienced pino users for more comfortable usage.
Logger Nest App logger Logger service Autobind request data to logs
nest-winston + + -
nestjs-pino-logger + + -
nestjs-pino + + +

Install

npm i nestjs-pino

Register module

Zero configuration

Just import LoggerModule to your module:

import { LoggerModule } from 'nestjs-pino';

@Module({
  imports: [LoggerModule.forRoot()],
  ...
})
class MyModule {}

Configuration params

nestjs-pino can be configured with params object of next interface:

interface Params {
  /**
   * Optional parameters for `pino-http` module
   * @see https://github.com/pinojs/pino-http#pinohttpopts-stream
   */
  pinoHttp?:
    | pinoHttp.Options
    | DestinationStream
    | [pinoHttp.Options, DestinationStream];

  /**
   * Optional parameter for routing. It should implement interface of
   * parameters of NestJS buil-in `MiddlewareConfigProxy['forRoutes']`.
   * @see https://docs.nestjs.com/middleware#applying-middleware
   * It can be used for disabling automatic req/res logs (see above).
   * Keep in mind that it will remove context data from logs that are called
   * inside not included or excluded routes and controlles.
   */
  forRoutes?: Parameters<MiddlewareConfigProxy["forRoutes"]>;

  /**
   * Optional parameter for routing. It should implement interface of
   * parameters of NestJS buil-in `MiddlewareConfigProxy['exclude']`.
   * @see https://docs.nestjs.com/middleware#applying-middleware
   * It can be used for disabling automatic req/res logs (see above).
   * Keep in mind that it will remove context data from logs that are called
   * inside not included or excluded routes and controlles.
   */
  exclude?: Parameters<MiddlewareConfigProxy["exclude"]>;

  /**
   * Optional parameter to skip `pino` configuration in case you are using
   * Fastify adapter, and already configuring it on adapter level.
   * Pros and cons of this approach are descibed in the last section.
   */
  useExisting?: true;

  /**
   * Optional parameter to change property name `context` in resulted logs,
   * so logs will be like:
   * {"level":30, ... "RENAME_CONTEXT_VALUE_HERE":"AppController" }
   * Works with both `Logger` and `PinoLogger`
   */
  renameContext?: string;
}

Synchronous configuration

Use LoggerModule.forRoot method with argument of Params interface:

import { LoggerModule } from 'nestjs-pino';

@Module({
  imports: [
    LoggerModule.forRoot({
      pinoHttp: [
        {
          name: 'add some name to every JSON line',
          level: process.env.NODE_ENV !== 'production' ? 'debug' : 'info',
          // install 'pino-pretty' package in order to use the following option
          prettyPrint: process.env.NODE_ENV !== 'production',
          useLevelLabels: true,
          // and all the others...
        },
        someWritableStream
      ],
      forRoutes: [MyController],
      exclude: [{ method: RequestMethod.ALL, path: "check" }]
    })
  ],
  ...
})
class MyModule {}

Asynchronous configuration

With LoggerModule.forRootAsync you can, for example, import your ConfigModule and inject ConfigService to use it in useFactory method.

useFactory should return object with Params interface or undefined

Here's an example:

import { LoggerModule } from 'nestjs-pino';

@Injectable()
class ConfigService {
  public readonly level = "debug";
}

@Module({
  providers: [ConfigService],
  exports: [ConfigService]
})
class ConfigModule {}

@Module({
  imports: [
    LoggerModule.forRootAsync({
      imports: [ConfigModule],
      inject: [ConfigService],
      useFactory: async (config: ConfigService) => {
        await somePromise();
        return {
          pinoHttp: { level: config.level },
        };
      }
    })
  ],
  ...
})
class TestModule {}

Or you can just pass ConfigService to providers, if you don't have any ConfigModule:

import { LoggerModule } from "nestjs-pino";

@Injectable()
class ConfigService {
  public readonly level = "debug";
  public readonly stream = stream;
}

@Module({
  imports: [
    LoggerModule.forRootAsync({
      providers: [ConfigService],
      inject: [ConfigService],
      useFactory: (config: ConfigService) => {
        return {
          pinoHttp: [{ level: config.level }, config.stream]
        };
      }
    })
  ],
  controllers: [TestController]
})
class TestModule {}

Extreme mode

In essence, extreme mode enables even faster performance by Pino.

Please, read pino extreme mode docs first. There is a risk of some logs being lost, but you can minimize it.

If you know what you're doing, you can enable it like so:

import * as pino from 'pino';
import { LoggerModule } from 'nestjs-pino';

const dest = pino.extreme();
const logger = pino(dest);

@Module({
  imports: [LoggerModule.forRoot({ pinoHttp: { logger } })],
  ...
})
class MyModule {}

Usage as Logger service

As it said before, there are 2 logger classes:

  • Logger - implements standard NestJS LoggerService interface. So if you are familiar with built-in NestJS logger, you are good to go.
  • PinoLogger - implements standard pino logging methods: trace, debug, info, warn, error, fatal. So if you are familiar with it, you are also good to go.

Logger

// my.service.ts
import { Logger } from "nestjs-pino";

@Injectable()
export class MyService {
  constructor(private readonly logger: Logger) {}

  getWorld(...params: any[]) {
    this.logger.log("getWorld(%o)", MyService.name, params);
    return "World!";
  }
}

PinoLogger

See pino logging method parameters for more logging examples.

// my.service.ts
import { PinoLogger, InjectPinoLogger } from "nestjs-pino";

@Injectable()
export class MyService {
  // regular injecting
  constructor(private readonly logger: PinoLogger) {}

  // regular injecting and set context
  constructor(private readonly logger: PinoLogger) {
    logger.setContext(MyService.name);
  }

  // inject and set context via `InjectPinoLogger`
  constructor(
    @InjectPinoLogger(MyService.name) private readonly logger: PinoLogger
  ) {}

  getWorld(...params: any[]) {
    this.logger.info("getWorld(%o)", params);
    return "World!";
  }
}

Testing a class that uses @InjectPinoLogger

This package exposes a getLoggerToken() function that returns a prepared injection token based on the provided context. Using this token, you can easily provide a mock implementation of the logger using any of the standard custom provider techniques, including useClass, useValue, and useFactory.

  const module: TestingModule = await Test.createTestingModule({
    providers: [
      MyService,
      {
        provide: getLoggerToken(MyService.name),
        useValue: mockLogger,
      },
    ],
  }).compile();

Usage as NestJS app logger

According to official docs, loggers with Dependency injection should be set via following construction:

import { Logger } from "nestjs-pino";

const app = await NestFactory.create(MyModule, { logger: false });
app.useLogger(app.get(Logger));

Extend the Logger class

You can extend the Logger class to add your own business logic.

// logger.service.ts
import { Logger, PinoLogger, Params, PARAMS_PROVIDER_TOKEN } from "nestjs-pino";

@Injectable()
class LoggerService extends Logger() {
  // regular injecting
  constructor(
    logger: PinoLogger,
    @Inject(PARAMS_PROVIDER_TOKEN) params: Params
  ) {
    ...
  }

  // extended method
  myMethod(): any {}
}

import { PinoLogger, Params, PARAMS_PROVIDER_TOKEN } from "nestjs-pino";

@Injectable()
class LoggerService extends PinoLogger() {
  // regular injecting
  constructor(
    @Inject(PARAMS_PROVIDER_TOKEN) params: Params
  ) {
    ...
  }

  // extended method
  myMethod(): any {}
}


// logger.module.ts
@Module({
  providers: [LoggerService],
  exports: [LoggerService],
  imports: [LoggerModule.forRoot()],
})
class LoggerModule {}

Migrating

v1

  • All parameters of v.0 are moved to pinoHttp property (except useExisting).
  • useExisting now accept only true, because false does not make any sense

FAQ

Q: How does it work?

A: It uses pino-http under hood, so every request has it's own child-logger, and with help of async_hooks Logger and PinoLogger can get it while calling own methods. So your logs can be grouped by req.id. If you run several instances, unique key is pair: pid + req.id.


Q: Why use async_hooks instead of REQUEST scope?

A: REQUEST scope can have perfomance issues. TL;DR: it will have to create an instance of the class (that injects Logger) on each request, and that will slow down your responce times.


Q: I'm using old nodejs version, will it work for me?

A: Please read this.


Q: What about pino built-in methods/levels?

A: Pino built-in methods are not compatible with NestJS built-in LoggerService methods. So for now there is option which logger to use, here is methods mapping:

pino method PinoLogger method Logger method
trace trace verbose
debug debug debug
info info log
warn warn warn
error error error
fatal fatal -

Q: Fastify already includes pino, and I want to configure it on Adapter level, and use this config for logger

A: You can do it by providing useExisting: true. But there is one caveat:

Fastify creates logger with your config per every request. And this logger is used by Logger/PinoLogger services inside that context underhood.

But Nest Application has another contexts of execution, for example lifecycle events, where you still may want to use logger. For that Logger/PinoLogger services use separate pino instance with config, that provided via forRoot/forRootAsync methods.

So, when you want to configure pino via FastifyAdapter, there is no way to get back this config from it and pass to that out of context logger.

And if you not pass config via forRoot/forRootAsync out of context logger will be instantiated with default params. So if you want to configure it anyway with the same options, then you have to provide the same config. And then If you are already provide that then you don't have to duplicate your code and provide pino config via fastify.

So these property (useExisting: true) is not recommended and useful only for cases when:

  • this logger is not using for lifecycle events and application level logging in Nest apps based on fastify
  • pino using with default params in Nest apps based on fastify

All the other cases are lead to either code duplication or unexpected behaviour.

Do you use this library?
Don't be shy to give it a star! ★

Also if you are into NestJS ecosystem you may be interested in one of my other libs:

nestjs-pino

GitHub stars npm

Platform agnostic logger for NestJS based on pino with request context in every log


nestjs-session

GitHub stars npm

Idiomatic session module for NestJS. Built on top of express-session


nestjs-cookie-session

GitHub stars npm

Idiomatic cookie session module for NestJS. Built on top of cookie-session


nestjs-roles

GitHub stars npm

Type safe roles guard and decorator made easy


nest-ratelimiter

GitHub stars npm

Distributed consistent flexible NestJS rate limiter based on Redis


create-nestjs-middleware-module

GitHub stars npm

Create simple idiomatic NestJS module based on Express/Fastify middleware in just a few lines of code with routing out of the box


nestjs-configure-after

GitHub stars npm

Declarative configuration of NestJS middleware order

About

Platform agnostic logger for NestJS based on Pino with REQUEST CONTEXT IN EVERY LOG

Resources

License

Code of conduct

Stars

Watchers

Forks

Packages

No packages published

Languages

  • TypeScript 100.0%