项目中如何实现 SQL 耗时监控？（实现篇）

项目开发中，经常会对耗时较长的 SQL 进行针对性优化，而在搭建项目雏形时，统计 SQL 耗时的能力，是项目中必不可少的基础服务能力。

那么，大家平时在项目中，都是怎么实现 SQL 耗时监控的呢？

本次结合实际项目，去看看如何实现 SQL 耗时监控？当下的绝大多数项目还是主要基于 MyBatis 技术栈完成 CRUD，接下来主要基于 MyBatis 技术栈去谈实现。

1

关键位置，横插一刀，学名：拦截器。

倘若要统计 Mybatis 数据库操作的耗时，那么需要人为指定拦截 Executor 类，因为在 Mybatis 中 SQL 的操作都是从 Executor 类开始的。

上面代码截图，主要是要告诉 MyBatis，当前插件用来拦截哪个对象的哪个方法。其中 type 指定要拦截的对象，例如 Excutor；method 指定要拦截的方法，例如要拦截 update、query 方法；args 代表传递的参数。

接下来就实现 MyBatis 提供的 Interceptor 接口的方法，代码截图如下。

重点关注上图中的标注 1 部分，拦截目标对象的目标方法的执行。此时便可以通过 MappedStatement 对象获取 xml 映射文件中的每一条 SQL 语句，进而完成 SQL 耗时的监控，当然可以进行美化 SQL 输出。

其余代码不解释，为了助你实现 SQL 监控功能，完整代码呈上。

import java.util.ArrayList;
import java.util.Date;
import java.util.List;
import java.util.Properties;
import java.util.regex.Pattern;


import org.apache.commons.lang3.StringUtils;
import org.apache.commons.lang3.time.DateFormatUtils;
import org.apache.ibatis.executor.Executor;
import org.apache.ibatis.mapping.BoundSql;
import org.apache.ibatis.mapping.MappedStatement;
import org.apache.ibatis.mapping.ParameterMapping;
import org.apache.ibatis.plugin.Interceptor;
import org.apache.ibatis.plugin.Intercepts;
import org.apache.ibatis.plugin.Invocation;
import org.apache.ibatis.plugin.Plugin;
import org.apache.ibatis.plugin.Signature;
import org.apache.ibatis.reflection.MetaObject;
import org.apache.ibatis.session.Configuration;
import org.apache.ibatis.session.ResultHandler;
import org.apache.ibatis.session.RowBounds;
import org.apache.ibatis.type.TypeHandlerRegistry;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;


@Intercepts({ @Signature(type = Executor.class, method = "update", args = { MappedStatement.class,
                                                                            Object.class }),
              @Signature(type = Executor.class, method = "query", args = { MappedStatement.class,
                                                                           Object.class,
                                                                           RowBounds.class,
                                                                           ResultHandler.class }) })
public class MybatisSqlLoggingInterceptor implements Interceptor {


  private static Logger logger = LoggerFactory.getLogger("db_file");


    private static final Pattern WHITE_SPACE_BLOCK_PATTERN = Pattern
        .compile("([\\s]{2,}|[\\t\\r\\n])");


    public Object intercept(Invocation invocation) throws Throwable {
        MappedStatement mappedStatement = (MappedStatement) invocation.getArgs()[0];
        Object parameter = null;
        if (invocation.getArgs().length > 1) {
            parameter = invocation.getArgs()[1];
        }
        String sqlId = mappedStatement.getId();
        BoundSql boundSql = mappedStatement.getBoundSql(parameter);
        Configuration configuration = mappedStatement.getConfiguration();
        Object returnValue = null;
        long start = System.currentTimeMillis();
        // 执行目标方法
        returnValue = invocation.proceed();
        // 统计 SQL 耗时
        long end = System.currentTimeMillis();
        long time = end - start;
        
        // 打印日志
        logSqlInfo(configuration, boundSql, sqlId, time);


        return returnValue;
    }


    public static void logSqlInfo(Configuration configuration, BoundSql boundSql, String sqlId,
                                  long time) {


        String sqlAndParams = showSqlAndParams(configuration, boundSql);


        StringBuilder str = new StringBuilder(100);
        str.append(sqlId);
        str.append(":");
        str.append(sqlAndParams);
        str.append(":");
        str.append(time);
        str.append("ms");


        String line = str.toString();


        logger.info(line);
    }


    private static String getParameterValue(Object obj) {
        String value = null;
        if (obj instanceof String) {
            value = "'" + obj.toString() + "'";
        } else if (obj instanceof Date) {
            value = "'" + DateFormatUtils.ISO_DATETIME_TIME_ZONE_FORMAT.format(new Date()) + "'";
        } else {
            if (obj != null) {
                value = obj.toString();
            } else {
                value = "";
            }


        }
        return value;
    }


    public static String showSqlAndParams(Configuration configuration, BoundSql boundSql) {
        Object parameterObject = boundSql.getParameterObject();
        List<ParameterMapping> parameterMappings = boundSql.getParameterMappings();


        String sql = WHITE_SPACE_BLOCK_PATTERN.matcher(boundSql.getSql()).replaceAll(" ");


        List<String> params = new ArrayList<>();


        if (parameterMappings.size() > 0 && parameterObject != null) {
            TypeHandlerRegistry typeHandlerRegistry = configuration.getTypeHandlerRegistry();
            if (typeHandlerRegistry.hasTypeHandler(parameterObject.getClass())) {
                params.add(getParameterValue(parameterObject));
            } else {
                MetaObject metaObject = configuration.newMetaObject(parameterObject);
                for (ParameterMapping parameterMapping : parameterMappings) {
                    String propertyName = parameterMapping.getProperty();
                    if (metaObject.hasGetter(propertyName)) {
                        Object obj = metaObject.getValue(propertyName);
                        params.add(getParameterValue(obj));
                    } else if (boundSql.hasAdditionalParameter(propertyName)) {
                        Object obj = boundSql.getAdditionalParameter(propertyName);
                        params.add(getParameterValue(obj));
                    }
                }
            }
        }


        return sql + ":[" + StringUtils.join(params, ',') + "]";
    }


    public Object plugin(Object target) {
        return Plugin.wrap(target, this);
    }


    @Override
    public void setProperties(Properties arg0) {
        // just ignore
    }
}

代码编写完成，最后别忘记把写好的插件，注册到全局配置文件 mybatis-config.xml 中。

<!-- 插件配置 -->
<plugins>
     <plugin interceptor="org.yiyuanxiaojiangV5.common.persistence.interceptor.MybatisSqlLoggingInterceptor" />
</plugins>

2

抓住关键位置，就可以为所欲为，学名：打蛇打七寸。

经过上面代码及配置，你若直接集成到项目中，让 SQL 以及耗时情况输出到日志文件，就不再是个难题。

既然知道在哪儿控制 SQL 耗时，那就可以做的更多，如果 SQL 执行耗时超过 5 秒，可以接入报警模块，进行邮件、短信、QQ、微信等进行实时报警。

可以把上图标注 2 的打印 SQL 耗时日志的部分，换成报警通知模块接入，让 SQL 耗时进行实时报警成为现实。

3

学以致用，大家先用明白再说。

本次聊个皮毛，贵在谈使用思路，至于原理等大家用明白了，一起带你钻进源码来个系列长谈。

一起聊技术、谈业务、喷架构，少走弯路，不踩大坑。会持续输出原创精彩分享，敬请期待！

推荐阅读：

真实|为什么要做有灵魂的程序员？

Java 如何实现优雅停服？刨根问底

MDC是什么鬼？用法、源码一锅端

520程序猿用最时尚的方式说爱你