Spring AOP监控SQL执行

         对数据库连接池Proxool比较熟悉的读者，都知道Proxool可以记录SQL执行内容和时间等信息日志。我们可以将该日志记录专门的SQL日志文件，对于查找执行特别耗时的SQL起了不小的作用。对于一些其他连接池，没有该特性时，本文介绍Spring AOP切面方法来记录SQL日志。

当然也可以通过数据库提供的特性来查询执行效率较低的SQL，本文不做探讨。

         本文介绍使用SpringJdbcTemplate执行SQL，使用其他方法或者ORM思路类似（Hibernate提供了日志记录功能）。

         使用AOP，可以使用Around通知，在JdbcTemplate执行方法前，记录当前时间，在方法执行完后，计算SQL耗时，并记录日志。思路很简单，不过多介绍，代码如下。

package org.enyes.sql.util;
import org.apache.log4j.Logger;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;

/**
 * 对Spring JdbcTemplate进行切面，记录每个sql执行时间。
 */
@Aspect
public class SqlExecutionTimeAspect {
	/**
	 * logger
	 */
	private static final Logger LOG = Logger
			.getLogger(SqlExecutionTimeAspect.class);

	/**
	 * 当Sql执行时间超过该值时，则进行log warn级别题型，否则记录INFO日志。
	 */
	private long warnWhenOverTime = 2 * 60 * 1000L;

	@Around("execution(* org.springframework.jdbc.core.JdbcTemplate.*(..))")
	public Object logSqlExecutionTime(ProceedingJoinPoint joinPoint)
			throws Throwable {
		long startTime = System.currentTimeMillis();
		Object result = joinPoint.proceed();
		long costTime = System.currentTimeMillis() - startTime;
		if (costTime > warnWhenOverTime) {
			StringBuilder sb = new StringBuilder();
			sb.append("execute method :").append(joinPoint.getSignature());
			sb.append("args: ").append(arrayToString(joinPoint.getArgs()));
			sb.append(" cost time[").append(costTime).append("]ms");
			LOG.warn(sb);
		} else if (LOG.isInfoEnabled()) {
			StringBuilder sb = new StringBuilder();
			sb.append("execute method :").append(joinPoint.getSignature());
			sb.append("args: ").append(arrayToString(joinPoint.getArgs()));
			sb.append(" cost time[").append(costTime).append("]ms");
			LOG.info(sb);
		}
		return result;
	}

	private static String arrayToString(Object[] a) {
		if (a == null)
			return "null";

		int iMax = a.length - 1;
		if (iMax == -1)
			return "[]";

		StringBuilder b = new StringBuilder();
		b.append('[');
		for (int i = 0;; i++) {
			if (a[i] instanceof Object[]) {
				b.append(arrayToString((Object[]) a[i]));
			} else {
				b.append(String.valueOf(a[i]));
			}
			if (i == iMax)
				return b.append(']').toString();
			b.append(", ");
		}
	}
}

<?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:p="http://www.springframework.org/schema/p"
	xmlns:context="http://www.springframework.org/schema/context"
	xmlns:mvc="http://www.springframework.org/schema/mvc" xmlns:tx="http://www.springframework.org/schema/tx"
	xmlns:aop="http://www.springframework.org/schema/aop"
	xmlns:task="http://www.springframework.org/schema/task" 
	xsi:schemaLocation="  
    http://www.springframework.org/schema/beans   
    http://www.springframework.org/schema/beans/spring-beans-3.1.xsd  
    http://www.springframework.org/schema/context  
    http://www.springframework.org/schema/context/spring-context-3.1.xsd  
    http://www.springframework.org/schema/mvc  
    http://www.springframework.org/schema/mvc/spring-mvc-3.1.xsd 
     http://www.springframework.org/schema/tx 
    http://www.springframework.org/schema/tx/spring-tx-3.1.xsd 
     http://www.springframework.org/schema/aop
    http://www.springframework.org/schema/aop/spring-aop-3.1.xsd  
    http://www.springframework.org/schema/task 
    http://www.springframework.org/schema/task/spring-task-3.1.xsd 
">
<beans>
<aop:aspectj-autoproxy proxy-target-class="true"/>
<bean class="org.enyes.sql.util.SqlExecutionTimeAspect"/>
</beans>

可以使用Log4J将SqlExecutionTimeAspect类的日志打印到专门的日志中，并且warnWhenOverTime提供setter方法，可以通过Spring xml来具体配置。