[Spring]로그에 필요한 정보 삽입하기-2.MDC 활용

먼저, 나는 사용자가 API를 호출했을 때 어떤 사용자가 어떤 API를 호출했는지 로그로 남기고 싶었다.

그러면 나중에 로그 데이터를 집계하여 이 서비스에서 어떤 api가 많이 사용되는지 분석이 가능하지 않을까?

또한 유저별로 어떤 서비스를 주로 사용하는지에 대한 분석도.

그래서 유저가 api를 호출했을 때 유저의 아이디와 호출한 api를 포함할 수 있도록 먼저 로그 커스텀(?) 방법에 대해 알아보고자 한다.

---

먼저, 나는 유저의 요청이 JWT필터를 지나고, 컨트롤러에 도달하기 직전 요청을 인터셉터하여 공통적으로  해당 요청을 보낸 사용자id, 목적지(api)를 MDC를 이용하여 저장하고자 했다.

 

MDC란(Mapped Diagnostic Context)?

Log4j2나 로그백 같은 로깅 시스템에서 제공하는 기능이다. 웹 서버는 다수의 클라이언트 요청을 멀티 스레드로 처리한다.

이때, 각 요청에 대한 고유 정보(ex.누가 요청한건지, 무엇을 요청한 건지) 등을 로그에 포함시키고 싶을 때, 이 MDC라는 것을 쓴다.

MDC는 스레드 로컬 저장소에 키-값 정보를 저장할 수 있는 곳이고 이 정보를 로그 포맷안에 변수처럼 불러다 쓸 수 있게 해준다.

*스레드 로컬 저장소: 각 스레드마다 독립적으로 값을 저장할 수 있는 공간

이를 통해, 각 요청이 들어올 때 마다 해당 요청을 보낸 사용자와 어떤 api에 접근하려는지 로그로 남기기 위해 MDC에 userId,와 uri를 저장하고자 했다.

@Slf4j
@Component
public class LoggingInterceptor implements HandlerInterceptor {

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {

        String uri = request.getRequestURI();
        //로그인 하지 않은 사용자나 jwt필터를 거치지 않은 경우에는 getName하면 "anonymousUser" 라는 문자열 이 남옴
        String loginId = SecurityContextHolder.getContext().getAuthentication().getName();

        MDC.put("userId", loginId);
        MDC.put("uri", uri);

        return true;
    }

    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {
       MDC.clear();
    }
}

 

 

*HandlerInterceptor :  이 인터페이스는 컨트롤러로 들어오는 요청에 대한 전/후 처리를 가능하게 해주는 인터페이스다.

지금 HTTP요청이 들어오면  JWT필터를 거친 다음 컨트롤러에 진입하는 구조에서 필터와 컨트롤러 사이에 이 인터셉터가 들어가면서 공통 로직을 처리하게 한다. 이 인터셉트는 아래의 3가지 주요 메서드를 제공함.

• preHandle() : 컨트롤러 호출 전에 호출되는 메서드. 반환 타입은 boolean인데, 만약 false를 반환한다면 다음 차례인 컨트롤러가 실행되지 않는다.
• postHandle() : 컨트롤러가 정상적으로 실행된 이후에 실행되는 메소드. 컨트롤러에서 예외가 발생한다면 이 메소드는 호출되지 않는다.
• afterCompletion(): 컨트롤러가 응답을 전송한 뒤에 실행되는 메서드. 컨트롤러 실행과정에서 예외가 발생한 경우에 afterCompletion()메소드의 4번째 파라미터로전달되어 로그를 남기는 등 후처리를 위해 주로 사용된다. 

---

그런데 이 인터셉트가 작동하기 위해서는 추가 설정이 더 필요하다.

이 클래스가 있어야 스프링은 인터셉터를 인식하고 작동시킨다.

@Configuration
public class InterceptorConfig implements WebMvcConfigurer {
    private final LoggingInterceptor loggingInterceptor;

    public InterceptorConfig(LoggingInterceptor loggingInterceptor) {
        this.loggingInterceptor = loggingInterceptor;
    }

    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        registry.addInterceptor(loggingInterceptor)
                .addPathPatterns("/**");
    }
}

---

그러면 이제 처음에 MDC에 나온 userId와 요청uri에 대한 정보가 로그가 찍힐 때 함께 출력되도록 해야한다.

지난 번, 설정했던 log4j2 클래스에서 로그 패턴을 설정하는 부분에서 해당 정보까지 포함되도록 수정만 해주면 된다.

아래 설정에서[userId:%x{userId}] [uri:%X{uri}] 추가 되었다.

%x{key} : MDC에 key-value형태로 저장했었는데 {}안에 key를 넣으면 해당 value가 출력되는 것이다.

<Property name="LOG_PATTERN">%d{yyyy-MM-dd HH:mm:ss} [%t] %highlight{%-5level} [userId:%X{userId}][uri:%X{uri}]%logger{36} - %msg%n</Property>

*전체 설정

<?xml version="1.0" encoding="UTF-8"?>

<Configuration status="WARN">
    <Properties>
        <Property name="LOG_PATH">logs</Property>
        <!--수정된 부분!!!!        -->
        <Property name="LOG_PATTERN">%d{yyyy-MM-dd HH:mm:ss} [%t] %highlight{%-5level} [userId:%X{userId}][uri:%X{uri}]%logger{36} - %msg%n</Property>
    </Properties>

    <Appenders>
        <!-- 콘솔 로그 -->
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout disableAnsi="false" pattern="${LOG_PATTERN}" />
        </Console>

        <!-- 파일 로그 -->
        <SpringProfile name="prod">
            <RollingFile name="File" fileName="${LOG_PATH}/app.log"
                         filePattern="${LOG_PATH}/app-%d{yyyy-MM-dd}.log.gz">
                <PatternLayout pattern="${LOG_PATTERN}" />
                <Policies>
                    <TimeBasedTriggeringPolicy interval="1" modulate="true" />
                </Policies>
                <DefaultRolloverStrategy>
                    <Delete basePath="${LOG_PATH}">
                        <IfAccumulatedFileCount exceeds="30"/>
                    </Delete>
                </DefaultRolloverStrategy>
        </RollingFile>
        </SpringProfile>
    </Appenders>

    <Loggers>
        <!-- 패키지별 로그 레벨 설정 -->
        <Logger name="org.springframework" level="INFO" additivity="false">
            <AppenderRef ref="Console" />
        </Logger>

        <!-- 전체 애플리케이션 기본 로그 -->
        <Root level="INFO">
            <AppenderRef ref="Console" />
            <SpringProfile name="prod">
                <AppenderRef ref="File" />
            </SpringProfile>
        </Root>
    </Loggers>
</Configuration>

---

그리고 로그를 찍어보면, 로그에 userId와 uri가 나온 것을 알 수 있다.