좌충우돌 LogBack 적용기

LogBack이란?

Java의 log4j의 후속버전입니다. log4j의 아키텍처 기반으로 재작성 되었으며, slf4j을 지원하기 때문에 다른 logger로 얼마든지 바꿀수 있게 구현되어 있습니다. 

 

로그 레벨

사전 지식으로 로그 레벨에 대해서 알아야 합니다.

1. ERROR : 요청을 처리하는 중 오류가 발생한 경우 표시하는 로그입니다.
2. WARN : 처리 가능한 문제, 향후 시스템 에러의 원인이 될 수 있는 경고성 메시지를 나타냅니다.
3. INFO : 상태변경과 같은 정보성 로그를 나타냅니다.
4. DEBUG : 프로그램을 디버깅하기 위한 정보를 표시합니다.
5. TRACE : 추적 레벨을 Debug보다 훨씬 상세한 정보를 나타냅니다.

로그 레벨의 경우는 역순으로, ERROR이 가장 높고, TRACE가 가장 낮은 레벨입니다.

 

 

Logging With Springboot

• spring-boot-starter-web 의존성 추가
• application.yml 또는 logback-spring.xml에서 설정하는것이 포인트입니다.
• 설정할 부분은 대략 다음과 같습니다.
  • 콘솔, 파일, DB 등 로그를 출력하는 방법을 지정하는 Appender
  • 출력할 곳을 정하는 logger
  • logback 설정 파일 경로는 /resources/logback-spring.xml입니다.

Configuration

1. Appender에서 콘솔에 출력되는 형식을 지정합니다.
   • Pattern에서 지정한 방식대로 시간/레벨 등이 설정된 후 콘솔에 메시지를 저장합니다.
   • filter, encoder, policy 등을 지정할 수 있습니다.프로젝트에서는 로그가 특정 크기(10MB)가 되면, 새로운 로그를 저장하도록 구현할 계획이므로 RollingFileAppender을 사용합니다.
   • RollingFileAppender엔 등록되어 있는 몇가지 정책(RollingPolicy)들이 있습니다. 이 중 파일 크기 기반으로 정책을 설정할 계획이므로 SizeBasedTriggeringPolicy를 사용하였습니다. 또한, 저장되는 로그 파일을 10개씩 관리하기 위해 FixedWindowRollingPolicy를 같이 사용하였습니다.
   • https://logback.qos.ch/manual/appenders.html

filter

• DENY, ACCEPT, NEUTRAL 값을 설정 가능합니다.
• DENY : 로그 이벤트가 즉시 삭제됩니다.
• NEUTRAL : 다음 필터로 넘어갑니다.
• ACCEPT : 나머지 필터의 호출을 건너뛰고 로깅 이벤트가 즉각 처리됩니다.

 

LevelFilter

• 레벨에 따라서 필터를 처리합니다.
• onMatch나 onMisMatch 속성을 사용하여 지정한 레벨과 같을 때, 이벤트를 accept 하거나 deny 할 수 있습니다.
• 다른 Filter에 대한 정보는 다음 사이트를 참고하시면 됩니다.
• https://logback.qos.ch/manual/filters.html

 

적용기

자.. 준비는 대충 된 거 같으니,, 프로젝트에 직접 적용해 봅시다.

resources/logback-spring.xml

<configuration>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <layout class="ch.qos.logback.classic.PatternLayout">
            <Pattern>%d{HH:mm} %-5level %logger{36} - %msg%n</Pattern>
        </layout>
    </appender>

    <appender name="MOMO_LOG" 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>

        <encoder>
            <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
        </encoder>

        <file>MOMO_LOG.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
            <fileNamePattern>MOMO-%i.log</fileNamePattern>
            <minIndex>1</minIndex>
            <maxIndex>10</maxIndex>
        </rollingPolicy>
        <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
            <maxFileSize>10MB</maxFileSize>
        </triggeringPolicy>
    </appender>

    <root level="INFO">
        <appender-ref ref="MOMO_LOG"/>
        <appender-ref ref="STDOUT"/>
    </root>
</configuration>

• 10MB 파일크기 단위로 10개의 로그 파일을 저장하도록 구현하였습니다.
  • SizeBasedTriggeringPolicy, FixedWindowRollingPolicy를 사용합니다.
• 표준 출력에 대해서는 ConsoleAppender로 바로 출력하도록 합니다. 이 부분을 생략하면 스프링 부트 실행이 콘솔에 찍히지 않습니다.

 

Filter

 <filter class="ch.qos.logback.classic.filter.LevelFilter">
    <level>ERROR</level>
    <onMatch>ACCEPT</onMatch>
    <onMismatch>DENY</onMismatch>
</filter>

레벨에 따라서 적용되는 필터입니다. 이번 예시에서는 ERROR 레벨에서만 로그를 찍도록 하기 위해 ERROR 단계에서의 onMatch 속성을 ACCEPT로 설정하고, ERROR 레벨이 아니라면 로그를 찍지 않도록 하기 위해 ERROR 레벨이 아니라면 무시하도록 DENY를 걸어주었습니다. 참고로 값들에 대한 설명은 다음과 같습니다.

https://logback.qos.ch/manual/filters.html

1. ACCEPT : 로깅 이벤트를 바로 실행합니다.
2. DENY : 나머지 필터를 참조하지 않고 로깅 이벤트를 바로 종료
3. NEUTRAL : 다음 필터로 넘어갑니다.

Encoder

<encoder>
    <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
</encoder>

pattern에 명시한 형식대로 로그가 출력됩니다. Pattern에 명시할 수 있는 데이터는 다음 자료를 참고하시면 좋을 것 같습니다.

https://logback.qos.ch/manual/layouts.html

Policy

<rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
    <fileNamePattern>MOMO-%i.log</fileNamePattern>
    <minIndex>1</minIndex>
    <maxIndex>10</maxIndex>
</rollingPolicy>
<triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
    <maxFileSize>10MB</maxFileSize>
</triggeringPolicy>

 

이번 예제에서는 rollingPolicy와 triggeringPolicy를 사용하였습니다.  triggeringPolicy는 rollover가 발생하는 시점이며, rollingPolicy는 rollover 발생 시 처리 방식에 대해 명시하였습니다. TriggeringPolicy인 SizeBasedTriggeringPolicy로 인해10MB의 파일 크기가 넘어간다면 FixedWindowRollingPolicy가 발생하여 <file>에 적힌 파일명에 숫자를 붙여서 다른 파일로 보관하며, 10개의 파일을 보관합니다.

 

테스트

적용을 다 했으면, 이제 직접 테스트해 봅시다. 예외를 터트리면 ERROR 단계일거 같으니, 한번 아무렇게나 예외를 터트려 봅시다.

public Group findGroup(Long id) {
    throw new IllegalArgumentException("hello world!");
    //return groupSearchRepository.findById(id)
    //        .orElseThrow(() -> new GroupException(NOT_EXIST));
}

실행했는데 로그 파일은 생성되지만, 슬프게도 아무 로그도 찍히지 않는 문제가 발생했습니다. 문제가 무엇일까요? 답은 예외를 터트린다고 하더라도 로그 레벨이 ERROR이 아니라는 점입니다.

즉, 예외를 처리하는 ControllerAdvice에서 Logger.error 메서드를 호출하여서 명시적으로 ERROR 로그 레벨의 로그를 출력해 주면 됩니다. 이때 Exception 객체를 넘겨주면, StackTrace도 함께 출력됩니다.

@ExceptionHandler(IllegalArgumentException.class)
public ResponseEntity<ExceptionResponse> handleException(IllegalArgumentException e) {
    logger.error("error", e);

    return ResponseEntity.badRequest().build();
}

 

테스트 해보다가 참고로 알게된 점은.. 서비스 테스트에서 예외를 터트리더라도 Advice로는 가지 않는 문제가 있었습니다. ControllerAdvice는 컨트롤러 단에서 터지는 예외에 대해서만 처리를 하기 때문에 서비스 테스트에서 백날 예외를 터트려 봐야 Advice로 들어가지 않는다고 하더라구요.. 이거때문에 삽질을 좀 오랜시간 했습니다..ㅠ