SpringBoot REST API请求总执行时间日志记录优化方案咨询

你的问题很典型：用切面记录单个方法的执行时间，没法直接得到从请求进入到最终响应完成（不管是正常返回还是异常处理）的总时长——因为控制器方法和异常处理器方法是两个独立的切点，切面只能分别记录它们的耗时，没法关联成同一个请求的总时间。

这里有两个更简便、更准确的方案，直接覆盖整个请求的生命周期：

方案一：使用HandlerInterceptor（推荐，Spring MVC原生支持） #

HandlerInterceptor是Spring MVC提供的拦截器，能在请求进入控制器前、视图渲染后、请求完全结束后执行逻辑。其中afterCompletion方法会在**整个请求处理完成（包括异常被ExceptionHandler处理完毕）**后执行，完美适合记录总时长。

步骤1：自定义拦截器 #

@Component
public class RequestDurationInterceptor implements HandlerInterceptor {

    private static final Logger logger = LoggerFactory.getLogger(RequestDurationInterceptor.class);
    // 用来存储请求开始时间的request属性键
    private static final String REQUEST_START_TIME = "requestStartTime";

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        // 请求进入时记录开始时间，存在request的属性中
        long startTime = System.currentTimeMillis();
        request.setAttribute(REQUEST_START_TIME, startTime);
        logger.debug("Request started: {} {}", request.getMethod(), request.getRequestURI());
        return true; // 返回true继续处理请求
    }

    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {
        // 请求完全结束时计算总时长
        long startTime = (long) request.getAttribute(REQUEST_START_TIME);
        long totalDuration = System.currentTimeMillis() - startTime;
        logger.debug("Request completed: {} {} | Total execution time: {} ms",
                request.getMethod(), request.getRequestURI(), totalDuration);
    }
}

步骤2：注册拦截器到Spring MVC #

@Configuration
public class WebMvcConfig implements WebMvcConfigurer {

    private final RequestDurationInterceptor requestDurationInterceptor;

    // 构造注入拦截器
    public WebMvcConfig(RequestDurationInterceptor requestDurationInterceptor) {
        this.requestDurationInterceptor = requestDurationInterceptor;
    }

    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        registry.addInterceptor(requestDurationInterceptor)
                .addPathPatterns("/**"); // 匹配所有请求，可根据业务调整路径
    }
}

方案二：使用OncePerRequestFilter（更底层的Servlet级拦截） #

如果需要在更底层（Servlet容器级别）处理请求，OncePerRequestFilter是个不错的选择，它确保每个请求只被过滤一次，避免重复执行。

实现Filter #

@Component
public class RequestDurationFilter extends OncePerRequestFilter {

    private static final Logger logger = LoggerFactory.getLogger(RequestDurationFilter.class);

    @Override
    protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException {
        long startTime = System.currentTimeMillis();
        try {
            // 继续执行后续的过滤链（包括Spring MVC的处理逻辑）
            filterChain.doFilter(request, response);
        } finally {
            // 不管请求成功还是失败，都计算总时长
            long totalDuration = System.currentTimeMillis() - startTime;
            logger.debug("Request {} {} | Total execution time: {} ms",
                    request.getMethod(), request.getRequestURI(), totalDuration);
        }
    }
}

这个Filter不需要额外注册，因为@Component注解会让Spring自动将其加入到Servlet的过滤链中。

为什么这两个方案比切面更好？ #

• 覆盖完整请求生命周期：不管请求是正常执行控制器方法，还是抛出异常进入ExceptionHandler，都能准确记录从请求进入到响应发出的总时长，不需要手动累加多个方法的耗时。
• 无需额外注解：不需要在控制器或异常处理器方法上标记@LogAround，减少代码侵入。
• 逻辑更清晰：把请求时长记录的逻辑集中在一个地方，便于维护。

你可以根据自己的需求选择其中一个方案，之后就可以移除原来的PointsAspect和@LogAround注解了。

内容的提问来源于stack exchange，提问作者Avhi