动态代理之详细DEBUG日志模式

动态代理应该有很多人都清楚了，但是比较少人还记得怎样去实现动态代理，当然我们不是去使用springAOP去实现动态代理，而是使用JDK中的proxy和CGLib中的enhancer去实现。

首先说明一下我们需要实现一个怎么样的功能，我目前需要实现的是一个详细的service层方法调用LOG，一般我们需要手动去打印例如传入什么参数了，那个方法被调用了，方法的耗时怎么样等等这些信息，这些在开发过程当中相当有价值，因为面对复杂的业务逻辑这个太有比较了，当然我们主要的目的还是希望通过这个日志工具去回忆一下动态代理的实现原理以及他们给我们带来什么样的好处。

说到日志，这个我是在一个真实的项目上使用的DEBUG日志模型，输出的日志如下：

============================EXECUTION LOG==============================
com.maxfunner.service.impl.TestServiceImpl$$EnhancerByCGLIB$$670a3f6e.login LOG [id->edbd8564-60ea-4d15-a577-31fed8474c96] : 
arguments : [ TONY , PWD ]
startTime : 2017-04-26 12:44:01
========================================================================


===============================FULL LOG=================================
com.maxfunner.service.impl.TestServiceImpl$$EnhancerByCGLIB$$670a3f6e.login LOG [id->edbd8564-60ea-4d15-a577-31fed8474c96] : 
arguments : [ TONY , PWD ]
startTime : 2017-04-26 12:44:01
endTime : 2017-04-26 12:44:02
elapsed_time(ms) : 1818
returning Object : username is : TONY , password : PWD
========================================================================

我在每个调用日志中打入了通过UUID随机生成的ID，然后查看过程当中可以好好的关联两段日志，里面有两种日志，第一种日志是EXECUTION LOG 这种是在方法一开始执行的时候输出的，第二种是FULL LOG 这种是在方法执行后输出的，还有一种FULL LOG 的样式是在发现exception异常的情况下输出的也是一个FULL LOG

===============================FULL LOG=================================
com.maxfunner.service.impl.TestServiceImpl$$EnhancerByCGLIB$$670a3f6e.register LOG [id->e0a35521-f82b-42c3-92c6-a20540181cb4] : 
arguments : [ TONY , PWD ]
startTime : 2017-04-26 12:44:02
endTime : 2017-04-26 12:44:02
elapsed_time(ms) : 2
exception : 
java.lang.RuntimeException: User name is exist
at com.maxfunner.service.impl.TestServiceImpl.register(TestServiceImpl.java:26)
at com.maxfunner.service.impl.TestServiceImpl$$EnhancerByCGLIB$$670a3f6e.CGLIB$register$0(<generated>)
at com.maxfunner.service.impl.TestServiceImpl$$EnhancerByCGLIB$$670a3f6e$$FastClassByCGLIB$$d181be51.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invokeSuper(MethodProxy.java:228)
at com.maxfunner.utils.log.LogProxy.intercept(LogProxy.java:28)
at com.maxfunner.service.impl.TestServiceImpl$$EnhancerByCGLIB$$670a3f6e.register(<generated>)
at App.main(App.java:20)


========================================================================

当然如果打印两段执行前和执行后的日志导致太多的日志输出的话，你们可以只选择打印执行后或者发现异常后的日志，这样每次得出的日志都是一个FULL LOG，当然这不是什么第三方的日志工具，只是我自己的一个日志实现模式而已，当然如果大家有兴趣我基于Spring去实现一个日志PROXY工具JAR给大家去使用。

首先说说这个日志里面究竟有些什么数据（如果看得懂我那些渣英文的话可以跳过）

com.maxfunner.service.impl.TestServiceImpl$$EnhancerByCGLIB$$670a3f6e.login
LOG的第一行是com.maxfunner.service.impl.TestServiceImpl$$EnhancerByCGLIB$$670a3f6e类对象中的login方法，然后后面跟一个LOG ID 如果只打印FULL LOG 可以完全忽略。

arguments 打印方法调用的实参内容，startTime和endTime、elapsed_time分别是开始执行的时间、执行结束的事件还有就是执行的耗时，exception 就是异常的栈信息，还有returning Object 就是返回的方法执行结果。当然无论是参数还是返回的方法执行结果，如果是非基本类型和String的话还是需要实现一下toString方法方便日志输出。

先贴出日志类文件：

/**
 * Created by yanzhichao on 26/04/2017.
 */
public class MyLog {

    private String logId;
    private String methodName;
    private String className;
    private Object[] argments;
    private long startTime;
    private long endTime;
    private long elapsed_time;
    private Object returningObj;
    private String exception;

    public MyLog() {
        this.logId = UUID.randomUUID().toString();
    }

    篇幅问题省略Getter 和 Setter

    public String getArgumentString(Object[] args) {
        if (args == null || args.length == 0) {
            return "NULL";
        }
        StringBuffer buffer = new StringBuffer("[ ");
        for (Object item : args) {
            buffer.append(item.toString());
            buffer.append(" , ");
        }
        buffer = new StringBuffer(buffer.substring(0,buffer.length() - 3));
        buffer.append(" ]");
        return buffer.toString();
    }

    public void printExecutionLog() {
        SimpleDateFormat format = new SimpleDateFormat("YYYY-MM-dd HH:mm:ss");
        StringBuffer buffer = new StringBuffer();
        buffer.append("============================EXECUTION LOG===============================\n");
        buffer.append(className + "." + methodName + " LOG [id->" + logId + "] : " + "\n");
        buffer.append("arguments : " + getArgumentString(argments) + "\n");
        buffer.append("startTime : " + format.format(new Date(startTime)) + "\n");
        buffer.append("========================================================================\n");
        System.out.println(buffer.toString());
    }

    public void printFullLog() {
        System.out.println(toString());
    }



    @Override
    public String toString() {
        SimpleDateFormat format = new SimpleDateFormat("YYYY-MM-dd HH:mm:ss");
        StringBuffer buffer = new StringBuffer();
        buffer.append("===============================FULL LOG=================================\n");
        buffer.append(className + "." + methodName + " LOG [id->" + logId + "] : " + "\n");
        buffer.append("arguments : " + getArgumentString(argments) + "\n");
        buffer.append("startTime : " + format.format(new Date(startTime)) + "\n");
        buffer.append("endTime : " + format.format(new Date(endTime)) + "\n");
        buffer.append("elapsed_time(ms) : " + elapsed_time + "\n");
        if (exception != null && !exception.isEmpty()) {
            buffer.append("exception : \n" + exception + "\n");
        } else {
            buffer.append("returning Object : " + returningObj + "\n");
        }
        buffer.append("========================================================================\n");
        return buffer.toString();
    }
}

这个主要有两部分第一部分是参数的遍历输出，还有就是 FULL LOG 和 EXECUTION LOG的打印。

然后在提出一个重点的MethodMonitor 主要用于日志记录：

/**
 * Created by yanzhichao on 26/04/2017.
 */
public class MethodMonitor {

    private MyLog myLog;
    private boolean isPrintLog;

    public MethodMonitor(boolean isPrintLog) {
        this.isPrintLog = isPrintLog;
    }

    public MyLog begin(Object target, Method method, Object[] args){
        myLog = new MyLog();
        myLog.setArgments(args);
        myLog.setClassName(target.getClass().getCanonicalName());
        myLog.setMethodName(method.getName());
        myLog.setStartTime(System.currentTimeMillis());
        if(isPrintLog){
            myLog.printExecutionLog();
        }
        return myLog;
    }

    public MyLog end(Object returningObj){
        myLog.setReturningObj(returningObj);
        myLog.setEndTime(System.currentTimeMillis());
        myLog.setElapsed_time(myLog.getEndTime() - myLog.getStartTime());
        if(isPrintLog){
            myLog.printFullLog();
        }
        return myLog;
    }

    public MyLog exception(Exception e){
        myLog.setException(getStackTrace(e));
        myLog.setEndTime(System.currentTimeMillis());
        myLog.setElapsed_time(myLog.getEndTime() - myLog.getStartTime());
        if(isPrintLog){
            myLog.printFullLog();
        }
        return myLog;
    }

    private static String getStackTrace(Exception e) {
        final Writer result = new StringWriter();
        final PrintWriter printWriter = new PrintWriter(result);
        e.printStackTrace(printWriter);
        return result.toString();
    }

}

getStackTrace主要是获得exception的信息其余三个方法就是不同阶段是执行的方法分别是开始执行、执行完毕、出现异常三个方法。

最后就是如何做动态代理了，有两个模式第一种刚刚都说了是使用JDK中提供的Proxy类，我们通过使用Proxy去实现了一个和目标service类完全一样的接口实现类，就是说我们有一个接口Service 然后有个实现ServiceImpl 最后我们代理了ServiceImpl 返回一个新的实现了Service接口的类，当然这个会局限于有接口的类才能实现，代码如下：

/**
 * Created by yanzhichao on 26/04/2017.
 */
public class LogProxyBasedInterface<T> implements InvocationHandler {

    Object targetObj;

    public LogProxyBasedInterface(Object targetObj) {
        this.targetObj = targetObj;
    }

    public T proxy(){
        return (T) Proxy.newProxyInstance(targetObj.getClass().getClassLoader(),
                targetObj.getClass().getInterfaces(),this);
    }

    public Object invoke(Object proxy, Method method, Object[] args) throws Throwable {
        MethodMonitor methodMonitor = new MethodMonitor(true);
        methodMonitor.begin(targetObj,method,args);
        Object returningObj = null;
        try {
            returningObj = method.invoke(targetObj, args);
        }catch (Exception e){
            methodMonitor.exception(e);
            throw e;
        }
        methodMonitor.end(returningObj);
        return returningObj;
    }
}

贴出一下调用的方法：

public static void testProxyBasedInterface(){
    TestService service = new TestServiceImpl();
    LogProxyBasedInterface<TestService> logProxy = new LogProxyBasedInterface<TestService>(service);
    service = logProxy.proxy();
    service.login("TONY","PWD");
    service.register("YAN","PWD");
    service.register("TONY","PWD");
}

当然我们也有不需要实现接口的动态代理方法，就是使用CGlib的方法，就是使用目标类创建一个动态子类，然后在动态子类当中调用父类的方法：

/**
 * Created by yanzhichao on 26/04/2017.
 */
public class LogProxy<T> implements MethodInterceptor {

    private Enhancer enhancer;

    public T getProxy(Class cls){
        enhancer = new Enhancer();
        enhancer.setSuperclass(cls);
        enhancer.setCallback(this);
        return (T) enhancer.create();
    }

    public Object intercept(Object o, Method method, Object[] objects, MethodProxy methodProxy) throws Throwable {
        MethodMonitor methodMonitor = new MethodMonitor(true);
        methodMonitor.begin(o,method,objects);
        Object returningObj;
        try {
            returningObj = methodProxy.invokeSuper(o, objects);
        }catch (Exception e){
            methodMonitor.exception(e);
            throw e;
        }
        methodMonitor.end(returningObj);
        return returningObj;
    }
}

提出使用以上方法的调用代码：

public static void main(String[] args){
    TestServiceImpl service = new LogProxy<TestServiceImpl>().getProxy(TestServiceImpl.class);
    service.login("TONY","PWD");
    service.register("YAN","PWD");
    service.register("TONY","PWD");
}

最后还需要我贴出TestService的代码吗，如果觉得不需要的话文章就算是看完了如果需要的话继续看吧，不过也没有什么好看的就是几行代码

/**
 * Created by yanzhichao on 26/04/2017.
 */
public interface TestService {

    public User login(String username, String password);

    public User register(String username,String password);

}

/**
 * Created by yanzhichao on 26/04/2017.
 */
public class TestServiceImpl implements TestService {

    public User login(String username, String password) {

        try {
            Thread.sleep(1700);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
        User user = new User();
        user.setPassword(password);
        user.setUsername(username);
        return user;
    }

    public User register(String username, String password) {
        if("TONY".equals(username)){
            throw new RuntimeException("User name is exist");
        }
        User user = new User();
        user.setUsername(username);
        user.setPassword(password);
        return user;
    }
}

看到我在注册的方法中抛出了异常，主要是测试一下异常的捕获日志而已。

原文链接：https://blog.csdn.net/tony308001970/article/details/70799801

你可能也喜欢