Springboot基于AOP 注解打印方法耗时

版本

springboot 版本 2.1.6.RELEASE

实现

1. 自定义注解

TimeConsumeLog

/**
 * @author : wh
 * @date : 2020/7/24 10:44
 * 记录方法执行时间注解
 *  自己调用自己请使用 通过暴露代理类方式调用
 *  ((ClearServiceImpl)AopContext.currentProxy()).testAOP1();
 */
@Documented
@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
public @interface TimeConsumeLog {

    /**
     * 方法描述
     * @return
     */
    String methodDesc() default "";
}

2. 定义切面AOP类

2.1 使用前置，后置通知

TimeConsumeAspect

import com.sinoxk.drug.common.annotation.TimeConsumeLog;
import lombok.extern.slf4j.Slf4j;
import org.aspectj.lang.JoinPoint;
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.aspectj.lang.reflect.MethodSignature;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;

import java.lang.reflect.Method;

/**
 * @author : wh
 * @date : 2020/7/24 10:47
 *  方法执行时间切面
 */
@Aspect
@Component
@Order(4)
@Slf4j
public class TimeConsumeAspect {
    private static final ThreadLocal<Long> firstThreadLocal = new ThreadLocal<>();
    private static final ThreadLocal<Long> threadLocal = new ThreadLocal<>();
    // 解决方法调用见清除 threadLocal 空指针
    private static final ThreadLocal<Integer> countThreadLocal = new ThreadLocal<>();

    @Pointcut("@annotation(com.sinoxk.drug.common.annotation.TimeConsumeLog)")
    public void fun() {

    }

    @Before("fun()")
    public void before(JoinPoint joinPoint) {
        // 获取方法签名
        MethodSignature methodSignature = (MethodSignature)joinPoint.getSignature();
        // 获取方法上的 TimeConsumeLog注解
        TimeConsumeLog timeConsumeLog = methodSignature.getMethod().getAnnotation(TimeConsumeLog.class);
        // 如果有内部方法调用
        Integer methodCount = countThreadLocal.get();
        if (methodCount != null) {
            int i = methodCount + 1;
            countThreadLocal.set(i);
        } else {
            countThreadLocal.set(0);
        }
        if (timeConsumeLog != null && countThreadLocal.get() == 0) {
            firstThreadLocal.set(System.currentTimeMillis());
        } else {
            threadLocal.set(System.currentTimeMillis());
        }


    }

    @After(("fun()"))
    public void after(JoinPoint joinPoint) {
        MethodSignature methodSignature = (MethodSignature)joinPoint.getSignature();
        Method method = methodSignature.getMethod();
        TimeConsumeLog timeConsumeLog = method.getAnnotation(TimeConsumeLog.class);
        Long startTime;
        Integer methodCount = countThreadLocal.get();
        if (timeConsumeLog != null && methodCount == 0) {
            startTime = firstThreadLocal.get();

        } else{
            startTime = threadLocal.get();
            threadLocal.remove();

        }

            Long endTime = System.currentTimeMillis();
            Long costTime = endTime - startTime;

//            String requestUri=method.getAnnotation(RequestMapping.class).value()[0];
            String methodName=method.getDeclaringClass().getName()+"."+method.getName();
            String methodDesc=timeConsumeLog.methodDesc();
            log.info("methodName: {}, methodDesc: {} ==> 花费时间 {}ms",methodName,methodDesc,costTime);
        if (methodCount != 0) {
            int i = methodCount - 1;
            countThreadLocal.set(i);
        } else {
            firstThreadLocal.remove();
            countThreadLocal.remove();
        }
    }


}

2.2 使用环绕通知(最为简单)

@Around("fun()")
    public Object doAround(ProceedingJoinPoint joinPoint) throws Throwable {

        MethodSignature methodSignature = (MethodSignature)joinPoint.getSignature();
        Method method = methodSignature.getMethod();
        TimeConsumeLog timeConsumeLog = method.getAnnotation(TimeConsumeLog.class);
        long startTime = System.currentTimeMillis();
        Object result = joinPoint.proceed();
        Long endTime = System.currentTimeMillis();
        Long costTime = endTime - startTime;
        String methodName=method.getDeclaringClass().getName()+"."+method.getName();
        String methodDesc=timeConsumeLog.methodDesc();
        log.info("methodName: {}, methodDesc: {} ==> 花费时间 {}ms",methodName,methodDesc,costTime);
        return result;
    }

3. 测试

service

public interface ClearService {
    void testPrintTime();
    void testAop();

}

ClearServiceImpl

public class ClearServiceImpl  implements ClearService {
     @TimeConsumeLog(methodDesc = "测试打印")
    @Override
    public void testPrintTime() {
        try {
            Thread.sleep(1000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }

    }

    @TimeConsumeLog(methodDesc = "测试内部调用")
    public void testAop() {
        try {
            Thread.sleep(1000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }

}

测试类
ClearServiceTest

@RunWith(SpringRunner.class)
@SpringBootTest(classes = Application.class)
public class ClearServiceTest {
 @Test
    public void testAop() {
        clearService.testPrintTime();
    }
}

注意如果service调用service方法，AOP会失效

@TimeConsumeLog(methodDesc = "测试打印")
    @Override
    public void testPrintTime() {
        try {
            Thread.sleep(1000);
            testAop();
        } catch (InterruptedException e) {
            e.printStackTrace();
        }

    }

    @TimeConsumeLog(methodDesc = "测试内部调用")
    public void testAop() {
        try {
            Thread.sleep(1000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }

这里我们使用 testPrintTime去调用 testAop，发现 testAop上的 TimeConsumeLog注解失效了，原因很简单，调用自己方法的时候使用的是this而没有走代理类，解决方式如下

1. 用@Autowired或Resource引入自身依赖

@Autowired
    ClearService clearService;
    @TimeConsumeLog(methodDesc = "测试打印")
    @Override
    public void testPrintTime() {
        try {
            Thread.sleep(1000);
            clearService.testAop();
        } catch (InterruptedException e) {
            e.printStackTrace();
        }

    }

    @TimeConsumeLog(methodDesc = "测试内部调用")
    @Override
    public void testAop() {
        try {
            Thread.sleep(1000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }

2. 开启暴露代理类，AopContext.currentProxy()方式获取代理类
   在 Application加上注解

@EnableAspectJAutoProxy(exposeProxy = true)

然后用如下方式调用

 @TimeConsumeLog(methodDesc = "测试打印")
    @Override
    public void testPrintTime() {
        try {
            Thread.sleep(1000);
            ((ClearService)AopContext.currentProxy()).testAop();
        } catch (InterruptedException e) {
            e.printStackTrace();
        }

    }

    @TimeConsumeLog(methodDesc = "测试内部调用")
    @Override
    public void testAop() {
        try {
            Thread.sleep(1000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }