Spring AOP way to monitor the execution time of a method

Some time ago a few peers and I spit out the system response more and more slowly, optimization do not know where to start! Today's writing uses spring's AOP to implement record monitoring of method-level execution time, to evaluate the performance of methods and to optimize targeted methods.

For monitoring, we are more concerned about the reliability and performance of monitoring, accurate, efficient, which can not affect the overall performance of our system can have a more accurate understanding.

As for spring AOP, I'm not going to go into this, I'm just a handful of people on the web, and everyone who has used spring knows spring's IOC and AOP. IOC we often use, but in our own system, AOP is used almost zero, except for the small function of this monitoring application, the other is basically not used.

We use Beannameautoproxycreator to specify the name of the bean and the name of the bean to be notified, and you can use wildcards to automatically proxy them when you specify a name, configured as follows

 <bean class= "Org.springframework.aop.framework.autoproxy.BeanNameAutoProxyCreator" > <property nam E= "Proxytargetclass" > <value>true</value> </property> <property  
            Name= "Interceptornames" > <list> <idref bean= "Profilerinterceptor"/>  
                </list> </property> <property name= "Beannames" > <list>  
                <value>*Service</value> <value>*ServiceImpl</value> <value>*Manager</value> <value>*ManagerImpl</value> ;value>*dao</value> </list> </property> </bean> 

The configuration file above we have configured a IDREF bean, which is the code for the monitoring logic we need to write. Interceptor is an interceptor, and the response to this configuration is to write one of its interceptors to intercept classes with the suffix Service,serviceimpl,manager,managerimpl,dao. As for class interception or method level interception, it depends on the logic and code of our interceptor.

More Wonderful content: http://www.bianceng.cnhttp://www.bianceng.cn/Programming/Java/

Talk about the implementation of the Interceptor. We want the interceptor to record the execution time of the method, as well as the output of the log, for example, the method of executing more than 500ms, we want to print out the internal execution of each method is time-consuming, so that we can perform a slow way at a glance, Optimization does not require a lot of time to logger exactly where the execution is slow. So in the interceptor, we add a cosmetic property that is used to configure how time-consuming it is to print to the log for execution of the configured time. Get a log output like the following:

[4359, 2, 100%, 0]com.profile.service.impl.orderserviceimpl.findrecentlyprofile
+---[4357, 4357, 99%, 1]com.profile.dao.genericmybatisdao.querypage

The first line represents the total time consuming of the overall method execution, and the next line indicates that other monitored methods that exist in this method are time-consuming. This makes it easy to know that the time it takes to execute SQL is optimized for SQL.

So how do you do that, show some of the code in the Interceptor. The interceptor inherits the Abstractmonitoringinterceptor class, which is a method-level interceptor that implements the Methodinterceptor interface.

Protected Object invokeundertrace (methodinvocation invocation, Log logger) throws Throwable {  
        String name = CREATEINV Ocationtracename (invocation);  
        Whether to delegate the interception of the annotation  
        boolean isexistsprintprofiler = Printprofilerhelper.ismethodexistsprintprofiler ( Invocation.getmethod ());  
        try {  
            if (!isexistsprintprofiler) {  
                Profiler.start (name, monitortime);  
            }  
            return Invocation.proceed ();  
        } Finally {  
            if (!isexistsprintprofiler) {  
                profiler.stop (name);  
      
    }}} public int Getmonitortime () {return  
        monitortime;  
    }  
      
    public void setmonitortime (int monitortime) {  
        this.monitortime = monitortime;  
    }

The code in the interceptor is very simple and simple to 10 lines of code. This is a good thing for us. In the profiler class, we did some monitoring, and given that we output log files in the tree format of the log described above, we used theadlocal in Profiler to manage the execution of the method, which makes the code very simple. Profiler's Start method also has 10 lines of code

Private final static threadlocal<execdata> Dataholder = new threadlocal<execdata> ();  
      
      
public static void Start (String logName) {  
    start (logName, Elapse_time_ms_to_log);  
}  
      
public static void Start (String logName, int elapsetimemstolog) {  
    Execdata execdata = Dataholder.get ();  
    Execnode CurrentNode = new Execnode (LogName, System.currenttimemillis (), elapsetimemstolog);  
    if (Execdata = = null) {  
        execdata = new Execdata ();  
        Execdata.root = CurrentNode;  
        Dataholder.set (Execdata);  
    } else {  
        Execnode parent = Execdata.currentnode;  
        Currentnode.setparent (parent);  
        Parent.getchildlist (). Add (CurrentNode);  
    Execdata.currentnode = CurrentNode;  
    execdata.level++;  
}

In this way, we record the hierarchical relationship of the methods, and after the monitored methods are executed, we use the Stop method to record the execution end time and log the output of the qualified method. So dozens of lines of code, we are very simple to put this monitoring finished, deployed to our own applications to monitor the performance of the method, from now on, we do not have to guess which method is too slow to perform, in the end is which step slow. Performance, monitoring, all in the grasp.