[Spring] 로그백을 사용하여 로그를 남겨보자

ExceptionHandler를 이용하여 에러를 핸들링할 때 에러가 어디서 발생한지 알 수 없는 이슈를 겪은 적이 있습니다. 이 문제를 해결하기 위해 모든 ExceptionHandler 메서드에 e.printStackTrace()를 사용했는데요. 개발 과정에서는 충분히 사용할 수 있지만 실제 프로그램을 운영할 때 해당 메서드를 이용해서 로깅을 하는 것은 적절하지 않다고 생각했습니다. 서버가 종료되면 어디서, 어떤 이유로 에러가 발생하는지 알 수 없기 때문입니다.

 

이 문제를 해결하기 위해 spring-boot-starter-web dependency에서 제공하는 logback 라이브러리를 이용하여 로깅을 남기고 로컬에 저장하는 과정을 학습해보았습니다.

AS-IS

@RestControllerAdvice
public class ControllerAdvice {
    @ExceptionHandler(SubwayException.class)
    public ResponseEntity<ErrorResponse> subwayExceptionHandler(SubwayException e) {
                e.printStackTrace();
        return ResponseEntity.badRequest().body(new ErrorResponse(e.getMessage()));
    }
}

logback라이브러리를 사용하기 전에는 e.printStackTrace()를 이용했습니다. 하지만 System.err을 사용하는 이 메서드는 크리티컬한 상황을 나타내기 때문에 스트림의 내용을 즉시 flush하여 성능도 안좋을 뿐더러, 서버가 종료된 후 로그를 더이상 확인할 수 없다는 점에서 큰 담점이 있습니다.

이 문제를 해결하기위해 LogBack라이브러리를 사용하게 됐습니다.

TO-BE

@RestControllerAdvice
public class ControllerAdvice {

    private final Logger logger;

    public ControllerAdvice() {
        logger = LoggerFactory.getLogger(this.getClass());
    }

    @ExceptionHandler(SubwayException.class)
    public ResponseEntity<ErrorResponse> subwayExceptionHandler(SubwayException e) {
        logger.error(e.getMessage(), e);
        return ResponseEntity.badRequest().body(new ErrorResponse(e.getMessage()));
    }
}

LoggerFactory에서 Logger를 가져오고 ERROR level의 로그를 남길 수 있게 되었습니다.

에러 레벨에는 TRACE -> DEBUG -> INFO -> WARN -> ERROR 가 존재합니다.

위 사진을 보면 ERROR레벨의 로그와 에러가 발생한 지점을 함께 확인할 수 있게 됐습니다.

 

하지만 여전히 서버를 종료하면 더이상 해당 로그를 확인할 수 없는 문제가 있습니다. 이럴 때 스프링은 logback-spring.xml 파일의 설정을 읽어 추가적인 작업을 해줄 수 있도록 돕습니다.

logback 설정

ERROR레벨의 로그를 서버가 종료되도 확인할 수 있도록 로컬 파일로 저장한다. 라는 목표를 설정하고 파일을 작성합니다.

<property name="LOG_PATH" value="log/error"/>
<property name="LOG_PATTERN" value="%-5level %d{yy-MM-dd HH:mm:ss}[%thread] [%logger{0}:%line] - %msg%n"/>
<property name="FILE_NAME" value="error"/>

먼저 xml 파일에서 전역적으로 사용할 수 있는 property를 선언합니다. 반복적으로 사용되는 변수를 위 코드와 같이 설정할 수 있습니다.

Log pattern 은 링크에서 확인하고 작성할 수 있습니다.

먼저 로그가 콘솔에 잘 출력 되도록 먼저 설정해줍니다.

<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
  <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
    <pattern>${LOG_PATTERN}</pattern>
  </encoder>
</appender>

<root level="info">
  <appender-ref ref="CONSOLE"/>
</root>

콘솔의 출력되는 INFO레벨 이상 로그를 출력하기위해 전역적으로 선언한 Pattern을 PatternLayoutEncoder에 저장해둡니다. 이제부터 Logger는 해당 설정을 기반으로 Console에 로그를 출력하게 됩니다.

위 사진을 보면 기존의 로그와는 형태가 조금 다른 커스텀한 로그가 남게됐습니다.

그리고 이제 똑같은 방식으로 파일에 저장되게끔해야하는데요.

<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
  <filter class="ch.qos.logback.classic.filter.LevelFilter">
    <level>error</level>
    <onMatch>ACCEPT</onMatch>
    <onMismatch>DENY</onMismatch>
  </filter>
  <file>${LOG_PATH}/${FILE_NAME}.log</file>
  <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
    <pattern>${LOG_PATTERN}</pattern>
  </encoder>
  <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
    <fileNamePattern>${LOG_PATH}/${FILE_NAME}.%d{yyyy-MM-dd}_%i.log</fileNamePattern>
    <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
      <maxFileSize>10MB</maxFileSize>
    </timeBasedFileNamingAndTriggeringPolicy>
    <maxHistory>30</maxHistory>
  </rollingPolicy>
</appender>
<root level="info">
  <appender-ref ref="CONSOLE"/>
  <appender-ref ref="FILE"/>
</root>

파일에는 ERROR레벨의 로그만 저장할 수 있게끔 LevelFilter를 설정해줍니다. error 레벨에 대해서는 accept이고, 나머지 레벨은 deny해주고 있습니다.

 

하지만 한 파일에 너무 많은 로그가 담기면 어떨까요? 로그를 찾는 것이 굉장히 어려워집니다. 이 문제를 해결하기 위해 Logback에서는 RollingFileAppender를 제공합니다. 원하는 파일 명 패턴을 설정할 수 있으며, rolling 전략으로 SizeAndTimeBasedFNATP를 선택하면 파일 크기, 날짜에 따라 롤링하고 파일 보관일을 설정해줄 수 있습니다.

이제 에러를 발생시켜볼까요?

파일이 잘 생성된 것을 확인할 수 있습니다.

또, 파일에 에러 내용이 잘 추가된 것을 볼 수 있습니다.

로그백 라이브러리 참 친절하네요!