利用Spring AOP记录方法的执行时间

利用Spring AOP记录方法的执行时间可以通过以下步骤实现：

1. 添加依赖

在pom.xml文件中添加Spring AOP的依赖：

<dependency>
    <groupId>org.springframework</groupId>
    <artifactId>spring-context</artifactId>
    <version>${spring.version}</version>
</dependency>

<dependency>
    <groupId>org.aspectj</groupId>
    <artifactId>aspectjweaver</artifactId>
    <version>${aspectj.version}</version>
</dependency>

2. 定义切面类

切面类必须实现org.aspectj.lang.annotation.Aspect接口，并使用@Aspect注解标记：

import org.aspectj.lang.annotation.After;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.aspectj.lang.annotation.Pointcut;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;

@Aspect
@Component
public class PerformanceAspect {
    private static final Logger logger = LoggerFactory.getLogger(PerformanceAspect.class);

    @Pointcut("execution(* com.example.demo.controller.*.*(..))")
    public void controllerExecution() {}

    @Before("controllerExecution()")
    public void beforeControllerExecution() {
        logger.info("Start executing controller");
    }

    @After("controllerExecution()")
    public void afterControllerExecution() {
        logger.info("Finish executing controller");
    }
}

上述代码定义了一个切面类PerformanceAspect，用来记录所有Controller中方法的执行时间。其中，@Pointcut注解用于定义切入点，该切入点匹配所有Controller中的方法；@Before和@After注解用于在目标方法执行之前和执行之后分别执行自定义的逻辑。

3. 配置AOP

在Spring配置文件中添加如下配置：

<aop:aspectj-autoproxy />
<bean id="performanceAspect" class="com.example.demo.aop.PerformanceAspect" />

上述配置会自动扫描并代理Spring容器中的所有@Aspect注解标记的切面类。

4. 测试

定义一个简单的Controller：

import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;

@RestController
public class DemoController {

    @GetMapping("/hello")
    public String hello() throws InterruptedException {
        Thread.sleep(1000);
        return "Hello, World!";
    }
}

启动应用程序并访问http://localhost:8080/hello，控制台将输出如下日志：

Start executing controller
Finish executing controller

日志表明，PerformanceAspect切面类成功地拦截了DemoController中的方法，并记录了方法的执行时间。下面再提供一条完整的代码示例：

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;

@Aspect
@Component
public class SystemLogAspect {

    private static final Logger log = LoggerFactory.getLogger(SystemLogAspect.class);

    /**
     * 定义切入点，拦截所有带有RequestMapping注解的方法
     */
    @Pointcut("execution(public * com.scienjoy.app.web..*Controller.*(..)) && @annotation(org.springframework.web.bind.annotation.RequestMapping)")
    public void controllerMethod() {
    }

    /**
     * 前置通知，方法调用前被调用
     * @param joinPoint 连接点对象，封装了被拦截方法的信息
     */
    @Before("controllerMethod()")
    public void beforeMethod(JoinPoint joinPoint) {
        log.info("调用了 " + joinPoint.getTarget().getClass().getName() + " 的 " + joinPoint.getSignature().getName() + " 方法，参数: " + joinPoint.getArgs());
    }

    /**
     * 后置通知，在方法执行完毕后执行，无论方法成功执行还是出现异常都会执行
     * @param joinPoint 连接点对象
     * @param result 方法返回值
     */
    @AfterReturning(pointcut = "controllerMethod()", returning = "result")
    public void afterReturning(JoinPoint joinPoint, Object result) {
        //把返回值转化为String类型，防止调用toString()方法时出现空指针异常
        String ret = result != null ? result.toString() :"null";
        log.info("调用 " + joinPoint.getTarget().getClass().getName() + " 的 " + joinPoint.getSignature().getName() + " 方法成功结束，返回值: " + ret);
    }

    /**
     * 异常通知，在拦截的方法出现异常时被调用
     * @param joinPoint 连接点对象
     * @param throwable 异常对象
     */
    @AfterThrowing(pointcut = "controllerMethod()", throwing = "throwable")
    public void afterThrowing(JoinPoint joinPoint, Throwable throwable) {
        log.error("调用 " + joinPoint.getTarget().getClass().getName() + " 的 " + joinPoint.getSignature().getName() + " 方法时出现异常: " + throwable.getMessage());
    }

    /**
     * 环绕通知，可以控制拦截方法的执行过程
     * @param proceedingJoinPoint 连接点
     * @return 拦截方法执行结果
     * @throws Throwable 异常
     */
    @Around("controllerMethod()")
    public Object aroundMethod(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
        log.info("开始调用 " + proceedingJoinPoint.getTarget().getClass().getName() + " 的 " + proceedingJoinPoint.getSignature().getName() + " 方法");
        long startTime = System.currentTimeMillis();
        Object result = null;
        try {
            result = proceedingJoinPoint.proceed();
        } catch (Throwable throwable) {
            throw throwable;
        } finally {
            long endTime = System.currentTimeMillis();
            log.info("调用 " + proceedingJoinPoint.getTarget().getClass().getName() + " 的 " + proceedingJoinPoint.getSignature().getName() + " 方法结束，耗时: " + (endTime - startTime) + "ms");
        }
        return result;
    }
}

该切面类实现了前置通知、后置通知、异常通知以及环绕通知功能，能够较全面地记录方法执行时间和出现的异常情况。