Troubleshooting a deployed application can be challenging. We can’t use the debugger and stop an application used by other people. Instead, we need to implement logs that we can inspect if we suspect that our API is not working as expected. In this article, we look at the logger built into NestJS and use it in different cases.
Logger available in NestJS
NestJS is equipped with a logger ready to use out of the box. The official documentation suggests creating an instance of the logger on top of each class we want to use it in.
1import { Injectable, Logger } from '@nestjs/common';
2import UsersRepository from './users.repository';
3
4@Injectable()
5class UsersService {
6 private readonly logger = new Logger();
7
8 // ...
9}
10
11export default UsersService;Log levels
A crucial concept we need to learn is the level of the log. There are a few to choose from, sorted by severity:
- error
- warn
- log
- verbose
- debug
Each logger instance has a set of methods that correspond with the above levels.
1import { Injectable, Logger } from '@nestjs/common';
2import { CreateUserDto } from './dto/createUser.dto';
3import UsersRepository from './users.repository';
4import UserAlreadyExistsException from './exceptions/userAlreadyExists.exception';
5
6@Injectable()
7class UsersService {
8 private readonly logger = new Logger(UsersService.name);
9
10 constructor(private readonly usersRepository: UsersRepository) {}
11
12 async create(user: CreateUserDto) {
13 try {
14 return await this.usersRepository.create(user);
15 } catch (error) {
16 if (error instanceof UserAlreadyExistsException) {
17 this.logger.warn(error.message);
18 }
19 throw error;
20 }
21 }
22
23 // ...
24}
25
26export default UsersService;The more severe a particular log, the more alarmed we should be. For example, a user trying to sign up using an occupied email address is not a reason to panic. Because of that, above, we use the logger.warn function.
We can specify what levels of logs we want to appear in our terminal. To do that, we need to adjust our bootstrap() function.
1import { NestFactory } from '@nestjs/core';
2import { AppModule } from './app.module';
3import * as cookieParser from 'cookie-parser';
4
5async function bootstrap() {
6 const app = await NestFactory.create(AppModule, {
7 logger: ['error', 'warn', 'log', 'verbose', 'debug'],
8 });
9
10 app.use(cookieParser());
11
12 await app.listen(3000);
13}
14bootstrap();It is a common approach to disregard some of the logs in the production environment. We might want to avoid having too many logs in production so that we see a potential issue more clearly.
1import { NestFactory } from '@nestjs/core';
2import { AppModule } from './app.module';
3import * as cookieParser from 'cookie-parser';
4import { LogLevel } from '@nestjs/common/services/logger.service';
5
6async function bootstrap() {
7 const isProduction = process.env.NODE_ENV === 'production';
8 const logLevels: LogLevel[] = isProduction
9 ? ['error', 'warn', 'log']
10 : ['error', 'warn', 'log', 'verbose', 'debug'];
11
12 const app = await NestFactory.create(AppModule, {
13 logger: logLevels,
14 });
15
16 app.use(cookieParser());
17
18 await app.listen(3000);
19}
20bootstrap();A surprising thing might be that providing ['debug'] turns on all of the log levels. When we look at the isLogLevelEnabled function we can see that NestJS looks for the highest severity included in the array and turns on all of the logs with the lower severity too. Above, we provide a full array for the sake of readability.
Once we do the above, logs start appearing in our terminal. There we can see that thanks to providing the name of the service with new Logger(UsersService.name), the name appears at the beginning of the log.
Using the logger in an interceptor
The above approach can be handy when handling some specific cases. Unfortunately, covering all possible situations with logs would be pretty demanding. Fortunately, we can use the power of interceptors that NestJS offers us. Let’s write an interceptor that allows us to cover a particular endpoint with a wide variety of logs.
1import {
2 Body,
3 Controller,
4 Post,
5 ClassSerializerInterceptor,
6 UseInterceptors,
7} from '@nestjs/common';
8import { AuthenticationService } from './authentication.service';
9import RegisterDto from './dto/register.dto';
10import { LoggerInterceptor } from '../utils/logger.interceptor';
11
12@Controller('authentication')
13@UseInterceptors(ClassSerializerInterceptor)
14export class AuthenticationController {
15 constructor(private readonly authenticationService: AuthenticationService) {}
16
17 @Post('register')
18 @UseInterceptors(LoggerInterceptor)
19 async register(@Body() registrationData: RegisterDto) {
20 return this.authenticationService.register(registrationData);
21 }
22
23 // ...
24}The job of the LoggerInterceptor is to gather information bout the request and response. We can write an interceptor that binds some logic before the method execution.
If you want to know more about interceptors, check out API with NestJS #5. Serializing the response with interceptors
1import {
2 Injectable,
3 NestInterceptor,
4 ExecutionContext,
5 CallHandler,
6 Logger,
7} from '@nestjs/common';
8import { Request, Response } from 'express';
9
10@Injectable()
11export class LoggerInterceptor implements NestInterceptor {
12 private readonly logger = new Logger('HTTP');
13
14 intercept(context: ExecutionContext, next: CallHandler) {
15 const httpContext = context.switchToHttp();
16 const request = httpContext.getRequest<Request>();
17 const response = httpContext.getResponse<Response>();
18
19 response.on('finish', () => {
20 const { method, originalUrl } = request;
21 const { statusCode, statusMessage } = response;
22
23 const message = `${method} ${originalUrl} ${statusCode} ${statusMessage}`;
24
25 if (statusCode >= 500) {
26 return this.logger.error(message);
27 }
28
29 if (statusCode >= 400) {
30 return this.logger.warn(message);
31 }
32
33 return this.logger.log(message);
34 });
35
36 return next.handle();
37 }
38}Above a few important things happen:
- we get the request and response object associated with a particular request,
- we wait for the finish event emitted by NodeJS
- we use the appropriate log level based on the status code.
If we want our interceptor to apply to every method in a given controller, we can apply it to the whole class.
1import {
2 Controller,
3 ClassSerializerInterceptor,
4 UseInterceptors,
5} from '@nestjs/common';
6import { LoggerInterceptor } from '../utils/logger.interceptor';
7
8@Controller('authentication')
9@UseInterceptors(ClassSerializerInterceptor)
10@UseInterceptors(LoggerInterceptor)
11export class AuthenticationController {
12 // ...
13}If we would like to apply the above logic to all of our controllers, we can use our interceptor globally with the useGlobalInterceptors method.
1import { NestFactory } from '@nestjs/core';
2import { AppModule } from './app.module';
3import * as cookieParser from 'cookie-parser';
4import { LogLevel } from '@nestjs/common/services/logger.service';
5import { LoggerInterceptor } from './utils/logger.interceptor';
6
7async function bootstrap() {
8 const isProduction = process.env.NODE_ENV === 'production';
9 const logLevels: LogLevel[] = isProduction
10 ? ['error', 'warn', 'log']
11 : ['error', 'warn', 'log', 'verbose', 'debug'];
12
13 const app = await NestFactory.create(AppModule, {
14 logger: logLevels,
15 });
16
17 app.use(cookieParser());
18
19 app.useGlobalInterceptors(new LoggerInterceptor());
20
21 await app.listen(3000);
22}
23bootstrap();Logging SQL queries
A helpful thing to do might be to log all SQL queries in our application. Unfortunately, the node-postgres library does not offer any logging functionalities.
Thankfully, it’s pretty easy to inject logging functionalities into our DatabaseService when performing simple queries.
1import { Inject, Injectable, Logger } from '@nestjs/common';
2import { Pool, PoolClient } from 'pg';
3import { CONNECTION_POOL } from './database.module-definition';
4
5@Injectable()
6class DatabaseService {
7 private readonly logger = new Logger('SQL');
8 constructor(@Inject(CONNECTION_POOL) private readonly pool: Pool) {}
9
10 async runQuery(query: string, params?: unknown[]) {
11 return this.queryWithLogging(this.pool, query, params);
12 }
13
14 getLogMessage(query: string, params?: unknown[]) {
15 if (!params) {
16 return `Query: ${query}`;
17 }
18 return `Query: ${query} Params: ${JSON.stringify(params)}`;
19 }
20
21 async queryWithLogging(
22 source: Pool | PoolClient,
23 query: string,
24 params?: unknown[],
25 ) {
26 const queryPromise = source.query(query, params);
27
28 // message without unnecessary spaces and newlines
29 const message = this.getLogMessage(query, params)
30 .replace(/\n|/g, '')
31 .replace(/ +/g, ' ');
32
33 queryPromise
34 .then(() => {
35 this.logger.log(message);
36 })
37 .catch((error) => {
38 this.logger.warn(message);
39 throw error;
40 });
41
42 return queryPromise;
43 }
44
45 // ...
46}
47
48export default DatabaseService;The problem arises when we perform transactions and implement the getPoolClient function.
If you want to know more about transactions check out API with NestJS #76. Working with transactions using raw SQL queries
1import { Inject, Injectable } from '@nestjs/common';
2import { Pool } from 'pg';
3import { CONNECTION_POOL } from './database.module-definition';
4
5@Injectable()
6class DatabaseService {
7 constructor(@Inject(CONNECTION_POOL) private readonly pool: Pool) {}
8
9 async getPoolClient() {
10 return this.pool.connect();
11 }
12
13 // ...
14}
15
16export default DatabaseService;Once we return the client, we no longer control how it executes queries. Fortunately, we can deal with the above problem using a proxy.
If you want to know more about proxies, check out Understanding JavaScript Proxy. Preserving backward compatibility in a library
1import { Inject, Injectable, Logger } from '@nestjs/common';
2import { Pool, PoolClient } from 'pg';
3import { CONNECTION_POOL } from './database.module-definition';
4
5@Injectable()
6class DatabaseService {
7 private readonly logger = new Logger('SQL');
8 constructor(@Inject(CONNECTION_POOL) private readonly pool: Pool) {}
9
10 async runQuery(query: string, params?: unknown[]) {
11 return this.queryWithLogging(this.pool, query, params);
12 }
13
14 getLogMessage(query: string, params?: unknown[]) {
15 if (!params) {
16 return `Query: ${query}`;
17 }
18 return `Query: ${query} Params: ${JSON.stringify(params)}`;
19 }
20
21 async queryWithLogging(
22 source: Pool | PoolClient,
23 query: string,
24 params?: unknown[],
25 ) {
26 const queryPromise = source.query(query, params);
27
28 // message without unnecessary spaces and newlines
29 const message = this.getLogMessage(query, params)
30 .replace(/\n|/g, '')
31 .replace(/ +/g, ' ');
32
33 queryPromise
34 .then(() => {
35 this.logger.log(message);
36 })
37 .catch((error) => {
38 this.logger.warn(message);
39 throw error;
40 });
41
42 return queryPromise;
43 }
44
45 async getPoolClient() {
46 const poolClient = await this.pool.connect();
47
48 return new Proxy(poolClient, {
49 get: (target: PoolClient, propertyName: keyof PoolClient) => {
50 if (propertyName === 'query') {
51 return (query: string, params?: unknown[]) => {
52 return this.queryWithLogging(target, query, params);
53 };
54 }
55 return target[propertyName];
56 },
57 });
58 }
59}
60
61export default DatabaseService;Thanks to the above approach, as soon as some other service gets a pool client and runs a query, it runs through our proxy first and logs the appropriate message.
Summary
In this article, we’ve learned how to work with the logger built into NestJS. We’ve covered a variety of cases in which we might need logging. It included logging messages automatically for specific endpoints and SQL queries. A thorough approach to logging can help us when there is a problem in our application, so it is worth spending some time on.