统计请求的处理时间(用时)既可以使用 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 {
@Override
public 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 {
@Bean
public 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 {
@Override
public 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;
}
@Override
public 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);
}
}
@Override
public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {
System.err.println("***LogInterceptor.afterCompletion***");
// 在此可以添加额外的后处理逻辑,但本例中我们不需要
}
}
注册拦截器(Interceptor)
@Configuration
public class WebMvcConfig implements WebMvcConfigurer {
@Autowired
private ResponsePostInterceptor responsePostInterceptor;
@Autowired
private LogInterceptor logInterceptor;
/**
* 为拦截器注册表添加拦截器
*
* @param registry 拦截器注册表
*/
@Override
public 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***