拦截mybatis sql并使用日志输出mybatis完整sql语句

在java开发过程中,有个比较难受的问题是,当我们开启mapper日志级别为debug时,打印的日志日下:

2019-07-06 21:57:14.576 DEBUG 40426 --- [nio-8999-exec-8] c.i.t.mapper.UserMapper.findUserByPhone  : ==>  Preparing: SELECT t1.`id` AS id, t1.`open_id` AS openId, t1.`nickname` AS nickname, t1.`phone` AS phone, t1.`real_name` AS realName, t1.`sex` AS sex, t1.`language` AS `language`, t1.`city` AS city, t1.`country` AS country, t1.`province` AS province, t1.`head_img_url` AS headImgUrl, t1.`subscribe_time` AS subscribeTime, t1.`remark` AS remark, t1.`group_id` AS groupId, t1.`tag_id_list` AS tagIdList, t1.`subscribe_scene` AS subscribeScene, t1.`user_type` AS userType, t1.`balance`, t1.`valid` AS valid, t1.`create_at` AS createAt, t1.`create_by` AS createBy, t1.`update_at` AS updateAt, t1.`update_by` AS updateBy, t2.discount_code AS discoundCode FROM iwiteks_user t1 LEFT JOIN iwiteks_user_discount_code t2 ON t1.`id` = t2.`user_id` where t1.phone = ? and t1.valid = 1 LIMIT 1
2019-07-06 21:57:14.577 DEBUG 40426 --- [nio-8999-exec-8] c.i.t.mapper.UserMapper.findUserByPhone  : ==> Parameters: 18585416836(String)

当查询参数过多的时候,我们需要拿到navicat中查询排查问题时,参数难免会遇到复制过来顺序不对的问题或者很麻烦,那么怎么解决呢?两种方案:

  1. 给idea安装mybatis sql log日志插件(但是在测试环境中,这插件就没法用了,还是很尴尬);
  2. 拦截mybatis接口,并提取sql和参数,将完整sql在日志中输出(如果需要生成独立的日志文件,用logback分包即可,容易查看,以及使用日志分析系统时,更容易分析);

废话不多说,先上代码,再细说代码细节。

import lombok.extern.slf4j.Slf4j;
import org.apache.ibatis.executor.statement.StatementHandler;
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.Signature;
import org.apache.ibatis.reflection.DefaultReflectorFactory;
import org.apache.ibatis.reflection.MetaObject;
import org.apache.ibatis.reflection.SystemMetaObject;
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.springframework.beans.factory.annotation.Value;
import org.springframework.stereotype.Component;

import java.lang.reflect.InvocationHandler;
import java.lang.reflect.Method;
import java.lang.reflect.Proxy;
import java.text.DateFormat;
import java.util.Date;
import java.util.List;
import java.util.Locale;
import java.util.Properties;

@Slf4j
@Component
@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}),*/
        @Signature(type = StatementHandler.class, method = "update", args = {MappedStatement.class, Object.class}),
        @Signature(type = StatementHandler.class, method = "query", args = {MappedStatement.class, Object.class, RowBounds.class, ResultHandler.class})
})
public class MybatisInterceptor implements Interceptor {

    @Value("${iwiteks.tools.plugins.enable}")
    private Boolean enable;

    @Override
    public Object intercept(Invocation invocation) throws Throwable {
        this.beginPluginAction(invocation);
        // 执行之前处理
        Object result = invocation.proceed();
        // 执行之后处理
        return result;
    }

    @Override
    public Object plugin(Object target) {// 复写本方法时,最好参考官方文档,网上博客异常的乱,运行不出来或者运行会导致mybatis本身运行异常的太多,谨慎复写该方法
        return Proxy.newProxyInstance(Interceptor.class.getClassLoader(), target.getClass().getInterfaces(), new InvocationHandler() {
            public Object invoke(Object proxy, Method method, Object[] args) throws Throwable {
                return intercept(new Invocation(target, method, args));
            }
        });
    }

    /**
     * 主要是拿来区别数据库,比如mysql,mssql,oracle等,这点在分页插件上有很大作用
     * 但是目前本拦截器只是为了将参数塞进sql中,在日志中打印出完整sql,如果需要setProperties生效,只有在
     * mybatis的配置文件中的plugins中的plugin节点加入本拦截方法,不然本方法将无效
     * @param properties
     */
    @Override
    public void setProperties(Properties properties) {
        log.info("start init mybatis properties......");
    }

    /**
     * 开始执行
     * @param invocation
     * @throws Throwable
     */
    private void beginPluginAction(Invocation invocation) {
        if (!enable) {
            return;
        }
        if (invocation.getTarget() instanceof StatementHandler) {
            StatementHandler statementHandler = (StatementHandler) invocation.getTarget();
            MetaObject metaObject = MetaObject.forObject(statementHandler, SystemMetaObject.DEFAULT_OBJECT_FACTORY, SystemMetaObject.DEFAULT_OBJECT_WRAPPER_FACTORY, new DefaultReflectorFactory());
            //先拦截到RoutingStatementHandler,里面有个StatementHandler类型的delegate变量,其实现类是BaseStatementHandler,然后就到BaseStatementHandler的成员变量mappedStatement
            MappedStatement mappedStatement = (MappedStatement) metaObject.getValue("delegate.mappedStatement");
            if (invocation.getArgs().length > 1) {
                Configuration configuration = mappedStatement.getConfiguration();
                // System.err.println(this.formatterSql(configuration, statementHandler.getBoundSql()));
                String type = mappedStatement.getSqlCommandType().toString();
                if (type.equals("SELECT")) {
                    log.error("(execute query)==> " + this.formatterSql(configuration, statementHandler.getBoundSql()));
                } else if (type.equals("INSERT") || type.equals("UPDATE")) {
                    log.error("(execute insert or update)==> " + this.formatterSql(configuration, statementHandler.getBoundSql()));
                } else {
                    log.error("(execute delete)==> " + this.formatterSql(configuration, statementHandler.getBoundSql()));
                }
            }
        }
        /*if (invocation.getTarget() instanceof Executor) {// 判断执行的接口对象
            if (invocation.getArgs()[0] instanceof MappedStatement) {// 避免类型转换异常导致mybatis查询异常
                MappedStatement mappedStatement = (MappedStatement) invocation.getArgs()[0];
                Object parameter = null;
                if (invocation.getArgs().length > 1) {
                    parameter = invocation.getArgs()[1];
                }

                BoundSql boundSql = mappedStatement.getBoundSql(parameter);
                System.err.println(boundSql.getSql());
                Configuration configuration = mappedStatement.getConfiguration();
                String type = mappedStatement.getSqlCommandType().toString();
                if (type.equals("SELECT")) {
                    log.debug("(execute query)==> " + this.formatterSql(configuration, boundSql));
                } else if (type.equals("INSERT") || type.equals("UPDATE")) {
                    log.info("(execute insert or update)==> " + this.formatterSql(configuration, boundSql));
                } else {
                    log.warn("(execute delete)==> " + this.formatterSql(configuration, boundSql));
                }
            }
        }*/
    }

    /**
     * 获取查询参数
     *
     * @param obj
     * @return
     */
    private String getParameterValue(Object obj) {
        String value;
        if (obj instanceof String) {
            value = "'" + obj.toString() + "'";
        } else if (obj instanceof Date) {
            DateFormat formatter = DateFormat.getDateTimeInstance(DateFormat.DEFAULT, DateFormat.DEFAULT, Locale.CHINA);
            value = "'" + formatter.format(obj) + "'";
        } else {
            if (obj != null) {
                value = obj.toString();
            } else {
                value = "";
            }
        }
        return value;
    }

    /**
     * 格式化sql脚本
     *
     * @param configuration
     * @param boundSql
     * @return
     */
    public String formatterSql(Configuration configuration, BoundSql boundSql) {
        Object parameterObject = boundSql.getParameterObject();
        List<ParameterMapping> parameterMappings = boundSql.getParameterMappings();
        String sql = boundSql.getSql().replaceAll("[\\s]+", " ");
        if (parameterMappings.size() > 0 && parameterObject != null) {
            TypeHandlerRegistry typeHandlerRegistry = configuration.getTypeHandlerRegistry();
            if (typeHandlerRegistry.hasTypeHandler(parameterObject.getClass())) {
                sql = sql.replaceFirst("\\?", 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);
                        sql = sql.replaceFirst("\\?", getParameterValue(obj));
                    } else if (boundSql.hasAdditionalParameter(propertyName)) {
                        Object obj = boundSql.getAdditionalParameter(propertyName);
                        sql = sql.replaceFirst("\\?", getParameterValue(obj));
                    }
                }
            }
        }
        return sql;
    }
}

效果如下:

2019-07-06 18:06:09.221 DEBUG 40426 --- [nio-8999-exec-7] c.i.t.mapper.CourseMapper.selectById     : ==>  Preparing: SELECT t1.`id`, t1.`name`, t1.`class_hour`, t1.`intro`, t1.`belong_organization`, t1.`capacity`, t1.`inventory`, t1.`class_hour_explain`, t1.`detail`, t1.`valid`, t1.`create_at`, t1.`create_by`, t1.`update_at`, t1.`update_by`, t1.`category`, t1.`sort`, t1.`activity_price`, t1.`original_price`, t1.`discount_price`, t1.`activity_royalty`, t1.`original_royalty`, t1.`discount_royalty`, t1.`in_activity`, t1.`valuation_type`, t1.`prepaid`, t1.`on_sale`, t2.username AS create_user_name, t3.username AS update_user_name, t4.content_html, t5.name AS belong_organization_name, t5.office_principal, t5.office_principal_phone FROM iwiteks_course t1 LEFT JOIN iwiteks_manage_user t2 ON t1.create_by = t2.id LEFT JOIN iwiteks_manage_user t3 ON t1.update_by = t3.id LEFT JOIN iwiteks_content t4 ON t1.detail = t4.id LEFT JOIN iwiteks_organization t5 ON t1.belong_organization = t5.id WHERE t1.`id` = ? 
2019-07-06 18:06:09.226 ERROR 40426 --- [nio-8999-exec-7] c.i.XXXX.config.MybatisInterceptor      : (execute query)==> SELECT t1.`id`, t1.`name`, t1.`class_hour`, t1.`intro`, t1.`belong_organization`, t1.`capacity`, t1.`inventory`, t1.`class_hour_explain`, t1.`detail`, t1.`valid`, t1.`create_at`, t1.`create_by`, t1.`update_at`, t1.`update_by`, t1.`category`, t1.`sort`, t1.`activity_price`, t1.`original_price`, t1.`discount_price`, t1.`activity_royalty`, t1.`original_royalty`, t1.`discount_royalty`, t1.`in_activity`, t1.`valuation_type`, t1.`prepaid`, t1.`on_sale`, t2.username AS create_user_name, t3.username AS update_user_name, t4.content_html, t5.name AS belong_organization_name, t5.office_principal, t5.office_principal_phone FROM iwiteks_course t1 LEFT JOIN iwiteks_manage_user t2 ON t1.create_by = t2.id LEFT JOIN iwiteks_manage_user t3 ON t1.update_by = t3.id LEFT JOIN iwiteks_content t4 ON t1.detail = t4.id LEFT JOIN iwiteks_organization t5 ON t1.belong_organization = t5.id WHERE t1.`id` = '03c853bd5a6045bdb50c8e834432dcf8'
2019-07-06 18:06:09.227 DEBUG 40426 --- [nio-8999-exec-7] c.i.t.mapper.CourseMapper.selectById     : ==> Parameters: 03c853bd5a6045bdb50c8e834432dcf8(String)

class文件顶部注解说明:@Intercepts为mybatis的注解,详细请参考官方文档,这个注解下面包含的子级注解@Signature有参数配置不一样,自定义拦截器效果也是不一样的,也是有执行顺序区别的,这个问题不多说,详细请参考官方文档(要养成看文档的好习惯,我也是看别人博客搞的,结果把我坑了个够,结果还是在看文档,查看mybatis的执行过程以及自己一步一步调试mybatis源码才懂的);
代码中的这句:

 MappedStatement mappedStatement = (MappedStatement) metaObject.getValue("delegate.mappedStatement");

是比较有意思的,mybatis定义的很多对象,都可以这样去获取,这个也是我在调试的时候,发现很多对象明明看到了,不知道怎么拿出来,这句有很帮助,比如“delegate.mappedStatement”;时间充裕的可以研究一下mybatis的四大接口,还是很有意思的。
代码中的一些问题基本已经给了注释了,不过我也只是小白而已。
本文记录一下自己遇到的问题,希望能帮助到看了博客的您。

  • 2
    点赞
  • 4
    收藏
    觉得还不错? 一键收藏
  • 0
    评论
Mybatis提供了拦截器(Interceptor)接口,可以在Mybatis执行SQL语句的过程中进行拦截和增强,比如在执行SQL语句前记录开始时间,在执行SQL语句后记录结束时间,从而计算SQL执行时间。 下面是一个简单的Mybatis拦截器实现统计SQL执行时间及打印完整SQL语句的示例代码: ```java @Intercepts({@Signature(type = Executor.class, method = "query", args = {MappedStatement.class, Object.class, RowBounds.class, ResultHandler.class}), @Signature(type = Executor.class, method = "update", args = {MappedStatement.class, Object.class})}) public class SqlCostInterceptor implements Interceptor { private static final Logger LOGGER = LoggerFactory.getLogger(SqlCostInterceptor.class); @Override public Object intercept(Invocation invocation) throws Throwable { // 记录开始时间 long start = System.currentTimeMillis(); // 执行 SQL 语句 Object result = invocation.proceed(); // 记录结束时间 long end = System.currentTimeMillis(); // 计算 SQL 执行时间 long cost = end - start; // 获取 MappedStatement MappedStatement mappedStatement = (MappedStatement) invocation.getArgs()[0]; // 获取 SQL BoundSql boundSql = mappedStatement.getBoundSql(invocation.getArgs()[1]); String sql = boundSql.getSql(); // 打印 SQL 语句及执行时间 LOGGER.info("SQL: {},Cost: {} ms", sql, cost); return result; } @Override public Object plugin(Object target) { return Plugin.wrap(target, this); } @Override public void setProperties(Properties properties) { // do nothing } } ``` 在这个拦截器中,我们重写了`intercept`方法,先记录开始时间,然后执行SQL语句,最后记录结束时间,计算SQL执行时间。接着,我们获取`MappedStatement`对象,并从中获取SQL语句。最后,打印SQL语句及执行时间。 要想使用拦截器,还需要在Mybatis配置文件中进行如下配置: ```xml <!-- 配置拦截器 --> <plugins> <plugin interceptor="com.example.interceptor.SqlCostInterceptor"/> </plugins> ``` 这样,在Mybatis执行SQL语句时,就会自动调用该拦截器的`intercept`方法,从而实现了统计SQL执行时间及打印完整SQL语句的功能。
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值