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

iamolegga/nestjs-pino

Repository files navigation

War in Ukraine
Children wait in a bomb shelter in Mariupol, Ukraine. AP
Help save their lives by donating:
Armed Forces of UkraineUkrainian volunteers
Thanks for your support!

NestJS-Pino

npm npm GitHub branch checks state Known Vulnerabilities Libraries.io Dependabot Supported platforms: Express & Fastify

✨✨✨ Platform agnostic logger for NestJS based on Pino withREQUEST 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 < 8here.


Install

npm i nestjs-pino pino-http

Example

Firstly, import module withLoggerModule.forRoot(...)orLoggerModule.forRootAsync(...)only once in root module (check out module configuration docsbelow):

import{LoggerModule}from'nestjs-pino';

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

Secondly, set up app logger:

import{Logger}from'nestjs-pino';

constapp=awaitNestFactory.create(AppModule,{bufferLogs:true});
app.useLogger(app.get(Logger));

Now you can use one of two loggers:

// NestJS standard built-in logger.
// Logs will be produced by pino internally
import{Logger}from'@nestjs/common';

exportclassMyService{
privatereadonlylogger=newLogger(MyService.name);
foo(){
// All logger methods have args format the same as pino, but pino methods
// `trace` and `info` are mapped to `verbose` and `log` to satisfy
// `LoggerService` interface of NestJS:
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';

exportclassMyService{
constructor(
privatereadonlylogger:PinoLogger
){
// Optionally you can set context for logger in constructor or...
this.logger.setContext(MyService.name);
}

constructor(
//... set context via special decorator
@InjectPinoLogger(MyService.name)
privatereadonlylogger:PinoLogger
){}

foo(){
// PinoLogger has same methods as pino instance
this.logger.trace({foo:'bar'},'baz %s','qux');
this.logger.debug('foo %s %o','bar',{baz:'qux'});
this.logger.info('foo');
}
}

Output:

// Logs by app itself
{"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"}

// Logs by injected Logger and PinoLogger in Services/Controllers. Every log
// has it's request data and unique `req.id` (by default id is unique per
// process, but you can set function to generate it from request context and
// for example pass here incoming `X-Request-ID` header or generate UUID)
{"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"}

// Automatic logs of every request/response
{"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 topino-super fast logger)whyyoushoulduseJSON
  • to log every request/response automatically (thanks topino-http)
  • to bind request data to the logs automatically from any service on any application layer without passing request context (thanks toAsyncLocalStorage)
  • to have another alternative logger with same API aspinoinstance (PinoLogger) for experiencedpinousers 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 importLoggerModuleto your module:

import{LoggerModule}from'nestjs-pino';

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

Configuration params

The following interface is using for the configuration:

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

/**
* Optional parameter for routing. It should implement interface of
* parameters of NestJS built-in `MiddlewareConfigProxy['forRoutes']`.
* @see https://docs.nestjs /middleware#applying-middleware
* It can be used for both disabling automatic req/res logs (see above) and
* removing request context from following logs. It works for all requests by
* default. If you only need to turn off the automatic request/response
* logging for some specific (or all) routes but keep request context for app
* logs use `pinoHttp.autoLogging` field.
*/
forRoutes?:Parameters<MiddlewareConfigProxy['forRoutes']>;

/**
* Optional parameter for routing. It should implement interface of
* parameters of NestJS built-in `MiddlewareConfigProxy['exclude']`.
* @see https://docs.nestjs /middleware#applying-middleware
* It can be used for both disabling automatic req/res logs (see above) and
* removing request context from following logs. It works for all requests by
* default. If you only need to turn off the automatic request/response
* logging for some specific (or all) routes but keep request context for app
* logs use `pinoHttp.autoLogging` field.
*/
exclude?:Parameters<MiddlewareConfigProxy['exclude']>;

/**
* Optional parameter to skip pino configuration in case you are using
* FastifyAdapter, and already configure logger in adapter's config. The Pros
* and cons of this approach are described in the FAQ section of the
* documentation:
* @see https://github /iamolegga/nestjs-pino#faq.
*/
useExisting?:true;

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

Synchronous configuration

UseLoggerModule.forRootmethod with argument ofParams 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
transport:process.env.NODE_ENV!=='production'
?{target:'pino-pretty'}
:undefined,


// and all the other fields of:
// - https://github /pinojs/pino-http#api
// - https://github /pinojs/pino/blob/HEAD/docs/api.md#options-object


},
someWritableStream
],
forRoutes:[MyController],
exclude:[{method:RequestMethod.ALL,path:'check'}]
})
],
...
})
classMyModule{}

Asynchronous configuration

WithLoggerModule.forRootAsyncyou can, for example, import yourConfigModuleand injectConfigServiceto use it inuseFactorymethod.

useFactoryshould return object withParams interfaceor undefined

Here's an example:

import{LoggerModule}from'nestjs-pino';

@Injectable()
classConfigService{
publicreadonlylevel='debug';
}

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

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

Asynchronous logging

In essence, asynchronous logging enables even faster performance bypino.

Please, readpino asynchronous mode docsfirst. There is a possibility of the most recently buffered log messages being lost in case of a system failure, e.g. a power cut.

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

importpinofrom'pino';
import{LoggerModule}from'nestjs-pino';

@Module({
imports:[
LoggerModule.forRoot({
pinoHttp:{
stream:pino.destination({
dest:'./my-file',// omit for stdout
minLength:4096,// Buffer before writing
sync:false,// Asynchronous logging
}),
},
}),
],
...
})
classMyModule{}

Seepino.destination

Testing a class that uses @InjectPinoLogger

This package exposes agetLoggerToken()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, includinguseClass,useValueanduseFactory.

constmodule:TestingModule=awaitTest.createTestingModule({
providers:[
MyService,
{
provide:getLoggerToken(MyService.name),
useValue:mockLogger,
},
],
}).compile();

Logger/PinoLogger class extension

LoggerandPinoLoggerclasses can be extended.

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

@Injectable()
classLoggerServiceextendsLogger{
constructor(
logger:PinoLogger,
@Inject(PARAMS_PROVIDER_TOKEN)params:Params
){
...
}
// extended method
myMethod():any{}
}

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

@Injectable()
classLoggerServiceextendsPinoLogger{
constructor(
@Inject(PARAMS_PROVIDER_TOKEN)params:Params
){
//...
}
// extended method
myMethod():any{}
}


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

Notes onLoggerinjection in constructor

Since logger substitution has appeared in NestJS@8 the main purpose ofLoggerclass is to be registered viaapp.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 versionLogger'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 orLoggerwas injected in some service viaconstructor(private logger: Logger) {}and the last argument is interpolation value for example.

Assign extra fields for future calls

You can enrich logs before calling log methods. It's possible by usingassignmethod ofPinoLoggerinstance. AsLoggerclass is used only for NestJS built-inLoggersubstitution viaapp.useLogger(...)this feature is only limited toPinoLoggerclass. Example:

@Controller('/')
classTestController{
constructor(
privatereadonlylogger:PinoLogger,
privatereadonlyservice:MyService,
){}

@Get()
get(){
// assign extra fields in one place...
this.logger.assign({userID:'42'});
returnthis.service.test();
}
}

@Injectable()
classMyService{
privatereadonlylogger=newLogger(MyService.name);

test(){
//...and it will be logged in another one
this.logger.log('hello world');
}
}

Due to thelimitationof the underlyingpino-httpPinoLogger.assigncannot extendRequest completedlogs.

Change pino params at runtime

Pino root instance with passed via module registration params creates a separate child logger for every request. This root logger params can be changed at runtime viaPinoLogger.rootproperty which is the pointer to logger instance. Example:

@Controller('/')
classTestController{
@Post('/change-loggin-level')
setLevel(){
PinoLogger.root.level='info';
returnnull;
}
}

Expose stack trace and error class inerrproperty

By default,pino-httpexposeserrproperty with a stack trace and error details, however, thiserrproperty contains default error details, which do not tell anything about actual error. To expose actual error details you need you to use a NestJS interceptor which captures exceptions and assigns them to the response objecterrproperty which is later processed by pino-http:

import{LoggerErrorInterceptor}from'nestjs-pino';

constapp=awaitNestFactory.create(AppModule);
app.useGlobalInterceptors(newLoggerErrorInterceptor());

Migration

v1

  • All parameters of v.0 are moved topinoHttpproperty (exceptuseExisting).
  • useExistingnow accept onlytruebecause you should already know if you want to use preconfigured fastify adapter's logger (and settrue) or not (and just not define this field).

v2

Logger substitution

A new more convenient way to inject a custom logger that implementsLoggerServicehas appeared in recent versions of NestJS (mind thebufferLogsfield, it will force NestJS to wait for logger to be ready instead of using built-in logger on start):

// main.ts
import{Logger}from'nestjs-pino';
//...
constapp=awaitNestFactory.create(AppModule,{bufferLogs:true});
app.useLogger(app.get(Logger));
//...

Note that forstandalone applications,buffering has to beflushed using app.flushLogs()manually after custom logger is ready to be used by NestJS (refer tothis issuefor more details):

// main.ts
import{Logger}from'nestjs-pino';

//...
constapp=awaitNestFactory.createApplicationContext(AppModule,{bufferLogs:true});
app.useLogger(app.get(Logger));
app.flushLogs();
//...

In all the other places you can use built-inLogger:

// my-service.ts
import{Logger}from'@nestjs/common';
classMyService{
privatereadonlylogger=newLogger(MyService.name);
}

To quote the official docs:

If we supply a custom logger viaapp.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 callingapp.useLogger().

That way if we follow the steps from the previous section and callapp.useLogger(app.get(MyLogger)),the following calls tothis.logger.log()fromMyServicewould result in calls to methodlogfromMyLoggerinstance.


This is recommended to update all your existingLoggerinjections fromnestjs-pinoto@nestjs/common.And inject it only in yourmain.tsfile as shown above. Support of injection ofLogger(don't confuse withPinoLogger) fromnestjs-pinodirectly in class constructors is dropped.


Since logger substitution has appeared the main purpose ofLoggerclass is to be registered viaapp.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 versionLogger'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 orLoggerwas injected in some service viaconstructor(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-inLoggerServicenow accept the same arguments without secondcontextargument (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 withpino's logging methods. So this is a breaking change in NestJS, and you should be aware of it.

In NestJS <= 7 andnestjs-pino@1when you callthis.logger.log('foo', 'bar');there would be such log:{... "context": "bar", "msg": "foo" }(second argument goes tocontextfield by desing). In NestJS 8 andnestjs-pino@2(with proper injection that shown above) same call will result in{... "context": "MyService", "msg": "foo" },socontextis passed via injection, but second argument disappear from log, because now it treats as interpolation value and there should be placeholder for it inmessageargument. So if you want to get bothfooandbarin log the right way to do this is:this.logger.log('foo %s', 'bar');.More info can be found inpino docs.

FAQ

Q:How to disable automatic request/response logs?

A:check outautoLogging field of pino-httpthat are set inpinoHttpfield ofParams


Q:How to passX-Request-IDheader or generate UUID forreq.idfield of log?

A:check outgenReqId field of pino-httpthat are set inpinoHttpfield ofParams


Q:How does it work?

A:It usespino-httpunder hood, so every request has it's ownchild-logger,and with help ofAsyncLocalStorageLoggerandPinoLoggercan get it while calling own methods. So your logs can be grouped byreq.id.


Q:Why useAsyncLocalStorageinstead ofREQUEST scope?

A:REQUEST scopecan haveperfomance issues.TL;DR: it will have to create an instance of the class (that injectsLogger) 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 outhistory of this feature.


Q:What aboutpinobuilt-in methods/levels?

A:Pino built-in methods names are not fully compatible with NestJS built-inLoggerServicemethods names, and there is an option which logger you use. Here is methods mapping:

pinomethod PinoLoggermethod NestJS built-inLoggermethod
trace trace verbose
debug debug debug
info info log
warn warn warn
error error error
fatal fatal fatal (since [email protected])

Q:Fastify already includespino,and I want to configure it onAdapterlevel, and use this config for logger

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

Fastify creates logger with your config per every request. And this logger is used byLogger/PinoLoggerservices inside that context underhood.

But Nest Application has another contexts of execution, for examplelifecycle events,where you still may want to use logger. For thatLogger/PinoLoggerservices use separatepinoinstance with config, that provided viaforRoot/forRootAsyncmethods.

So, when you want to configurepinoviaFastifyAdapterthere is no way to get back this config from fastify and pass it to thatout of contextlogger.

And if you will not pass config viaforRoot/forRootAsyncout of contextlogger 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 toLoggerModuleconfiguration too. But if you already provide it toLoggerModuleconfiguration you can dropuseExistingfield from config and drop logger configuration onFastifyAdapter,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
  • pinois 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 you might be interested in one of myother NestJS libs.