这是我参与8月更文挑战的第14天，活动详情查看：8月更文挑战

需求

项目中遇到需要打印sql语句日志，还有其执行时间，还要把sql语句美化下(把？替换成实际的参数、换行符删除)，目的在于打印sql语句时加入我们自己的日志关键字。比如说项目中集成了链路追踪功能，那么我们想打印sql 语句时，能如下输出：

span:xxxx, [SQL:......] 	执行耗时	[.. ms]

这样如果我们有集成了es的话后期出问题查日志很方便，只要有这个链路id，我们就可以找到所有这个链路中执行的sql（异步除外）

这个肯定是用mybatis plugins没错了，但是具体sql 中的参数如何获取呢，这个需要看下源码，研究下mybatis 官方打印日志源码

源码分析

mybatis 官方如何打印日志？

先看看官方打印出的日志在这里插入图片描述我们一个个找，看看这个些日志都是怎么打印的

小编找源码就一种套路，debug！！一言不合就debug，但是呢这个debug得有技巧（日志等级得是debug！！！！），你得刚刚号打在日志打印之前，比如说 Preparing 日志打印之后，Parameters 日志打印之前，这里就得提到官方提供的插件机制

// Component 是在spring 中注入的不是官方写的
@Component
@Slf4j
@Intercepts({@Signature(type = StatementHandler.class, method = "query", args = {Statement.class, ResultHandler.class}),
    @Signature(type = StatementHandler.class, method = "update", args = {Statement.class}),
    @Signature(type = StatementHandler.class, method = "batch", args = { Statement.class })})
public class ExamplePlugin implements Interceptor {
  private Properties properties = new Properties();
  public Object intercept(Invocation invocation) throws Throwable {
    // 在这里打断点~~~~~~~~~~~~~
    Object returnObject = invocation.proceed();
    // implement post processing if need
    return returnObject;
  }
  public void setProperties(Properties properties) {
    this.properties = properties;
  }
}

这个其实是对 org.apache.ibatis.executor.statement.StatementHandler实现了这个接口的类中的指定方法形成类似aop切面打了断点之后然后呢你就看到控制台就打印了一条Preparing 日志,这时候看下栈在这里插入图片描述嗯？没啥感觉？一开始我也不知道怎么查，结果看到 com.baomidou.mybatisplus.core.executor.MybatisSimpleExecutor#doQuery

@Override
    public <E> List<E> doQuery(MappedStatement ms, Object parameter, RowBounds rowBounds, ResultHandler resultHandler, BoundSql boundSql) throws SQLException {
        Statement stmt = null;
        try {
            Configuration configuration = ms.getConfiguration();
            StatementHandler handler = configuration.newStatementHandler(wrapper, ms, parameter, rowBounds, resultHandler, boundSql);
            //继续在这打断点
            stmt = prepareStatement(handler, ms.getStatementLog(), false);
            return stmt == null ? Collections.emptyList() : handler.query(stmt, resultHandler);
        } finally {
            closeStatement(stmt);
        }
    }

继续断点，com.baomidou.mybatisplus.core.executor.MybatisSimpleExecutor#prepareStatement 在这里插入图片描述看到这个 connection 么，xxxLogger,还是代理类，只要你继续打断点在这，就知道 Preparing日志在这之后打印的，那么这个类 org.apache.ibatis.logging.jdbc.ConnectionLogger就很关键了

public final class ConnectionLogger extends BaseJdbcLogger implements InvocationHandler {

  private final Connection connection;

  private ConnectionLogger(Connection conn, Log statementLog, int queryStack) {
    super(statementLog, queryStack);
    this.connection = conn;
  }

  @Override
  public Object invoke(Object proxy, Method method, Object[] params)
      throws Throwable {
    try {
      if (Object.class.equals(method.getDeclaringClass())) {
        return method.invoke(this, params);
      }
      if ("prepareStatement".equals(method.getName())) {
        if (isDebugEnabled()) {
        // 是不是很眼熟！！！！！！！！！！！
          debug(" Preparing: " + removeBreakingWhitespace((String) params[0]), true);
        }
        PreparedStatement stmt = (PreparedStatement) method.invoke(connection, params);
        stmt = PreparedStatementLogger.newInstance(stmt, statementLog, queryStack);
        return stmt;
      } else if ("prepareCall".equals(method.getName())) {
        if (isDebugEnabled()) {
          debug(" Preparing: " + removeBreakingWhitespace((String) params[0]), true);
        }
        PreparedStatement stmt = (PreparedStatement) method.invoke(connection, params);
        stmt = PreparedStatementLogger.newInstance(stmt, statementLog, queryStack);
        return stmt;
      } else if ("createStatement".equals(method.getName())) {
        Statement stmt = (Statement) method.invoke(connection, params);
        stmt = StatementLogger.newInstance(stmt, statementLog, queryStack);
        return stmt;
      } else {
        return method.invoke(connection, params);
      }
    } catch (Throwable t) {
      throw ExceptionUtil.unwrapThrowable(t);
    }
  }

  /**
   * 代理对象生成
   */
  public static Connection newInstance(Connection conn, Log statementLog, int queryStack) {
    ...
  }
....
}

到这里 Preparing 日志找到了,这时候大家看这个结构，也能猜到了 org.apache.ibatis.logging.jdbc.BaseJdbcLogger,看下有哪些类继承了这个在这里插入图片描述 org.apache.ibatis.logging.jdbc.PreparedStatementLogger

/**
*	实现 InvocationHandler 接口，显然是一个代理对象
*/
public final class PreparedStatementLogger extends BaseJdbcLogger implements InvocationHandler {

  private final PreparedStatement statement;
	
 //真正执行的是 PreparedStatement
  private PreparedStatementLogger(PreparedStatement stmt, Log statementLog, int queryStack) {
    super(statementLog, queryStack);
    this.statement = stmt;
  }

  @Override
  public Object invoke(Object proxy, Method method, Object[] params) throws Throwable {
    try {
      .....
      if (EXECUTE_METHODS.contains(method.getName())) {
        if (isDebugEnabled()) {
        // 打印参数，这里很关键
          debug("Parameters: " + getParameterValueString(), true);
        }
        clearColumnInfo();
        if ("executeQuery".equals(method.getName())) {
        // 生成 ResultSet 代理对象 ResultSetLogger，打印 Total 日志
          ResultSet rs = (ResultSet) method.invoke(statement, params);
          return rs == null ? null : ResultSetLogger.newInstance(rs, statementLog, queryStack);
        } else {
          return method.invoke(statement, params);
        }
      } else if (SET_METHODS.contains(method.getName())) {
        if ("setNull".equals(method.getName())) {
          setColumn(params[0], null);
        } else {
          setColumn(params[0], params[1]);
        }
        return method.invoke(statement, params);
      } else if ("getResultSet".equals(method.getName())) {
        ResultSet rs = (ResultSet) method.invoke(statement, params);
        return rs == null ? null : ResultSetLogger.newInstance(rs, statementLog, queryStack);
      } else if ("getUpdateCount".equals(method.getName())) {
        int updateCount = (Integer) method.invoke(statement, params);
        if (updateCount != -1) {
        // 打印 Update 日志
          debug("   Updates: " + updateCount, false);
        }
        return updateCount;
      } else {
        return method.invoke(statement, params);
      }
    } catch (Throwable t) {
      throw ExceptionUtil.unwrapThrowable(t);
    }
  }

  /**
   * jdk反射创建一个代理对象实例
   *
   */
  public static PreparedStatement newInstance(PreparedStatement stmt, Log statementLog, int queryStack) {
    ........
  }

  /**
   * Return the wrapped prepared statement.
   *
   * @return the PreparedStatement
   */
  public PreparedStatement getPreparedStatement() {
    return statement;
  }

}

实际上这就是一个代理对象，目的是在执行增删改查等sql时打印日志 Parameters 同理 ResultSetLogger 这个打印的就是 Total 日志。

这几个类像不像一条完整的链路，myabtis 执行sql，封装数据结果的链路 ConnectionLogger sql 预加载，连接 mysql，打印的是 Preparing PreparedStatementLogger 动态参数编译,打印的是 Parameters ResultSetLogger 结果集处理,打印的是 Total

mybatis 官方如何打印参数？

根据上面的结果，同理在 org.apache.ibatis.logging.jdbc.PreparedStatementLogger#invoke方法中打个断点,就能找到 com.baomidou.mybatisplus.core.MybatisDefaultParameterHandler#setParameters

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 | SQLException e) {
                        throw new TypeException("Could not set parameters for mapping: " + parameterMapping + ". Cause: " + e, e);
                    }
                }
            }
        }
    }

这样所有的sql 参数全部能拿到

代码实现



import lombok.extern.slf4j.Slf4j;
import org.apache.ibatis.binding.MapperMethod;
import org.apache.ibatis.executor.statement.StatementHandler;
import org.apache.ibatis.mapping.BoundSql;
import org.apache.ibatis.mapping.ParameterMapping;
import org.apache.ibatis.mapping.ParameterMode;
import org.apache.ibatis.plugin.*;
import org.apache.ibatis.reflection.MetaObject;
import org.apache.ibatis.session.Configuration;
import org.apache.ibatis.session.ResultHandler;
import org.apache.ibatis.session.SqlSessionFactory;
import org.apache.ibatis.session.defaults.DefaultSqlSession;
import org.apache.ibatis.type.TypeHandlerRegistry;

import java.lang.reflect.Field;
import java.sql.Statement;
import java.util.*;

/**
 * Sql执行时间记录拦截器
 */

@Slf4j
@Intercepts({@Signature(type = StatementHandler.class, method = "query", args = {Statement.class, ResultHandler.class}),
    @Signature(type = StatementHandler.class, method = "update", args = {Statement.class}),
    @Signature(type = StatementHandler.class, method = "batch", args = { Statement.class })})
public class SqlCostInterceptor implements Interceptor {

    @Override
    public Object intercept(Invocation invocation) throws Throwable {
        Object target = invocation.getTarget();

        long startTime = System.currentTimeMillis();
        StatementHandler statementHandler = (StatementHandler)target;
        try {
            return invocation.proceed();
        } finally {
            printSqlLog(startTime, statementHandler);
        }
    }

    /**
     * 打印sql 日志
     * @param startTime
     * @param statementHandler
     */
    public void printSqlLog(long startTime, StatementHandler statementHandler) {
        long endTime = System.currentTimeMillis();
        long sqlCost = endTime - startTime;


        BoundSql boundSql = statementHandler.getBoundSql();
        Object parameterObject = boundSql.getParameterObject();
        String sql = boundSql.getSql();

        // 格式化Sql语句，去除换行符，替换参数
        // 推荐方案
        String allSql = null;
        try {
            allSql = getFllSql(boundSql, parameterObject);
           
        } catch (Exception e) {
            log.warn("sql 格式化失败:{}", e.getMessage());
        }

        if (allSql == null) {
            allSql = sql;
        }


        log.info("SQL：[" + allSql + "]  执行耗时    [" + sqlCost + "ms]");
//        ActiveSpan.info("SQL：[" + allSql + "]   执行耗时    [" + sqlCost + "ms]");
    }

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

    @Override
    public void setProperties(Properties properties) {

    }

   
    /**
     * 获取完整的sql（推荐方案）
     */
    public String getFllSql(BoundSql boundSql, Object parameterObject) {
       // 从 
        SqlSessionFactory bean = SpringContext.getBean(SqlSessionFactory.class);
        if (bean == null) {
            return null;
        }
        Configuration configuration = bean.getConfiguration();

        TypeHandlerRegistry typeHandlerRegistry = configuration.getTypeHandlerRegistry();

        List<ParameterMapping> parameterMappings = boundSql.getParameterMappings();

        if (CollectionUtil.isEmpty(parameterMappings)) {
            return null;
        }
        List<Object> paramList = new ArrayList<>();

        for (int i = 0; i < parameterMappings.size(); i++) {
            ParameterMapping parameterMapping = parameterMappings.get(i);
            if (parameterMapping.getMode() == ParameterMode.OUT) {
                continue;
            }
            Object value = null;
            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();
                }*/
            paramList.add(value);
        }
        String sql = boundSql.getSql();
        for (Object o : paramList) {
            sql = sql.replaceFirst("\\?", formatParamValue(o));
        }

        return beautifySql(sql);
    }

    public String formatParamValue(Object paramValue) {
        if (paramValue == null) {
            return "null";
        }
        if (paramValue instanceof String) {
            paramValue =  "'" + paramValue + "'";
        }
        if (paramValue instanceof Date) {
            paramValue =  "'" + paramValue + "'";
        }
        return paramValue.toString();
    }

}

SpringContext

@Component
public class SpringContext implements ApplicationContextAware {

    private static ApplicationContext applicationContext;

   
    @Override
    public void setApplicationContext(ApplicationContext applicationContext) throws BeansException {
        SpringContext.applicationContext = applicationContext;
    }

    public static ApplicationContext getApplicationContext() {
        return applicationContext;
    }

    public static Object getBean(String name) {
        return applicationContext.getBean(name);
    }

    public static <T> T getBean(Class<T> clazz) {
        try {
            return applicationContext.getBean(clazz);
        } catch (BeansException e) {
            return null;
        }
    }

   

}

写在最后

遗憾的是total还没办法打印出来，如果有想法的小伙伴，下方留言评论谢谢了哈

mybatis 打印完整sql日志

需求

源码分析

mybatis 官方如何打印日志？

mybatis 官方如何打印参数？

代码实现

写在最后