在实际项目开发中,我们常常需要实时监测一个方法的执行情况,如:方法执行开始、注入方法的参数列表、方法执行时间、方法结束等信息。将这些信息以日志形式进行记录,可以方便开发人员分析方法的执行情况,比如,可以自定义一个时间标准,将执行时间超过此标准时间的方法标记为慢速,以便能及时监测到执行时间过慢的方法,给检查和调试带来方便。
下面为一个记录方法执行情况的日志记录器,使用Spring AOP的方式实现,并可定义方法执行过慢的时间标准,以便监测方法的执行情况。
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层的方法执行情况的配置:
<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xmlns:tx="http://www.springframework.org/schema/tx"
xsi:schemaLocation="http://www.springframework.org/schema/beans
http://www.springframework.org/schema/beans/spring-beans-2.0.xsd
http://www.springframework.org/schema/tx
http://www.springframework.org/schema/tx/spring-tx-2.0.xsd">
<!-- 方法运行情况日志记录器 -->
<bean id="log" class="com.zhangsx.util.log.OperationLog">
<!-- 方法运行时间高于500毫秒定义为慢速 -->
<property name="slowExecutionTime" value="500" />
</bean>
<!-- 记录DAO方法的执行 -->
<bean class="org.springframework.aop.framework.autoproxy.BeanNameAutoProxyCreator">
<property name="beanNames" value="*Dao" />
<property name="interceptorNames">
<list>
<value>log</value>
</list>
</property>
</bean>
</beans>