wangji92/mybatis-sql-log

spring boot 打印mybaits 完整的sql 日志 插件,支持spring boot2.x pagehelp mybaits-generator mybatis-plus

mybatis-sql-log

支持spring boot spring pageHelp,将完整日志打印出来

mybatis-sql-log 主要是为了打印mybatis 完整的sql语句，通过mybaits 提供的插件的方式进行拦截， 获取内部执行的sql，并将完整的sql语句打印出来。

spring boot 其实可以的打印log日志出来的只要将当前的包日志打印为debug也是可以，只是参数不够完整，直接复制查询sql 不太友好。 eg: logging.level.com.boot.mybatis.mybatisdemo=debug

1、使用

mybaits sql log Demo 工程

插件可以在maven 仓库中搜索 mybatis-sql-log 阿里云搜索

         <dependency>
            <groupId>com.github.WangJi92</groupId>
            <artifactId>mybatis-sql-log</artifactId>
            <version>1.0.6</version>
        </dependency>

实现原理主要类：com.mybatis.spring.boot.autoconfigure.MybatisSqlCompletePrintInterceptor

        <dependency>
            <groupId>org.mybatis.spring.boot</groupId>
            <artifactId>mybatis-spring-boot-starter</artifactId>
            <version>2.1.0</version>
        </dependency>
         <dependency>
            <groupId>com.github.WangJi92</groupId>
            <artifactId>mybatis-sql-log</artifactId>
            <version>1.0.6</version>
        </dependency>

mybats.print=true 使用spring boot 工程集成

org.mybatis.spring.boot.autoconfigure.MybatisAutoConfiguration 内部自动集成了插件

mybatis.print=true
server.port = 7012
#数据库连接
spring.datasource.url = jdbc:mysql://127.0.0.1:3306/test
spring.datasource.username = root
spring.datasource.password = mysql-root
spring.datasource.driver-class-name= com.mysql.jdbc.Driver
spring.datasource.hikari.connection-test-query = SELECT 1

效果，可以打印完整的SQL信息 【Mybatis Print SQL】【 select name, age, type from user WHERE ( name = '汪吉' ) 】 执行耗时=42

2019-08-31 16:58:21.996  INFO 8762 --- [nio-7012-exec-1] s.b.a.MybatisSqlCompletePrintInterceptor : 【Mybatis Print SQL】【 select name, age, type from user WHERE ( name = '汪吉' ) 】   执行耗时=42

或者通过mybatis-config原生配置处理

<!-- mybatis-config.xml -->
<plugins>
  <plugin interceptor="com.mybatis.spring.boot.autoconfigure.MybatisSqlCompletePrintInterceptor">
  </plugin>
</plugins

2、mybatis 官方插件

• 插件（plugins）
  MyBatis 允许你在已映射语句执行过程中的某一点进行拦截调用。默认情况下，MyBatis 允许使用插件来拦截的方法调用包括：
  Executor (update, query, flushStatements, commit, rollback, getTransaction, close, isClosed)
  ParameterHandler (getParameterObject, setParameters)
  ResultSetHandler (handleResultSets, handleOutputParameters)
  StatementHandler (prepare, parameterize, batch, update, query)

3、相关参考 Documentation

• Mybatis插件-sql日志美化输出
• MyBatis插件及示例----打印每条SQL语句及其执行时间

上面的两篇文章整体上思路都是一致的主要是在处理参数的问题上不是很完善。这里通过mybatis 自带的ParameterHandler处理参数就比较的简单，
而不是通过各种复杂的判断进行处理。org/apache/ibatis/scripting/defaults/DefaultParameterHandler 这里提供了很完善的参数处理。
如下的代码，可以清晰的了解整个参数的解析过程，无论是动态的参数，还是对象参数，都可以完善的处理参数的解析过程。

public void setParameters(PreparedStatement ps) {
    ErrorContext.instance().activity("setting parameters").object(mappedStatement.getParameterMap().getId());
    List<ParameterMapping> parameterMappings = boundSql.getParameterMappings();
    if (parameterMappings != null) {
      for (int i = 0; i < parameterMappings.size(); i++) {
        ParameterMapping parameterMapping = parameterMappings.get(i);
        if (parameterMapping.getMode() != ParameterMode.OUT) {
          Object value;
          String propertyName = parameterMapping.getProperty();
          if (boundSql.hasAdditionalParameter(propertyName)) { // issue #448 ask first for additional params
            value = boundSql.getAdditionalParameter(propertyName);
          } else if (parameterObject == null) {
            value = null;
          } else if (typeHandlerRegistry.hasTypeHandler(parameterObject.getClass())) {
            value = parameterObject;
          } else {
            MetaObject metaObject = configuration.newMetaObject(parameterObject);
            value = metaObject.getValue(propertyName);
          }
          TypeHandler typeHandler = parameterMapping.getTypeHandler();
          JdbcType jdbcType = parameterMapping.getJdbcType();
          if (value == null && jdbcType == null) {
            jdbcType = configuration.getJdbcTypeForNull();
          }
          try {
            typeHandler.setParameter(ps, i + 1, value, jdbcType);
          } catch (TypeException e) {
            throw new TypeException("Could not set parameters for mapping: " + parameterMapping + ". Cause: " + e, e);
          } catch (SQLException e) {
            throw new TypeException("Could not set parameters for mapping: " + parameterMapping + ". Cause: " + e, e);
          }
        }
      }
    }
  }

4、mybatis在执行期间，主要有四大核心接口对象：

执行器Executor，执行器负责整个SQL执行过程的总体控制。
参数处理器ParameterHandler，参数处理器负责PreparedStatement入参的具体设置。
语句处理器StatementHandler，语句处理器负责和JDBC层具体交互，包括prepare语句，执行语句，以及调用ParameterHandler.parameterize()设置参数。
结果集处理器ResultSetHandler，结果处理器负责将JDBC查询结果映射到java对象。

了解了这四大对象，其实我们的处理本次这个插件十分的重要，插件对象可以在Executor、或者StatementHandler两个上面处理。

plugins 实现了两种

分别在两个分支中实现，可以根据自己的需求进行处理

• Executor plugins 方式拦截
• StatementHandler plugins 方式拦截

mybatis-sql-log's Issues

issues

1. SimpleDateFormat 少个y。
2. value 为null，还原sql有问题

String paramValueStr = "";
if (value instanceof Date) {
    paramValueStr = "'" + DATE_FORMAT_THREAD_LOCAL.get().format(value) + "'";
 } else {
    paramValueStr = "'" + value + "'";
 }

当待替换的值里有字符串问号的时候，replaceFirst()的替换会错位

谢谢作者的无私付出。不过貌似这句有些问题：

sql = sql.replaceFirst("\?", Matcher.quoteReplacement(paramValueStr));

假设SQL为: SELECT * FROM t WHERE c1 = ? AND c2 = ?

假设2个查询条件分别为字符串 '?'和数字100。

第一次循环，SQL被替换为：SELECT * FROM t WHERE c1 = '?' AND c2 = ?
第二次循环，SQL被替换为：SELECT * FROM t WHERE c1 = '100' AND c2 = ?

另外，当SQL是类似 select * from t where a="你是王者吗?" and b=? and c=? 的时候，仅适用?来定位也可能会不准确。

建议使用精准替换操作，而不是简单的replaceFirst()。如有理解错误，请指正。

是否有配置参数可以管理该插件在不同环境下日志的输出

例如在springboot内随着启动的配置在dev和test环境下输出，切换到prod的时候就不再输出了

master分支的打印sql的时候，能否获取到sql对应的id

貌似还是要获取MappedStatement，从中获取id

mybatis-plus兼容问题

位于73行的这句代码
final DefaultParameterHandler parameterHandler = (DefaultParameterHandler) statementHandler.getParameterHandler();
如果使用的是mybatis-plus会报一个类型转换的错误：
MybatisParameterHandler不能转换为DefaultParameterHandler
建议做一个判断

和pagehelper结合后打印sql不对，能麻烦看看么？

replaceFirst有个小瑕疵

mybatis-sql-log/src/main/java/com/mybatis/spring/boot/autoconfigure/MybatisSqlCompletePrintInterceptor.java

Line 135 in 2d17c3e

sql = sql.replaceFirst("\\?", paramValueStr);

当paramValueStr中包含$时会出现
java.lang.IllegalArgumentException: Illegal group reference

导入了之后,每次打印SQL都会打印两次...

Cannot resolve com.github.WangJi92:mybatis-sql-log:1.0.4

1.0.4.pom不能导入，1.0.3的可以

[bug]sql的拼接时机与日志打印时机不正确

拦截query，update，batch是语句最后执行阶段了，拼接Sql日志在invocation.proceed()之后执行，也就是查询已完成，在有selectKey的查询语句中，拼接出来的自增id是有值的，这是不对的，而且查询执行之后再打印sql日志会出现SELECT LAST_INSERT_ID()日志先于insert日志出现的情况（拦截器原理决定了这种情况），不符合实际，sql语句的打印要在查询执行之前。
此处贴上我自己修改的代码，欢迎探讨指正

@Override
    public Object intercept(Invocation invocation) throws Throwable {
        Object target = invocation.getTarget();
        //拼接sql语句一定要在查询执行之前
        //日志打印异常不能影响业务
        String sql = "SQL日志打印出错！";
        try {
            //此处configuration的赋值，参数处理中参数值的获取照抄自源代码 @org.apache.ibatis.scripting.defaults.DefaultParameterHandler
            StatementHandler statementHandler = (StatementHandler) target;
            BoundSql boundSql = statementHandler.getBoundSql();

            if (configuration == null) {
                setConfiguration(statementHandler);
            }

            //替换参数格式化Sql语句，去除换行符
            sql = formatSql(boundSql, configuration);
        } catch (Exception e) {
            log.error("", e);
        }
        final String sqlId = "" + System.nanoTime() + RandomStringUtils.randomNumeric(5);
        log.info("{} {{}}", sql, sqlId);
        long startTime = System.currentTimeMillis();
        try {
            return invocation.proceed();
        } finally {
            long endTime = System.currentTimeMillis();
            long sqlCost = endTime - startTime;
            log.info("sqlId:[{}],执行时间：[{}]ms}", sqlId, sqlCost);
        }
    }