[NestJS] winston으로 로그 관리

위의 블로그를 참고하자.

💡 고민과 해결과정

배경

고민

• interceptor와 middleware 등 로그를 어느 부분에서 처리해야할까
• interceptor에서 처리하면 요청이 시작되고 끝나는 부분에 둘 다 거쳐 요청이 처리되는 데 걸리는 시간까지 기록해 성능개선에 용이하다, 하지만 라우트 핸들러를 지나야해서 잘못된 요청(404 등)은 로그가 찍히지 않는다. ncloud에 서버를 올리면 악성 공격을 하는 ip는 밴을 해야할 필요가 있을 수 있으니 로그가 찍혀야 한다.
• middleware로 구현하면 이런 로그들은 찍히지만, 응답 처리 후 거치지 않아 요청이 처리되는 데 걸린 시간을 계산하기 힘들다.

해결과정

• nestjs의 미들웨어는 요청이 들어오는 시점에 실행되고, 이후 요청 처리 부분을 지나고 나서는 다시 실행되지 않는 다는 것을 볼 수 있다.
• 그런데, 미들웨어에 구현한 로깅시스템으로 요청이 처리되는 데 걸린 시간을 계산할 수 있다.
• node.js의 response 객체는 finish이벤트를 제공한다.
• 이 이벤트는 http 응답이 클라이언트로 전송되고 완료될 때 발생하게 된다. 미들웨어에서 finish 이벤트 리스너를 설정하면 요청이 시작되는 시간과 응답이 완료되는 시간 차이를 계산해서 로그에 찍어낼 수 있는 것이다.
• 대략 코드는 아래와 같다.

@Injectable()
export class LoggerMiddleware implements NestMiddleware {
  constructor(private readonly logger: Logger) {}

  use(req: Request, res: Response, next: NextFunction) {
    const startTime = Date.now();  // 요청 시작 시간

    res.on('finish', () => {
      const duration = Date.now() - startTime;  // 요청 처리 시간 계산
      // ... 로그 기록 ...
    });

    next();  // 다음 미들웨어 또는 핸들러로 제어권 전달
  }
}