使用动态代理记录方法执行的时间

简介: 在大型系统中,我们经常需要监视我们系统执行的性能状况,当出现性能问题时,我们要能够迅速地找到瓶颈在什么地方。在程序的层面上来说,就是看哪个方法执行所消耗的时间很长。       使用动态代理可以非常方便的记录方法执行的时间,比如,下面的截图,就是ESBasic.

      在大型系统中,我们经常需要监视我们系统执行的性能状况,当出现性能问题时,我们要能够迅速地找到瓶颈在什么地方。在程序的层面上来说,就是看哪个方法执行所消耗的时间很长。

      使用动态代理可以非常方便的记录方法执行的时间,比如,下面的截图,就是ESBasic.Emit.Aop.Interceptors.MethodTimeInterceptor截获器记录的片段:

2009 - 4 - 17   18 : 50 : 12 :TY.Web.AgentInterface.IGameRecordDetailBL.GetPaginationData方法耗时:390ms
2009 - 4 - 17   18 : 50 : 16 :TY.Web.MemberInterface.IMemberBL.GetOne方法耗时:106ms
2009 - 4 - 17   18 : 50 : 23 :TY.Web.MemberInterface.IMemberBL.GetOne方法耗时:105ms
2009 - 4 - 17   18 : 50 : 23 :TY.Web.MemberInterface.IMemberBL.GetOne方法耗时:105ms
2009 - 4 - 17   18 : 50 : 24 :TY.Web.AgentInterface.IGameRecordDetailBL.GetPaginationData方法耗时:386ms
2009 - 4 - 17   18 : 50 : 30 :TY.Web.AgentInterface.IGameRecordDetailBL.GetPaginationData方法耗时:387ms
2009 - 4 - 17   18 : 50 : 35 :TY.Web.AgentInterface.IGameRecordDetailBL.GetPaginationData方法耗时:377ms
2009 - 4 - 17   18 : 50 : 43 :TY.Web.MemberInterface.IMemberBL.GetOne方法耗时:105ms
2009 - 4 - 17   18 : 51 : 14 :TY.Web.MemberInterface.IGameBenefitBL.GetMemberBenefitData方法耗时:714ms

 

      在我们常见的三层架构中,我们可能需要记录UI层调用BL层的每个方法所执行的时间,那我们可以这样做。假设BL提供给UI访问的接口为IBL(可能有多个,如IBL1,IBL2,IBL3,......),BL通过Remoting的方式发布它的服务。

     // BL层给UI层调用的接口
     public   interface  IBL
    {        
    }
    
// BL的实现
     public   class  BLObject IBL
    {
    }

      那么,我们让BL不直接发布实现了IBL接口的对象(BLObject),而是发布拦截了这个对象的动态代理,就像这样:

IMethodTimeLogger logger = new MethodTimeLogger(new FileAgileLogger("TimeLogger.txt") ,100) ; 
IBL blObject 
= ...; //BLObject 的实例
IBL blObjectProxy = DynamicProxyFactory.CreateAopProxy<IBL>(blObject, nullnew MethodTimeInterceptor(logger));

 

      blObjectProxy即是拦截了blObject调用的动态代理,它和BLObject 一样实现了IBL接口,并且将所有的调用转发给blObject,而且记录了blObject每个方法执行的时间。我们可以将blObjectProxy对象发布为Remoting,这样就可以记录下BL每个方法的执行时间了。

 

      在上面的例子中,IMethodTimeLogger 接口是用于记录时间的记录器接口,我们可以将时间记录到日志文件,当然也可以记录到数据库或其他地方,你只要实现IMethodTimeLogger 接口就可以了。这里我们将时间记录到TimeLogger.txt文件,注意,MethodTimeLogger 的第二个参数100,表示只记录那些执行时间超过100ms的方法调用,因为如果要记录所有的方法调用的话,在大型系统中日志可能会在很短的时间内就变得非常的庞大,这样反而不利于日志查看。

 

      再回到上面的日志片段,我们看到,日志记录了BL接口中具体方法的调用时间,执行所消耗的时长,这样我们就可以很方便的找到性能的瓶颈是在那个方法的调用上产生的了。

      上述例子中所用到的类都位于ESBasic.dll中,你可以从这里下载进行试验。ESBasic中的动态代理技术是基于Emit实现的,有兴趣的话你可以使用Reflector来查看其实现原理。

      关于ESBasic中动态代理实现的更多介绍,可以参考我的这两篇文章:动态代理DynamicProxy 介绍  和 使用动态代理,提高工作效率


 

 

相关实践学习
日志服务之使用Nginx模式采集日志
本文介绍如何通过日志服务控制台创建Nginx模式的Logtail配置快速采集Nginx日志并进行多维度分析。
目录
相关文章
|
7月前
|
SQL 存储 Java
java通过拦截器实现项目每次执行sql耗时统计,可配置是否打印
java通过拦截器实现项目每次执行sql耗时统计,可配置是否打印
|
监控 Cloud Native Java
字节码编程,Byte-buddy篇二《监控方法执行耗时动态获取出入参类型和值》
在前面的ASM、Javassist 章节中也有陆续实现过获取方法的出入参信息,但实现的方式还是偏向于字节码控制,尤其ASM,更是需要使用到字节码指令将入参信息压栈操作保存到局部变量用于输出,在这个过程中需要深入了解Java虚拟机规范,否则很不好完成这一项的开发。但!ASM也是性能最牛的。其他的字节码编程框架都是基于它所开发的。
618 0
字节码编程,Byte-buddy篇二《监控方法执行耗时动态获取出入参类型和值》
|
Java Android开发
JobService源码探究之 onStartJob()里执行耗时逻辑导致Job可能被强制销毁
JobService源码探究之 onStartJob()里执行耗时逻辑导致Job可能被强制销毁
|
Java 关系型数据库 MySQL
抽象类与接口的比较?构造方法,构造方法重载,什么是复制构造方法?求N的阶乘?Java环境搭建:JDK、JRE、JVM关系?MySQL事务并发三大问题,针对事务并发的问题、java接口详情
抽象类与接口的比较?构造方法,构造方法重载,什么是复制构造方法?求N的阶乘?Java环境搭建:JDK、JRE、JVM关系? 抽象类与接口的比较
119 1
你真的明白关于迭代器的方法、使用异常、并发修改异常介绍嘛?
关于迭代器的方法、使用异常、并发修改异常介绍的使用
100 0
你真的明白关于迭代器的方法、使用异常、并发修改异常介绍嘛?
|
Java Spring
spring源码系列11:事务代理对象的执行(上)
spring源码系列11:事务代理对象的执行(上)
|
Java 数据库连接 数据库
spring源码系列11:事务代理对象的执行(下)
spring源码系列11:事务代理对象的执行(下)
让某一个请求先执行(时机问题)
让某一个请求先执行(时机问题)
|
Arthas JSON 监控
项目中使用了这个属性赋值方法,接口耗时提升了几十毫秒
使用了这个属性赋值方法,接口耗时提升了几十毫秒
123 0
项目中使用了这个属性赋值方法,接口耗时提升了几十毫秒