代码片段：自己动手写SQL慢查询统计

前言

首先，MySQL是有自己的慢查询日志记录的，但是作为开发者，并不一定有权限查看MySQL的日志。因此可以自己动手写个SQL慢查询统计，但这个实现方式所统计到的时间是包含网络开销的，不过在正常情况下，没啥关系，根据统计也能分析到一定原因，主要是这种方式我们能实时监控SQL的大致执行时间，然后有针对的进行SQL优化，能尽快的发现一些问题。

代码实现

• 切面

import org.apache.ibatis.session.SqlSessionFactory;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import javax.annotation.Resource;
import java.util.Arrays;
import java.util.concurrent.Executor;
import java.util.concurrent.Executors;

/**
 * @author itoak
 */
@Aspect
public class SlowQueryMonitorAspect {

    private final Logger logger = LoggerFactory.getLogger(this.getClass());
    private static final Long THRESHOLD = 500L;

    @Resource
    private SqlSessionFactory sqlSessionFactory;

    private Executor executor = Executors.newSingleThreadExecutor();
	
	/**
    * 第一个 * 号表示接口返回类型为任意类型
    * dao后面的 .. 表示dao包以及子包
    * 第二个 * 表示任意接口
    * 第三个 * 表示任意函数名
    * 最后括号内 .. 表示任意参数
    */
    @Pointcut("execution(* cn.itoak.storm.dao..*.*(..))")
    public void monitorPointCut(){}

    @Around("monitorPointCut()")
    public Object around(ProceedingJoinPoint joinPoint) throws Throwable {
        String methodName = joinPoint.getSignature().getName();
        String declaringType = joinPoint.getSignature().getDeclaringTypeName();
        long start = System.currentTimeMillis();
        Object object = joinPoint.proceed();
        long end = System.currentTimeMillis() - start;
        if (logger.isInfoEnabled() && end > THRESHOLD) {
            String sql = sqlSessionFactory.getConfiguration().getMappedStatement(declaringType + "." + methodName).getBoundSql(null).getSql();
            logger.info("==> Preparing：{}", sql);
            logger.info("==> Parameters：{}", Arrays.toString(joinPoint.getArgs()));
            logger.info("<== Time consuming：{} ms", end);

            //异步保存到DB，让切面对主流程影响降到最低
            executor.execute(() -> {
                //保存到DB
            });
        }
        return object;
    }
}

• 配置

import cn.itoak.storm.aspects.SlowQueryMonitorAspect;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.context.annotation.EnableAspectJAutoProxy;

/**
 * @author itoak
 */
@Configuration
@EnableAspectJAutoProxy
public class AspectConfig {
    @Bean
    public SlowQueryMonitorAspect slowQueryMonitorAspect(){
        return new SlowQueryMonitorAspect();
    }
}

• 结果

c.i.s.aspects.SlowQueryMonitorAspect     : ==> Preparing：select * from z_per where id = ?
c.i.s.aspects.SlowQueryMonitorAspect     : ==> Parameters：[1]
c.i.s.aspects.SlowQueryMonitorAspect     : <== Time consuming：522 ms

注释：代码中THRESHOLD阈值设置的500L ms是为了看到效果，需要自行更改为合适的值。MySQL官方定义慢查询的时间是10S，但是这个时间已经很长了，所以读者根据自己系统的性能要求设置合理的阈值即可。