基于Spring AOP实现方法执行时间监控与日志记录

在开发和维护大型应用时，监控方法的执行时间和记录日志是非常重要的任务。通过这些信息，开发者可以了解系统的性能瓶颈，追踪错误，并优化代码。Spring AOP（Aspect-Oriented Programming）提供了一种非侵入式的方式来实现这些功能。本文将详细介绍如何通过自定义注解和Spring AOP实现方法执行时间的监控和日志记录。

---

1. 什么是Spring AOP？

Spring AOP 是一种通过动态代理实现的面向切面编程框架。它允许开发者定义切面（Aspect），并在特定的点（Pointcut）织入增强处理（Advice）。常见的应用场景包括日志记录、事务管理、权限控制、性能监控等。

---

2. 自定义注解 @TakeTime

为了方便地标记需要监控的方法，我们可以创建一个自定义注解 @TakeTime。

import java.lang.annotation.Documented;
import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;@Documented
@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
public @interface TakeTime {String methodName() default "";
}

说明

• @Documented：标记该注解应该被作为被标注的程序成员的公共API，可以被如 javadoc 等工具文档化。
• @Target(ElementType.METHOD)：指定该注解只能用于方法。
• @Retention(RetentionPolicy.RUNTIME)：指定注解在运行时保留，可以通过反射获取。

---

3. 实现方法执行时间监控

通过创建一个基于Spring AOP的切面，可以在方法执行前后记录时间和日志信息。

代码实现

import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.annotation.AfterReturning;
import org.aspectj.lang.annotation.AfterThrowing;
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;
import com.alibaba.fastjson.JSON;
import java.text.SimpleDateFormat;
import java.util.Date;
import java.util.UUID;
import javax.servlet.http.HttpServletRequest;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;@Component
@Aspect
public class TakeTimeAspect {private static final Logger log = LoggerFactory.getLogger(TakeTimeAspect.class);private static final SimpleDateFormat sdf = new SimpleDateFormat("yyyy年MM月dd日 HH:mm:ss");// 统一线程本地变量ThreadLocal<Long> startTime = new ThreadLocal<>();ThreadLocal<Long> endTime = new ThreadLocal<>();/*** 定义切点：带有@TakeTime注解的方法*/@Pointcut("@annotation(com.example.demo.annotation.TakeTime)")public void takeTime() {}/*** 方法执行前** @param joinPoint 连接点*/@Before("takeTime()")public void doBefore(JoinPoint joinPoint) {String methodName = joinPoint.getSignature().getName();Object[] params = joinPoint.getArgs();// 记录开始时间startTime.set(System.currentTimeMillis());String startDateTime = sdf.format(new Date(startTime.get()));log.info("【方法开始】==> 方法名称: {}, 开始时间: {}, 参数: {}",methodName, startDateTime, JSON.toJSONString(params));// 记录请求信息ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();HttpServletRequest request = attributes.getRequest();String requestId = UUID.randomUUID().toString();log.info("【请求信息】==> 请求ID: {}, URL: {}, 方法: {}, 参数: {}",requestId, request.getRequestURL().toString(),request.getMethod(), JSON.toJSONString(params));}/*** 方法执行后** @param joinPoint 连接点* @param ret      返回值*/@AfterReturning(pointcut = "takeTime()", returning = "ret")public void doAfterReturning(JoinPoint joinPoint, Object ret) {// 记录结束时间endTime.set(System.currentTimeMillis());String endDateTime = sdf.format(new Date(endDateTime));log.info("【方法结束】==> 方法名称: {}, 结束时间: {}, 执行时长: {}ms, 返回值: {}",joinPoint.getSignature().getName(),endDateTime,endTime.get() - startTime.get(),JSON.toJSONString(ret));// 清除线程本地变量startTime.remove();endTime.remove();}/*** 方法执行异常** @param joinPoint 连接点* @param ex       异常*/@AfterThrowing(pointcut = "takeTime()", throwing = "ex")public void doAfterThrowing(JoinPoint joinPoint, Throwable ex) {endTime.set(System.currentTimeMillis());String endDateTime = sdf.format(new Date(endTime.get()));log.error("【方法异常】==> 方法名称: {}, 异常时间: {}, 异常信息: {}, 执行时长: {}ms",joinPoint.getSignature().getName(),endDateTime,ex.getMessage(),endTime.get() - startTime.get());// 清除线程本地变量startTime.remove();endTime.remove();}/*** 格式化日期** @param date 日期对象* @return 格式化后的日期字符串*/private String formatDateTime(Date date) {return sdf.format(date);}
}

功能说明

1. 记录开始时间：在方法执行前记录开始时间，并输出方法名称、开始时间和参数信息。
2. 记录请求信息：输出请求ID、URL、方法和参数信息，方便追踪和分析。
3. 记录结束时间：在方法执行后记录结束时间，并输出方法名称、结束时间、执行时长和返回值。
4. 记录异常信息：在方法执行异常时记录异常时间、异常信息和执行时长，方便排查问题。

---

4. 使用示例

步骤 1：在目标方法上添加 @TakeTime 注解

@Service
public class UserService {@TakeTimepublic User getUserById(Long id) {// 方法实现return userRepository.findById(id).orElse(null);}
}

步骤 2：查看日志输出

当调用 getUserById 方法时，会输出以下日志信息：

方法开始

【方法开始】==> 方法名称: getUserById, 开始时间: 2023年12月25日 12:34:56, 参数: [1]
【请求信息】==> 请求ID: xxxxxxxx-xxxx-4xxx-yxxx-xxxxxxxxxxxx, URL: http://localhost:8080/api/user/1, 方法: GET, 参数: [1]

方法结束

【方法结束】==> 方法名称: getUserById, 结束时间: 2023年12月25日 12:34:56, 执行时长: 100ms, 返回值: {"id":1,"username":"admin","email":"admin@example.com"}

5. 优缺点分析

优点

1. 非侵入式：通过AOP实现，不需要修改业务代码。
2. 灵活性高：可以通过自定义注解灵活配置需要监控的方法。
3. 详细日志：记录了方法的执行时间、入参、出参、异常信息等，方便排查问题。
4. 统一管理：所有监控逻辑集中在一个切面中，维护和扩展更加方便。

缺点

1. 性能开销：AOP的动态代理和反射操作可能会对性能产生一定影响。
2. 日志量大：详细的日志记录可能会占用较多的磁盘空间，需要合理配置日志策略。
3. 依赖框架：需要依赖Spring AOP框架，增加了项目的依赖复杂性。

---

6. 总结

通过自定义注解和Spring AOP，可以实现对方法执行时间的监控和详细日志的记录。这不仅有助于性能优化和问题排查，还能提升开发效率和系统可维护性。希望本文可以帮助你在实际项目中更好地利用Spring AOP进行方法执行时间监控和日志记录！