Winston Logger
Winston의 Logging 레벨은 RFC5424 표준을 따르고 있다고 한다.
RFC 5424: The Syslog Protocol
Numerical Severity
Code
0 Emergency: system is unusable
1 Alert: action must be taken immediately
2 Critical: critical conditions
3 Error: error conditions
4 Warning: warning conditions
5 Notice: normal but significant condition
6 Informational: informational messages
7 Debug: debug-level messages- winston logger level
const levels = {
error: 0,
warn: 1,
info: 2,
http: 3,
verbose: 4,
debug: 5,
silly: 6
};winston logger를 생성할 때
level 옵션을 주게 되면 주어진 옵션보다 작거나 같은 레벨만 출력된다.
const logger = winston.createLogger({
level: 'info',
transports: [
new winston.transports.Console(),
]
});예를 들어 위와같이 info 레벨을 주게되면, error, warn, info만 출력되게 된다.
로그 파일로 남기기
winston으로 로그를 남길 때 어디에 로그를 출력할 지 설정할 수 있다.
transports 옵션으로 출력을 설정할 수 있다.
위의 예시 처럼 남기게되면 콘솔에만 찍히고 어디에도 남아있게 되지 않는다.
const logger = winston.createLogger({
transports: [
new winston.transports.File({
filename: 'combined.log',
level: 'info'
}),
]
});이렇게 설정하게 되면 파일로 저장할 수 있다.
하지만 위와 같이 설정하게 되면 모든 로그가 한 파일에 담길 수 있다.
로그를 날짜, 시간별로 관리하기 위해서 winston-daily-rotate-file을 도입했다.
로그를 순환할 수 있고, 개수, 경과일 수를 기준으로 오래된 로그를 삭제할 수있게 도와주는 패키지이다.
const transport: winston.transport[] = [
new winstonDaily({
filename: '%DATE%.log',
datePattern: 'YYYY-MM-DD-HH',
dirname: logDir,
zippedArchive: true,
maxSize: '20m',
maxFiles: '7d',
}),
];각종 옵션들로 로그파일의 최대 사이즈, 몇 일간의 로그를 저장할지, 어떤 패턴으로 저장할 지 등을 지정할 수 있다.
NestJS에 도입하기
NestJs에서는 기본적으로 Logger를 제공하고 있고, 싱글톤 패턴으로 관리한다.
Winston을 NestJS 생명주기에 적합하게 도입하기 위해서 Winston으로 LoggerService의 구현체를 만들어 주입해서 이용해야한다.
LoggerService 인터페이스는 다음과 같이 구현되어있었다.
export interface LoggerService {
/**
* Write a 'log' level log.
*/
log(message: any, ...optionalParams: any[]): any;
/**
* Write an 'error' level log.
*/
error(message: any, ...optionalParams: any[]): any;
/**
* Write a 'warn' level log.
*/
warn(message: any, ...optionalParams: any[]): any;
/**
* Write a 'debug' level log.
*/
debug?(message: any, ...optionalParams: any[]): any;
/**
* Write a 'verbose' level log.
*/
verbose?(message: any, ...optionalParams: any[]): any;
/**
* Write a 'fatal' level log.
*/
fatal?(message: any, ...optionalParams: any[]): any;
/**
* Set log levels.
* @param levels log levels
*/
setLogLevels?(levels: LogLevel[]): any;
}로깅 레벨이 Winston과 살짝 다른 것을 발견할 수 있었다.
NestJS는 Logging Level을 지정하는 것이 아니라 출력하고 싶은 레벨을 배열로 설정하는 형태인 것을 알 수 있었다.
const app = await NestFactory.create(AppModule, {
logger: ['error', 'warn'],
});
await app.listen(3000);Winston과 NestJS은 서로 다른 로그 시스템을 가지고 있지만,
NestJS에서 Winston을 이용하기위해 인터페이스에서 제공하는 것과 Winston에서 일치하는 로그레벨만 사용했다.
Winston에서 제공하는 로그레벨의 순서를 알아냈어야 했다.
// winstonLogger.service.ts
// LoggerService 구현체
log(message: string, ...optionalParams: any[]) {
this.logger.log(message, ...optionalParams);
}
error(message: string, ...optionalParams: any[]) {
this.logger.error(message, ...optionalParams);
}
warn(message: string, ...optionalParams: any[]) {
this.logger.warn(message, ...optionalParams);
}
debug(message: string, ...optionalParams: any[]) {
return this.logger.debug(message, ...optionalParams);
}
verbose(message: string, ...optionalParams: any[]) {
this.logger.verbose(message, ...optionalParams);
}@Controller()
export class AppController {
private readonly logger = new Logger();
constructor(private readonly appService: AppService) {}
@Get()
getHello(): string {
this.logger.log('log level');
this.logger.error('error level');
this.logger.warn('warn level');
this.logger.debug('debug level');
this.logger.verbose('verbose level');
return this.appService.getHello();
}
}위와 같이 테스트용 컨트롤러를 구성하고, winson 출력로그 레벨을 바꾸면서 테스트했다.
레벨별 출력 결과
debug
verbose
info
warn
error
우선순위는
error → warn → info → verbose → debug 순서임을 알 수 있었고
NestJS의 log가 Winston의 info에 해당한다는 것도 알 수 있었다.
운영하는 서버에서 로그 확인하기
winston, winston-daily-rotate-file, NestJS LoggerService를 이용해서 서버 로그를 남길 수 있게되었고
서버에서 로그파일을 확인할 수 있었다.
그런데 한 가지 문제가 있었다.
도커로 서버를 띄워서 운영하고 있었기 때문에, 재배포가 일어나면 도커컨테이너가 변경되어 쌓아온 로그파일이 날라가 버렸다.
개발 중 서버가 한 번 죽은 적이 있었는데, 이전 로그가 다 날아가버려서 이유를 찾을 수 없었다.
도커 볼륨 마운트
이를 해결하기 위해서 서버의 볼륨과 도커 컨테이너의 볼륨을 마운트해서 로그파일이 계속 유지되도록 했다.
version: '3.8'
services:
blue:
container_name: blue
image: hkleeeee/api
ports:
- 4001:4000
env_file:
- .env
volumes:
- ./logs:/var/app/logs
restart:
always
green:
container_name: green
image: hkleeeee/api
ports:
- 4002:4000
env_file:
- .env
volumes:
- ./logs:/var/app/logs
restart:
always도커 컴포즈 파일에 volumes을 연결해주었다.
이 옵션을 통해 도커 재시작에도 로그 파일을 유지할 수 있게 되었고,
로그를 확인하는 것도 더 편해졌다.
전에는 서버 ssh 접속 → 도커 인터렉티브 모드로 접속 → 로그파일 위치로 이동 과정을 통해 로그파일을 확인할 수 있었는데,
볼륨 마운트를 통해서 도커에 접속하지 않고도 로그 파일을 확인할 수 있었다.
에러 레벨 별도로 모으기
모든 로그를 한 파일에 작성하면서 서버를 운영하고 있었다.
그리고 부하테스트를 진행했는데 이 부분에 불편함이 생겼다.
무수히 많은 요청 속에서 에러가 발생하는 곳의 로그를 보고 싶었는데, 모든 레벨의 로그를 한 파일에 담고 있으니 에러 로그를 찾기가 너무 어려웠다.
그래서 에러레벨의 로그만 별도로 저장하는 설정을 추가해주었다.
const transport: winston.transport[] = [
new winstonDaily({
filename: '%DATE%.log',
datePattern: 'YYYY-MM-DD-HH',
dirname: logDir,
zippedArchive: true,
maxSize: '20m',
maxFiles: '7d',
}),
new winstonDaily({
filename: '%DATE%.error.log',
datePattern: 'YYYY-MM-DD-HH',
dirname: logDir + '/error',
zippedArchive: true,
maxSize: '20m',
maxFiles: '7d',
level: 'error',
}),
];첫번째 transport는 모든 로그를 순서대로 보여주어 로그의 흐름을 알 수 있다.
두번째 transport는 출력되는 로그중 에러레벨만 따로 저장하고 있어 에러가 발생한 경우만 따로 찾아볼 수 있게되었다.
완성한 코드
//winstonLogger.service.ts
import { utilities, WinstonModule } from 'nest-winston';
import * as winstonDaily from 'winston-daily-rotate-file';
import * as winston from 'winston';
import * as path from 'path';
const { combine, timestamp, printf, colorize } = winston.format;
import { Injectable, LoggerService } from '@nestjs/common';
import { ConfigService } from '@nestjs/config';
@Injectable()
export class WinstonLogger implements LoggerService {
private logger: LoggerService;
private readonly logDir = (() => {
const __dirname = path.resolve();
return path.join(__dirname, 'logs');
})();
constructor(private configService: ConfigService) {
const transport = this.getTransport();
this.logger = this.createLogger(transport);
}
getTransport(): winston.transport[] {
const transport: winston.transport[] = [
new winstonDaily({
filename: '%DATE%.log',
datePattern: 'YYYY-MM-DD-HH',
dirname: this.logDir,
zippedArchive: true,
maxSize: '20m',
maxFiles: '7d',
}),
new winstonDaily({
filename: '%DATE%.error.log',
datePattern: 'YYYY-MM-DD-HH',
dirname: this.logDir + '/error',
zippedArchive: true,
maxSize: '20m',
maxFiles: '7d',
level: 'error',
}),
];
if (this.configService.get<string>('NODE_ENV') !== 'production') {
const devConsole = new winston.transports.Console({
format: combine(
colorize(),
utilities.format.nestLike('API Server', {
prettyPrint: true,
}),
),
});
transport.push(devConsole);
}
return transport;
}
createLogger(transport: winston.transport[]) {
const logFormat = printf(
({ level, message, timestamp }) => `${timestamp} ${level}: ${message}`,
);
return WinstonModule.createLogger({
format: combine(
timestamp({ format: 'YYYY-MM-DD HH:mm:ss.SSS' }),
logFormat,
),
level:
this.configService.get<string>('NODE_ENV') !== 'production'
? 'debug'
: 'info',
transports: transport,
});
}
log(message: string, ...optionalParams: any[]) {
this.logger.log(message, ...optionalParams);
}
error(message: string, ...optionalParams: any[]) {
this.logger.error(message, ...optionalParams);
}
warn(message: string, ...optionalParams: any[]) {
this.logger.warn(message, ...optionalParams);
}
debug(message: string, ...optionalParams: any[]) {
return this.logger.debug(message, ...optionalParams);
}
verbose(message: string, ...optionalParams: any[]) {
this.logger.verbose(message, ...optionalParams);
}
}