As our application grows, more and more people start depending on it. At a time like this, it is crucial to ensure that our API works well. To do that, we could use a way to troubleshoot the application to detect anomalies and to be able to find their origin. This article serves as an introduction to how we can keep logs on what happens in our application.
Logger built into NestJS
Fortunately, NestJS comes with a logger built-in. Before using it, we should create its instance.
1import { Injectable, Logger } from '@nestjs/common';
2
3@Injectable()
4export default class PostsService {
5 private readonly logger = new Logger(PostsService.name)
6
7 // ...
8}Although we could use the Logger we import from @nestjs/common directly, creating a brand new instance for every service is a good practice and allows us to supply the name of the service for the Logger constructor.
Log levels
A crucial thing about the Logger is that it comes with a few methods:
- error
- warn
- log
- verbose
- debug
The above methods correspond with log levels that we can configure for our application.
1import { NestFactory } from '@nestjs/core';
2import { AppModule } from './app.module';
3import getLogLevels from './utils/getLogLevels';
4
5async function bootstrap() {
6 const app = await NestFactory.create(AppModule, {
7 logger: getLogLevels(process.env.NODE_ENV === 'production')
8 });
9
10 // ...
11}
12bootstrap();We don’t use the ConfigService above to read the environment variables because it isn’t initialized yet.
1import { LogLevel } from '@nestjs/common/services/logger.service';
2
3function getLogLevels(isProduction: boolean): LogLevel[] {
4 if (isProduction) {
5 return ['log', 'warn', 'error'];
6 }
7 return ['error', 'warn', 'log', 'verbose', 'debug'];
8}
9
10export default getLogLevels;Because of the above setup, the debug and verbose methods won’t produce logs on production.
If we take a look at the isLogLevelEnabled function, we can notice that providing ['debug'] turns on all of the log levels, not only verbose. This is because NestJS assumes that if we want to display the verbose logs, we also want to display logs of all of the lower levels. Because of that, ['debug'] is the same as ['error', 'warn', 'log', 'verbose', 'debug']. We can find the importance of each log level here.
After doing all of the above, let’s start using the logger.
1import { Injectable, Logger } from '@nestjs/common';
2import Post from './post.entity';
3import { InjectRepository } from '@nestjs/typeorm';
4import { Repository } from 'typeorm';
5import PostNotFoundException from './exceptions/postNotFound.exception';
6
7@Injectable()
8export default class PostsService {
9 private readonly logger = new Logger(PostsService.name)
10
11 constructor(
12 @InjectRepository(Post)
13 private postsRepository: Repository<Post>,
14 ) {}
15
16 async getPostById(id: number) {
17 const post = await this.postsRepository.findOne(id, { relations: ['author'] });
18 if (post) {
19 return post;
20 }
21 this.logger.warn('Tried to access a post that does not exist');
22 throw new PostNotFoundException(id);
23 }
24
25 // ...
26}Now we can see that passing PostsService.name caused PostService to appear as a prefix to our log message.
Using the logger in a middleware
Even though the above approach might come in handy, it might be cumbersome to write log messages manually. Thankfully, we can produce logs from middleware.
1import { Injectable, Logger, NestMiddleware } from '@nestjs/common';
2import { Request, Response, NextFunction } from 'express';
3
4@Injectable()
5class LogsMiddleware implements NestMiddleware {
6 private readonly logger = new Logger('HTTP');
7
8 use(request: Request, response: Response, next: NextFunction) {
9 response.on('finish', () => {
10 const { method, originalUrl } = request;
11 const { statusCode, statusMessage } = response;
12
13 const message = `${method} ${originalUrl} ${statusCode} ${statusMessage}`;
14
15 if (statusCode >= 500) {
16 return this.logger.error(message);
17 }
18
19 if (statusCode >= 400) {
20 return this.logger.warn(message);
21 }
22
23 return this.logger.log(message);
24 });
25
26 next();
27 }
28}
29
30export default LogsMiddleware;Check out the MDN documentation to read more about HTTP response status codes.
Above, we gather information about the request and response and log it based on the status code. Of course, the request and response objects contain more helpful information, so feel free to make your logs even more verbose.
The last step is to apply our middleware for all of our routes.
1import { MiddlewareConsumer, Module } from '@nestjs/common';
2import { PostsModule } from './posts/posts.module';
3import { DatabaseModule } from './database/database.module';
4import LogsMiddleware from './utils/logs.middleware';
5
6@Module({
7 imports: [
8 PostsModule,
9 DatabaseModule,
10 // ...
11 ],
12 // ...
13})
14export class AppModule {
15 configure(consumer: MiddlewareConsumer) {
16 consumer
17 .apply(LogsMiddleware)
18 .forRoutes('*');
19 }
20}Using the logger with TypeORM
Another helpful thing we can do is to log all SQL queries that happen in our application. To do that with TypeORM, we need to implement the Logger interface:
1import { Logger as TypeOrmLogger } from 'typeorm';
2import { Logger as NestLogger } from '@nestjs/common';
3
4class DatabaseLogger implements TypeOrmLogger {
5 private readonly logger = new NestLogger('SQL');
6
7 logQuery(query: string, parameters?: unknown[]) {
8 this.logger.log(`${query} -- Parameters: ${this.stringifyParameters(parameters)}`);
9 }
10
11 logQueryError(error: string, query: string, parameters?: unknown[]) {
12 this.logger.error(`${query} -- Parameters: ${this.stringifyParameters(parameters)} -- ${error}`);
13 }
14
15 logQuerySlow(time: number, query: string, parameters?: unknown[]) {
16 this.logger.warn(`Time: ${time} -- Parameters: ${this.stringifyParameters(parameters)} -- ${query}`);
17 }
18
19 logMigration(message: string) {
20 this.logger.log(message);
21 }
22
23 logSchemaBuild(message: string) {
24 this.logger.log(message);
25 }
26
27 log(level: 'log' | 'info' | 'warn', message: string) {
28 if (level === 'log') {
29 return this.logger.log(message);
30 }
31 if (level === 'info') {
32 return this.logger.debug(message);
33 }
34 if (level === 'warn') {
35 return this.logger.warn(message);
36 }
37 }
38
39 private stringifyParameters(parameters?: unknown[]) {
40 try {
41 return JSON.stringify(parameters);
42 } catch {
43 return '';
44 }
45 }
46}
47
48export default DatabaseLogger;The last step is to use the above class in our TypeORM configuration:
1import { Module } from '@nestjs/common';
2import { TypeOrmModule } from '@nestjs/typeorm';
3import { ConfigModule, ConfigService } from '@nestjs/config';
4import DatabaseLogger from './databaseLogger';
5
6@Module({
7 imports: [
8 TypeOrmModule.forRootAsync({
9 imports: [ConfigModule],
10 inject: [ConfigService],
11 useFactory: (configService: ConfigService) => ({
12 type: 'postgres',
13 logger: new DatabaseLogger(),
14 host: configService.get('POSTGRES_HOST'),
15 // ...
16 })
17 }),
18 ],
19})
20export class DatabaseModule {}When we start looking into the logs from TypeORM, we notice that it often produces quite lengthy queries. For example, the below query happens when we retrieve the data of the user that attempts to log in:
Saving logs into a PostgreSQL database
So far, we’ve only been logging all of the messages to the console. While that might work fine when developing the application on our machine, it wouldn’t make a lot of sense in a deployed application. There are a lot of services that can help us gather and manage logs, such as DataDog and Loggly. They are not free of charge, though. Therefore, in this article, we save logs into a PostgreSQL database.
For starters, let’s create an entity for our log:
1import { Column, CreateDateColumn, Entity, PrimaryGeneratedColumn } from 'typeorm';
2
3@Entity()
4class Log {
5 @PrimaryGeneratedColumn()
6 public id: number;
7
8 @Column()
9 public context: string;
10
11 @Column()
12 public message: string;
13
14 @Column()
15 public level: string;
16
17 @CreateDateColumn()
18 creationDate: Date;
19}
20
21export default Log;Above, we use the @CreateDateColum decorator. If you want to know more about dates in PostgreSQL, check out Managing date and time with PostgreSQL and TypeORM
Once we’ve got the above done, let’s create a service that allows us to create logs:
1import { Injectable } from '@nestjs/common';
2import { InjectRepository } from '@nestjs/typeorm';
3import { Repository } from 'typeorm';
4import Log from './log.entity';
5import CreateLogDto from './dto/createLog.dto';
6
7@Injectable()
8export default class LogsService {
9 constructor(
10 @InjectRepository(Log)
11 private logsRepository: Repository<Log>
12 ) {}
13
14 async createLog(log: CreateLogDto) {
15 const newLog = await this.logsRepository.create(log);
16 await this.logsRepository.save(newLog, {
17 data: {
18 isCreatingLogs: true
19 }
20 });
21 return newLog;
22 }
23}Above, you can notice that we pass isCreatingLogs: true when saving our logs to the database. The above is because we need to overcome the issue of an infinite loop. When we store logs in the database, it causes SQL queries to be logged. When we log SQL queries, they are saved to the database, causing an infinite loop. Because of that, we need to adjust our DatabaseLogger slightly:
1import { Logger as TypeOrmLogger, QueryRunner } from 'typeorm';
2import { Logger as NestLogger } from '@nestjs/common';
3
4class DatabaseLogger implements TypeOrmLogger {
5 private readonly logger = new NestLogger('SQL');
6
7 logQuery(query: string, parameters?: unknown[], queryRunner?: QueryRunner) {
8 if (queryRunner?.data?.isCreatingLogs) {
9 return;
10 }
11 this.logger.log(`${query} -- Parameters: ${this.stringifyParameters(parameters)}`);
12 }
13 logQueryError(error: string, query: string, parameters?: unknown[], queryRunner?: QueryRunner) {
14 if (queryRunner?.data?.isCreatingLogs) {
15 return;
16 }
17 this.logger.error(`${query} -- Parameters: ${this.stringifyParameters(parameters)} -- ${error}`);
18 }
19 logQuerySlow(time: number, query: string, parameters?: unknown[], queryRunner?: QueryRunner) {
20 if (queryRunner?.data?.isCreatingLogs) {
21 return;
22 }
23 this.logger.warn(`Time: ${time} -- Parameters: ${this.stringifyParameters(parameters)} -- ${query}`);
24 }
25 logMigration(message: string) {
26 this.logger.log(message);
27 }
28 logSchemaBuild(message: string) {
29 this.logger.log(message);
30 }
31 log(level: 'log' | 'info' | 'warn', message: string, queryRunner?: QueryRunner) {
32 if (queryRunner?.data?.isCreatingLogs) {
33 return;
34 }
35 if (level === 'log') {
36 return this.logger.log(message);
37 }
38 if (level === 'info') {
39 return this.logger.debug(message);
40 }
41 if (level === 'warn') {
42 return this.logger.warn(message);
43 }
44 }
45 private stringifyParameters(parameters?: unknown[]) {
46 try {
47 return JSON.stringify(parameters);
48 } catch {
49 return '';
50 }
51 }
52}
53
54export default DatabaseLogger;Above, we don’t log SQL queries if they are involved in creating logs.
Now we need to extend the logger built into NestJS and use the LogsService:
1import { Injectable, ConsoleLogger } from '@nestjs/common';
2import { ConsoleLoggerOptions } from '@nestjs/common/services/console-logger.service';
3import { ConfigService } from '@nestjs/config';
4import getLogLevels from '../utils/getLogLevels';
5import LogsService from './logs.service';
6
7@Injectable()
8class CustomLogger extends ConsoleLogger {
9 private readonly logsService: LogsService;
10
11 constructor(
12 context: string,
13 options: ConsoleLoggerOptions,
14 configService: ConfigService,
15 logsService: LogsService
16 ) {
17 const environment = configService.get('NODE_ENV');
18
19 super(
20 context,
21 {
22 ...options,
23 logLevels: getLogLevels(environment === 'production')
24 }
25 );
26
27 this.logsService = logsService;
28 }
29
30 log(message: string, context?: string) {
31 super.log.apply(this, [message, context]);
32
33 this.logsService.createLog({
34 message,
35 context,
36 level: 'log'
37 })
38 }
39 error(message: string, stack?: string, context?: string) {
40 super.error.apply(this, [message, stack, context]);
41
42 this.logsService.createLog({
43 message,
44 context,
45 level: 'error'
46 })
47 }
48 warn(message: string, context?: string) {
49 super.warn.apply(this, [message, context]);
50
51 this.logsService.createLog({
52 message,
53 context,
54 level: 'error'
55 })
56 }
57 debug(message: string, context?: string) {
58 super.debug.apply(this, [message, context]);
59
60 this.logsService.createLog({
61 message,
62 context,
63 level: 'error'
64 })
65 }
66 verbose(message: string, context?: string) {
67 super.debug.apply(this, [message, context]);
68
69 this.logsService.createLog({
70 message,
71 context,
72 level: 'error'
73 })
74 }
75}
76
77export default CustomLogger;We also need to create the LoggerModule so that we can add it into our AppModule:
1import { Module } from '@nestjs/common';
2import CustomLogger from './customLogger';
3import { ConfigModule } from '@nestjs/config';
4import LogsService from './logs.service';
5import { TypeOrmModule } from '@nestjs/typeorm';
6import Log from './log.entity';
7
8@Module({
9 imports: [ConfigModule, TypeOrmModule.forFeature([Log])],
10 providers: [CustomLogger, LogsService],
11 exports: [CustomLogger],
12})
13export class LoggerModule {}The final step is to call the useLogger method to inject our custom logger into the application:
1import { NestFactory } from '@nestjs/core';
2import { AppModule } from './app.module';
3import CustomLogger from './logger/customLogger';
4
5async function bootstrap() {
6 const app = await NestFactory.create(AppModule, {
7 bufferLogs: true,
8 });
9 app.useLogger(app.get(CustomLogger));
10
11 // ...
12}
13bootstrap();We could store some data in separate columns. Fore example, we could do that with the HTTP methods to be able to query the logs looking only for POST request, for example.
Summary
In this article, we’ve gone through the basics of logging with NestJS and TypeORM. We’ve learned about various log levels and how we can log messages directly and through middleware. We’ve also learned how to save our logs into an SQL database. Doing that has some benefits. For example, we could store more data in separate columns and use them when querying the data.
Even if saving logs into an SQL database has some advantages, the performance might not be the best if we have a lot of logs. Also, it could fill up the available space of our database. Therefore, it might be a good idea to look into services such as DataDog and Loggly. However, it is a topic for another article, so stay tuned!