Use Dynamic proxy to record the execution time of the Method

In large systems, we often need to monitor the performance of our system execution. When there is a performance problem, we need to be able to quickly find the bottleneck. InProgramIn terms of method execution, it takes a long time.

The dynamic proxy can easily record the execution time of the method. For example, the following is the segment recorded by esbasic. emit. AOP. interceptors. methodtimeinterceptor:

2009 - 4 - 17   18 : 50 : 12 : Ty. Web. agentinterface. igamerecorddetailbl. getpaginationdata method time: 390 Ms
2009 - 4 - 17   18 : 50 : 16 : Ty. Web. memberinterface. imemberbl. getone method time consumption: 106 Ms
2009 - 4 - 17   18 : 50 : 23 : Ty. Web. memberinterface. imemberbl. getone method time consumption: 105 Ms
2009 - 4 - 17   18 : 50 : 23 : Ty. Web. memberinterface. imemberbl. getone method time consumption: 105 Ms
2009 - 4 - 17   18 : 50 : 24 : Ty. Web. agentinterface. igamerecorddetailbl. getpaginationdata method time: 386 Ms
2009 - 4 - 17   18 : 50 : 30 : Ty. Web. agentinterface. igamerecorddetailbl. getpaginationdata method time: 387 Ms
2009 - 4 - 17   18 : 50 : 35 : Ty. Web. agentinterface. igamerecorddetailbl. getpaginationdata method time: 377 Ms
2009 - 4 - 17   18 : 50 : 43 : Ty. Web. memberinterface. imemberbl. getone method time consumption: 105 Ms
2009 - 4 - 17   18 : 51 : 14 : Ty. Web. memberinterface. igamebenefitbl. getmemberbenefitdata method time: 714 ms

 

In our common three-tier architecture, we may need to record the time when each method of the UI Layer calls the BL layer is executed, so we can do this. Suppose that BL provides the interface for UI access to IBL (there may be multiple interfaces, such as ibl1, ibl2, ibl3 ,......), BL publishes its services through remoting.

// Interface called by the BL layer to the UI Layer
Public   Interface  IBL
{
}
// BL implementation
Public   Class  Blobject:IBL
{
}

So we let BL not directly publish the object that implements the IBL interface (blobject), but publish the dynamic proxy that intercepts this object, like this:

ImethodtimeloggerLogger =   New  Methodtimelogger( New  Fileagilelogger( " Timelogger.txt " ), 100 );
IBLBlobject = ...; // Blobject instance
IBLBlobjectproxy =  Dynamicproxyfactory. Createaopproxy < IBL > (Blobject, Null , New  Methodtimeinterceptor(Logger ));

 

Blobjectproxy is the dynamic proxy that intercepts the call of blobject.BlobjectThe same IBL interface is implemented, and all calls are forwarded to blobject, And the execution time of each method of blobject is recorded. We can publish the blobjectproxy object as remoting, so that we can record the execution time of each bl method.

 

In the preceding example,ImethodtimeloggerThe interface is the recorder interface used to record the time. We can record the time to the log file, and of course we can also record it to the database or other places. You only need to implementImethodtimeloggerInterface. Here we record the timeTimelogger.txtFile. Note that the second parameter 100 of methodtimelogger indicates that only method calls whose execution time exceeds ms are recorded, because if you want to record all method calls, in a large system, logs may become very large in a short period of time, which is not conducive to log viewing.

 

Return to the preceding log segment. We can see that the log records the call time of specific methods in the BL interface, and the duration of execution, in this way, we can easily find that the performance bottleneck is generated by calling that method.

The classes used in the above example are all located in esbasic. dll. You can download them here for testing. The dynamic proxy technology in esbasic is implemented based on emit. If you are interested, you can use reflector to view its implementation principles.

For more information about the dynamic proxy implementation in esbasic, refer to these two articles.Article: Introduction to dynamic proxy dynamicproxy and use of dynamic proxy to improve work efficiency