统计请求的处理时间(用时)既可以使用 Servlet 过滤器(Filter)
,也可以使用 Spring 拦截器(Interceptor)
。两者都可以在请求处理前后插入自定义逻辑,从而实现对请求响应时间的统计。
使用建议
如果你需要在更底层、与框架无关的地方记录所有请求(包括静态资源请求)的处理时间,那么 Servlet 过滤器
是一个更好的选择。
如果你正在使用 Spring MVC 并且关注的是 Controller 层的处理时间,或者需要访问到 Spring 上下文中的服务,那么 Spring 拦截器
可能更为合适。
代码样例
Servlet 过滤器(Filter)
import jakarta.servlet.*;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import lombok.extern.slf4j.Slf4j;
import org.springframework.stereotype.Component;import java.io.IOException;
import java.time.Instant;// @Component 注册时会new 这里无需指定 registration.setFilter(new LogFilter());
@Slf4j
public class LogFilter implements Filter {@Overridepublic void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {System.err.println("***LogFilter.doFilter.start***");HttpServletRequest httpReq = (HttpServletRequest) request;long startTime = Instant.now().toEpochMilli();// 记录请求开始时间及请求信息log.warn("LogFilter.doFilter: Start processing request at {} - {}", Instant.now(), httpReq.getRequestURI());try {// 将请求传递给下一个过滤器或目标资源chain.doFilter(request, response);} finally {// 记录请求结束时间及响应状态码long endTime = Instant.now().toEpochMilli();int statusCode = ((HttpServletResponse) response).getStatus();log.warn("LogFilter.doFilter: Finished processing request at {} - {} in {} ms. Status code: {}", Instant.now(), httpReq.getRequestURI(), (endTime - startTime), statusCode);}System.err.println("***LogFilter.doFilter.end***");}
}
注册过滤器(Filter)
@Configuration
public class AppConfig {@Beanpublic FilterRegistrationBean<LogFilter> tokenFilterRegistration() {FilterRegistrationBean<LogFilter> registration = new FilterRegistrationBean<>();registration.setFilter(new LogFilter());// 可以设置过滤器名称registration.setName("logFilter");// 设置拦截规则registration.addUrlPatterns("/*"); // 拦截所有请求// 设置过滤器执行顺序,默认为0,数值越小优先级越高registration.setOrder(1);return registration;}
}
Spring 拦截器(Interceptor)
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import lombok.extern.slf4j.Slf4j;
import org.springframework.stereotype.Component;
import org.springframework.web.servlet.HandlerInterceptor;
import org.springframework.web.servlet.ModelAndView;import java.time.Instant;@Component
@Slf4j
public class LogInterceptor implements HandlerInterceptor {@Overridepublic boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {System.err.println("***LogInterceptor.preHandle***");long startTime = Instant.now().toEpochMilli();request.setAttribute("startTime", startTime);log.warn("LogInterceptor.postHandle: Start processing request at {} - {}", Instant.now(), request.getRequestURI());return true;}@Overridepublic void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) {System.err.println("***LogInterceptor.preHandle***");// 获取请求开始时间Long startTime = (Long) request.getAttribute("startTime");if (startTime != null) {long executionTime = Instant.now().toEpochMilli() - startTime;int statusCode = response.getStatus();log.warn("LogInterceptor.postHandle: Finished processing request at {} - {} in {} ms. Status code: {}", Instant.now(), request.getRequestURI(), executionTime, statusCode);}}@Overridepublic void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {System.err.println("***LogInterceptor.afterCompletion***");// 在此可以添加额外的后处理逻辑,但本例中我们不需要}
}
注册拦截器(Interceptor)
@Configuration
public class WebMvcConfig implements WebMvcConfigurer {@Autowiredprivate ResponsePostInterceptor responsePostInterceptor;@Autowiredprivate LogInterceptor logInterceptor;/*** 为拦截器注册表添加拦截器** @param registry 拦截器注册表*/@Overridepublic void addInterceptors(InterceptorRegistry registry) {// 在Spring MVC配置中注册一个名为responsePostInterceptor的拦截器,使其能够对匹配路径“/**”(即对应用程序中的所有路径)的请求进行拦截registry.addInterceptor(responsePostInterceptor).addPathPatterns("/**");registry.addInterceptor(logInterceptor).addPathPatterns("/**");}
}
[Ref] 在Spring Boot中注册过滤器几种方式
测试验证
# 过滤器开始计时
***LogFilter.doFilter.start***
[2024-01-17 08:17:55] [WARN ] [http-nio-8080-exec-2] [LogFilter.java:22] → [LogFilter.doFilter: Start processing request at 2024-01-17T00:17:55.662652400Z - /students]
***RequestHeaderCheckFilter.doFilter.start***# 拦截器组的 preHandle
***ResponsePostInterceptor.preHandle***
# log用时拦截器开始计时
***LogInterceptor.preHandle***
[2024-01-17 08:17:55] [WARN ] [http-nio-8080-exec-2] [LogInterceptor.java:20] → [LogInterceptor.postHandle: Start processing request at 2024-01-17T00:17:55.852229500Z - /students]# Controller层
***StudentController.edit***
[2024-01-17 08:17:56] [INFO ] [http-nio-8080-exec-2] [HikariDataSource.java:110] → [practisedb - Starting...]
[2024-01-17 08:17:56] [INFO ] [http-nio-8080-exec-2] [HikariPool.java:565] → [practisedb - Added connection com.mysql.cj.jdbc.ConnectionImpl@34a6ebfc]
[2024-01-17 08:17:56] [INFO ] [http-nio-8080-exec-2] [HikariDataSource.java:123] → [practisedb - Start completed.]# @ControllerAdvice对Response增强,比如修改状态码,补充header值
***ResponsePostAdvice.supports***
***ResponsePostAdvice.beforeBodyWrite***# 拦截器组的 postHandle
***LogInterceptor.postHandle***
# log用时拦截器结束计时
[2024-01-17 08:17:56] [WARN ] [http-nio-8080-exec-2] [LogInterceptor.java:32] → [LogInterceptor.postHandle: Finished processing request at 2024-01-17T00:17:56.636557900Z - /students in 784 ms. Status code: 200]
***ResponsePostInterceptor.postHandle***# 拦截器组的 afterCompletion
***LogInterceptor.afterCompletion***
***ResponsePostInterceptor.afterCompletion***# 过滤器结束计时
***RequestHeaderCheckFilter.doFilter.end***
[2024-01-17 08:17:56] [WARN ] [http-nio-8080-exec-2] [LogFilter.java:31] → [LogFilter.doFilter: Finished processing request at 2024-01-17T00:17:56.920165800Z - /students in 1258 ms. Status code: 200]
***LogFilter.doFilter.end***