动态代理之详细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