bytebuddy解决spring AOP切面同一个类嵌套方法不生效问题

bytebuddy解决spring AOP切面同一个类嵌套方法不生效问题

    sping AOP切面注解使用中的坑中详细介绍了spring AOP切面注解的同一个类嵌套方法不生效问题和产生的原因，这篇实际是为了完美的解决打印方法运行时间的问题。
    bytebuddy是字节码生成库，可以生成和操作java的字节码，在Java应用程序的运行期间可以使用该字节码工程库来修改当前要执行的代码，甚至包括自己的代码。 由于是使用植入字节码，而不是spring AOP的代理的模式，所以不会有嵌套不生效的问题。

1.首先在一个项目pom.xml中引入bytebuddy:

<dependency>
    <groupId>net.bytebuddy</groupId>
    <artifactId>byte-buddy</artifactId>
    <version>1.5.7</version>
</dependency>
<dependency>
    <groupId>net.bytebuddy</groupId>
    <artifactId>byte-buddy-agent</artifactId>
    <version>1.5.7</version>
</dependency>

2.接着需要书写功能代码，和使用spring AOP的方式一样，需要先声明一个注解：

//@TimeLog注解
package com;
import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;
@Retention(value = RetentionPolicy.RUNTIME)
@Target({ElementType.TYPE,ElementType.METHOD})
public @interface TimeLog {
}

3.然后实现这个注解的“切面”逻辑(bytebuddy的advice相当于是切面，其实也可以使用另一种interceptor实现)：

package com;
import com.LoggingUtils
/*
*LoggingUtils自己写的一个输出切点类日志，而不是当前切面类的log小工具。
*可以修改为一个普通log或者控制台打印方法。后面我会附LoggingUtils代码，介绍原因，给大家研究。
*/
import net.bytebuddy.asm.Advice;
import net.bytebuddy.implementation.bytecode.assign.Assigner;
import java.lang.reflect.Method;

public class TimeLogAdvice {
    @Advice.OnMethodEnter //方法进入前记录开始时间
    static long enter(@Advice.AllArguments Object args[], @Advice.Origin Method method) {
        return System.currentTimeMillis();
    }

    //方法退出后，结算运行时间，并按照格式输出
    @Advice.OnMethodExit(onThrowable = Exception.class)
    static void exit(@Advice.Enter long startTime,
                     @Advice.Return(typing=Assigner.Typing.DYNAMIC) Object result,
                     @Advice.Origin Method method,
                     @Advice.Thrown Throwable t
                     ) {
        if(t!=null){
            LoggingUtils.error(method.getDeclaringClass(), method.getName(),t);
        }else{
            LoggingUtils.info(method.getDeclaringClass(), "[TIMELOG][{}.{}()]: {} ms", method.getDeclaringClass(),
                                  method.getName(), (System.currentTimeMillis() - startTime));
        }
    }
}

4.和spring AOP不同的时，bytebuddy需要定义注入规则，一般是通过AgentBuilder方法，生成一个Agent。如：

package com;
import com.LoggingUtils;
import com.TimeLogAdvice;
import net.bytebuddy.agent.ByteBuddyAgent;
import net.bytebuddy.agent.builder.AgentBuilder;
import net.bytebuddy.asm.Advice;
import net.bytebuddy.description.type.TypeDescription;
import net.bytebuddy.dynamic.DynamicType;
import net.bytebuddy.matcher.ElementMatchers;
import net.bytebuddy.utility.JavaModule;
import static net.bytebuddy.matcher.ElementMatchers.nameStartsWith;
import static net.bytebuddy.matcher.ElementMatchers.named;

public class Agent {
    //生成一个agent单例
    private static Agent instance = new Agent();
    private Agent() {}
    public static Agent getInstance(){ return instance; }
    public void install() {
        synchronized (Agent.class) {
            ByteBuddyAgent.install();
            new AgentBuilder.Default().ignore( //忽略的包，这些包不会注入
                    nameStartsWith("org.aspectj."))
                    .or(nameStartsWith("org.groovy."))
                    .or(nameStartsWith("com.sun."))
                    .or(nameStartsWith("sun."))
                    .or(nameStartsWith("jdk."))
                    .or(nameStartsWith("org.springframework.asm."))
                    .or(nameStartsWith("com.p6spy."))
                    .or(nameStartsWith("net.bytebuddy."))
                    .type(ElementMatchers.nameStartsWith("com.")) //以com.开头的包会注入
                    //定义规则，将TimeLogAdvice和注解TimeLog绑定
                    .transform((builder, type, classLoader, module) ->
                            builder.visit(Advice.to(TimeLogAdvice.class).on(ElementMatchers.isAnnotatedWith(named("com.TimeLog")))))
                    .with(new AgentBuilder.Listener(){
                        @Override
                        public void onDiscovery(String s, ClassLoader classLoader, JavaModule javaModule, boolean b) {
                        }

                        @Override
                        public void onTransformation(TypeDescription typeDescription, ClassLoader classLoader, JavaModule module, boolean loaded, DynamicType dynamicType) {
                        }

                        @Override
                        public void onIgnored(TypeDescription typeDescription, ClassLoader classLoader, JavaModule module, boolean loaded) {
                        }

                        @Override
                        public void onError(String typeName, ClassLoader classLoader, JavaModule module, boolean loaded, Throwable throwable) {
                            LoggingUtils.error(Agent.class,typeName,throwable);
                        }

                        @Override
                        public void onComplete(String typeName, ClassLoader classLoader, JavaModule module, boolean loaded) {
                        }
                    })
                    .installOnByteBuddyAgent();
            LoggingUtils.info(Agent.class, "agent install finished");
        }
    }
}

5.最后就是需要是合适的时机注入，一般要在程序初始化的时候，太晚是不行的。网上有很多都是在premain中，我觉得不太方便。如果使用spring mvc的，我建议监听ApplicationEnvironmentPreparedEvent，在这个事件发生时也是可以注入成功的。例：

package com;

import com.LoggingUtils;
import org.springframework.boot.context.event.ApplicationEnvironmentPreparedEvent;
import org.springframework.context.ApplicationListener;

public class AppEnvListener implements ApplicationListener<ApplicationEnvironmentPreparedEvent> {
    @Override
    public void onApplicationEvent(ApplicationEnvironmentPreparedEvent applicationEnvironmentPreparedEvent) {
            Agent.getInstance().install();  //监听程序准备事件，注入
    }
}

就是不要忘了这个监听器是需要在spring.factories里注册的。
日志打印模拟结果：

[INFO][2019-11-17][com.TestController:37] [TIMELOG][class com.TestController.test()]: 22 ms
[INFO][2019-11-17][com.TestController:37] [TIMELOG][class com.TestController.test2()]: 68 ms

最后附上LoggingUtils实现，这个类的主要作用是，如果单纯使用log.info打印，显示的类会一直是TimeLogAdvice，比如上例就不会是com.TestController，而这个方法运行时间的注解显然是想确定被注解的方法的类名，所以需要一个小技巧转化一下：

package com;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class LoggingUtils {

    private static Logger logger = LoggerFactory.getLogger(LoggingUtils.class);

    public static boolean isDebugEnabled(){
        return logger.isDebugEnabled();
    }

    public static boolean isInfoEnabled(){
        return logger.isInfoEnabled();
    }

    public static boolean isErrorEnabled(){
        return logger.isErrorEnabled();
    }

    public static void debug(Class clazz, String msg, Object... args) {
        if (clazz != null) {
            logger = LoggerFactory.getLogger(clazz);
        }
        logger.debug(msg, args);
    }

    public static void info(Class clazz, String msg, Object... args) {
        if (clazz != null) {
            logger = LoggerFactory.getLogger(clazz);
        }
        logger.info(msg, args);
    }
    public static void error(Class clazz,String msg,Throwable throwable) {
        if (clazz != null) {
            logger = LoggerFactory.getLogger(clazz);
        }
        logger.error(msg, throwable);
    }
}

这里是将Class当做入参传入，而且需要是静态方法。