[NestJS] Logging 알아보기 (feat. winston)

이번 포스팅은 Interceptor의 개념을 알고 있는 상태여야 이해하기가 쉬운 내용이 포함되어 있습니다. Interceptor에 대한 설명은 다음 링크를 참고해주세요.

 

[NestJS] Interceptor 개념정리 (+간단한 Logger)

 

1. Logging

1-1. Logger

Nest는 내장된 텍스트 기반의 logger를 가지고 있는데, 이는 애플리케이션 부팅 중에 사용되며 잡은 예외를 보여주는 일부 다른 환경들에서도 사용됩니다.

 

logger가 가진 기능들은 모두 Logger 클래스에서 제공하는 기능들입니다. 우리는 이 클래스를 사용해서 로깅 시스템의 완전한 제어권을 가질 수 있게 됩니다.

 

Logger 기능의 예시는 다음과 같습니다:

• logging 전체 비활성화
• 구체적인 로그 수준 지정(ex. error, warning, debug information, 등등...)
• 기본 로거에 timestamp 기능 추가 (ex. 날짜 형식인 ISO8601 표준 사용)
• 기본 로거를 완전히 재정의
• 기본 로거를 확장하여 커스터마이징
• 애플리케이션 구성과 테스팅을 단순화하기 위해 의존성 주입 사용

 

또한 우리는 애플리케이션 수준의 이벤트와 메세지를 로깅하기 위해서 내장 로거를 사용하거나 자체 커스텀 구현을 따로 만들어 사용합니다.

 

더 심화된 로깅 기능을 위해서는, 다양한 Node.js 로깅 패키지를 사용할 수 있습니다. (ex. Wiston)

 

1-2. 기본 커스터마이징

로깅을 비활성화하려면 NestFactory.create() 메서드에 두번째 인자로 전달되는 Nest application 옵션 객체의 logger 속성을 false로 설정하면 됩니다.

const app = await NestFactory.create(AppModule, {
  logger: false,
});
await app.listen(3000);

 

 

특정 level의 로깅을 활성화하려면 logger 속성에 보여줄 로그 수준의 이름을 명시하는 string 배열을 지정하면 됩니다:

const app = await NestFactory.create(AppModule, {
  logger: ['error', 'warn'],
});
await app.listen(3000);

 

이 배열에 들어갈 수 있는 값은 'log', 'fatal', 'error', 'warn', 'debug', 'verbose'의 조합입니다.

 

기본 로거 메세지의 색상을 비활성화하고 싶다면, NO_COLOR 환경 변수를 빈 문자열이 아닌 값으로 설정하면 됩니다.

 

1-3. Custom implementation (커스텀 구현)

logger 속성 값을 LoggerService 인터페이스를 구현하는 객체로 설정하여 Nest에서 시스템 로깅에 사용할 사용자 정의 로거 구현을 제공할 수도 있습니다.

 

예를 들어, 다음과 같이 Nest에 내장된 전역 JavaScript console 객체(LoggerService 인터페이스를 구현하는)를 사용하도록 지시할 수 있습니다:

const app = await NestFactory.create(AppModule, {
  logger: console,
});
await app.listen(3000);

 

사용자 정의 로거를 구현하는 방법은 되게 직관적입니다. 아래와 같이 LoggerService 인터페이스의 각 메서드를 구현해주기만 하면 됩니다.

import { LoggerService } from '@nestjs/common';

export class MyLogger implements LoggerService {
  /**
   * Write a 'log' level log.
   */
  log(message: any, ...optionalParams: any[]) {}

  /**
   * Write a 'fatal' level log.
   */
  fatal(message: any, ...optionalParams: any[]) {}

  /**
   * Write an 'error' level log.
   */
  error(message: any, ...optionalParams: any[]) {}

  /**
   * Write a 'warn' level log.
   */
  warn(message: any, ...optionalParams: any[]) {}

  /**
   * Write a 'debug' level log.
   */
  debug?(message: any, ...optionalParams: any[]) {}

  /**
   * Write a 'verbose' level log.
   */
  verbose?(message: any, ...optionalParams: any[]) {}
}

 

 

그런 다음 Nest 애플리케이션 옵션 개체의 logger 속성을 통해 앞서 만든 MyLogger 인스턴스를 제공하도록 합니다.

const app = await NestFactory.create(AppModule, {
  logger: new MyLogger(),
});
await app.listen(3000);

 

이러한 방식은 매우 간단하지만 여기서 MyLogger 클래스에 대한 의존성 주입을 활용하고 있지 않습니다.

 

이는 특히 테스트 시에 몇 가지 문제를 일으킬 수 있고, MyLogger의 재사용성을 제한하는 방식이기에 그렇게 좋은 방식은 아닙니다. 이를 해결하기 위한 방법은 아래 1-5장 의존성 주입 파트에서 다룰 것입니다.

 

1-4. Extend build-in logger (내장 로거 확장)

logger를 백지상태에서부터 만들지 않고 기본으로 제공하는 ConsoleLogger 클래스를 상속하여 default 구현의 정해진 동작을 재정의(override)하여 우리의 요구 사항에 맞게 확장시킬 수 있습니다.

 

import { ConsoleLogger } from '@nestjs/common';

export class MyLogger extends ConsoleLogger {
  error(message: any, stack?: string, context?: string) {
    // 이곳에 추가 로직을 구현합니다.
    super.error(...arguments);
  }
}

 

아래의 애플리케이션 로깅을 위한 로거 사용 섹션에 설명된 대로 기능 모듈(Feature module)에서 이러한 확장 로거를 사용할 수 있습니다.

위의 사용자 정의 구현 섹션에서 보여준 것처럼, 애플리케이션 옵션 객체의 logger 속성을 통해 인스턴스를 전달하거나 아래의 의존성 주입 섹션에서 보여주는 테크닉을 사용하여 확장 로거를 시스템 로깅에도 사용하도록 Nest에게 지시할 수 있습니다.

 

그러한 경우, 위의 샘플 코드에 보이는 것처럼 super()를 호출하며, Nest가 내장 기능을 사용할 수 있도록 하기 위해서,  특정 로그 메서드 호출을 부모(내장) 클래스에 위임하는 super() 호출에 신경써야 합니다.

 

1-5. Dependency Injection (의존성 주입)

고급 로깅 기능을 사용하기 위해선 의존성 주입을 활용해야 할 것입니다.

 

예를 들어, 로거에 ConfigService를 주입하여 커스터마이징한 다음, 해당 커스텀 로거를 다른 컨트롤러나 provider에 주입해야 하는 경우를 가정합시다.

 

그러기 위해선 커스텀 로거에 의존성 주입을 사용해야 하는데, LoggerService를 구현하는 클래스를 먼저 만들고 해당 클래스를 어떤 모듈에 providers로 등록합니다.

 

예를 들면 다음과 같습니다.

• 이전 섹션에서 설명한 대로 기본 제공 ConsoleLogger를 상속하여 완전히 재정의하는 MyLogger 클래스를 정의합니다. 이때 반드시 LoggerService 인터페이스를 구현하도록 합니다.
• 아래와 같이 LoggerModule을 생성하고 해당 모듈에서 MyLogger를 providers에 등록합니다.

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

@Module({
  providers: [MyLogger],
  exports: [MyLogger],
})
export class LoggerModule {}

 

이러한 구조를 통해 이제 다른 모듈에서 사용할 수 있도록 커스텀 로거를 제공할 수 있게 된 것입니다. MyLogger 클래스도 결국 모듈의 일부이므로 의존성 주입을 사용할 수 있습니다(ex. ConfigService 주입)).

 

이 커스텀 로거를 제공함으로써 Nest가 시스템 로깅(ex. 부팅 및 에러 핸들링)을 사용할 수 있도록 하기 위해 요구되는 작업이 아직 하나 남아있습니다.

 

애플리케이션 인스턴스화(NestFactory.create())는 모듈의 context 외부에서 발생하기 때문에(main.ts) 일반적인 초기화 단계인 의존성 주입 단계에 참여하지 않습니다. 이말은 즉슨, 적어도 하나의 애플리케이션 모듈은 반드시 LoggerModule을 import 해야지 Nest가 MyLogger 클래스의 Singleton 인스턴스를 인스턴스화를 한다는 것입니다.

 

아래와 같이 구성하여 nest가 동일한 MyLogger의 singleton 인스턴스를 사용하도록 지시할 수 있습니다:

const app = await NestFactory.create(AppModule, {
  bufferLogs: true,
});
app.useLogger(app.get(MyLogger));
await app.listen(3000);

 

위의 예에서는 커스텀 로거(이 경우 MyLogger)가 연결되고 애플리케이션 초기화 프로세스가 완료되거나 실패할 때까지 모든 로그가 버퍼링되도록 bufferLogs를 true로 설정했습니다.

만약 초기화 프로세스가 실패하면 Nest는 원래 ConsoleLogger로 fallback하여 보고된 모든 오류 메시지를 출력합니다. 또한, autoFlushLogs를 false(기본값 true)으로 설정하여 로그를 수동으로 플러시할 수도 있습니다(Logger#flush() 메서드 사용).

 

여기서는 NestApplication 인스턴스(app)의 get() 메서드를 사용하여 MyLogger 객체의 싱글톤 인스턴스를 가져옵니다. 이 테크닉은 기본적으로 Nest에서 사용할 로거 인스턴스를 "주입"하는 방법입니다. app.get() 호출은 MyLogger의 싱글톤 인스턴스를 찾으며, 위에서 설명한 대로 해당 인스턴스가 다른 모듈에 먼저 주입되는지 여부에 따라 달라질 수 있습니다.

또한 기능 클래스에도 이 MyLogger provider를 삽입하여 Nest 시스템 로깅과 애플리케이션 로깅 모두에서 일관된 로깅 동작을 보장할 수 있습니다. 

 

1-6. Using the logger for application logging (애플리케이션 로깅을 위한 로거 사용하기)

위의 몇 가지 기술을 결합하여 Nest 시스템 로깅과 자체 애플리케이션 이벤트/메시지 로깅 모두에서 일관된 동작과 형식을 제공할 수가 있습니다.

가장 좋은 방법은 아래와 같이 각 서비스에서 @nestjs/common의 Logger 클래스를 인스턴스화하는 것입니다. 여기서는 Logger의 consturctor에 서비스 이름을 컨텍스트의 인자로 제공하였습니다:

import { Logger, Injectable } from '@nestjs/common';

@Injectable()
class MyService {
  private readonly logger = new Logger(MyService.name);

  doSomething() {
    this.logger.log('Doing something...');
  }
}

 

default 로거 구현에서는 아래 예제의 NestFactory와 같이 해당 컨텍스트가 대괄호(' [ ] ') 안에 출력됩니다:

[Nest] 19096   - 12/08/2019, 7:12:59 AM   [NestFactory] Starting Nest application...

 

app.useLogger()를 통해 커스텀 로거를 공급하면, 실제로 해당 로거를 Nest가 내부적으로 사용합니다. 즉, 코드가 구현에 구애받지 않고 유지되며, app.useLogger()를 호출하여 기본 로거를 커스텀 로거로도 쉽게 대체할 수 있습니다.

이렇게 하면 이전 섹션의 단계를 따라 app.useLogger(app.get(MyLogger))를 호출하면 MyService에서 this.logger.log()를 호출할 때 MyLogger 인스턴스에서 메서드 log를 호출하게 됩니다.

이는 거의 대부분의 경우에 아주 적합합니다. 하지만 커스텀 메서드 추가나 호출과 같은 추가적인 커스터마이징이 필요하다면 다음 섹션을 확인해주시면 됩니다.

 

1-7. Injecting a custom logger (커스텀 로거 주입)

가장 먼저, 아래과 같은 코드로 기본으로 제공하는 로거를 확장해야 합니다.

 

각 기능 모듈마다 고유한 MyLogger 인스턴스를 갖도록 하기 위해 transient scope를 지정해야 하는데, 이는 ConsoleLogger 클래스에 대한 configuration 메타데이터로 scope 옵션을 제공하면 됩니다.

 

이 예에서는 log(), warn() 등과 같은 개별 ConsoleLogger 내장 메서드를 확장하진 않았지만, 원하는 경우 확장할 수도 있습니다.

import { Injectable, Scope, ConsoleLogger } from '@nestjs/common';

@Injectable({ scope: Scope.TRANSIENT })
export class MyLogger extends ConsoleLogger {
  customLog() {
    this.log('Please feed the cat!');
  }
}

 

그 다음, 아래와 같은 구조의 LoggerModule을 생성합니다:

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

@Module({
  providers: [MyLogger],
  exports: [MyLogger],
})
export class LoggerModule {}

 

다음으로 LoggerModule을 아무 기능 모듈에서 import합니다. 기본 로거를 확장했기 때문에 해당 ConsoleLogger가 제공하는 setContext 메서드를 편리하게 사용할 수 있습니다. 이제 다음과 같이 context-aware(context를 파악하고 있는) 커스텀 로거를 사용할 수 있습니다:

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

@Injectable()
export class CatsService {
  private readonly cats: Cat[] = [];

  constructor(private myLogger: MyLogger) {
    // transient scope 때문에, CatsService는 자신만의 고유한 MyLogger 인스턴스를 갖습니다.
    // 그래서 여기서 context를 설정하는 것은 다른 service의 다른 인스턴스에 영향을 끼치지 않습니다.
    this.myLogger.setContext('CatsService');
  }

  findAll(): Cat[] {
    // 모든 default methods들도 역시 사용가능합니다.
    this.myLogger.warn('About to return cats!');
    // And your custom methods
    this.myLogger.customLog();
    return this.cats;
  }
}

 

이렇게 하면 로그가 찍힐 때 앞에 컨텍스트 이름이 붙어서 나오기 때문에 어느 부분에서 찍힌 로그인지 파악하는 데 용이합니다. (ex. [Nest] 72540  - 02/10/2024, 9:19:30 AM   WARN [CatsService] About to return cats)

 

마지막으로 아래와 같이 Nest가 main.ts 파일에서 커스텀 로거의 인스턴스를 사용하도록 지시합니다.

const app = await NestFactory.create(AppModule, {
  bufferLogs: true,
});
app.useLogger(new MyLogger());
await app.listen(3000);

 

물론 이 예제에서는 실제로 로거 동작을 커스텀하지는 않았기 때문에(log(), warn() 등과 같은 로거 메서드를 확장하여) 이 단계는 사실 필요하지 않습니다.

 

하지만 만약 해당 메서드에 커스텀 로직을 추가하였고 Nest가 동일한 구현을 사용하도록 하고자 한다면  반드시 이 단계를 추가해주셔야 합니다.

 

또는 bufferLogs를 true로 설정하는 대신 logger: false 명령어를 사용하여 일시적으로 로거를 비활성화할 수 있습니다. 다만 NestFactory.create에 logger: false를 제공하면 useLogger를 호출할 때까지 아무 것도 기록되지 않으므로 중요한 초기화 에러를 놓칠 수 있다는 점에 유의해야 하빈다. 초기 메시지 중 일부가 기본 로거로 기록되어도 괜찮다면 logger: false 옵션을 생략할 수 있습니다.

 

1-8. Use external logger (외부 로거 사용)

프로덕션 애플리케이션에는 고급 필터링, 포맷 지정, 중앙 집중식 로깅 등 기본 동작 이외의 특정 로깅 요구 사항이 있는 경우가 많습니다.

 

Nest의 내장 로거는 Nest 시스템 동작을 모니터링하는 데 사용되며 개발 중 기능 모듈의 기본 형식의 텍스트 로깅에도 유용하긴 하지만, 프로덕션 애플리케이션은 종종 Winston과 같은 전용 로깅 모듈을 활용합니다.

 

다른 표준 Node.js 애플리케이션과 마찬가지로 Nest에서도 이러한 모듈을 최대한 활용할 수 있습니다.

 

2. Logging 실습

내장 Logger, Custom Logger, 외부 Logger(유저 서비스)와 같이 세 가지 방식의 로거를 구현해보면서 로깅 시스템이 어떤 방식으로 활용되는지 알아보도록 하겠습니다.

 

2-1. 내장 Logger

내장 Logger 클래스는 @nest/common 패키지에서 제공합니다.

 

2-1-1. 로깅 비활성화

앞서 말했듯, 내장 로거는 로그를 남기려는 곳에서 인스턴스를 직접 생성하여 사용할 수 있습니다.

import { Injectable, Logger } from '@nestjs/common';

@Injectable()
export class AppService {
  // 로거 인스턴스 생성 시 클래스명을 컨텍스트로 설정하여 로그 메시지 앞에 클래스명이 함께 출력되도록 함. 
  private readonly logger = new Logger(AppService.name);
  getHello(): string {
    this.logger.error('this is error');
    this.logger.warn('this is warn');
    this.logger.log('this is log');
    this.logger.verbose('this is verbose');
    this.logger.debug('this is debug');

    return 'Hello World!';
  }
}

 

$ curl --location 'http://localhost:3000'
Hello World!

[Nest] 72540  - 04/17/2023, 9:19:30 AM   ERROR [AppService] this is error
[Nest] 72540  - 04/17/2023, 9:19:30 AM    WARN [AppService] this is warn
[Nest] 72540  - 04/17/2023, 9:19:30 AM     LOG [AppService] this is log
[Nest] 72540  - 04/17/2023, 9:19:30 AM VERBOSE [AppService] this is verbose
[Nest] 72540  - 04/17/2023, 9:19:30 AM   DEBUG [AppService] this is debug

 

NestFactory.create() 메서드의 인자인 NestApplicationOptions 객체에 logger를 비활성화할 수 있는 옵션이 있습니다. 해당 옵션을 false 로 설정 하면 위와 같은 로그가 출력되지 않습니다.

// main.ts
import { NestFactory } from '@nestjs/core';
import { AppModule } from './app.module';

async function bootstrap() {
  //const app = await NestFactory.create(AppModule);
  // 로그 비활성화
  const app = await NestFactory.create(AppModule, {
    logger: false,
  });
  await app.listen(3000);
}
bootstrap();

 

2-1-2.  로그 레벨 지정

production 환경에서까지 모든 로그를 남기게 된다면 사용자의 행동을 전부 추적한 결과를 포함하기 때문에 사용자의 민감한 정보가 드러나게 될 수 있고, 로그 파일의 사이즈 역시 커질 것이기 때문에 실행 환경에 따라 로그 레벨을 지정해 주는 경우가 일반적입니다.

// main.ts
import { NestFactory } from '@nestjs/core';
import { AppModule } from './app.module';

async function bootstrap() {
  //const app = await NestFactory.create(AppModule);

  // 로그 비활성화
  // const app = await NestFactory.create(AppModule, {
  //   logger: false,
  // });

  // 로그 레벨 지정 (PROD 환경은 log 레벨 이상, 그 외 환경은 debug 레벨 이상 로그 출력
  const app = await NestFactory.create(AppModule, {
    logger:
      process.env.NODE_ENV === 'prod' ? ['error', 'warn', 'log'] : ['debug'],
  });
  await app.listen(3000);
}
bootstrap();

 

<참고>: nest의 로그 레벨

const LOG_LEVEL_VALUES = {
  debug: 0,
  verbose: 1,
  log: 2,
  warn: 3,
  error: 4,
};

 

2-2. Custom Logger

앞선 내장 Logger는 파일이나 DB로 저장할 수 있는 기능을 따로 제공하고 있지는 않기 때문에 이를 위해선 Custom Logger를 사용해야 합니다.

Custom Logger는 @nestjs/common 패키지의 LoggerService 인터페이스를 구현할 수 있습니다.

 

LoggerService의 구현 시그니처는 다음과 같습니다.

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;
}

 

LoggerService를 상속한 MyloggerService를 다음과 같이 만들어줍니다.

// src/loggin/mylogger.service.ts
import { LoggerService } from '@nestjs/common';

export class MyloggerService implements LoggerService {
  debug(message: any, ...optionalParams: any[]): any {
    console.log(message);
  }

  error(message: any, ...optionalParams: any[]): any {
    console.log(message);
  }

  log(message: any, ...optionalParams: any[]): any {
    console.log(message);
  }

  verbose(message: any, ...optionalParams: any[]): any {
    console.log(message);
  }

  warn(message: any, ...optionalParams: any[]): any {
    console.log(message);
  }
}

 

이를 사용하는 서비스에서는 해당 로거를 아래와 같이 사용할 수 있습니다.

import { Injectable, Logger } from '@nestjs/common';
import { MyloggerService } from './logging/mylogger.service';

@Injectable()
export class AppService {
  private readonly logger = new Logger(AppService.name);
  private readonly mylogger = new MyloggerService();
  getHello(): string {
    console.log(process.env.NODE_ENV);
    this.logger.error('this is error');
    this.logger.warn('this is warn');
    this.logger.log('this is log');
    this.logger.verbose('this is verbose');
    this.logger.debug('this is debug');

    this.mylogger.error('test');

    return 'Hello World!';
  }
}

 

[Nest] 80549  - 04/17/2023, 11:30:13 AM   ERROR [AppService] this is error
[Nest] 80549  - 04/17/2023, 11:30:13 AM    WARN [AppService] this is warn
[Nest] 80549  - 04/17/2023, 11:30:13 AM     LOG [AppService] this is log
test

 

그런데 이렇게 하면 그냥 해당 메세지만 출력이 되기 때문에 로그를 통해 알 수 있는 정보가 많이 없습니다.

 

그래서 만약 Custom Logger로 로그를 출력할 때도, 내장 Logger 처럼 프로세스 ID, 로깅 시간, 로그 레벨, 컨텍스트명 등이 출력되게 하려면 Custom Logger가 ConsoleLogger를 상속하도록 한 후, 원하는 메서드들을 override 해주면 됩니다.

// src/logging/mylogger.service.ts
import { ConsoleLogger } from '@nestjs/common';

export class MyloggerService extends ConsoleLogger {
  error(message: any, ...optionalParams: [...any, string?]) {
    super.error(`${message}...`, ...optionalParams);
    this.doSomething();
  }

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

 

import { Injectable, Logger } from '@nestjs/common';
import { MyloggerService } from './logging/mylogger.service';

@Injectable()
export class AppService {
  // 로거 인스턴스 생성 시 클래스명을 컨텍스트로 설정하여 로그 메시지 앞에 클래스명이 함께 출력되도록 합니다.
  private readonly logger = new Logger(AppService.name);
  private readonly mylogger = new MyloggerService();
  getHello(): string {
    console.log(process.env.NODE_ENV);
    this.logger.error('this is error');
    this.logger.warn('this is warn');
    this.logger.log('this is log');
    this.logger.verbose('this is verbose');
    this.logger.debug('this is debug');

    this.mylogger.error('test');

    return 'Hello World!';
  }
}

 

[Nest] 81840  - 02/10/2024, 11:42:54 AM   ERROR [AppService] this is error
[Nest] 81840  - 02/10/2024, 11:42:54 AM    WARN [AppService] this is warn
[Nest] 81840  - 02/10/2024, 11:42:54 AM     LOG [AppService] this is log
[Nest] 81840  - 02/10/2024, 11:42:54 AM   ERROR test...

 

2-2-1. Custom Logger 주입하여 사용하는 방법

위에선 Logger 를 사용하는 곳에서 매번 new 로 커스텀 로거 인스턴스를 생성하는 식으로 사용했는데, 이렇게 하는 것보다 Logger를 모듈로 만든 후 생성자에서 주입받아 사용하는 것이 더 안전하고 편한 방식인 건 이제 다들 잘 아실 겁니다.

 

LoggerModule을 생성한 후 AppModule에서 해당 모듈을 import 합니다.

// /src/logging/logger.module.ts

import { Module } from '@nestjs/common';
import { MyloggerService } from './mylogger.service';

@Module({
  providers: [MyloggerService],
  exports: [MyloggerService],
})
export class LoggerModule {}

 

// app.module.ts

import { Module } from '@nestjs/common';
import { AppController } from './app.controller';
import { AppService } from './app.service';
import { LoggerModule } from './logging/logger.module';

@Module({
  imports: [LoggerModule],
  controllers: [AppController],
  providers: [AppService],
})
export class AppModule {}

 

 

이제 MyLogger Provider는 다른 곳에서 생성자를 통해 주입받아 사용할 수 있게 됩니다 .

import { Injectable } from '@nestjs/common';
import { MyloggerService } from './logging/mylogger.service';

@Injectable()
export class AppService {
  constructor(private myLogger: MyloggerService) {}
  getHello(): string {
    console.log(process.env.NODE_ENV);
    this.myLogger.error('test');
    this.myLogger.debug('test');

    return 'Hello World!';
  }
}

 

[Nest] 82508  - 02/10/2024, 11:50:48 AM   ERROR test...
[Nest] 82508  - 02/10/2024, 11:50:48 AM   DEBUG test

앞서 우리가 error 수준의 로그는 ...이 찍히도록 커스텀하여 두 로그가 다른 것을 볼 수 있습니다.

 

2-2-2. Custom Logger 전역으로 사용하는 방법

Custom Logger를 main.ts에 지정해주면 전역으로 사용이 가능합니다. 이러한 방식을 사용하면 서비스 Bootstrapping 과정에서도 Custom Logger가 사용됩니다.

// main.ts

import { NestFactory } from '@nestjs/core';
import { AppModule } from './app.module';
import { MyloggerService } from './logging/mylogger.service';

async function bootstrap() {
  // 커스텀 로거 전역으로 사용
  const app = await NestFactory.create(AppModule, {
    bufferLogs: true, // 이 설정이 없으면 NestJS 앱이 구동되는 초반에 잠시동안 내장 로거가 사용됨
  });
  app.useLogger(app.get(MyloggerService));
  await app.listen(3000);
}
bootstrap();

 

2-2-3. 외부 Logger 사용

위와 같이 직접 Custom Logger를 만드는 것도 때에 따라선 좋은 선택이 될 수도 있겠지만, 많은 상황에서 이미 잘 만들어진 외부 로깅 라이브러리를 사용하는 것이 효율적입니다.

 

이 다음부터는 winston을 nest 모듈로 만들어놓은 nest-winston 패키지를 이용하여 로깅 기능을 구현해볼 것입니다.

 

2-3. 유저 서비스 (winston)

실제 서비스 운영 단계에서는 매번 로그를 확인할 수 있는 것이 아니기 때문에 로그를 콘솔에만 출력하는 것이 아니라 별도의 파일이나 DB에 저장하며, 로그 필터링와 추적을 쉽게 도와주는 외부 서비스로 우리의 로그를 전송하기도 합니다. 이때, nest-winston 패키지를 사용하면 이러한 것들을 쉽게 구현할 수 있습니다.

 

winston 공식 문서에서는 winston이 다중 전송(multiple transport)를 지원한다고 되어있습니다.

 

또한 로깅 프로세스 과정들을 분리시켜 좀 더 유연한 로깅 시스템 구성이 가능합니다.

 

nest-winston 은 총 세 가지 방식으로 적용이 가능한데 "필요한 곳만 nest-winston 을 적용하는 방법", "내장 Logger를 대체하는 방법" 그리고 "BootStrapping까지 포함하여 내장 Logger를 대체하는 방법" 이렇게 총 세 가지 방식이 있습니다.

 

이제 순서대로 그 방식을 살펴보도록 하겠습니다.

 

2-3-1. nest-winston 사용

$  npm i nest-winston winston

 

// app.module.ts

...
import * as winston from 'winston';
import { utilities, 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(), // 로그 남긴 시각 표시
            utilities.format.nestLike('MyApp', {  // 로그 출처인 appName('MyApp') 설정
              prettyPrint: true,
            }),
          ),
        }),
      ],
    }),
  ],
...
})
export class AppModule {}

 

winston 의 로그 레벨은 총 7단계입니다.

const levels = {
  error: 0,
  warn: 1,
  info: 2,
  http: 3,
  verbose: 4,
  debug: 5,
  silly: 6
};

 

이제 WINSTON_MODULE_PROVIDER 토큰으로 winston에서 제공하는 Logger 객체를 주입받아 로그를 남길 수 있습니다.

 

// src/users/users.controller.ts

...
import { WINSTON_MODULE_PROVIDER } from 'nest-winston';
import { Logger as WinstonLogger } from 'winston';

@Controller('users')
export class UsersController {
  // UsersService 를 컨트롤러에 주입
  constructor(
          ...
          @Inject(WINSTON_MODULE_PROVIDER) private readonly logger: WinstonLogger,
  ) {
  }

  // 회원 가입
  @Post()
  async createUser(@Body() dto: CreateUserDto): Promise<void> {
    const {name, email, password} = dto;
    console.log('createUser dto: ', dto);
    this.printWinstonLog(dto);
    await this.usersService.createUser(name, email, password);
  }

  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);
  }
}

 

$ curl --location 'http://localhost:3000/users/' \
--header 'Content-Type: application/json' \
--data-raw '{
    "name": "cdragon",
    "email": "abcd@test.com",
    "password": "1234"
}'

 

[MyApp] Error   2/10/2024, 2:31:50 PM error:  - { name: 'cdragon', email: 'abcd@test.com', password: '1234' }
[MyApp] Warn    2/10/2024, 2:31:50 PM warn:  - { name: 'cdragon', email: 'abcd@test.com', password: '1234' }
[MyApp] Info    2/10/2024, 2:31:50 PM info:  - { name: 'cdragon', email: 'abcd@test.com', password: '1234' }
[MyApp] Http    2/10/2024, 2:31:50 PM http:  - { name: 'cdragon', email: 'abcd@test.com', password: '1234' }
[MyApp] Verbose 2/10/2024, 2:31:50 PM verbose:  - { name: 'cdragon', email: 'abcd@test.com', password: '1234' }
[MyApp] Debug   2/10/2024, 2:31:50 PM debug:  - { name: 'cdragon', email: 'abcd@test.com', password: '1234' }
[MyApp] Silly   2/10/2024, 2:31:50 PM silly:  - { name: 'cdragon', email: 'abcd@test.com', password: '1234' }

 

2-3-2. 내장 Logger 대체

nest-winston은 LoggerService를 구현한 WinstonLogger 클래스를 제공하는데, Nest가 시스템 로깅을 할 때 바로 이 클래스를 이용하도록 해서 Nest 시스템에서 출력하는 로그와 우리가 출력하려는 로그의 형식을 동일하도록 설정할 수 있습니다.

 

WinstonLogger의 구현 시그니처는 다음과 같습니다.

export declare class WinstonLogger implements LoggerService {
    private readonly logger;
    private context?;
    constructor(logger: Logger);
    setContext(context: string): void;
    log(message: any, context?: string): any;
    error(message: any, trace?: string, context?: string): any;
    warn(message: any, context?: string): any;
    debug?(message: any, context?: string): any;
    verbose?(message: any, context?: string): any;
    getWinstonLogger(): Logger;
}

 

해당 기능의 구현을 위해 우선 WinstonLogger를 전역 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 토큰으로 주입받아서 사용합니다.

// src/users/users.controller.ts

import {
  LoggerService,
  InternalServerErrorException,
} from '@nestjs/common';
import { WINSTON_MODULE_NEST_PROVIDER } from 'nest-winston';

@Controller('users')
export class UsersController {
  // UsersService 를 컨트롤러에 주입
  constructor(
          // nest-winston 적용
          //@Inject(WINSTON_MODULE_PROVIDER) private readonly logger: WinstonLogger,

          // 내장 로거 대체
          @Inject(WINSTON_MODULE_NEST_PROVIDER) private readonly logger: LoggerService,
  ) {
  }

  // 회원 가입
  @Post()
  async createUser(@Body() dto: CreateUserDto): Promise<void> {
    const {name, email, password} = dto;
    console.log('createUser dto: ', dto);
    //this.printWinstonLog(dto);
    this.printLoggerServiceLog(dto);
    await this.usersService.createUser(name, email, password);
  }

  // nest-winston 적용
  // 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);
  // }

  // 내장 로거 대체
  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] Error   4/17/2023, 3:03:22 PM [InternalServerErrorException: test
    at UsersController.printLoggerServiceLog (/Users/-/Developer/05_nestjs/me/user-service/src/users/users.controller.ts:63:13)
    at UsersController.createUser (/Users/-/Developer/05_nestjs/me/user-service/src/users/users.controller.ts:43:10)
    at /Users/-/Developer/05_nestjs/me/user-service/node_modules/@nestjs/core/router/router-execution-context.js:38:29
    at processTicksAndRejections (node:internal/process/task_queues:95:5)
    at /Users/-/Developer/05_nestjs/me/user-service/node_modules/@nestjs/core/router/router-execution-context.js:46:28
    at /Users/-/Developer/05_nestjs/me/user-service/node_modules/@nestjs/core/router/router-proxy.js:9:17] 
    error:: - {
  		stack: [ '{name:'cdragon', email:'abcd@test.com', password:'1234'}' ]
	}
[MyApp] Warn    2/10/2024, 3:03:22 PM [{name:'cdragon', email:'abcd@test.com', password:'1234'}] warn:  - {}
[MyApp] Info    2/10/2024, 3:03:22 PM [{name:'cdragon', email:'abcd@test.com', password:'1234'}] log:  - {}
[MyApp] Verbose 2/10/2024, 3:03:22 PM [{name:'cdragon', email:'abcd@test.com', password:'1234'}] verbose:  - {}
[MyApp] Debug   2/10/2024, 3:03:22 PM [{name:'cdragon', email:'abcd@test.com', password:'1234'}] debug:  - {}

 

LoggerService가 제공하는 로그 레벨은 아무래도 WinstonLogger에 비해 좀 제한적입니다. LoggerService는 WinstonLogger와 다르게 인자로 받은 객체를 출력하지 않기 때문에 내용을 출력하기 위해서는 dto 객체를 아래와 같이 string으로 변환하여 메시지 내에 포함시켜 주었습니다.

this.logger.error('error::', JSON.stringify(dto), e.stack);

 

error() 함수는 두 번째 인자로 받은 객체를 stack 속성을 가진 객체로 출력합니다.

 

<error 함수에 넘기는 인자에 따른 출력 비교>

this.logger.error('error::', JSON.stringify(dto), e.stack);
----------------------------------------------------------------
[MyApp] Error   2/10/2024, 3:34:47 PM [InternalServerErrorException: test
    at UsersController.printLoggerServiceLog (/Users/-/Developer/05_nestjs/me/user-service/src/users/users.controller.ts:63:13)
    at UsersController.createUser (/Users/-/Developer/05_nestjs/me/user-service/src/users/users.controller.ts:43:10)
    at /Users/-/Developer/05_nestjs/me/user-service/node_modules/@nestjs/core/router/router-execution-context.js:38:29
    at processTicksAndRejections (node:internal/process/task_queues:95:5)
    at /Users/-/Developer/05_nestjs/me/user-service/node_modules/@nestjs/core/router/router-execution-context.js:46:28
    at /Users/-/Developer/05_nestjs/me/user-service/node_modules/@nestjs/core/router/router-proxy.js:9:17] error:: - {
  stack: [
    '{name:'cdragon', email:'abcd@test.com', password:'1234'}'
  ]
}

 

this.logger.error('error::', e.stack);
-------------------------------------------------------
[MyApp] Error   2/10/2024, 3:34:47 PM error:: - {
  stack: [
    'InternalServerErrorException: test\n' +
      '    at UsersController.printLoggerServiceLog (/Users/-/Developer/05_nestjs/me/user-service/src/users/users.controller.ts:63:13)\n' +
      '    at UsersController.createUser (/Users/-/Developer/05_nestjs/me/user-service/src/users/users.controller.ts:43:10)\n' +
      '    at /Users/-/Developer/05_nestjs/me/user-service/node_modules/@nestjs/core/router/router-execution-context.js:38:29\n' +
      '    at processTicksAndRejections (node:internal/process/task_queues:95:5)\n' +
      '    at /Users/-/Developer/05_nestjs/me/user-service/node_modules/@nestjs/core/router/router-execution-context.js:46:28\n' +
      '    at /Users/-/Developer/05_nestjs/me/user-service/node_modules/@nestjs/core/router/router-proxy.js:9:17'
  ]
}

 

this.logger.error('error::', JSON.stringify(dto));
-------------------------------------------------------------------
[MyApp] Error   2/10/2024, 3:34:47 PM error:: - {
  stack: [
    '{name:'cdragon', email:'abcd@test.com', password:'1234'}'
  ]
}

 

Nest는 라우터 엔드포인트를 시스템 로그로 출력하는데 서비스 재시작 시 nest-winston 모듈이 적용된 것을 확인할 수 있습니다. ([Nest]가 아닌 [MyApp] 태그)

[Nest] 1069  - 02/10/2024, 3:34:44 PM     LOG [NestFactory] Starting Nest application...
[Nest] 1069  - 02/10/2024, 3:34:44 PM     LOG [InstanceLoader] AppModule dependencies initialized +75ms
[Nest] 1069  - 02/10/2024, 3:34:44 PM     LOG [InstanceLoader] TypeOrmModule dependencies initialized +1ms
[Nest] 1069  - 02/10/2024, 3:34:44 PM     LOG [InstanceLoader] ConfigHostModule dependencies initialized +2ms
[Nest] 1069  - 02/10/2024, 3:34:44 PM     LOG [InstanceLoader] WinstonModule dependencies initialized +1ms
[Nest] 1069  - 02/10/2024, 3:34:44 PM     LOG [InstanceLoader] EmailModule dependencies initialized +0ms
[Nest] 1069  - 02/10/2024, 3:34:44 PM     LOG [InstanceLoader] AuthModule dependencies initialized +0ms
[Nest] 1069  - 02/10/2024, 3:34:44 PM     LOG [InstanceLoader] ConfigModule dependencies initialized +0ms
[Nest] 1069  - 02/10/2024, 3:34:44 PM     LOG [InstanceLoader] TypeOrmCoreModule dependencies initialized +42ms
[Nest] 1069  - 02/10/2024, 3:34:44 PM     LOG [InstanceLoader] TypeOrmModule dependencies initialized +0ms
[Nest] 1069  - 02/10/2024, 3:34:44 PM     LOG [InstanceLoader] UsersModule dependencies initialized +1ms
[MyApp] Info    2/10/2024, 3:34:44 PM [RoutesResolver] UsersController {/users}: - {}
[MyApp] Info    2/10/2024, 3:34:44 PM [RouterExplorer] Mapped {/users, POST} route - {}
[MyApp] Info    2/10/2024, 3:34:44 PM [RouterExplorer] Mapped {/users/email-verify, POST} route - {}
[MyApp] Info    2/10/2024, 3:34:44 PM [RouterExplorer] Mapped {/users/login, POST} route - {}
[MyApp] Info    2/10/2024, 3:34:44 PM [RouterExplorer] Mapped {/users/:id, GET} route - {}
[MyApp] Info    2/10/2024, 3:34:44 PM [NestApplication] Nest application successfully started - {}

 

2-3-3. BootStrapping까지 포함하여 내장 Logger로 대체

위 로그를 보면 시스템이 시작될 때 BootStrapping 과정에서는 아직 WinstonLogger가 적용되지 않기 때문에 [Nest] 태그가 붙은 내장 로거가 사용되고 있는 것을 볼 수 있습니다.

BootStrapping 과정까지 포함하여 Nest Logger를 대체하고 싶다면 NestFactory.create 시 bufferLogs 설정을 true로 설정하면 됩니다. (버퍼링 해 두었다가 WinstonLogger가 적용되고 나면 출력)

// main.ts

import { NestFactory } from '@nestjs/core';
import { AppModule } from './app.module';
import { ValidationPipe } from '@nestjs/common';
import {
  utilities,
  WINSTON_MODULE_NEST_PROVIDER,
  WinstonModule,
} from 'nest-winston';

async function bootstrap() {
  const app = await NestFactory.create(AppModule, {
    bufferLogs: true, // 부트스트래핑 과정까지 nest-winston 로거 사용
  });
  app.useLogger(app.get(WINSTON_MODULE_NEST_PROVIDER));
  await app.listen(3000);
}
bootstrap();

 

2-3-4. 외부 서비스에 로그 전송

winston을 사용하는 이유는 로그 포맷을 구성하기 쉽다는 점과 로그를 파일이나 DB에 저장하기도 쉽고, New Relic이나 DataDog와 같은 외부 유료 서비스에 로그를 전송하여 로그 분석툴와 시각화 툴을 사용할 수 있게끔 하기 위해서입니다.

 

그래서 winston을 사용하면 다른 매체에 로그를 저장하거나 외부 서비스에 로그를 전송할 때 간단한 설정만으로도 구현이 가능합니다.

 

transport 옵션이 리스트를 받도록 되어있기 때문에 여기에 로그를 전송할 옵션을 추가해 주기만 하면 되고, winston-transport 라이브러리를 이용하여 TransportStream으로 지속적인 로그 전달도 가능합니다.