Implementing Request Logging with Spring AOP: From Basic Aspect to High‑Concurrency and TraceId Support

The author introduces a common problem in service‑protocol integration where incorrect JSON parameters cause debugging failures, and proposes a request‑logging aspect to capture request details and provide evidence for troubleshooting.

Aspect‑Oriented Programming (AOP) is described as a complement to OOP for handling cross‑cutting concerns such as transaction management, permission control, caching, and logging, allowing separation of core business logic from auxiliary functions.

Using annotation‑based AOP, the article shows how to declare an aspect with @Aspect , define a pointcut targeting all controller methods, and apply various advice annotations (@Before, @After, @Around, @AfterReturning, @AfterThrowing) to log request information.

Example code for the pointcut and before advice:

@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());
}

The @Around advice records the start time, proceeds with the original method, and logs request parameters, result, and execution 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;
}

A helper method extracts method arguments, 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) {
            MultipartFile file = (MultipartFile) value;
            value = file.getOriginalFilename();
        }
        requestParams.put(paramNames[i], value);
    }
    return requestParams;
}

To avoid log interleaving under high concurrency, the author refactors logging into a single JSON line by defining a RequestInfo DTO, populating it with IP, URL, HTTP method, class method, parameters, result, and time cost, and printing the serialized object:

@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 use this DTO:

@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;
}

Exception handling is added with an @AfterThrowing advice and a RequestErrorInfo DTO to log error details without timing information:

@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));
}

Finally, the article shows how to add a traceId for end‑to‑end request tracing by implementing a HandlerInterceptor that stores a UUID in the logging thread context, and updating the log pattern to include the traceId placeholder:

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

Log configuration example (log4j2):

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

The author encourages readers to integrate this aspect into their applications to obtain clear request evidence and improve debugging efficiency.