自定义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

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 https://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>
    <parent>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-parent</artifactId>
        <version>2.3.4.RELEASE</version>
        <relativePath/> <!-- lookup parent from repository -->
    </parent>
    <groupId>com.example</groupId>
    <artifactId>springboot-demo</artifactId>
    <version>0.0.1-SNAPSHOT</version>
    <name>springboot-demo</name>
    <description>Demo project for Spring Boot</description>
    <properties>
        <java.version>1.8</java.version>
    </properties>
    <dependencies>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-web</artifactId>
        </dependency>
        <dependency>
            <groupId>mysql</groupId>
            <artifactId>mysql-connector-java</artifactId>
        </dependency>
        <dependency>
            <groupId>org.mybatis.spring.boot</groupId>
            <artifactId>mybatis-spring-boot-starter</artifactId>
            <version>2.1.4</version>
        </dependency>
        <dependency>
            <groupId>mysql</groupId>
            <artifactId>mysql-connector-java</artifactId>
            <scope>runtime</scope>
        </dependency>
        <dependency>
            <groupId>cn.hutool</groupId>
            <artifactId>hutool-all</artifactId>
            <version>5.8.3</version>
        </dependency>
        <dependency>
            <groupId>com.github.xiaoymin</groupId>
            <artifactId>knife4j-spring-boot-starter</artifactId>
            <version>2.0.4</version>
        </dependency>
        <dependency>
            <groupId>com.alibaba</groupId>
            <artifactId>fastjson</artifactId>
            <version>1.2.72</version>
        </dependency>
        <dependency>
            <groupId>org.projectlombok</groupId>
            <artifactId>lombok</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-test</artifactId>
            <scope>test</scope>
            <exclusions>
                <exclusion>
                    <groupId>org.junit.vintage</groupId>
                    <artifactId>junit-vintage-engine</artifactId>
                </exclusion>
            </exclusions>
        </dependency>
    </dependencies>


    <build>
        <plugins>
            <plugin>
                <groupId>org.springframework.boot</groupId>
                <artifactId>spring-boot-maven-plugin</artifactId>
            </plugin>
        </plugins>
    </build>

</project>

实现 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;

    @Override
    public 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;
    }

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

    @Override
    public 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<ParameterMapping> 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 {

    @Autowired
    private SqlSessionFactory sqlSessionFactory;

    @Override
    public void afterSingletonsInstantiated() {
        sqlSessionFactory.getConfiguration().addInterceptor(new SqlInterceptor());
    }
}

测试

测试方便 , 省略service

controller

@RestController
@RequestMapping("/test")
public class HelloController {


    @Autowired
    private PersonDao personDao;


    @GetMapping("/ssm")
    public List<PersonEntity> 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<PersonEntity> select(Integer pid , String pname){
        return personDao.selectByParam(pid , pname);
    }
}

dao

@Mapper
public interface PersonDao  {


     @Select("select * from person")
     List<PersonEntity> list();
     
     int insert(PersonEntity personEntity);

     List<PersonEntity> 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