Mastering Request Logging with Spring AOP: From Basics to High‑Concurrency Solutions

Preface

This article is a practical guide; it does not cover AOP theory in depth, only the essential concepts needed for implementing a request‑logging aspect.

What is AOP?

Aspect‑Oriented Programming (AOP) complements object‑oriented programming by handling cross‑cutting concerns such as transaction management, permission control, cache handling, and logging. AOP separates core business logic from these cross‑cutting concerns, improving modularity and maintainability.

Centralized handling of a specific concern

Easy addition or removal of concerns

Low intrusion, enhancing code readability and maintainability

Annotation‑Based Aspect Usage

Declare an aspect class with @Aspect and define a pointcut that matches all controller methods.

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

Pointcut Annotation

@Pointcut

defines a reusable pointcut expression.

Advice Annotations

@Before

: Executes before the pointcut. @After: Executes after the pointcut. @AfterReturning: Executes after the pointcut returns, allowing result manipulation. @AfterThrowing: Executes when the pointcut throws an exception. @Around: Wraps the pointcut, executing code before and after.

Implementing a Request Logging Aspect

Before Advice – logs IP, URL, HTTP method, and the invoked class method.

@Before("requestServer()")
public void doBefore(JoinPoint joinPoint) {
    ServletRequestAttributes attrs = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
    HttpServletRequest request = attrs.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());
}

Around Advice – records execution time, request parameters, and result.

@Around("requestServer()")
public Object doAround(ProceedingJoinPoint pjp) throws Throwable {
    long start = System.currentTimeMillis();
    Object result = pjp.proceed();
    LOGGER.info("Request Params : {}", getRequestParams(pjp));
    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 file name.

private Map<String, Object> getRequestParams(ProceedingJoinPoint pjp) {
    Map<String, Object> params = new HashMap<>();
    String[] names = ((MethodSignature) pjp.getSignature()).getParameterNames();
    Object[] values = pjp.getArgs();
    for (int i = 0; i < names.length; i++) {
        Object val = values[i];
        if (val instanceof MultipartFile) {
            val = ((MultipartFile) val).getOriginalFilename();
        }
        params.put(names[i], val);
    }
    return params;
}

After Advice – simply marks the end of the request.

@After("requestServer()")
public void doAfter(JoinPoint joinPoint) {
    LOGGER.info("===============================End========================");
}

High‑Concurrency Optimizations

To avoid log interleaving under heavy load, assemble all request information into a single RequestInfo object and serialize it as JSON.

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

Updated @Around advice:

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

For exception handling, define RequestErrorInfo and an @AfterThrowing advice that logs the error 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 attrs = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
    HttpServletRequest request = attrs.getRequest();
    RequestErrorInfo errInfo = new RequestErrorInfo();
    errInfo.setIp(request.getRemoteAddr());
    errInfo.setUrl(request.getRequestURL().toString());
    errInfo.setHttpMethod(request.getMethod());
    errInfo.setClassMethod(String.format("%s.%s", joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName()));
    errInfo.setRequestParams(getRequestParamsByJoinPoint(joinPoint));
    errInfo.setException(e);
    LOGGER.info("Error Request Info : {}", JSON.toJSONString(errInfo));
}

Adding TraceId for Distributed Tracing

Implement a HandlerInterceptor that generates a UUID‑based traceId and stores it in the logging context.

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

Update the logging pattern to include the traceId placeholder:

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

When using Logback or Log4j2, replace ThreadContext.put with MDC.put accordingly.