Spring Boot Logback

Logback 은 Spring MVC 에서 로그를 남길 때 사용되던 log4j 의 후속 로그 라이브러리이다. SLF4J 의 구현체로, SLF4J 의 API 를 그대로 사용할 수 있다. 이는 spring-boot-starter-web 에 포함되어 있으니 따로 dependency 를 추가해줄 필요 없다.

 

 

로그를 사용할 때에는 로깅으로 인한 side effect 가 생기게 해서는 안된다. 예를 들어, 로그를 남기는 로직에서 예외가 발생하여 프로그램이 정상적으로 동작하지 않는 일이 생겨서는 안된다는 뜻이다. 각 로그에는 해당 로직에서 사용된 데이터와 설명이 들어가야 하며, 로그에는 사용자의 개인정보와 같은 민감한 정보가 들어가서는 안된다. 메소드의 input, output 을 로그로 남기면 debugger 을 사용하여 디버깅하지 않아도 되어 편리하다. (특히 디버거를 사용할 수 없는 상황이라면 더 유용할 것이다) 이를 구현할 때 메소드의 앞뒤로 코드가 중복해서 발생하는 것을 AOP 를 통해 해결할 수 있다.

 

 

Logback 은 logback-core, logback-classic 그리고 logback-access 3 개의 모듈로 나뉜다. logback-core 은 logback-classic, logback-access 두 모듈의 기반 역할을 담당하며 appender, layout 인터페이스가 이 모듈에 들어있다. logback-classic 은 SLF4J API 를 구현하여 log4j 혹은 java.util.logging 과 같은 다른 로깅 프레임워크 간 전환을 쉽게 가능하게 해준다. Logger 클래스가 이 모듈에 들어있다. 마지막으로 logging-access 는 Tomcat, Jetty 등 Servlet 컨테이너에 HTTP Access 로그 기능을 제공해준다고 한다.

 

 

 

Spring-Boot 에서 Logback 을 사용하면 Logback 은 resource 내의 logback-spring.xml (logback.xml 도 가능하며, xml 이 아닌 groovy 파일도 가능) 파일을 참조한다. 만약 다른 이름, 경로에 로깅 설정 파일을 두고싶다면, application.properties 파일에 아래와 같은 형식으로 경로를 설정해줄 수 있다.

 

 

# LOGBACK
logging.config=classpath:logs/logback-local.xml

 

 

 

아래는 Logback 설정 파일 예시이다.

 

 

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <property name="LOG_PATH" value="./logs/" />
    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>INFO</level>
        </filter>
        <encoder>
            <pattern>[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%-5level] [%thread] %logger %msg%n</pattern>
        </encoder>
    </appender>
    <appender name="INFO_LOG" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>INFO</level>
        </filter>
        <file>${LOG_PATH}/info.log</file>
        <append>true</append>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOG_PATH}/inf0_${type}.%d{yyyy-MM-dd}.gz</fileNamePattern>
            <maxHistory>30</maxHistory>
        </rollingPolicy>
        <encoder>
            <pattern>[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%-5level] [%thread] %logger %msg%n</pattern>
        </encoder>
    </appender>

    <root level="INFO">
        <appender-ref ref="console" />
        <appender-ref ref="INFO_LOG" />
    </root>
</configuration>

 

 

Appender 영역은 로그의 형태를 설정하고 어떤 방법으로 출력할지를 설정하는 곳이다. Appender 자체는 하나의 인터페이스를 의미하며, 하위에 여러 구현체가 존재한다.

 

 

 

Appender

 

 

 

이름 그대로 ConsoleAppender 은 콘솔에 로그를 출력, FileAppender 은 파일에 로그를 저장하는 클래스이다. RollingFileAppender 은 여러 개의 파일을 순회하면서 로그를 저장한다. 이 외에도 SMTPAppender 로 메일로 로그를 저장할 수도 있고, DBAppender 로 DB 에 로그를 저장할 수도 있다.

 

 

위 설정 파일의 각 <appender>  내에는 <filter> 이 들어있는데, 해당 <filter> 내에서는 Appender 이 어떤 레벨로 로그를 기록하는지 지정한다. (위에서는 둘 다 INFO) 로그 레벨은 아래와 같은 5 단계가 있다.

 

• ERROR: 예상하지 못한 심각한 문제가 발생하는 경우
• WARN: 로직 상 유효성 확인, 예상 가능한 문제로 인한 예외 처리 / 당장 서비스 운영에는 영향이 없지만 주의해야 할 부분
• INFO: 운영에 참고할만한 사항, 중요한 비즈니스 프로세스
• DEBUG: SQL 로깅 가능 / 개발 단계에서 사용
• TRACE: 모든 레벨에 대한로깅 추적 / 개발 단계에서 사용

 

 

그 다음으로는 <encoder> 요소를 통해서 로그의 표현 형식을 패턴으로 정의한다. 사용 가능한 패턴은 몇 가지 정해져 있으며, 대표적인 패턴은 아래와 같다.

 

패턴	의미
%Logger{length}	로거의 이름
%-5level	로그 레벨. -5는 출력 고정폭의 값
%msg (%message)	로그 메시지
%d	로그 기록 시간
%p	로깅 레벨
%F	로깅이 발생한 애플리케이션 파일 명
%M	로깅이 발생한 메소드 이름
%I	로깅이 발생한 호출지의 정보
%thread	현재 쓰레드 명
%t	로깅이 발생한 쓰레드 명
%c	로깅이 발생한 카테고리
%C	로깅이 발생한 클래스명
%m	로그 메시지
%n	줄바꿈
%r	애플리케이션 실행 후 로깅이 발생한 시점까지의 시간
%L	로깅이 발생한 호출 지점의 라인 수

 

 

그 다음으로 <root> 에서 위에 정의한 <appender> 들을 참조해서 로깅 레벨을 정한다. 만약 특정 패키지에 대해 다른 로깅 레벨을 설정하고 싶다면 <root> 대신 <logger> 을 사용해볼 수 있기도 하다.

 

 

 

이렇게 설정한 로거를 다른 클래스 파일 내에서 사용해볼 수 있다. Logback 은 출력할 메시지를 Appender 에게 전달할 Logger 객체를 각 클래스에 정의해서 사용한다. 

 

 

private final Logger LOGGER = LoggerFactory.getLogger(ChatController.class);

 

 

위와 같이 Logger 은 LoggerFactory 를 통해 객체를 생성한다. 이 때 클래스의 이름을 함께 지정해서 클래스의 정보를 Logger 에서 가져가게 한다. 로그를 출력하는 방법도 간단하다.

 

 

@MessageMapping("/queue/kafka/wonil")
public void messageKafka(@Payload Message message) throws JsonProcessingException {
    LOGGER.info("GOT MSG FROM USER : {}", message);
    kafkaProducer.send("kafkatopic", message);
}

 

 

log

 

 

INFO 레벨에서 로그가 출력되는 것을 확인할 수 있다. 위와 같이 변수의 값이 들어갈 부분을 중괄호로 지정하면 포맷팅을 통해 로그 메시지가 구성된다.

 

 

 

그 다음으로는 AOP, Global Handler 을 사용하여 로깅을 일괄처리하는 방법에 대해서도 조사해보았다. 클라이언트가 데이터를 담아서 API 를 호출하면, Controller 에서는 해당 데이터에 대한 처리를 수행한다. 데이터가 정상적으로 처리된 경우에는 성공 응답을 클라이언트로 다시 전송하지만, 데이터 처리가 정상적으로 되지 않고 Exception 이 발생한 경우에는 @RestControllerAdvice, @ExceptionHandler 로 구성한 Global Exception 에서 에러를 캐치한다. 그 다음 클라이언트로는 에러 응답을 다시 전송하게 된다. 여기서 Global Excpetion Handler 이란 @ControllerAdvice, @RestControllerAdvice, @ExceptionHandler 애노테이션을 기반으로 Controller 내에서 발생하는 에러에 대해 핸당 핸들러에서 캐치하여 오류를 발생시키지 않고 응답 메시지로 클라이언트에게 전달해주는 기능이다. @ControllerAdvice 는 AOP 를 이용하여 @Controller 로 선언한 지점에서 발생한 에러를 도중에 캐치하여 Controller 에서 발생한 에러를 처리할 수 있도록 해준다. (@RestControllerAdvice 도 마찬가지) 아래와 같이 간단하게 작성해볼 수 있다.

 

 

@Slf4j
@RestControllerAdvice
public class LoggingAspect {

    @ExceptionHandler(Exception.class)
    protected final ResponseEntity<Exception> handleAllExceptions(Exception ex) {
        log.error("EXCEPTION OCCURED: {} / cause: {}", ex.getMessage(), ex.getCause());
        return new ResponseEntity<>(ex, HttpStatus.OK);
    }

}

 

 

위와 같이 @ExceptionHandler(Exception.class) 를 사용하여 우선 간단하게 모든 Exception 에 대해 처리해줄 수 있게끔 해주었다. 만약 예외가 발생하면 클라이언트에는 Exception 을 담은 ResponseEntity 가 반환될 것이다. (물론 실제로 사용할 때에는 Exception 클래스를 그대로 사용하는게 아니라 다른 적절한 클래스를 만들어서 담아주어야 할 것이다) (참고: @Slf4j 애노테이션은 Logger 객체를 log 라는 이름으로 자동 생성해준다)

 

 

 

또, MDC 에 대해서도 간단히 알아본다. MDC (Mapped Diagnostic Context) 는 멀티쓰레드 로깅에 활용되는 기술인 NDC 에 java.util.map 의 적용으로 사용성을 높인 기술로, 각 쓰레드 별로 별도의 로깅 쓰레드를 정적 메소드로 관리할 수 있다. (현재는 log4j, logback 에서만 MDC 기능을 제공하고 있다고 한다) MDC 를 활용하여 요청마다 고유의 ID 를 부여하면 그 ID 를 이용하여 각 요청 별로 로그를 묶어서 확인할 수 있다. 자바에서는 ThreadLocal 을 이용하여 ID 변수를 저장해서 이를 가능하게끔 한다. 아래와 같이 하나의 Filter 클래스를 추가해준다.

 

 

package com.begin.board.common;

import jakarta.servlet.*;
import jakarta.servlet.http.HttpServletRequest;
import lombok.extern.slf4j.Slf4j;
import org.slf4j.MDC;
import org.springframework.stereotype.Component;

import java.io.IOException;
import java.util.UUID;

@Component
@Slf4j
public class MdcLogFilter implements Filter {

    @Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
        MDC.put("transactionId", UUID.randomUUID().toString());
        String url = (request instanceof HttpServletRequest) ? ((HttpServletRequest) request).getRequestURI() : null;
        log.info("Request to URL {}", url);
        chain.doFilter(request, response);
        MDC.clear();
    }
}

 

 

Filter 인터페이스는 init(), doFilter(), destroy() 3 개의 메소드를 가진다. init() 메소드는 필터 객체가 생성되고 준비 작업을 위해 딱 한 번만 호출되는 메소드이다. 해당 메소드의 매개변수는 FilterConfig 인스턴스로, 이를 통해 필터 초기화 매개변수의 값을 꺼낼 수 있다. doFilter() 은 매핑된 URL 에 요청이 들어올 때마다 호출되는 메소드이다. 위 코드에서는 매 요청마다 MDC 에 고유한 transactionId 값을 부여한다. 또, 요청된 URL 에 대한 정보를 로깅한다. 마지막으로 destroy() 는 웹 애플리케이션을 종료하기 전에 필터들에 대한 마무리 작업을 진행한다.

 

 

위 코드에서는 doFilter 가 끝나서 나오면 MDC.clear() 을 해준다. Spring 은 쓰레드 풀에 쓰레드들을 만들어 두고, 요청이 오면 쓰레드를 사용해 요청을 처리하고 반납한다. 그런데 MDC 는 쓰레드 별로 저장되는 쓰레드 로컬을 사용하므로, 요청이 완료될 때 Clear 을 해주지 않으면 다른 요청이 이 쓰레드를 재사용할 때 이전 데이터가 남아있을 수 있다. 그래서 항상 clear 메소드를 호출해주는 것이 좋다.

 

 

그 다음으로는 위에서 만들어준 transactionId 를 로깅에 사용할 수 있도록 encoder 의 pattern 을 아래와 같이 수정해준다.

 

 

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

 

 

위와 같이 작성하면 mdc 에서 transactionId 값을 찾아서 로그에 찍어준다.

 

 

result

 

 

 

 

 

 

 

 

 

Reference:

https://atoz-develop.tistory.com/entry/Servlet-Filter%EC%82%AC%EC%9A%A9%ED%95%98%EA%B8%B0

https://adjh54.tistory.com/79

https://lovethefeel.tistory.com/91

https://goddaehee.tistory.com/206

https://mangkyu.tistory.com/266