[NestJS] Logger

Hocaron·2022년 5월 21일
4

NestJS

목록 보기
12/12

로깅이 뭐지?

  • 서비스에 기능이 늘어나고 사이즈가 커지게 되면 동작 과정을 남기고 추적하는 일이 중요
  • 이슈가 발생했을 경우 이슈 증상만으로 원인을 파악하는 데에는 시간과 노력이 많이 들고 코드를 다시 역추적하면서 이해하는 데에 어려움
  • 이슈가 발생한 지점과 콜스택이 함께 제공된다면 빨리 해결이 가능
  • 또 어떤 기능이 많이 사용되는지와 같이 유저의 사용패턴을 분석하는 데에도 로그를 활용

우리는 이미 로깅을 보고 있다

서비스를 실행하면 서버 콘솔에는 아래 그림과 같은 로그가 출력됩니다. 이미 각 컴포넌트에서는 내장 로거를 이용하여 로그를 출력하고 있다.

어떻게 적용하는거지?

내장로거

내장 Logger클래스는 @nest/common 패키지로 제공됩니다. 로깅 옵션을 조절하면 다음과 같이 로깅 시스템의 동작을 제어할 수 있다.

  • 로깅 비활성화
  • 로그 레벨 지정 - logerrorwarndebugverbose
  • 로거의 타임스탬프 재정의. ex) 날짜를 ISO8601 형식으로 변경
  • 기본 로거를 재정의(오버라이딩)
  • 기본 로거를 확장해서 커스텀 로거를 작성
  • 의존성 주입을 통해 손쉽게 로거를 주입하거나 테스트 모듈로 제공
import {Injectable,Logger }from '@nestjs/common';

@Injectable()
exportclassAppService {
  private readonly logger =newLogger(AppService.name);

getHello(): string {
    this.logger.error('level: error');
    this.logger.warn('level: warn');
    this.logger.log('level: log');
    this.logger.verbose('level: verbose');
    this.logger.debug('level: debug');

return 'Hello World!';
  }
}

로그 레벨 지정

일반적으로 프로덕션 환경에서는 debug 로그가 남지 않도록 하는 게 좋다.
실행환경에 따라 로그 레벨을 지정하는 경우가 보통이다.

일반적으로 프로덕션 환경에서는 debug 로그가 남지 않도록 하는 게 좋다. 디버그 로그는 테스트 과정에서 디버깅용으로 객체가 가지고 있는 세부 데이터까지 남기는 경우가 많은데 상용환경에서는 사용자의 민감 정보가 포함될 수 있기 때문에 제외한다. 디버깅 로그는 로그의 크기 자체도 큰 경우가 대부분이므로 로그 파일의 사이즈를 줄이기 위한 목적도 있다.

const app = await NestFactory.create(AppModule, {
    logger: process.env.NODE_ENV === 'production' 
    ? ['error', 'warn', 'log']
    : ['error', 'warn', 'log', 'verbose', 'debug']
});

💡 만약 로그레벨을 하나만 설정한다면 해당 로그레벨보다 레벨이 낮은 레벨의 로그도 모두 함께 출력됩니다.따라서 debug로만 설정한다면 모든 로그가 출력된다.

const LOG_LEVEL_VALUES: Record<LogLevel, number> = {
  debug: 0,
  verbose: 1,
  log: 2,
  warn: 3,
  error: 4,
};

로그레벨

  • Log - 중요한 정보의 범용 로깅
  • Warning - 치명적이거나 파괴적이지 않은 처리되지 않은 문제
  • Error - 치명적이거나 파괴적인 처리되지 않은 문제
  • Debug - 오류 발생시 로직을 디버그하는데 도움이 되는 유용한 정보. 개발자용
  • Verbose - 응용 프로그램의 동작에 대한 통찰력을 제공하는 정보입니다. 운영자용

커스텀 로거

export interface LoggerService {
  log(message: any, ...optionalParams: any[]): any;
  error(message: any, ...optionalParams: any[]): any;
  warn(message: any, ...optionalParams: any[]): any;
  debug?(message: any, ...optionalParams: any[]): any;
  verbose?(message: any, ...optionalParams: any[]): any;
    setLogLevels?(levels: LogLevel[]): any;
}
export class MyLogger extends ConsoleLogger {
  error(message: any, stack?: string, context?: string) {
    super.error.apply(this, arguments);
    this.doSomething();
  }

  private doSomething() {
    // 여기에 로깅에 관련된 부가 로직을 추가합니다.
    // ex. DB에 저장    
  }

  ...
}

커스텀 로거 주입해서 사용하기

import { Module } from '@nestjs/common';
import { MyLogger } from './my-logger.service';

@Module({
  providers: [MyLogger],
  exports: [MyLogger],
})
export class LoggerModule { }
import { LoggerModule } from './logging/logger.module';

@Module({
  imports: [LoggerModule],
  ...
})
export class AppModule { }
import { MyLogger } from './logging/my-logger.service';

@Injectable()
export class AppService {
  constructor(private myLogger: MyLogger) { }

    getHello(): string {
        this.myLogger.error('level: error');
    this.myLogger.warn('level: warn');
    this.myLogger.log('level: log');
    this.myLogger.verbose('level: verbose');
    this.myLogger.debug('level: debug');

    return 'Hello World!';
  }
}

winston 로거

@nestjs/common 패키지에서 제공하는 Logger 클래스를 이용하여 로깅을 구현하는 것도 가능하지만, 서비스를 상용 수준으로 운용하기 위해서는 로그를 콘솔에만 출력하는 게 아니라 파일에 저장을 하거나, 중요한 로그는 데이터베이스에 저장을 해서 쉽게 검색할 수 있도록 해야 한다.

$ npm i nest-winston winston

AppModule에 WinstonModule 을 import합니다.

import * as winston from 'winston';
import {
  utilities as nestWinstonModuleUtilities,
  WinstonModule,
} from 'nest-winston';

@Module({
  imports: [
        ...
    WinstonModule.forRoot({
      transports: [
        new winston.transports.Console({
                    level: process.env.NODE_ENV === 'production' ? 'info' : 'silly',
          format: winston.format.combine(
            winston.format.timestamp(),
            nestWinstonModuleUtilities.format.nestLike('MyApp', { prettyPrint: true }),
          ),
        }),
      ],
    }),
  ],
})
export class AppModule { }
{ 
  error: 0, 
  warn: 1, 
  info: 2, 
  http: 3,
  verbose: 4, 
  debug: 5, 
  silly: 6 
}
import { Logger as WinstonLogger } from 'winston';
import { WINSTON_MODULE_PROVIDER } from 'nest-winston';
...

export class UsersController {

  constructor(
    @Inject(WINSTON_MODULE_PROVIDER) private readonly logger: WinstonLogger,
  ) { }

  @Post()
  async createUser(@Body() dto: CreateUserDto): Promise<void> {
        this.printWinstonLog(dto);
        ...
  }

    private printWinstonLog(dto) {
    console.log(this.logger.name);

    this.logger.error('error: ', dto);
    this.logger.warn('warn: ', dto);
    this.logger.info('info: ', dto);
    this.logger.http('http: ', dto);
    this.logger.verbose('verbose: ', dto);
    this.logger.debug('debug: ', dto);
    this.logger.silly('silly: ', dto);
  }
    ...
}
[MyApp] Error   5/21/2022, 4:20:00 AM error:  - {}
[MyApp] Warn    5/21/2022, 4:20:00 AM warn:  - {}
[MyApp] Info    5/21/2022, 4:20:00 AM info:  - {}
[MyApp] Http    5/21/2022, 4:20:00 AM http:  - {}
[MyApp] Verbose 5/21/2022, 4:20:00 AM verbose:  - {}
[MyApp] Debug   5/21/2022, 4:20:00 AM debug:  - {}
[MyApp] Silly   5/21/2022, 4:20:00 AM silly:  - {}

Nest Logger를 대체하기

먼저 main.ts에 전역 로거로 설정합니다.

import { WINSTON_MODULE_NEST_PROVIDER } from 'nest-winston';

async function bootstrap() {
  const app = await NestFactory.create(AppModule);
  app.useLogger(app.get(WINSTON_MODULE_NEST_PROVIDER));
  await app.listen(3000);
}
bootstrap();

그 다음 로깅을 하고자 하는 곳에서 LoggerService를 WINSTON_MODULE_NEST_PROVIDER토큰으로 주입받습니다.

import { LoggerService } from '@nestjs/common';
import { WINSTON_MODULE_NEST_PROVIDER } from 'nest-winston';
...
export class UsersController {
  constructor(
    @Inject(WINSTON_MODULE_NEST_PROVIDER) private readonly logger: LoggerService,
  ) { }
    ...

  @Post()
  async createUser(@Body() dto: CreateUserDto): Promise<void> {
        this.printLoggerServiceLog(dto);
        ...
  }

    private printLoggerServiceLog(dto) {
        try {
      throw new InternalServerErrorException('test');
    } catch (e) {
      this.logger.error('error: ' + JSON.stringify(dto), e.stack);
    }
    this.logger.warn('warn: ' + JSON.stringify(dto));
    this.logger.log('log: ' + JSON.stringify(dto));
    this.logger.verbose('verbose: ' + JSON.stringify(dto));
    this.logger.debug('debug: ' + JSON.stringify(dto));
  }
}
[MyApp] Info    2021-11-19 9:32:07F10: PM[RoutesResolver] UsersController {/users}: - {}
[MyApp] Info    2021-11-19 9:32:07F10: PM[RouterExplorer] Mapped {/users, POST} route - {}
[MyApp] Info    2021-11-19 9:32:07F10: PM[RouterExplorer] Mapped {/users/email-verify, POST} route - {}
[MyApp] Info    2021-11-19 9:32:07F10: PM[RouterExplorer] Mapped {/users/login, POST} route - {}
[MyApp] Info    2021-11-19 9:32:07F10: PM[RouterExplorer] Mapped {/users/:id, GET} route - {}
[MyApp] Info    2021-11-19 9:32:07F10: PM[NestApplication] Nest application successfully started - {}

Nest의 의존성 주입은 한가지 단점이 있는데, 부트스트래핑 과정(모듈, 프로바이더, 의존성 주입 등을 초기화)에서 WinstonLogger는 아직 사용이 불가하다.

[Nest] 88819  - 2021-11-19 9:39:28F10: PMLOG [InstanceLoader] ConfigHostModule dependencies initialized +2ms
[Nest] 88819  - 2021-11-19 9:39:28F10: PMLOG [InstanceLoader] WinstonModule dependencies initialized +0ms
[Nest] 88819  - 2021-11-19 9:39:28F10: PMLOG [InstanceLoader] EmailModule dependencies initialized +0ms
[Nest] 88819  - 2021-11-19 9:39:28F10: PMLOG [InstanceLoader] AuthModule dependencies initialized +1ms
[Nest] 88819  - 2021-11-19 9:39:28F10: PMLOG [InstanceLoader] ConfigModule dependencies initialized +0ms
[Nest] 88819  - 2021-11-19 9:39:28F10: PMLOG [InstanceLoader] TypeOrmCoreModule dependencies initialized +83ms
[Nest] 88819  - 2021-11-19 9:39:28F10: PMLOG [InstanceLoader] TypeOrmModule dependencies initialized +0ms
[Nest] 88819  - 2021-11-19 9:39:28F10: PMLOG [InstanceLoader] UsersModule dependencies initialized +2ms

부트스트래핑까지 포함하여 Nest Logger를 대체하려면?

import { WinstonModule } from 'nest-winston';

async function bootstrap() {
    const app = await NestFactory.create(AppModule, {
    logger: WinstonModule.createLogger({
      transports: [
        new winston.transports.Console({
          level: process.env.NODE_ENV === 'production' ? 'info' : 'silly',
          format: winston.format.combine(
            winston.format.timestamp(),
            nestWinstonModuleUtilities.format.nestLike('MyApp', { prettyPrint: true }),
          ),
        }),
      ],
    })
  });
  await app.listen(3000);
}
bootstrap();
import { Logger } from '@nestjs/common';
...
@Module({
    ...
  providers: [Logger]
})
export class UsersModule { }
import { Logger } from '@nestjs/common';
...
export class UsersController {
  constructor(
    @Inject(Logger) private readonly logger: LoggerService,
  ) { }
    ...
}
[MyApp] Info    2021-11-19 9:55:16F10: PM[NestFactory] Starting Nest application... - {}
[MyApp] Info    2021-11-19 9:55:16F10: PM[InstanceLoader] AppModule dependencies initialized - {}
[MyApp] Info    2021-11-19 9:55:16F10: PM[InstanceLoader] TypeOrmModule dependencies initialized - {}
[MyApp] Info    2021-11-19 9:55:16F10: PM[InstanceLoader] ConfigHostModule dependencies initialized - {}
[MyApp] Info    2021-11-19 9:55:16F10: PM[InstanceLoader] EmailModule dependencies initialized - {}
[MyApp] Info    2021-11-19 9:55:16F10: PM[InstanceLoader] AuthModule dependencies initialized - {}
[MyApp] Info    2021-11-19 9:55:16F10: PM[InstanceLoader] ConfigModule dependencies initialized - {}
[MyApp] Info    2021-11-19 9:55:16F10: PM[InstanceLoader] TypeOrmCoreModule dependencies initialized - {}
[MyApp] Info    2021-11-19 9:55:16F10: PM[InstanceLoader] TypeOrmModule dependencies initialized - {}
[MyApp] Info    2021-11-19 9:55:16F10: PM[InstanceLoader] UsersModule dependencies initialized - {}
import {
  CallHandler,
  ExecutionContext,
  Inject,
  Injectable,
  Logger,
  NestInterceptor,
} from '@nestjs/common';
import { Request, Response } from 'express';
import { Observable } from 'rxjs';
import { catchError, tap } from 'rxjs/operators';
import { v4 as uuid } from 'uuid';
import { PrivacyReplacer } from './PrivacyReplacer';
import { clone } from 'ramda';

@Injectable()
export class LogInterceptor implements NestInterceptor {
  private requestLogger = new Logger('HTTP_REQUEST');
  private responseLogger = new Logger('HTTP_RESPONSE');
  constructor(
    @Inject('LOGGING_IGNORE_PATH') private readonly loggingIgnorePath: string[],
    private readonly privacyReplacer: PrivacyReplacer,
  ) {}

  intercept(context: ExecutionContext, next: CallHandler): Observable<any> {
    const executionId = uuid();
    this.logRequest(context, executionId);

    return next.handle().pipe(
      catchError((error: any) => {
        console.log(error);
        this.logResponse(context, executionId, error);
        throw error;
      }),
      tap((data) => {
        this.logResponse(context, executionId, data);
      }),
    );
  }

  private logResponse(
    context: ExecutionContext,
    executionId: string,
    data: any,
  ) {
    if (this.isIgnorePath(context)) return;

    const response = context.switchToHttp().getResponse<Response>();
    const loggingParams: Record<string, any> = {
      executionId,
      user: this.getUser(context),
      headers: this.privacyReplacer.replaceResponseHeader(
        clone(response.header),
      ),
    };
    if (data instanceof Error) {
      loggingParams.error = { message: data.message };
    } else {
      loggingParams.body = this.privacyReplacer.replaceResponseBody(
        clone(data),
      );
    }

    this.responseLogger.log(JSON.stringify(loggingParams));
  }

  private logRequest(context: ExecutionContext, executionId: string) {
    if (this.isIgnorePath(context)) return;

    const request = context.switchToHttp().getRequest<Request>();
    this.requestLogger.log(
      JSON.stringify({
        executionId,
        user: this.getUser(context),
        path: request.path,
        body: this.privacyReplacer.replaceRequestBody(clone(request.body)),
        headers: this.privacyReplacer.replaceRequestHeader(
          clone(request.headers),
        ),
      }),
    );
  }

  private getUser(context: ExecutionContext) {
    const request = context.switchToHttp().getRequest();
    if (request.user == null || typeof request.user !== 'object') {
      return null;
    }

    const user = { ...request.user };
    delete user.password;

    return user;
  }

  private isIgnorePath(context: ExecutionContext): boolean {
    return this.loggingIgnorePath.includes(
      context.switchToHttp().getRequest<Request>().path,
    );
  }
}
profile
기록을 통한 성장을

2개의 댓글

comment-user-thumbnail
2024년 12월 13일

잘읽었습니다!

1개의 답글