Spring Boot 에서 log를 남기는 방법 - Spring log 남기기

spring

Monitoring?

오늘은 Spring 에서 로그를 남기는 방법에 대해 알아보도록 하겠습니다~!

Spring Application을 제작할 때, 시스템의 성능, 서비스도 중요하지만

서비스를 유지하기 위해서는 모니터링이 꼭 필수적인 요소로 필요한데요~!

Monitoring 지표

모니터링을 하기 위해서는 특정 정보가 있어야 하겠죠~?

모니터링을 위한 정보는 어떻게 만드나요?

 

바로 Logging을 통해서 정보를 남기는 것이 아주아주 중요합니다

 

특히나, 요새는 DevOps 추세로 이어지고 있기 때문에

개발팀에서 모니터링까지 신경써주는 것이 일반적입니다

 

모니터링을 위한 정보를 만들어보는 것이 이번 게시글의 목표입니다~!

 

자, 그럼 이제 로깅하는 방법을 알아보도록 할까요?

Spring에서 로그를 남기는 방법

일단 로그를 남기고 싶은데, 어디다 남겨야 하고, 어떻게 남겨야 하는지를 모르겠죠?

간단히 spring에서 request가 들어오는 과정에 대한 설명을 보고 넘어가보도록 하겠습니다

Spring MVC Request Life Cycle

보통 Request가 들어오는 Flow는

Filter -> DispatcherServlet -> HandlerInterceptor -> controller 순으로 들어오게 됩니다

 

우리가 흔히 Spring Boot에서 Controller부터 바로 작성해서 요청이 바로 Controller로 들어오는 것인줄 알았지만,

실제는 그게 아니라는 거죠

 

그렇다면 Controller에 넘어가기 직전에, Interceptor에서 로그를 남긴다면?

-> API별 호출 횟수와 통계를 남길 수 있겠죠

-> 혹은 특정 API에 대한 통계를 남길 수도 있고요

 

로그를 남긴다는 것은 모니터링과 바로 직결되는 이야기이기 때문에

무엇을 남길지는 여러분이 직접 생각하셔야 됩니다

 

그래서, 어떤 로그를 남기고 싶은지 어떻게 남기고 싶은지 고민해보고 생각해봐야 합니다

1. API 접근에 대한 통계를 로그로 남기고 싶은지
2. API Call에 대한 시간 통계를 남기고 싶은지
3. Request에 대한 사용자별 정보를 로그로 남기고 싶은지
4. 기타.. ( 우리가 원하는 것 )

요번 시간에는 간단히 1,2 에 대해서 남기는 방법을 소개해볼까 해요

Custom Interceptor 만들기

한번 Interceptor를 직접 만들어볼까요?

package com.huisam.springstudy.interceptor;

import lombok.extern.log4j.Log4j2;
import org.springframework.stereotype.Component;
import org.springframework.web.servlet.ModelAndView;
import org.springframework.web.servlet.handler.HandlerInterceptorAdapter;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;

@Log4j2
@Component
public class Interceptor extends HandlerInterceptorAdapter {
    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        log.info("url : {}", request.getRequestURI());
        return super.preHandle(request, response, handler);
    }

    @Override
    public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) throws Exception {
        log.info("response status: {}", response.getStatus());
        super.postHandle(request, response, handler, modelAndView);
    }

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

HandlerInterceptorAdapter를 상속하게 되면,

여러 메서드들을 오버라이딩할 수 있는데요,

• preHandle의 경우, Request가 들어오고 Controller에 넘어가기 직전에 처리하게 되고,
• postHandle의 경우, Controller에서 요청이 다 마무리하고, View로 Rendering하게 전에 처리하게 되고,
• afterCompletion의 경우, Controller에서 요청이 다 마무리되고, View로 Rendering이 다 끝나면 처리하게 됩니다~!

이렇게 처리되는 시점이 다양하기 때문에,

입맛에 맞는 로그를 처리할 수 있게 됩니다~!

 

위에 있는 Custom Interceptor만 만들면 바로 로그가 남을까요?

 

아닙니다

 

아직 Spring에서는 내가 만든 Interceptor가 정상적으로 등록되지 않았기 때문에,

아무리 요청을 보내도 해당 코드는 등록하지 않습니다

 

Spring MVC에게 등록요청을 하는 Config 설정용 Class가 필요하다는 것이죠

package com.huisam.springstudy.interceptor;

import lombok.RequiredArgsConstructor;
import org.springframework.context.annotation.Configuration;
import org.springframework.web.servlet.config.annotation.InterceptorRegistry;
import org.springframework.web.servlet.config.annotation.WebMvcConfigurer;

@Configuration
@RequiredArgsConstructor
public class WebConfig implements WebMvcConfigurer {

    private final Interceptor interceptor;

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

위에서 만든 Interceptor를 의존성 주입해주고,

WebMvcConfigurer를 상속받게 되면, 다양한 메서드를 오버라이딩 할 수 있는데요

 

그 중의 하나인, addInterceptors 메서드를 통해서 해당 커스텀 Interceptor를 등록해주는 모습입니다

addPathPatterns를 통해서 내가 원하는 url에 대한 패턴도 직접 정의할 수 있게되죠!

 

위에서는 모든 Request에 대한 로그를 남기기 위해, 모든 url을 등록해준 모습입니다!

 

한번 실제 요청을 보내볼까요?

package com.huisam.springstudy.objectmapper;

import com.huisam.springstudy.mapstruct.Order;
import com.huisam.springstudy.reactive.OrderRequestBody;
import lombok.extern.log4j.Log4j2;
import org.springframework.web.bind.annotation.PostMapping;
import org.springframework.web.bind.annotation.RequestBody;
import org.springframework.web.bind.annotation.RestController;

import javax.validation.Valid;
import java.time.LocalDateTime;

@RestController
@Log4j2
public class OrderController {

    @PostMapping("/orders")
    public Order order(@RequestBody @Valid OrderRequestBody body) {
        log.info("Order Controller : {}", body);
        return Order.builder()
                .id(1L)
                .name(body.getName())
                .address("seoul")
                .price(123)
                .product("computer")
                .orderedTime(LocalDateTime.now())
                .build();
    }
}

테스트용 요청을 만들어보고 실제 로그에 남는지 알아보겠습니다~!

url이 정상적으로 로그에 남는지만 확인하면 되요~!

POST localhost:8080/orders
를 날려보면?  

로그 남긴 결과

잘 남기는 것을 볼 수 있네요 ㅎㅎ

 

그렇다면 이번에는 다른 방식으로 로그를 남겨볼까요?

AOP를 활용하여 남겨보기

spring에서 제공해주는 AspectJ를 활용해서 한번 남겨보도록 할게요~!

우선 build.gradle에서 다음 의존성을 추가해주세요~!

implementation 'org.springframework.boot:spring-boot-starter-aop'

그러면 우리는 훌륭한 라이브러리를 사용할 수 있게 되는데요 ㅎㅎ

우선 어노테이션 방식을 활용한 사례를 소개할까 해요

간단하게 어노테이션을 하나 만들어 봅시다

package com.huisam.springstudy.aop;

import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;

@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
@interface LogExecutionTime {
}

Target을 메서드 어노테이션으로 지정해주고, 런타임에 동작할 수 있게 정책을 만들었어요~!

위 어노테이션이 붙게 되면, 실행시간을 측정하고 로그에 남겨보도록 할 거에요!

 

package com.huisam.springstudy.aop;

import lombok.extern.log4j.Log4j2;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.springframework.stereotype.Component;
import org.springframework.util.StopWatch;

@Component
@Aspect // Aspect 를 꼭 명시!
@Log4j2
class LogAspect {

    @Around("@annotation(LogExecutionTime)") // 해당 어노테이션에 대해서 
    public Object logExecutionTime(ProceedingJoinPoint joinPoint) throws Throwable {
        StopWatch stopWatch = new StopWatch();
        stopWatch.start();

        Object proceed = joinPoint.proceed();

        stopWatch.stop();
        log.info(stopWatch.prettyPrint());
        return proceed;
    }
}

중요한 항목들이 몇가지 있는데요,

위 코드에서는 특정 메서드에 대한 실행시간을 측정하기 위해 남겨보는 테스트용 코드입니다~!

 

Aspect를 사용할 수 있는 어노테이션을 지정하고,

joinPoint를 가져와서, 해당 Point에서 동작되는 시간을 측정하게 한 코드에요~!

 

Aspect는 기본적으로 Proxy 패턴을 사용해서 동작되므로,

Proxy 패턴에 관한 설명은 이 게시글을 참고해주세요~!

 

자 그러면 만들었으니, 한번 잘되나 볼까요?

package com.huisam.springstudy.aop;

import lombok.extern.log4j.Log4j2;
import org.springframework.http.ResponseEntity;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;

import java.time.LocalDateTime;

@RestController
@Log4j2
public class AopController {
    @GetMapping("/order")
    @LogExecutionTime
    public ResponseEntity<Order> order() {
        Order order = Order.builder()
                .id(1L)
                .name("huisam")
                .address("서울")
                .price(200)
                .product("ice cream")
                .orderedTime(LocalDateTime.now())
                .build();

        return ResponseEntity.ok(order);
    }
}

아까처럼 Controller를 하나 만들어서

특정 url에 대해 @LogExecutionTIme 이라는 어노테이션을 붙여보도록 하겠습니다

GET localhost:8080/order

해당 요청을 보내게 되면?

로그 결과

위 게시글에서 만든 Interceptor에서 남긴 로그와, AspectJ로 만든 로그가 잘 남겨지는 모습을 볼 수 있습니다~!

정리

이번시간에는 로그를 남기는 방법에 대해 알아보았어요 ㅎㅎ

 

하지만, 중요한 항목이 하나 빠졌는데요.

로그를 남기는 파일에 대한 설정이 빠져있어요!

로그를 남기는 방법을 알았으니, 저장하는 방법도 알아봐야겠죠?

 

저장하는 방법은 다른 게시글로 찾아보도록 할게요~!

참고

Spring AOP 총 정리