NestJS-Pino
✨✨✨ Platform agnostic logger for NestJS based on Pino with REQUEST CONTEXT IN EVERY LOG ✨✨✨
This is documentation for v2 which works with NestJS 8+.
Please see documentation for the previous major version which works with NestJS < 8 here.
Install
npm i nestjs-pino pino-http
Example
Firstly, import module with LoggerModule.forRoot(...)
or LoggerModule.forRootAsync(...)
only once in root module (check out module configuration docs below):
import { LoggerModule } from 'nestjs-pino';
@Module({
imports: [LoggerModule.forRoot()],
})
class AppModule {}
Secondly, set up app logger:
import { Logger } from 'nestjs-pino';
const app = await NestFactory.create(AppModule, { bufferLogs: true });
app.useLogger(app.get(Logger));
Now you can use one of two loggers:
import { Logger } from '@nestjs/common';
export class MyService {
private readonly logger = new Logger(MyService.name);
foo() {
this.logger.verbose({ foo: 'bar' }, 'baz %s', 'qux');
this.logger.debug('foo %s %o', 'bar', { baz: 'qux' });
this.logger.log('foo');
}
}
Usage of the standard logger is recommended and idiomatic for NestJS. But there is one more option to use:
import { PinoLogger, InjectPinoLogger } from 'nestjs-pino';
export class MyService {
constructor(
private readonly logger: PinoLogger
) {
this.logger.setContext(MyService.name);
}
constructor(
@InjectPinoLogger(MyService.name)
private readonly logger: PinoLogger
) {}
foo() {
this.logger.trace({ foo: 'bar' }, 'baz %s', 'qux');
this.logger.debug('foo %s %o', 'bar', { baz: 'qux' });
this.logger.info('foo');
}
}
Output:
{"level":30,"time":1629823318326,"pid":14727,"hostname":"my-host","context":"NestFactory","msg":"Starting Nest application..."}
{"level":30,"time":1629823318326,"pid":14727,"hostname":"my-host","context":"InstanceLoader","msg":"LoggerModule dependencies initialized"}
{"level":30,"time":1629823318327,"pid":14727,"hostname":"my-host","context":"InstanceLoader","msg":"AppModule dependencies initialized"}
{"level":30,"time":1629823318327,"pid":14727,"hostname":"my-host","context":"RoutesResolver","msg":"AppController {/}:"}
{"level":30,"time":1629823318327,"pid":14727,"hostname":"my-host","context":"RouterExplorer","msg":"Mapped {/, GET} route"}
{"level":30,"time":1629823318327,"pid":14727,"hostname":"my-host","context":"NestApplication","msg":"Nest application successfully started"}
{"level":10,"time":1629823792023,"pid":15067,"hostname":"my-host","req":{"id":1,"method":"GET","url":"/","query":{},"params":{"0":""},"headers":{"host":"localhost:3000","user-agent":"curl/7.64.1","accept":"*/*"},"remoteAddress":"::1","remotePort":63822},"context":"MyService","foo":"bar","msg":"baz qux"}
{"level":20,"time":1629823792023,"pid":15067,"hostname":"my-host","req":{"id":1,"method":"GET","url":"/","query":{},"params":{"0":""},"headers":{"host":"localhost:3000","user-agent":"curl/7.64.1","accept":"*/*"},"remoteAddress":"::1","remotePort":63822},"context":"MyService","msg":"foo bar {\"baz\":\"qux\"}"}
{"level":30,"time":1629823792023,"pid":15067,"hostname":"my-host","req":{"id":1,"method":"GET","url":"/","query":{},"params":{"0":""},"headers":{"host":"localhost:3000","user-agent":"curl/7.64.1","accept":"*/*"},"remoteAddress":"::1","remotePort":63822},"context":"MyService","msg":"foo"}
{"level":30,"time":1629823792029,"pid":15067,"hostname":"my-host","req":{"id":1,"method":"GET","url":"/","query":{},"params":{"0":""},"headers":{"host":"localhost:3000","user-agent":"curl/7.64.1","accept":"*/*"},"remoteAddress":"::1","remotePort":63822},"res":{"statusCode":200,"headers":{"x-powered-by":"Express","content-type":"text/html; charset=utf-8","content-length":"12","etag":"W/\"c-Lve95gjOVATpfV8EL5X4nxwjKHE\""}},"responseTime":7,"msg":"request completed"}
Comparison with others
There are other Nestjs loggers. Key purposes of this module are:
- to be idiomatic NestJS logger
- to log in JSON format (thanks to pino - super fast logger) why you should use 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 (thanks to AsyncLocalStorage)
- to have another alternative logger with same API as
pino
instance (PinoLogger
) for experienced pino
users to make more comfortable usage.
Logger | Nest App logger | Logger service | Auto-bind request data to logs |
---|
nest-winston | + | + | - |
nestjs-pino-logger | + | + | - |
nestjs-pino | + | + | + |
Configuration
Zero configuration
Just import LoggerModule
to your module:
import { LoggerModule } from 'nestjs-pino';
@Module({
imports: [LoggerModule.forRoot()],
...
})
class MyModule {}
Configuration params
The following interface is using for the configuration:
interface Params {
pinoHttp?:
| pinoHttp.Options
| DestinationStream
| [pinoHttp.Options, DestinationStream];
forRoutes?: Parameters<MiddlewareConfigProxy['forRoutes']>;
exclude?: Parameters<MiddlewareConfigProxy['exclude']>;
useExisting?: true;
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',
prettyPrint: process.env.NODE_ENV !== 'production',
useLevelLabels: true,
},
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 {}
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 {}
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 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();
Logger/PinoLogger class extension
Logger
and PinoLogger
classes can be extended.
import { Logger, PinoLogger, Params, PARAMS_PROVIDER_TOKEN } from 'nestjs-pino';
@Injectable()
class LoggerService extends Logger {
constructor(
logger: PinoLogger,
@Inject(PARAMS_PROVIDER_TOKEN) params: Params
) {
...
}
myMethod(): any {}
}
import { PinoLogger, Params, PARAMS_PROVIDER_TOKEN } from 'nestjs-pino';
@Injectable()
class LoggerService extends PinoLogger {
constructor(
@Inject(PARAMS_PROVIDER_TOKEN) params: Params
) {
}
myMethod(): any {}
}
@Module({
providers: [LoggerService],
exports: [LoggerService],
imports: [LoggerModule.forRoot()],
})
class LoggerModule {}
Notes on Logger
injection in constructor
Since logger substitution has appeared in NestJS@8 the main purpose of Logger
class is to be registered via app.useLogger(app.get(Logger))
. But that requires some internal breaking change, because with such usage NestJS pass logger's context as the last optional argument in logging function. So in current version Logger
's methods accept context as a last argument.
With such change it's not possible to detect if method was called by app internaly and the last argument is context or Logger
was injected in some service via constructor(private logger: Logger) {}
and the last argument is interpolation value for example.
Migration
v1
- All parameters of v.0 are moved to
pinoHttp
property (except useExisting
). useExisting
now accept only true
because you should already know if you want to use preconfigured fastify adapter's logger (and set true
) or not (and just not define this field).
v2
Logger substitution
A new more convenient way to inject a custom logger that implements LoggerService
has appeared in recent versions of NestJS (mind the bufferLogs
field, it will force NestJS to wait for logger to be ready instead of using built-in logger on start):
import { Logger } from 'nestjs-pino';
const app = await NestFactory.create(AppModule, { bufferLogs: true });
app.useLogger(app.get(Logger));
In all the other places you can use built-in Logger
:
import { Logger } from '@nestjs/common';
class MyService {
private readonly logger = new Logger(MyService.name);
}
To quote the official docs:
If we supply a custom logger via app.useLogger()
, it will actually be used by Nest internally. That means that our code remains implementation agnostic, while we can easily substitute the default logger for our custom one by calling app.useLogger()
.
That way if we follow the steps from the previous section and call app.useLogger(app.get(MyLogger))
, the following calls to this.logger.log()
from MyService
would result in calls to method log
from MyLogger
instance.
This is recommended to update all your existing Logger
injections from nestjs-pino
to @nestjs/common
. And inject it only in your main.ts
file as shown above. Support of injection of Logger
(don't confuse with PinoLogger
) from nestjs-pino
directly in class constructors is dropped.
Since logger substitution has appeared the main purpose of Logger
class is to be registered via app.useLogger(app.get(Logger))
. But that requires some internal breaking change, because with such usage NestJS pass logger's context as the last optional argument in logging function. So in current version Logger
's methods accept context as the last argument.
With such change it's not possible to detect if method was called by app internaly and the last argument is context or Logger
was injected in some service via constructor(private logger: Logger) {}
and the last argument is interpolation value for example. That's why logging with such injected class still works, but only for 1 argument.
NestJS LoggerService interface breaking change
In NestJS@8 all logging methods of built-in LoggerService
now accept the same arguments without second context
argument (which is set via injection, see above), for example: log(message: any, ...optionalParams: any[]): any;
. That makes usage of built-in logger more convenient and compatible with pino
's logging methods. So this is a breaking change in NestJS, and you should be aware of it.
In NestJS <= 7 and nestjs-pino@1
when you call this.logger.log('foo', 'bar');
there would be such log: {..."context":"bar","msg":"foo"}
(second argument goes to context
field by desing). In NestJS 8 and nestjs-pino@2
(with proper injection that shown above) same call will result in {..."context":"MyService","msg":"foo"}
, so context
is passed via injection, but second argument disappear from log, because now it treats as interpolation value and there should be placeholder for it in message
argument. So if you want to get both foo
and bar
in log the right way to do this is: this.logger.log('foo %s', 'bar');
. More info can be found in pino docs.
FAQ
Q: How to disable automatic request/response logs?
A: check out autoLogging field of pino-http that are set in pinoHttp
field of Params
Q: How to pass X-Request-ID
header or generate UUID for req.id
field of log?
A: check out genReqId field of pino-http that are set in pinoHttp
field of Params
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 AsyncLocalStorage Logger
and PinoLogger
can get it while calling own methods. So your logs can be grouped by req.id
.
Q: Why use AsyncLocalStorage 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 response times.
Q: I'm using old nodejs version, will it work for me?
A: Please check out history of this feature.
Q: What about pino
built-in methods/levels?
A: Pino built-in methods names are not fully compatible with NestJS built-in LoggerService
methods names, and there is an option which logger you use. Here is methods mapping:
pino method | PinoLogger method | NestJS built-in 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 fastify and pass it to that out of context logger.
And if you will not pass config via forRoot
/forRootAsync
out of context logger will be instantiated with default params. So if you want to configure it with the same options for consistency you have to provide the same config to LoggerModule
configuration too. But if you already provide it to LoggerModule
configuration you can drop useExisting
field from config and drop logger configuration on FastifyAdapter
, and it will work without code duplication.
So this property (useExisting: true
) is not recommended, and can be useful only for cases when:
- this logger is not using for lifecycle events and application level logging in NestJS apps based on fastify
pino
is using with default params in NestJS apps based on fastify
All the other cases are lead to either code duplication or unexpected behavior.
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
Platform agnostic logger for NestJS based on pino with request context in every log
nestjs-session
Idiomatic session module for NestJS. Built on top of express-session
nestjs-cookie-session
Idiomatic cookie session module for NestJS. Built on top of cookie-session
nestjs-roles
Type safe roles guard and decorator made easy
nestjs-injectable
@Injectable()
on steroids that simplifies work with inversion of control in your hexagonal architecture
nest-ratelimiter
Distributed consistent flexible NestJS rate limiter based on Redis
create-nestjs-middleware-module
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
Declarative configuration of NestJS middleware order