SpringBoot 统计接口调用耗时的多种方式

在实际开发中，了解项目中接口的响应时间是必不可少的事情。SpringBoot 项目支持监听接口的功能也不止一个，接下来我们分别以 AOP、ApplicationListener、Tomcat 三个方面去实现三种不同的监听接口响应时间的操作。

AOP

首先我们在项目中创建一个类 ，比如就叫 WebLogAspect ，然后在该类上加上 @Aspect 和 @Component 注解，声明是一个 Bean 并且是一个切面：

import org.aspectj.lang.JoinPoint;  
import org.aspectj.lang.ProceedingJoinPoint;  
import org.aspectj.lang.annotation.*;  
import org.slf4j.Logger;  
import org.slf4j.LoggerFactory;  
import org.springframework.stereotype.Component;  
import org.springframework.web.context.request.RequestContextHolder;  
import org.springframework.web.context.request.ServletRequestAttributes;  import javax.servlet.http.HttpServletRequest;  
import java.util.Date;  @Aspect  
@Component  
public class WebLogAspect {  private static final Logger logger = LoggerFactory.getLogger(WebLogAspect.class);  // 定义一个切入点，拦截所有带有@RequestMapping注解的方法@Pointcut("@annotation(org.springframework.web.bind.annotation.RequestMapping)")  public void webLog() {}  // 前置通知，在方法执行前记录请求信息  @Before("webLog()")  public void doBefore(JoinPoint joinPoint) {  ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();  HttpServletRequest request = attributes.getRequest();  // 记录请求信息  logger.info("请求开始：URL={}, IP={}, 方法={}", request.getRequestURL(), request.getRemoteAddr(), request.getMethod());  }  // 环绕通知，记录方法执行时间  @Around("webLog()")  public Object doAround(ProceedingJoinPoint joinPoint) throws Throwable {  long startTime = System.currentTimeMillis();  Object result = joinPoint.proceed(); // 继续执行被拦截的方法  long endTime = System.currentTimeMillis();  long executeTime = endTime - startTime;  // 记录执行时间  logger.info("请求结束：耗时={}ms", executeTime);  return result;  }  // 异常通知，在方法抛出异常时记录异常信息  @AfterThrowing(pointcut = "webLog()", throwing = "ex")  public void doAfterThrowing(JoinPoint joinPoint, Exception ex) {  ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();  HttpServletRequest request = attributes.getRequest();  // 记录异常信息  logger.error("请求异常：URL={}, 异常={}", request.getRequestURL(), ex.getMessage());  }  // 后置通知（返回通知），在方法正常返回后记录信息  @AfterReturning(returning = "retVal", pointcut = "webLog()")  public void doAfterReturning(JoinPoint joinPoint, Object retVal) {  // 你可以在这里记录返回值，但通常我们不记录，因为可能会包含敏感信息  // logger.info("请求返回：返回值={}", retVal);  }  
}

2024-06-19 17:49:37.373 [TID: N/A] WARN  [com.springboot.demo.TakeTimeCountListener] 请求开始：URL=http://localhost:18080/springboot/test1, IP=0:0:0:0:0:0:0:1, 方法=POST
2024-06-19 17:49:37.386 [TID: N/A] WARN  [com.springboot.demo.TakeTimeCountListener] 请求结束：耗时=13ms
2024-06-19 17:49:37.501 [TID: N/A] WARN  [com.springboot.demo.TakeTimeCountListener] 请求开始：URL=http://localhost:18080/springboot/test2, IP=0:0:0:0:0:0:0:1, 方法=POST
2024-06-19 17:49:37.516 [TID: N/A] WARN  [com.springboot.demo.TakeTimeCountListener] 请求结束：耗时=15ms
2024-06-19 17:49:37.905 [TID: N/A] WARN  [com.springboot.demo.TakeTimeCountListener] 请求开始：URL=http://localhost:18080/springboot/test3, IP=0:0:0:0:0:0:0:1, 方法=POST
2024-06-19 17:49:37.913 [TID: N/A] WARN  [com.springboot.demo.TakeTimeCountListener] 请求结束：耗时=8ms

优点：

• 全局性：可以在不修改业务代码的情况下，对全局范围内的接口进行执行时间的记录。
• 灵活性：可以根据需要灵活定义哪些接口需要记录执行时间。
• 精确性：可以精确记录从方法开始执行到结束的时间。

缺点：

• 配置复杂性：AOP配置可能相对复杂，特别是对于初学者来说。
• 性能开销：虽然性能开销通常很小，但在高并发场景下仍然需要考虑，并且它是会阻塞主线程的。

**常用性：**在Spring框架中，AOP是一个强大的工具，用于实现诸如日志记录、事务管理等横切关注点。因此，使用AOP记录接口执行时间是一种非常常见和推荐的做法。

ApplicationListener

首先我们在项目中创建一个类 ，比如就叫 TakeTimeCountListener，然后实现 ApplicationListener 接口：

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.context.ApplicationListener;
import org.springframework.stereotype.Component;
import org.springframework.web.context.support.ServletRequestHandledEvent;@Component
public class TakeTimeCountListener implements ApplicationListener<ServletRequestHandledEvent> {public final Logger logger = LoggerFactory.getLogger(this.getClass());@Overridepublic void onApplicationEvent(ServletRequestHandledEvent event) {Throwable failureCause = event.getFailureCause() ;if (failureCause != null) {logger.warn("错误原因: {}", failureCause.getMessage());}// 比如我这里只记录接口响应时间大于1秒的日志if (event.getProcessingTimeMillis() > 1000) {logger.warn("请求客户端地址：{}, 请求URL: {}, 请求Method: {}, 请求耗时:{} ms",event.getClientAddress(),event.getRequestUrl(),event.getMethod(),event.getProcessingTimeMillis());}}
}

2024-06-19 17:14:59.620 [TID: N/A] WARN  [com.springboot.demo.TakeTimeCountListener] 请求客户端地址：0:0:0:0:0:0:0:1, 请求URL: /springboot/test1, 请求Method: GET, 请求耗时:51 ms
2024-06-19 17:14:59.716 [TID: N/A] WARN  [com.springboot.demo.TakeTimeCountListener] 请求客户端地址：0:0:0:0:0:0:0:1, 请求URL: /springboot/test2, 请求Method: GET, 请求耗时:136 ms
2024-06-19 17:14:59.787 [TID: N/A] WARN  [com.springboot.demo.TakeTimeCountListener] 请求客户端地址：0:0:0:0:0:0:0:1, 请求URL: /springboot/test3, 请求Method: POST, 请求耗时:255 ms
2024-06-19 17:14:59.859 [TID: N/A] WARN  [com.springboot.demo.TakeTimeCountListener] 请求客户端地址：0:0:0:0:0:0:0:1, 请求URL: /springboot/test4, 请求Method: POST, 请求耗时:167 ms

优点：

• 集成性：与Spring MVC框架紧密集成，无需额外配置。
• 性能：改方法是不会阻塞主线程的，也就是说 该方法在处理的时候，controller 已经正常返回了，可以通过在该方法进行断点调试来验证。
• 简单易用：实现ApplicationListener接口并监听ServletRequestHandledEvent事件即可。

缺点：

• 适用范围：主要适用于Spring MVC 框架下的 Web 请求，对于非 Web 接口（如RESTful API）可能不适用。
• 精度：只能记录整个请求的处理时间，无法精确到具体的方法执行时间。

**常用性：**在Spring MVC应用中，使用ApplicationListener来记录请求处理时间是一种常见做法，但通常用于监控和性能分析，而不是精确记录接口执行时间。

Tomcat

Tomcat 的实现很简单，只需要开启它本身就支持的访问日志就可以了 ，在 SpringBoot 中，我们可以在 properties 或 yaml 文件中增加下面配置：

# 启用Tomcat访问日志
server.tomcat.accesslog.enabled=true  
# 启用缓冲模式，日志会先写入缓冲区，然后定期刷新到磁盘 
server.tomcat.accesslog.buffered=true  
# 指定日志存储目录，这里是相对于项目根目录的logs文件夹  
server.tomcat.accesslog.directory=logs 
# 定义日志文件名的日期格式
server.tomcat.accesslog.file-date-format=.yyyy-MM-dd 
# 定义日志记录的格式  
# 各个字段的意义：  
# %{X-Forwarded-For}i: 请求头中的X-Forwarded-For，通常用于记录客户端真实IP  
# %p: 本地端口  
# %l: 远程用户，通常为'-'  
# %r: 请求的第一行（例如：GET / HTTP/1.1）  
# %t: 请求时间（格式由日志处理器决定）  
# 注意：这里有一个重复的%r，可能是个错误，通常第二个%r不需要  
# %s: HTTP状态码  
# %b: 响应字节数，不包括HTTP头，如果为0则不输出  
# %T: 请求处理时间（以秒为单位）  
server.tomcat.accesslog.pattern=%{X-Forwarded-For}i %p %l %r %t %r %s %b %T
# 日志文件名前缀  
server.tomcat.accesslog.prefix=localhost_access_log
# 日志文件名后缀  
server.tomcat.accesslog.suffix=.log

server:  tomcat:  accesslog:  enabled: true  # 启用Tomcat访问日志buffered: true  # 启用缓冲模式，日志会先写入缓冲区，然后定期刷新到磁盘 directory: logs  # 指定日志存储目录，这里是相对于项目根目录的logs文件夹  file-date-format: ".yyyy-MM-dd"   # 定义日志文件名的日期格式pattern: "%{X-Forwarded-For}i %p %l %r %t %s %b %T"  # 定义日志记录的格式   prefix: localhost_access_log   # 日志文件名前缀  suffix: .log # 日志文件名后缀

- 8080 - - [19/Jun/2024:00:00:09 +0800] GET /springboot/test1 HTTP/1.1 200 92 0.247 Ignored_Trace
- 8080 - - [19/Jun/2024:00:00:09 +0800] GET /springboot/test2 HTTP/1.1 200 92 0.247 Ignored_Trace
- 8080 - - [19/Jun/2024:09:49:55 +0800] POST /springboot/test3 HTTP/1.1 200 291556 0.314 Ignored_Trace

优点：

• 集成性：Tomcat 内置功能，无需额外代码或配置。
• 全面性：记录所有通过 Tomcat 处理的请求和响应信息。

缺点：

• 性能：访问日志可能会对 Tomcat 性能产生一定影响。
• 精度：同样只能记录整个请求的处理时间，无法精确到具体的方法执行时间。
• 配置复杂性：对于复杂的日志格式或需求，可能需要修改 Tomcat 的配置文件。

**常用性：**Tomcat 的访问日志通常用于监控 Web 服务器的访问情况，如 IP 地址、请求路径、HTTP 状态码等。虽然它可以记录请求处理时间，但通常不会用于精确的性能分析或接口执行时间记录。