AOP를 활용하여 로깅 기능 개발

개발을 진행하다 보면 디버깅을 통해 에러를 찾고 해결하는 일이 많습니다. 하지만 운영 환경, 즉 배포된 서버에서는 개발 환경처럼 쉽게 디버깅하기 어렵습니다. 이때 중요한 것이 로그입니다. 로그는 문제의 원인을 빠르게 파악하고 해결하는 데 도움이 됩니다.

현재 프로젝트에서는 커스텀 에러를 발생시키고, ControllerAdvice에서 이를 일괄적으로 처리하고 있습니다. 그러나 요청별로 어떤 정보를 담고 있는지까지 파악하기 위해서는 추가적인 정보가 필요합니다. 특히 다음 정보들을 로그에 포함하면 에러 처리 뿐만 아니라 사용자의 요청을 분석하여 캐시할 데이터를 선정하는 데 도움이 될 수 있다고 판단하여 로그에 남기기로 했습니다.

• HTTP 요청 정보
• 사용자 정보

위 정보들은 모든 요청에 대해 적용되어야 하며, 이를 AOP를 활용해 효율적으로 처리할 수 있습니다.

---

AOP

출처 : https://javarush.com/en/groups/posts/en.3137.what-is-aop-fundamentals-of-aspect-oriented-programming

 

AOP(Aspect Oriented Programming, 관점 지향 프로그래밍)는 프로젝트 전반에서 반복적으로 나타나는 공통 관심사를 모듈화하여 관리하는 방식입니다.

스프링 프레임워크에서는 트랜잭션 관리에서 AOP가 대표적으로 사용됩니다. @Transactional 애노테이션이 붙은 메서드는 다음과 같은 방식으로 동작합니다.

• @Transactional이 붙은 메서드 실행 시 프록시가 생성되어 메서드를 감쌉니다.
• 메서드 호출 전후로 트랜잭션을 시작하고 종료하는 로직이 적용됩니다.

트랜잭션처럼 공통으로 적용되는 관심사를 모듈화하여 관리하는 것이 바로 AOP입니다.

이번 프로젝트에서는 모든 요청에 대한 로깅이 공통 관심사이므로, 이를 AOP를 통해 효과적으로 관리하고자 합니다.

---

MDC

MDC (Mapped Diagnostic Context)는 Slf4j에서 지원하는 기능 중 하나로, 특정 요청과 관련된 정보를 ThreadLocal에 저장해 로그에 포함시킬 수 있게 해줍니다. 예를 들어, 요청 ID나 사용자 ID와 같은 정보를 ThreadLocal에 저장한 후 로그에서 자동으로 추가해 어떤 요청에서 에러가 발생했는지를 쉽게 추적할 수 있습니다. Spring MVC에서는 요청마다 스레드가 할당되는 구조이므로, MDC와 ThreadLocal을 활용해 요청별 고유한 정보를 안전하게 관리할 수 있습니다.

MDC를 활용하여 컨트롤러에 요청이 들어올 때 HTTP 요청 정보와 사용자의 정보를 MDC에 저장하고, 이를 로그를 남길 때 사용하도록 하겠습니다.

---

RequestAspect

import jakarta.servlet.http.HttpServletRequest;
import java.security.Principal;
import java.util.Map;
import java.util.UUID;
import lombok.extern.slf4j.Slf4j;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.AfterThrowing;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.aspectj.lang.annotation.Pointcut;
import org.slf4j.MDC;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;

@Slf4j
@Component
@Aspect
public class RequestAspect {

  @Pointcut("@annotation(org.springframework.web.bind.annotation.RequestMapping) || " +
      "@annotation(org.springframework.web.bind.annotation.GetMapping) || " +
      "@annotation(org.springframework.web.bind.annotation.PostMapping) || " +
      "@annotation(org.springframework.web.bind.annotation.PutMapping) || " +
      "@annotation(org.springframework.web.bind.annotation.DeleteMapping) || " +
      "@annotation(org.springframework.web.bind.annotation.PatchMapping)")
  public void allRequestMappings() {
  }

  @Pointcut("execution(* com.e205..*.*(..))")
  public void allComE205Exceptions() {
  }

  @Before("allRequestMappings()")
  public void beforeControllerMethod() {
    ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
    if (attributes != null) {
      MDC.clear();

      HttpServletRequest request = attributes.getRequest();
      Principal userPrincipal = request.getUserPrincipal();

      String requestId = UUID.randomUUID().toString();
      String userId = (userPrincipal != null) ? userPrincipal.getName() : "unknown";

      MDC.put("userId", userId);
      MDC.put("requestId", requestId);
      MDC.put("requestURI", request.getRequestURI());
    }
  }

  @AfterThrowing(pointcut = "allComE205Exceptions()", throwing = "ex")
  public void logException(Exception ex) throws Exception {
    StackTraceElement stackTraceElement = ex.getStackTrace()[0];
    String className = stackTraceElement.getClassName();
    int lineNumber = stackTraceElement.getLineNumber();

    MDC.put("exceptionClassName", className);
    MDC.put("exceptionLineNumber", String.valueOf(lineNumber));

    throw ex;
  }

  @Around("@annotation(org.springframework.scheduling.annotation.Async)")
  public Object propagateMDC(ProceedingJoinPoint joinPoint) throws Throwable {
    Map<String, String> contextMap = MDC.getCopyOfContextMap();
    try {
      if (contextMap != null) {
        MDC.setContextMap(contextMap);
      }
      return joinPoint.proceed();
    } finally {
      MDC.clear();
    }
  }
}

이 코드는 AOP를 활용하여 요청과 관련된 정보를 MDC에 저장하고, 예외 발생 시에도 MDC 정보를 활용해 로그를 남기는 기능을 구현합니다. 컨트롤러로 들어오는 요청에 요청 ID, 사용자 ID, URI 등의 정보를 MDC에 저장하고, 비동기 메서드에서도 MDC 컨텍스트를 전파하여 일관된 로그를 유지합니다.

코드 설명

1. @Pointcut
   • allRequestMappings(): 모든 HTTP 요청을 대상으로 하는 포인트컷입니다.
   • allComE205Exceptions(): com.e205 패키지의 모든 메서드를 타겟팅하는 포인트컷입니다. 이 포인트컷은 예외 발생 시 로그를 남기기 위해 사용됩니다.
2. @Before - beforeControllerMethod()
   • allRequestMappings() 포인트컷을 기준으로 HTTP 요청이 컨트롤러에 도달하기 전에 실행됩니다.
   • 혹시 이전 요청에 대한 정보가 남아있을 수도 있으니 MDC를 clear 해줍니다.
   • 요청이 들어오면 ServletRequestAttributes를 사용해 HttpServletRequest 객체를 얻습니다.
   • UUID를 이용해 requestId를 생성하고, 사용자 ID (userPrincipal이 null일 경우 "unknown"으로 설정)를 MDC에 저장합니다.
   • 또한, 요청 URI도 MDC에 추가합니다. 이를 통해 각 요청의 정보가 로그에 포함되도록 설정합니다.
3. @AfterThrowing - logException(Exception ex)
   • allComE205Exceptions() 포인트컷을 기준으로 예외 발생 시 실행됩니다.
   • 예외 발생 시 첫 번째 스택 트레이스 정보를 추출해 예외가 발생한 클래스와 라인 번호를 MDC에 저장합니다.
   • 이 정보를 통해 로그에 예외 발생 위치를 기록해 디버깅에 도움을 줍니다.
   • 마지막으로 예외를 다시 던져 처리 흐름에 영향을 미치지 않도록 합니다.
4. @Around - propagateMDC(ProceedingJoinPoint joinPoint)
   • @Async 어노테이션이 붙은 비동기 메서드에 대해 MDC 정보를 전파하는 기능을 담당합니다.
   • 비동기 메서드는 기본적으로 별도의 스레드에서 실행되기 때문에 MDC 정보가 자동으로 전달되지 않습니다. 이를 해결하기 위해 현재 MDC의 컨텍스트 맵을 복사하여 비동기 메서드에 전달합니다.
   • 메서드가 끝난 후에는 MDC를 정리하여 메모리 누수를 방지합니다.

ControllerAdvice

@Slf4j
@RequiredArgsConstructor
@RestControllerAdvice
public class GlobalExceptionHandler {

  private final ExceptionLoader errorCodeManager;

  @ExceptionHandler(GlobalException.class)
  public ResponseEntity<ErrorResponse> handleGlobalException(GlobalException ex) {
    logRequestInfo(ex);
    String errorCode = ex.getCode();
    ErrorDetails details = errorCodeManager.getErrorDetails(errorCode);
    return ResponseEntity.status(details.httpStatus()).body(ErrorResponse.from(details));
  }

  private void logRequestInfo(Exception ex) {
    Map<String, String> mdcValues = MDC.getCopyOfContextMap();

    if (!mdcValues.isEmpty()) {
      String mdcInfo = mdcValues.entrySet()
          .stream()
          .map(entry -> entry.getKey() + "=" + entry.getValue())
          .collect(Collectors.joining(", "));

      log.info("Exception handled: currentThread={}, {}, exceptionMessage={}, stackTrace={}",
          Thread.currentThread().getName(), mdcInfo, ex.getMessage(), ex.getStackTrace());
    }
  }
}

이 클래스는 전역적으로 발생하는 예외를 처리하기 위해 작성된 GlobalExceptionHandler입니다. Spring의 @RestControllerAdvice를 사용해 모든 컨트롤러에서 발생하는 특정 예외를 한곳에서 처리할 수 있도록 합니다. @ExceptionHandler를 사용해 특정 예외 유형을 감지하고, 이에 대해 적절한 응답을 생성합니다.

예외가 발생하면 다음과 같은 작업을 처리합니다.

• MDC (Mapped Diagnostic Context)에 저장된 모든 정보를 가져와 로깅에 포함합니다.
• MDC에서 가져온 정보를 mdcInfo에 연결하여 출력 형식으로 정리하고, 로그 메시지로 남깁니다.
• 로그 메시지에는 현재 스레드 이름, MDC 정보, 예외 메시지, 스택 트레이스를 포함하여, 문제가 발생한 위치와 상황을 파악하는 데 도움을 줍니다.

예시 로그 메시지

로그 메시지는 다음과 같은 형태로 출력됩니다:

Exception handled: currentThread=main, userId=123, requestId=abc-123, requestURI=/api/sample, exceptionMessage=Sample error message, stackTrace=...

이렇게 하면 클라이언트로부터 어떤 요청에서 문제가 발생했는지, 어느 사용자가 관련되었는지, 그리고 예외 메시지와 스택 트레이스까지 한 번에 파악할 수 있어 운영 환경에서 문제를 더 쉽게 추적하고 해결할 수 있습니다.