Implementing Request Logging with Spring AOP: A Practical Guide

Introduction

The article addresses the common problem of debugging request parameters during integration testing by introducing a request‑logging aspect that prints inbound data, method names, and execution details, helping developers locate issues and provide evidence for troubleshooting.

AOP Overview

Aspect‑Oriented Programming (AOP) separates core business logic from cross‑cutting concerns such as transaction management, permission control, caching, and logging, allowing these concerns to be handled centrally and with minimal intrusion.

AOP Annotations

The key annotations used are:

@Aspect – declares a class as an aspect.

@Pointcut – defines a reusable pointcut expression.

@Before – runs before the matched method.

@Around – surrounds the method execution, allowing pre‑ and post‑processing.

@After – runs after the method completes.

@AfterThrowing – runs when the method throws an exception.

Basic Request‑Logging Aspect

The following code defines a pointcut that matches all controller methods and logs IP, URL, HTTP method, and the invoked class method before execution.

@Pointcut("execution(* your_package.controller..*(..))")
public void requestServer() {}

@Before("requestServer()")
public void doBefore(JoinPoint joinPoint) {
    ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
    HttpServletRequest request = attributes.getRequest();
    LOGGER.info("===============================Start========================");
    LOGGER.info("IP : {}", request.getRemoteAddr());
    LOGGER.info("URL : {}", request.getRequestURL().toString());
    LOGGER.info("HTTP Method : {}", request.getMethod());
    LOGGER.info("Class Method : {}.{}", joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName());
}

An @Around advice records the start time, proceeds with the original method, then logs the request parameters, result, and elapsed time.

@Around("requestServer()")
public Object doAround(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
    long start = System.currentTimeMillis();
    Object result = proceedingJoinPoint.proceed();
    LOGGER.info("Request Params : {}", getRequestParams(proceedingJoinPoint));
    LOGGER.info("Result : {}", result);
    LOGGER.info("Time Cost : {} ms", System.currentTimeMillis() - start);
    return result;
}

The helper method extracts parameter names and values, handling MultipartFile specially to log only the original filename.

private Map
getRequestParams(ProceedingJoinPoint proceedingJoinPoint) {
    Map
requestParams = new HashMap<>();
    String[] paramNames = ((MethodSignature) proceedingJoinPoint.getSignature()).getParameterNames();
    Object[] paramValues = proceedingJoinPoint.getArgs();
    for (int i = 0; i < paramNames.length; i++) {
        Object value = paramValues[i];
        if (value instanceof MultipartFile) {
            value = ((MultipartFile) value).getOriginalFilename();
        }
        requestParams.put(paramNames[i], value);
    }
    return requestParams;
}

High‑Concurrency Enhancements

To avoid log interleaving under heavy load, the article introduces a RequestInfo DTO that aggregates all request data into a single JSON string.

@Data
public class RequestInfo {
    private String ip;
    private String url;
    private String httpMethod;
    private String classMethod;
    private Object requestParams;
    private Object result;
    private Long timeCost;
}

The @Around advice is updated to populate this object and log it in one line.

@Around("requestServer()")
public Object doAround(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
    long start = System.currentTimeMillis();
    ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
    HttpServletRequest request = attributes.getRequest();
    Object result = proceedingJoinPoint.proceed();
    RequestInfo requestInfo = new RequestInfo();
    requestInfo.setIp(request.getRemoteAddr());
    requestInfo.setUrl(request.getRequestURL().toString());
    requestInfo.setHttpMethod(request.getMethod());
    requestInfo.setClassMethod(String.format("%s.%s", proceedingJoinPoint.getSignature().getDeclaringTypeName(), proceedingJoinPoint.getSignature().getName()));
    requestInfo.setRequestParams(getRequestParamsByProceedingJoinPoint(proceedingJoinPoint));
    requestInfo.setResult(result);
    requestInfo.setTimeCost(System.currentTimeMillis() - start);
    LOGGER.info("Request Info : {}", JSON.toJSONString(requestInfo));
    return result;
}

An @AfterThrowing advice captures exception details in a separate RequestErrorInfo DTO.

@Data
public class RequestErrorInfo {
    private String ip;
    private String url;
    private String httpMethod;
    private String classMethod;
    private Object requestParams;
    private RuntimeException exception;
}

@AfterThrowing(pointcut = "requestServer()", throwing = "e")
public void doAfterThrow(JoinPoint joinPoint, RuntimeException e) {
    ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
    HttpServletRequest request = attributes.getRequest();
    RequestErrorInfo errorInfo = new RequestErrorInfo();
    errorInfo.setIp(request.getRemoteAddr());
    errorInfo.setUrl(request.getRequestURL().toString());
    errorInfo.setHttpMethod(request.getMethod());
    errorInfo.setClassMethod(String.format("%s.%s", joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName()));
    errorInfo.setRequestParams(getRequestParamsByJoinPoint(joinPoint));
    errorInfo.setException(e);
    LOGGER.info("Error Request Info : {}", JSON.toJSONString(errorInfo));
}

TraceId Integration

For distributed tracing, a LogInterceptor adds a unique traceId to the logging context before each request and removes it after completion.

public class LogInterceptor implements HandlerInterceptor {
    private static final String TRACE_ID = "traceId";
    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
        String traceId = UUID.randomUUID().toString().replaceAll("-", "").toUpperCase();
        ThreadContext.put(TRACE_ID, traceId);
        return true;
    }
    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) {
        ThreadContext.remove(TRACE_ID);
    }
}

The log pattern is updated to include the traceId placeholder, e.g.:

<property name="pattern">[TRACEID:%X{traceId}] %d{HH:mm:ss.SSS} %-5level %class{-1}.%M()/%L - %msg%xEx%n</property>

Conclusion

By applying the aspect, DTOs, and traceId interceptor, developers obtain comprehensive, single‑line logs that are safe under high concurrency, include error details, and are easily searchable across distributed systems.