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());
    
    @Override
    public 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 状态码等。虽然它可以记录请求处理时间，但通常不会用于精确的性能分析或接口执行时间记录。