클라이언트가 어떤 정보로 어떤 API를 호출했는지 확인하고자 했습니다.
또, Request가 처리되는데 얼마나 걸렸는지 알 수 있다면 "문제가 발생했을 때 어느 지점에서 시간이 오래 소요됐는지 빠르게 파악할 수 있지 않을까?" 하는 생각이 들었습니다.
코드를 두 개의 관점으로 나누고, 공통된 로직 또는 기능을 하나의 단위로 묶어 모듈화하는 것으로 관점 지향 프로그래밍이라고 합니다.
부가적인 코드를 핵심 비즈니스 로직에서 분리해 재사용합니다.
다이나믹 프록시 기법
으로 구현@Aspect
, @Component
Aspect
: 흩어진 관심사를 모듈화한 것 Target
: Aspect 적용 위치 (클래스, 메서드 등)Advice
: 실질적인 부가 기능 구현체 (어떤 일을 할 것인지)JoinPoint
: Advice 적용 위치 (메서드 진입 지점, 생성자 호출 지점 등)PointCut
: JoinPoint의 상세 스펙 (구체적인 Advice의 실행 시점)LogAspect 클래스를 구현해 위와 같이 로그를 출력해보겠습니다.
해당 포스팅의 실제 코드는 EunsilSon - BookMarky에서 확인할 수 있습니다.
implementation 'org.springframework.boot:spring-boot-starter-aop'
@Pointcut("execution(* com.eunsil.bookmarky..*Controller.*(..))")
public void controller() {
}
Pointcut
을 생성합니다.com.eunsil.bookmarky
패키지 내의 모든 Controller
클래스의 모든 메서드, 모든 매개변수를 의미하는 패턴입니다.execution 표현식
execution(<access-modifier> <return-type> <class-name>.<method-name>(<parameters>))
@Before
어노테이션을 사용했습니다.@Before("controller()")
public void logBeforeExecution(JoinPoint joinPoint) throws Throwable {
// Request 정보
HttpServletRequest request = ((ServletRequestAttributes) Objects.requireNonNull(RequestContextHolder.getRequestAttributes())).getRequest();
String username = request.getUserPrincipal() != null ? request.getUserPrincipal().getName() : "None";
// 호출된 컨트롤러와 메서드 정보
String controllerName = joinPoint.getSignature().getDeclaringTypeName();
String methodName = joinPoint.getSignature().getName();
Map<String, Object> params = new HashMap<>();
// URI 인코딩 및 출력에 필요한 변수들
try {
String decodedRequestURI = URLDecoder.decode(request.getRequestURI(), StandardCharsets.UTF_8);
params.put("controller", controllerName);
params.put("method", methodName);
params.put("http_method", request.getMethod());
params.put("request_uri", decodedRequestURI);
params.put("user", username);
} catch (Exception e) {
log.error("LogAspect Error", e);
}
// 로그 출력
log.info("Request - HTTP: {} | URI: {} | User: {} | Method: {}.{}",
params.get("http_method"),
params.get("request_uri"),
params.get("user"),
params.get("controller"),
params.get("method"));
}
로그에 출력할 변수들을 Map에 넣고 다시 Map에서 꺼낸 이유는, 여러 개의 로깅 데이터들을 쉽게 추가하고 삭제하기 위함입니다.
또한, log 출력 코드에서 코드 가독성을 높일 수 있었습니다.
시작 시간과 종료 시간을 측정하기 위해 @Around
어노테이션을 사용했습니다.
@Around("controller()")
public Object logExecutionTime(ProceedingJoinPoint joinPoint) throws Throwable {
long start = System.currentTimeMillis();
try {
return joinPoint.proceed();
} finally {
long end = System.currentTimeMillis();
long timeMs = end - start;
log.info("Execution Time: {} ms", timeMs);
}
}
proceed()
호출 전의 시작 시간을 기록하고, finally 블록에서 종료 시간을 측정해 두 시간의 차이를 계산합니다.
메서드 실행 전후를 제어하는
@Around
메서드에는 PreceedingJoinPoint를 매개변수로 받고,
메서드 실행 전을 제어하는@Before
메서드에서는 PreceedingJoinPoint을 사용하지 못하고 JoinPoint를 매개변수로 받아야 했습니다.
둘 다 AOP Advice에서 메서드 실행과 관련된 정보를 제공하는 인터페이스이지만, 제공 기능과 목적에 차이가 있었습니다.
PreceedingJoinPoint
는 JoinPoint의 하위 인터페이스로, @Around
Advice에서 사용됩니다.
JoinPoint에서 제공하는 메서드 외에, 대상 메서드를 실제 실행할 수 있는 proceed()
메서드를 제공합니다. 메서드 실행 흐름을 제어할 수 있었습니다. (트랜잭션, 성능 측정, Return 값 변경, 예외 처리)
@Slf4j
@Aspect
@Component
public class LogAspect {
@Pointcut("execution(* com.eunsil.bookmarky..*Controller.*(..))")
public void controller() {
}
@Around("controller()")
public Object logExecutionTime(ProceedingJoinPoint joinPoint) throws Throwable {
long start = System.currentTimeMillis();
try {
return joinPoint.proceed();
} finally {
long end = System.currentTimeMillis();
long timeMs = end - start;
log.info("Execution Time: {} ms", timeMs);
}
}
@Before("controller()")
public void logBeforeExecution(JoinPoint joinPoint) throws Throwable {
HttpServletRequest request = ((ServletRequestAttributes) Objects.requireNonNull(RequestContextHolder.getRequestAttributes())).getRequest();
String username = request.getUserPrincipal() != null ? request.getUserPrincipal().getName() : "None";
String controllerName = joinPoint.getSignature().getDeclaringTypeName();
String methodName = joinPoint.getSignature().getName();
Map<String, Object> params = new HashMap<>();
try {
String decodedRequestURI = URLDecoder.decode(request.getRequestURI(), StandardCharsets.UTF_8);
params.put("controller", controllerName);
params.put("method", methodName);
params.put("http_method", request.getMethod());
params.put("request_uri", decodedRequestURI);
params.put("user", username);
} catch (Exception e) {
log.error("LogAspect Error", e);
}
log.info("Request - HTTP: {} | URI: {} | User: {} | Method: {}.{}",
params.get("http_method"),
params.get("request_uri"),
params.get("user"),
params.get("controller"),
params.get("method"));
}
}