需求

项目中遇到需要打印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 needreturn returnObject;}public void setProperties(Properties properties) {this.properties = properties;}
}

这个其实是对 org.apache.ibatis.executor.statement.StatementHandler实现了这个接口的类中的指定方法形成类似aop切面
打了断点之后
然后呢你就看到控制台就打印了一条Preparing 日志,这时候看下栈

嗯？没啥感觉？一开始我也不知道怎么查，结果看到 com.baomidou.mybatisplus.core.executor.MybatisSimpleExecutor#doQuery

@Overridepublic <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;}@Overridepublic 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;//真正执行的是 PreparedStatementprivate PreparedStatementLogger(PreparedStatement stmt, Log statementLog, int queryStack) {super(statementLog, queryStack);this.statement = stmt;}@Overridepublic 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 paramsvalue = 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 {@Overridepublic 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]");}@Overridepublic Object plugin(Object target) {return Plugin.wrap(target, this);}@Overridepublic 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 paramsvalue = 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;@Overridepublic 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 打印自定义完整日志相关推荐

MybatisPlus自定义SQL日志打印
前言 mybatisplus在mybatis的基础上为我们提供了诸多方便,大大加快了开发的速率,但是在日常工作中,还是会发现有一些不方便之处,那就是关于日志的打印,框架虽然也提供了日志打印,但是日志的 ...
解决Fast api打印两次日志的问题
完整的问题描述情况一:打印两次日志情况二:一次是自定义格式,一次是原始日志,总之会打两个日志解决方法方法一:在初始化logger的时候使用: logger.removeHandler(logg ...
django 完整日志配置
django 完整日志配置 django中的log需要在settings.py中配置 import timecur_path = os.path.dirname(os.path.realpath(__ ...
oracle typehandler,Mybatis实现自定义的类型转换器TypeHandler
此文其实是java操作Oracle类型XMLType总结二:使用Mybatis附带的一篇小结. Mybatis实现自定义的转换器,十分的简单,其主要步骤分为三步,这里以操作XMLType类型为例. 第 ...
Mybatis狂神说完整笔记
狂神说Mybatis视频链接: B站视频狂神公众号链接: 公众号 Mytbtis官方文档: 官方中文文档 1.第一个程序 MyBatis简介什么是MyBatis MyBatis 是一款优秀的持久层 ...
python使用logging打印信息到日志文件中
python使用logging打印信息到日志文件中参考 Python输出日志信息 Python + logging 输出到屏幕,将log日志写入文件使用logging打印日志到文件中的目的是: 解 ...
快速入门mybatis(查询、添加日志、插入)
快速入门mybatis(查询.添加日志.插入) 参考学习视频网址:https://www.bilibili.com/video/BV185411s7Ry?p=9&spm_id_from=pag ...
Java：如果优雅地打印出完美日志
我是 ABin-阿斌:写一生代码,创一世佳话,筑一揽芳华. 如果小伙伴们觉得我的文章有点 feel ,那就点个赞再走哦. 文章目录前言 1. 选择恰当的日志级别 2. 日志要打印出方法的入参.出参 ...
MyBatis官方文档-日志
最近更新: 15 七月 2019|版本: 3.5.2 文章目录日志日志配置步骤 1:添加 Log4J 的 jar 包步骤 2:配置 Log4J 日志 MyBatis 的内置日志工厂提供日志功能 ...
gin自定义路由日志的格式
gin自定义路由日志的格式默认的路由日志是这样的: [GIN-debug] POST /foo --> main.main.func1 (3 handlers) [GIN-debug] GET ...

mybatis 打印自定义完整日志

需求