方法运行情况日志记录器

方法日志记录器

文章分类:Java编程

    在实际项目开发中，我们常常需要实时监测一个方法的执行情况，如：方法执行开始、注入方法的参数列表、方法执行时间、方法结束等信息。将这些信息以日志形式进行记录，可以方便开发人员分析方法的执行情况，比如，可以自定义一个时间标准，将执行时间超过此标准时间的方法标记为慢速，以便能及时监测到执行时间过慢的方法，给检查和调试带来方便。

    下面为一个记录方法执行情况的日志记录器，使用Spring AOP的方式实现，并可定义方法执行过慢的时间标准，以便监测方法的执行情况。

Java代码

1. package com.zhangsx.util.log;   
2.   
3. import org.apache.commons.logging.Log;   
4. import org.apache.commons.logging.LogFactory;   
5. import org.aopalliance.intercept.MethodInvocation;   
6. import org.aopalliance.intercept.MethodInterceptor;   
7.   
8. /**  
9.  * 记录方法执行情况的日志记录器。  
10.  * 使用Spring AOP的方式，记录方法运行情况，  
11.  * 包括方法开始、方法参数列表、方法执行时间、是否为执行慢速、方法结束等。  
12.  * 可配置将方法定义为执行慢速的时间参数slowExecuteTime，单位为毫秒。  
13.  *   
14.  * @author ZhangShixi  
15.  */  
16. public class OperationLog implements MethodInterceptor {   
17.   
18.     // 方法为执行慢速的时间标准，默认为 1000 毫秒   
19.     private long slowExecuteTime = 1000;   
20.     // 日志级别静态常量   
21.     private static final String LEVEL_INFO = "info";   
22.     private static final String LEVEL_DEBUG = "debug";   
23.     private static final String LEVEL_ERROR = "error";   
24.     private static final String LEVEL_WARAN = "waran";   
25.     // 日志记录器   
26.     private static Log log = LogFactory.getLog(OperationLog.class);   
27.   
28.     /**  
29.      * 获取将方法标记为执行慢速的时间标准，如果方法执行时间超过此值，将被标记为执行慢速。  
30.      * @return 执行慢速的时间标准  
31.      */  
32.     public long getSlowExecuteTime() {   
33.         return slowExecuteTime;   
34.     }   
35.   
36.     /**  
37.      * 设置将方法标记为执行慢速的时间标准，如果方法执行时间超过此值，将被标记为执行慢速。  
38.      * 如果不配置此参数，将默认为 1000 毫秒。  
39.      * @param slowExecuteTime 执行慢速的时间标准  
40.      */  
41.     public void setSlowExecuteTime(long slowExecuteTime) {   
42.         this.slowExecuteTime = slowExecuteTime;   
43.     }   
44.   
45.     /**  
46.      * 重写invoke(MethodInvocation invocation)方法，以便在日志中记录方法执行情况的信息。  
47.      * @param invocation 目标对象信息  
48.      * @return Object 方法返回值  
49.      * @throws java.lang.Throwable 异常  
50.      */  
51.     @Override  
52.     public Object invoke(MethodInvocation invocation) throws Throwable {   
53.   
54.         before(invocation);   
55.   
56.         long startTime = System.currentTimeMillis();   
57.         Object result = invocation.proceed();   
58.         long endTime = System.currentTimeMillis();   
59.   
60.         long executeTime = endTime - startTime;   
61.         logExecuteTime(invocation, executeTime);   
62.   
63.         after(invocation);   
64.   
65.         return result;   
66.     }   
67.   
68.     /**  
69.      * 在目标对象方法调用之前调用，以记录方法调用之前的情况。  
70.      * @param invocation 目标对象信息  
71.      */  
72.     private void before(MethodInvocation invocation) {   
73.         String methodName = invocation.getMethod().getName();   
74.   
75.         StringBuilder builder = new StringBuilder();   
76.         builder.append("Started ");   
77.         builder.append(methodName);   
78.         builder.append(" method!");   
79.         recordLog(builder.toString(), LEVEL_DEBUG, null);   
80.   
81.         Object[] args = invocation.getArguments();   
82.         builder.delete(0, builder.length());   
83.         builder.append(methodName);   
84.         builder.append(" way into the parameters are different：");   
85.         recordLog(builder.toString(), LEVEL_DEBUG, null);   
86.   
87.         for (int count = 0; count < args.length; count++) {   
88.             builder.delete(0, builder.length());   
89.             builder.append("The ");   
90.             builder.append(count);   
91.             builder.append(" parameters for the ");   
92.             builder.append(args[count] == null ? null : args[count].toString());   
93.             recordLog(builder.toString(), LEVEL_DEBUG, null);   
94.         }   
95.     }   
96.   
97.     /**  
98.      * 在目标对象方法调用之后调用，以记录方法调用之后的情况。  
99.      * @param invocation 目标对象信息  
100.      */  
101.     private void after(MethodInvocation invocation) {   
102.         String methodName = invocation.getMethod().getName();   
103.         recordLog(methodName + " the implementation of the end.", LEVEL_DEBUG,   
104.                 null);   
105.     }   
106.   
107.     /**  
108.      * 记录方法执行时间。  
109.      * 如果执行时间超过 getSlowExecuteTime() 的返回值，  
110.      * 则将记录等级提升为 waran ，并标记为慢速执行。  
111.      * @param invocation 目标对象信息  
112.      * @param executeTime 方法执行时间  
113.      */  
114.     private void logExecuteTime(MethodInvocation invocation, long executeTime) {   
115.         long slowTime = getSlowExecuteTime();   
116.         StringBuilder builder = new StringBuilder();   
117.         builder.append(invocation.getMethod().getName());   
118.         if (executeTime > slowTime) {   
119.             builder.append(" implementation of the method is much too slow,");   
120.             builder.append(" the execute time for the implementation is ");   
121.             builder.append(executeTime);   
122.             builder.append(" ms.");   
123.             recordLog(builder.toString(), LEVEL_WARAN, null);   
124.         } else {   
125.             builder.append(" execution time od the method is ");   
126.             builder.append(executeTime);   
127.             builder.append(" ms.");   
128.             recordLog(builder.toString(), LEVEL_DEBUG, null);   
129.         }   
130.         builder = null;   
131.     }   
132.   
133.     /**  
134.      * 记录日志信息。  
135.      * @param message 日志信息  
136.      * @param level 日志级别  
137.      * @param throwable 如果日志级别是异常，此属性用来描述异常信息。  
138.      */  
139.     private void recordLog(String message, String level, Throwable throwable) {   
140.         if (message != null && !message.isEmpty() &&   
141.                 level != null && !level.isEmpty()) {   
142.             if (LEVEL_INFO.equals(level)) {   
143.                 if (log.isInfoEnabled()) {   
144.                     log.info(message);   
145.                 }   
146.             } else if (LEVEL_DEBUG.equals(level)) {   
147.                 if (log.isDebugEnabled()) {   
148.                     log.debug(message);   
149.                 }   
150.             } else if (LEVEL_ERROR.equals(level)) {   
151.                 if (log.isErrorEnabled()) {   
152.                     log.error(message);   
153.                 }   
154.             } else if (LEVEL_WARAN.equals(level)) {   
155.                 if (log.isWarnEnabled()) {   
156.                     if (throwable == null) {   
157.                         log.warn(message);   
158.                     } else {   
159.                         log.warn(message, throwable);   
160.                     }   
161.                 }   
162.             }   
163.         }   
164.     }   
165. }  

package com.zhangsx.util.log;

import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.aopalliance.intercept.MethodInvocation;
import org.aopalliance.intercept.MethodInterceptor;

/**
 * 记录方法执行情况的日志记录器。
 * 使用Spring AOP的方式，记录方法运行情况，
 * 包括方法开始、方法参数列表、方法执行时间、是否为执行慢速、方法结束等。
 * 可配置将方法定义为执行慢速的时间参数slowExecuteTime，单位为毫秒。
 * 
 * @author ZhangShixi
 */
public class OperationLog implements MethodInterceptor {

    // 方法为执行慢速的时间标准，默认为 1000 毫秒
    private long slowExecuteTime = 1000;
    // 日志级别静态常量
    private static final String LEVEL_INFO = "info";
    private static final String LEVEL_DEBUG = "debug";
    private static final String LEVEL_ERROR = "error";
    private static final String LEVEL_WARAN = "waran";
    // 日志记录器
    private static Log log = LogFactory.getLog(OperationLog.class);

    /**
     * 获取将方法标记为执行慢速的时间标准，如果方法执行时间超过此值，将被标记为执行慢速。
     * @return 执行慢速的时间标准
     */
    public long getSlowExecuteTime() {
        return slowExecuteTime;
    }

    /**
     * 设置将方法标记为执行慢速的时间标准，如果方法执行时间超过此值，将被标记为执行慢速。
     * 如果不配置此参数，将默认为 1000 毫秒。
     * @param slowExecuteTime 执行慢速的时间标准
     */
    public void setSlowExecuteTime(long slowExecuteTime) {
        this.slowExecuteTime = slowExecuteTime;
    }

    /**
     * 重写invoke(MethodInvocation invocation)方法，以便在日志中记录方法执行情况的信息。
     * @param invocation 目标对象信息
     * @return Object 方法返回值
     * @throws java.lang.Throwable 异常
     */
    @Override
    public Object invoke(MethodInvocation invocation) throws Throwable {

        before(invocation);

        long startTime = System.currentTimeMillis();
        Object result = invocation.proceed();
        long endTime = System.currentTimeMillis();

        long executeTime = endTime - startTime;
        logExecuteTime(invocation, executeTime);

        after(invocation);

        return result;
    }

    /**
     * 在目标对象方法调用之前调用，以记录方法调用之前的情况。
     * @param invocation 目标对象信息
     */
    private void before(MethodInvocation invocation) {
        String methodName = invocation.getMethod().getName();

        StringBuilder builder = new StringBuilder();
        builder.append("Started ");
        builder.append(methodName);
        builder.append(" method!");
        recordLog(builder.toString(), LEVEL_DEBUG, null);

        Object[] args = invocation.getArguments();
        builder.delete(0, builder.length());
        builder.append(methodName);
        builder.append(" way into the parameters are different：");
        recordLog(builder.toString(), LEVEL_DEBUG, null);

        for (int count = 0; count < args.length; count++) {
            builder.delete(0, builder.length());
            builder.append("The ");
            builder.append(count);
            builder.append(" parameters for the ");
            builder.append(args[count] == null ? null : args[count].toString());
            recordLog(builder.toString(), LEVEL_DEBUG, null);
        }
    }

    /**
     * 在目标对象方法调用之后调用，以记录方法调用之后的情况。
     * @param invocation 目标对象信息
     */
    private void after(MethodInvocation invocation) {
        String methodName = invocation.getMethod().getName();
        recordLog(methodName + " the implementation of the end.", LEVEL_DEBUG,
                null);
    }

    /**
     * 记录方法执行时间。
     * 如果执行时间超过 getSlowExecuteTime() 的返回值，
     * 则将记录等级提升为 waran ，并标记为慢速执行。
     * @param invocation 目标对象信息
     * @param executeTime 方法执行时间
     */
    private void logExecuteTime(MethodInvocation invocation, long executeTime) {
        long slowTime = getSlowExecuteTime();
        StringBuilder builder = new StringBuilder();
        builder.append(invocation.getMethod().getName());
        if (executeTime > slowTime) {
            builder.append(" implementation of the method is much too slow,");
            builder.append(" the execute time for the implementation is ");
            builder.append(executeTime);
            builder.append(" ms.");
            recordLog(builder.toString(), LEVEL_WARAN, null);
        } else {
            builder.append(" execution time od the method is ");
            builder.append(executeTime);
            builder.append(" ms.");
            recordLog(builder.toString(), LEVEL_DEBUG, null);
        }
        builder = null;
    }

    /**
     * 记录日志信息。
     * @param message 日志信息
     * @param level 日志级别
     * @param throwable 如果日志级别是异常，此属性用来描述异常信息。
     */
    private void recordLog(String message, String level, Throwable throwable) {
        if (message != null && !message.isEmpty() &&
                level != null && !level.isEmpty()) {
            if (LEVEL_INFO.equals(level)) {
                if (log.isInfoEnabled()) {
                    log.info(message);
                }
            } else if (LEVEL_DEBUG.equals(level)) {
                if (log.isDebugEnabled()) {
                    log.debug(message);
                }
            } else if (LEVEL_ERROR.equals(level)) {
                if (log.isErrorEnabled()) {
                    log.error(message);
                }
            } else if (LEVEL_WARAN.equals(level)) {
                if (log.isWarnEnabled()) {
                    if (throwable == null) {
                        log.warn(message);
                    } else {
                        log.warn(message, throwable);
                    }
                }
            }
        }
    }
}

 

在使用时，只需在Spring的配置文件中，配置要记录的方法即可。

例如，记录所有Dao层的方法执行情况的配置：

Java代码

1. <?xml version="1.0" encoding="UTF-8"?>   
2.   
3. <beans xmlns="http://www.springframework.org/schema/beans"  
4.        xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"  
5.        xmlns:tx="http://www.springframework.org/schema/tx"  
6.        xsi:schemaLocation="http://www.springframework.org/schema/beans   
7.        http://www.springframework.org/schema/beans/spring-beans-2.0.xsd   
8.        http://www.springframework.org/schema/tx   
9.        http://www.springframework.org/schema/tx/spring-tx-2.0.xsd">   
10.   
11.     <!-- 方法运行情况日志记录器 -->   
12.     <bean id="log" class="com.zhangsx.util.log.OperationLog">   
13.         <!-- 方法运行时间高于500毫秒定义为慢速 -->   
14.         <property name="slowExecutionTime" value="500" />   
15.     </bean>   
16.   
17.     <!-- 记录DAO方法的执行 -->   
18.     <bean class="org.springframework.aop.framework.autoproxy.BeanNameAutoProxyCreator">   
19.         <property name="beanNames" value="*Dao" />   
20.         <property name="interceptorNames">   
21.             <list>   
22.                 <value>log</value>   
23.             </list>   
24.         </property>   
25.     </bean>   
26.   
27. </beans>