基于AspectJ加强代码，实现一行注解记录方法执行耗时

背景

因须要对项目中的方法执行进行性能测试，若是在每一个方法先后都加上以下代码

long beginTime = System.currentTimeMillis(); 
long endTime = System.currentTimeMillis(); 
long timeConsume = endTime - beginTime; 
复制代码

显然会让代码变得很是冗杂，并且须要统计性能的地方可能还会有不少，若是能够单纯在方法上加上一个注解，就能实现方法执行耗时的记录，这样便能减小许多简单且繁琐的代码，更加方便的扩展

技术选型

像这种场景就是典型的AOP场景，搜索SpringAOP就能找到不少的代码样例，可是项目并不依赖于Spring， 也没有必要引入Spring。一般要实现这样的功能，有两种方案，一种是像SpringAOP那样，经过CGLib动态代理或JDK动态代理，在建立对象的时候，动态地生成代理类的对象，另外一种是AspectJ，在编译代码的时候就将须要执行的逻辑织入到字节码中。

对于动态代理，须要建立代理类的对象，才能够加强，而项目中，存在不少静态方法，在使用的时候并不经过对象来调用，并且即使是经过对象来调用的方法，没有Spring方便的IOC机制，也得修改全部代码中new对象的处理，才可使用加强后的代理对象，略麻烦。并且若是是频繁的建立对象，由于还有一步建立代理对象的操做，性能上会有必定的损失。

对于AspectJ这种方式，则能够对知足切点表达式的地方，都织入加强后的逻辑，可是须要依赖于织入工具的协助，来对编译后的字节码进行加强。幸亏maven上已经有对应的aspectj编译插件，能够很方便的处理织入

综合考虑之下，决定采用自定义注解（指定目标）+ ApsectJ(Aop加强) + aspectj的Maven编译插件来实现

技术实现

一、自定义注解

@Retention(RetentionPolicy.RUNTIME) 
@Target(ElementType.METHOD) 
public @interface TimeConsumeLogAnnotation { 

} 
复制代码

二、引入Aspectj依赖

<dependency> 
​    <groupId>org.aspectj</groupId> 
​    <artifactId>aspectjrt</artifactId> 
​    <version>1.8.9</version> 
</dependency> 
复制代码

三、Aspectj切面

@Aspect 
public class TimeConsumeLogAspectJ { 
​    //经过ThreadLocal隔离不一样线程的变量 
​    ThreadLocal<Long> timeRecord = new ThreadLocal<>(); 

​    @Pointcut("execution(* *(..)) && @annotation(cn.freekiddo.annotation.TimeConsumeLogAnnotation)") 
​    public void jointPoint(){} 

​    @Before("jointPoint()") 
​    public void doBefore(JoinPoint joinPoint){ 
​        MethodSignature signature = (MethodSignature) joinPoint.getSignature(); 
​        Method method = signature.getMethod(); 
​        System.out.println("方法" + method.getName() + "开始"); 
​        timeRecord.set(System.currentTimeMillis()); 
​    } 

​    @After("jointPoint()") 
​    public void doAfter(JoinPoint joinPoint){ 
​        long beginTime = timeRecord.get(); 
​        System.out.println("方法" +joinPoint.getSignature().getName()+ "结束,耗时"+(System.currentTimeMillis()-beginTime) +"ms"); 
​    } 
} 
复制代码

四、引入maven编译插件

在maven-compiler-plugin处理完以后再工做

<plugin> 
​    <groupId>org.codehaus.mojo</groupId> 
​    <artifactId>aspectj-maven-plugin</artifactId> 
​    <version>1.10</version> 
​    <configuration> 
​        <source>1.8</source> 
​        <target>1.8</target> 
​        <complianceLevel>1.8</complianceLevel> 
​    </configuration> 
​    <executions> 
​        <execution> 
​            <phase>compile</phase> 
​            <goals> 
​                <goal>compile</goal> 
​            </goals> 
​        </execution> 
​    </executions> 
</plugin> 
复制代码

五、在目标方法上加入@TimeConsumeLogAnnotation注解编译运行便可

@TimeConsumeLogAnnotation() 
public static void sayHelloWorld(String name) { 
​    System.out.println("Hello " + name); 
} 
复制代码

编译后的字节码

@TimeConsumeLogAnnotation 
public static void sayHelloWorld(String name) { 
​    JoinPoint var1 = Factory.makeJP(ajc$tjp_0, (Object)null, (Object)null, name); 
​    try { 
​        TimeConsumeLogAspectJ.aspectOf().doBefore(var1); 
​        System.out.println("Hello " + name); 
​    } catch (Throwable var4) { 
​        TimeConsumeLogAspectJ.aspectOf().doAfter(var1); 
​        throw var4; 
​    } 
​    TimeConsumeLogAspectJ.aspectOf().doAfter(var1); 
} 
复制代码

效果

方法sayHelloWorld开始 
Hello world 
方法sayHelloWorld结束,耗时1ms 
复制代码

六、踩过的坑

（1）切面执行两次

在一开始切面的表达式为

@Pointcut("@annotation(cn.freekiddo.annotation.TimeConsumeLogAnnotation)") 
复制代码

而aspectj的编译器会识别出方法调用和方法执行两个阶段的切入点，由于会在这两个阶段都执行

经过将切面表达式修改成

@Pointcut("execution(* *(..)) && @annotation(cn.freekiddo.annotation.TimeConsumeLogAnnotation)") 
复制代码

能够限定成只识别方法执行这个阶段

（2）多模块项目aspectj编译失败

若是在多模块项目，在具体的某个子模块声明切面类，定义切点表达式，可是链接点切分散在各个其余模块时，ajc扫描具到切点表达式时，只会在本模块扫描对应的链接点，其余模块的链接点是没有办法编绎期切入切面，ajc是不会在编绎其余模块时再去扫描有没有某个切点表达式与当前链接点匹配的

经过在每一个模块都加上自定义注解和切面，可解决编译的问题

更多的操做

因为自定义注解支持赋值，Aspectj切面又能够拦截到方法，而且经过反射获取到方法参数，所以能够在这基础作更多定制化的优化

参考连接

Spring AOP 实现原理与 CGLIB 应用

关于AspectJ你可能不知道的事

AspectJ切面执行两次缘由分析

多模块maven项目使用Eclipse的 AspectJ编绎期织入