自定义mybatis插件实现sql日志打印

mysql插件实现原理

官网的关键信息

参考文档

https://mybatis.org/mybatis-3/zh/configuration.html#plugins

官方文档

MyBatis 允许你在映射语句执行过程中的某一点进行拦截调用。默认情况下，MyBatis 允许使用插件来拦截的方法调用包括：

• Executor (update, query, flushStatements, commit, rollback, getTransaction, close, isClosed)
• ParameterHandler (getParameterObject, setParameters)
• ResultSetHandler (handleResultSets, handleOutputParameters)
• StatementHandler (prepare, parameterize, batch, update, query)

插件运行源码流程

mybatis 在 配置文件里面设置 plug , 所以 configuration 可以添加插件

Configuration.java

• Executor
• ParameterHandler
• ResultSetHandler
• StatementHandler

通过查看源码 , 知道插件增强的是 mybatis 以上的几个对象

interceptorChain

interceptorChain.pluginAll(…)方法

mybatis 中的 InterceptorChain 类似于 springmvc 中的 拦截器链

Interceptor

实现 InvocationHandler , 我们知道 Plugin 类使用了 JDK 动态代理

最后执行插件方法 , 调用的是该类的 invoke 方法

inovke方法

参考pagehelper

实现sql日志打印插件

前置环境

springboot + mybatis + mysql

pom.xml

4.0.0org.springframework.bootspring-boot-starter-parent2.3.4.RELEASE com.examplespringboot-demo0.0.1-SNAPSHOTspringboot-demoDemo project for Spring Boot1.8org.springframework.bootspring-boot-starter-webmysqlmysql-connector-javaorg.mybatis.spring.bootmybatis-spring-boot-starter2.1.4mysqlmysql-connector-javaruntimecn.hutoolhutool-all5.8.3com.github.xiaoyminknife4j-spring-boot-starter2.0.4com.alibabafastjson1.2.72org.projectlomboklombokorg.springframework.bootspring-boot-starter-testtestorg.junit.vintagejunit-vintage-engineorg.springframework.bootspring-boot-maven-plugin

实现 Interceptor 接口

package com.example.plug;import cn.hutool.core.util.StrUtil;
import com.alibaba.fastjson.JSON;
import lombok.extern.slf4j.Slf4j;
import org.apache.ibatis.cache.CacheKey;
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.mapping.SqlCommandType;
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.RowBounds;
import org.apache.ibatis.type.TypeHandlerRegistry;import java.text.SimpleDateFormat;
import java.util.Collection;
import java.util.Date;
import java.util.List;
import java.util.Properties;/*** 1.可以用来分析SQL执行效率* 2.可以用来获取实际执行的SQL*/@Intercepts({@Signature(type = Executor.class, method = "query", args = {MappedStatement.class, Object.class, RowBounds.class, ResultHandler.class}),@Signature(type = Executor.class, method = "query", args = {MappedStatement.class, Object.class, RowBounds.class, ResultHandler.class, CacheKey.class, BoundSql.class}),@Signature(type = Executor.class, method = "update", args = {MappedStatement.class, Object.class})}
)
@Slf4j
public class SqlInterceptor implements Interceptor {
//    private static final Log log = LogFactory.getLog(SqlInterceptor.class);    /*** 最小打印时间 sql时间超过这个值才打印日志 毫秒**/private int MIN_SIZE = 0;@Overridepublic 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();long startTime = System.currentTimeMillis();Object result = null;try {result = invocation.proceed();} finally {try {long sqlCostTime = System.currentTimeMillis() - startTime;String sql = getSql(configuration, boundSql);formatSqlLog(mappedStatement.getSqlCommandType(), sqlId, sql, sqlCostTime, result);} catch (Exception ignored) {log.error("SQL插件执行失败 Mapper:{} 参数对象：{}", sqlId, JSON.toJSONString(boundSql.getParameterObject()), ignored);}}return result;}@Overridepublic Object plugin(Object target) {return Plugin.wrap(target, this);}@Overridepublic void setProperties(Properties properties) {if (properties == null) {return;}if (properties.containsKey("minLogSize")) {MIN_SIZE = Integer.valueOf(properties.getProperty("minLogSize"));}}private String getSql(Configuration configuration, BoundSql boundSql) {// 输入sql字符串空判断String sql = boundSql.getSql();if (StrUtil.isBlank(sql)) {return "";}//去掉换行符sql = sql.replaceAll("[\\s\n ]+", " ");//填充占位符, 目前基本不用mybatis存储过程调用,故此处不做考虑Object parameterObject = boundSql.getParameterObject();List parameterMappings = boundSql.getParameterMappings();if (!parameterMappings.isEmpty() && parameterObject != null) {TypeHandlerRegistry typeHandlerRegistry = configuration.getTypeHandlerRegistry();if (typeHandlerRegistry.hasTypeHandler(parameterObject.getClass())) {sql = this.replacePlaceholder(sql, 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 = replacePlaceholder(sql, obj);} else if (boundSql.hasAdditionalParameter(propertyName)) {Object obj = boundSql.getAdditionalParameter(propertyName);sql = replacePlaceholder(sql, obj);}}}}return sql;}private String replacePlaceholder(String sql, Object parameterObject) {String result;if (parameterObject == null) {result = "NULL";} else if (parameterObject instanceof String) {result = String.format("'%s'", parameterObject.toString());} else if (parameterObject instanceof Date) {result = String.format("'%s'", new SimpleDateFormat("yyyy-MM-dd HH:mm:ss").format(parameterObject));} else {result = parameterObject.toString();}return sql.replaceFirst("\\?", result);}private void formatSqlLog(SqlCommandType sqlCommandType, String sqlId, String sql, long costTime, Object obj) {if (costTime > MIN_SIZE) {if (sqlCommandType == SqlCommandType.UPDATE || sqlCommandType == SqlCommandType.INSERT || sqlCommandType == SqlCommandType.DELETE) {log.info("[{}ms] [{}] {}; 影响行数：{}", costTime, sqlId, sql, obj);}if (sqlCommandType == SqlCommandType.SELECT) {log.info("[{}ms] [{}] {}; 结果行数：{}", costTime, sqlId, sql, ((Collection) obj).size());}}}
}

mybatis 添加该插件

SpringBoot 中 SqlSessionFactory 是单例的

通过 SqlSessionFactory 得到 Configuration

configuration 的 addInterceptor 方法添加插件

@Configuration
public class MybatisPlugConfig implements SmartInitializingSingleton {@Autowiredprivate SqlSessionFactory sqlSessionFactory;@Overridepublic void afterSingletonsInstantiated() {sqlSessionFactory.getConfiguration().addInterceptor(new SqlInterceptor());}
}

测试

测试方便 , 省略service

controller

@RestController
@RequestMapping("/test")
public class HelloController {@Autowiredprivate PersonDao personDao;@GetMapping("/ssm")public List ssm() {return personDao.list();}@GetMapping("/insert")public String insert(){PersonEntity personEntity = new PersonEntity();personEntity.setPid(null);personEntity.setPname(UUID.randomUUID().toString().substring(8).toString());personDao.insert(personEntity);return "插入成功";}@GetMapping("/select")public List select(Integer pid , String pname){return personDao.selectByParam(pid , pname);}
}

dao

@Mapper
public interface PersonDao  {@Select("select * from person")List list();int insert(PersonEntity personEntity);List selectByParam(@Param("pid") Integer pid, @Param("pname") String pname);
}

控制台打印

2022-10-28 22:07:18.913 INFO 26316 — [nio-8080-exec-2] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring DispatcherServlet ‘dispatcherServlet’
2022-10-28 22:07:18.913 INFO 26316 — [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet : Initializing Servlet ‘dispatcherServlet’
2022-10-28 22:07:18.917 INFO 26316 — [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet : Completed initialization in 4 ms
2022-10-28 22:07:27.247 INFO 26316 — [nio-8080-exec-6] com.example.plug.SqlInterceptor : [48ms] [com.example.dao.PersonDao.list] select * from person; 结果行数：5
2022-10-28 22:07:30.759 INFO 26316 — [nio-8080-exec-8] com.example.plug.SqlInterceptor : [34ms] [com.example.dao.PersonDao.selectByParam] select * from person WHERE pname like concat(‘%’,concat(‘1’,‘%’)) and pid = 1; 结果行数：0
2022-10-28 22:07:32.936 INFO 26316 — [nio-8080-exec-9] com.example.plug.SqlInterceptor : [31ms] [com.example.dao.PersonDao.selectByParam] select * from person WHERE pname like concat(‘%’,concat(‘1’,‘%’)); 结果行数：2
2022-10-28 22:07:36.464 INFO 26316 — [io-8080-exec-10] com.example.plug.SqlInterceptor : [34ms] [com.example.dao.PersonDao.selectByParam] select * from person WHERE pid = 1; 结果行数：1
2022-10-28 22:07:38.605 INFO 26316 — [nio-8080-exec-1] com.example.plug.SqlInterceptor : [33ms] [com.example.dao.PersonDao.selectByParam] select * from person; 结果行数：5
oncat(‘1’,‘%’)); 结果行数：2
2022-10-28 22:07:36.464 INFO 26316 — [io-8080-exec-10] com.example.plug.SqlInterceptor : [34ms] [com.example.dao.PersonDao.selectByParam] select * from person WHERE pid = 1; 结果行数：1
2022-10-28 22:07:38.605 INFO 26316 — [nio-8080-exec-1] com.example.plug.SqlInterceptor : [33ms] [com.example.dao.PersonDao.selectByParam] select * from person; 结果行数：5
2022-10-28 22:07:45.440 INFO 26316 — [nio-8080-exec-2] com.example.plug.SqlInterceptor : [53ms] [com.example.dao.PersonDao.insert] INSERT INTO person ( pid, pname ) VALUES ( 6, ‘-9bac-472f-a95c-9d97b11ab0e1’ ); 影响行数：1