MyBatis插件及示例----打印每条SQL语句及其执行时间
Posted 五月的仓颉
tags:
篇首语：本文由小常识网(cha138.com)小编为大家整理，主要介绍了MyBatis插件及示例----打印每条SQL语句及其执行时间相关的知识，希望对你有一定的参考价值。
Plugins
摘一段来自MyBatis官方文档的文字。
MyBatis允许你在某一点拦截已映射语句执行的调用。默认情况下，MyBatis允许使用插件来拦截方法调用
- Executor（update、query、flushStatements、commint、rollback、getTransaction、close、isClosed）
- ParameterHandler（getParameterObject、setParameters）
- ResultSetHandler（handleResultSets、handleOutputParameters）
- StatementHandler（prepare、parameterize、batch、update、query）
这些类中方法的详情可以通过查看每个方法的签名来发现，而且它们的源代码存在于MyBatis发行包中。你应该理解你所覆盖方法的行为，假设你所做的要比监视调用要多。如果你尝试修改或覆盖一个给定的方法，你可能会打破MyBatis的核心。这是低层次的类和方法，要谨慎使用插件。
插件示例：打印每条SQL语句及其执行时间
以下通过代码来演示一下如何使用MyBatis的插件，要演示的场景是：打印每条真正执行的SQL语句及其执行的时间。这是一个非常有用的需求，MyBatis本身的日志可以记录SQL，但是有以下几个问题：
- MyBatis日志打印出来的SQL日志，参数都被占位符"?"替换，无法知道真正执行的SQL语句中的参数是什么
- MyBatis日志打印出来的SQL日志，有大量的换行符，通常一句SQL语句要通过十几行显示，阅读体验非常差
- 无法记录SQL执行时间，有SQL执行时间就可以精准定位到执行时间比较慢的SQL
写MyBatis插件非常简单，只需要实现Interceptor接口即可，我这里将我的Interceptor命名为SqlCostInterceptor：
1 package org.xrq.mybatis.plugin; 2 3 import java.lang.reflect.Field; 4 import java.sql.Statement; 5 import java.util.Collection; 6 import java.util.List; 7 import java.util.Map; 8 import java.util.Properties; 9 10 import org.apache.ibatis.executor.statement.StatementHandler; 11 import org.apache.ibatis.mapping.BoundSql; 12 import org.apache.ibatis.mapping.ParameterMapping; 13 import org.apache.ibatis.plugin.Interceptor; 14 import org.apache.ibatis.plugin.Intercepts; 15 import org.apache.ibatis.plugin.Invocation; 16 import org.apache.ibatis.plugin.Plugin; 17 import org.apache.ibatis.plugin.Signature; 18 import org.apache.ibatis.session.ResultHandler; 19 import org.apache.ibatis.session.defaults.DefaultSqlSession.StrictMap; 20 21 /** 22 * Sql执行时间记录拦截器 23 */ 24 @Intercepts({@Signature(type = StatementHandler.class, method = "query", args = {Statement.class, ResultHandler.class}), 25 @Signature(type = StatementHandler.class, method = "update", args = {Statement.class}), 26 @Signature(type = StatementHandler.class, method = "batch", args = { Statement.class })}) 27 public class SqlCostInterceptor implements Interceptor { 28 29 @Override 30 public Object intercept(Invocation invocation) throws Throwable { 31 Object target = invocation.getTarget(); 32 33 long startTime = System.currentTimeMillis(); 34 StatementHandler statementHandler = (StatementHandler)target; 35 try { 36 return invocation.proceed(); 37 } finally { 38 long endTime = System.currentTimeMillis(); 39 long sqlCost = endTime - startTime; 40 41 BoundSql boundSql = statementHandler.getBoundSql(); 42 String sql = boundSql.getSql(); 43 Object parameterObject = boundSql.getParameterObject(); 44 List<ParameterMapping> parameterMappingList = boundSql.getParameterMappings(); 45 46 // 格式化Sql语句，去除换行符，替换参数 47 sql = formatSql(sql, parameterObject, parameterMappingList); 48 49 System.out.println("SQL：[" + sql + "]执行耗时[" + sqlCost + "ms]"); 50 } 51 } 52 53 @Override 54 public Object plugin(Object target) { 55 return Plugin.wrap(target, this); 56 } 57 58 @Override 59 public void setProperties(Properties properties) { 60 61 } 62 63 @SuppressWarnings("unchecked") 64 private String formatSql(String sql, Object parameterObject, List<ParameterMapping> parameterMappingList) { 65 // 输入sql字符串空判断 66 if (sql == null || sql.length() == 0) { 67 return ""; 68 } 69 70 // 美化sql 71 sql = beautifySql(sql); 72 73 // 不传参数的场景，直接把Sql美化一下返回出去 74 if (parameterObject == null || parameterMappingList == null || parameterMappingList.size() == 0) { 75 return sql; 76 } 77 78 // 定义一个没有替换过占位符的sql，用于出异常时返回 79 String sqlWithoutReplacePlaceholder = sql; 80 81 try { 82 if (parameterMappingList != null) { 83 Class<?> parameterObjectClass = parameterObject.getClass(); 84 85 // 如果参数是StrictMap且Value类型为Collection，获取key="list"的属性，这里主要是为了处理<foreach>循环时传入List这种参数的占位符替换 86 // 例如select * from xxx where id in <foreach collection="list">...</foreach> 87 if (isStrictMap(parameterObjectClass)) { 88 StrictMap<Collection<?>> strictMap = (StrictMap<Collection<?>>)parameterObject; 89 90 if (isList(strictMap.get("list").getClass())) { 91 sql = handleListParameter(sql, strictMap.get("list")); 92 } 93 } else if (isMap(parameterObjectClass)) { 94 // 如果参数是Map则直接强转，通过map.get(key)方法获取真正的属性值 95 // 这里主要是为了处理<insert>、<delete>、<update>、<select>时传入parameterType为map的场景 96 Map<?, ?> paramMap = (Map<?, ?>) parameterObject; 97 sql = handleMapParameter(sql, paramMap, parameterMappingList); 98 } else { 99 // 通用场景，比如传的是一个自定义的对象或者八种基本数据类型之一或者String 100 sql = handleCommonParameter(sql, parameterMappingList, parameterObjectClass, parameterObject); 101 } 102 } 103 } catch (Exception e) { 104 // 占位符替换过程中出现异常，则返回没有替换过占位符但是格式美化过的sql，这样至少保证sql语句比BoundSql中的sql更好看 105 return sqlWithoutReplacePlaceholder; 106 } 107 108 return sql; 109 } 110 111 /** 112 * 美化Sql 113 */ 114 private String beautifySql(String sql) { 115 // sql = sql.replace("\\n", "").replace("\\t", "").replace(" ", " ").replace("( ", "(").replace(" )", ")").replace(" ,", ","); 116 sql = sql.replaceAll("[\\\\s\\n ]+"," "); 117 return sql; 118 } 119 120 /** 121 * 处理参数为List的场景 122 */ 123 private String handleListParameter(String sql, Collection<?> col) { 124 if (col != null && col.size() != 0) { 125 for (Object obj : col) { 126 String value = null; 127 Class<?> objClass = obj.getClass(); 128 129 // 只处理基本数据类型、基本数据类型的包装类、String这三种 130 // 如果是复合类型也是可以的，不过复杂点且这种场景较少，写代码的时候要判断一下要拿到的是复合类型中的哪个属性 131 if (isPrimitiveOrPrimitiveWrapper(objClass)) { 132 value = obj.toString(); 133 } else if (objClass.isAssignableFrom(String.class)) { 134 value = "\\"" + obj.toString() + "\\""; 135 } 136 137 sql = sql.replaceFirst("\\\\?", value); 138 } 139 } 140 141 return sql; 142 } 143 144 /** 145 * 处理参数为Map的场景 146 */ 147 private String handleMapParameter(String sql, Map<?, ?> paramMap, List<ParameterMapping> parameterMappingList) { 148 for (ParameterMapping parameterMapping : parameterMappingList) { 149 Object propertyName = parameterMapping.getProperty(); 150 Object propertyValue = paramMap.get(propertyName); 151 if (propertyValue != null) { 152 if (propertyValue.getClass().isAssignableFrom(String.class)) { 153 propertyValue = "\\"" + propertyValue + "\\""; 154 } 155 156 sql = sql.replaceFirst("\\\\?", propertyValue.toString()); 157 } 158 } 159 160 return sql; 161 } 162 163 /** 164 * 处理通用的场景 165 */ 166 private String handleCommonParameter(String sql, List<ParameterMapping> parameterMappingList, Class<?> parameterObjectClass, 167 Object parameterObject) throws Exception { 168 for (ParameterMapping parameterMapping : parameterMappingList) { 169 String propertyValue = null; 170 // 基本数据类型或者基本数据类型的包装类，直接toString即可获取其真正的参数值，其余直接取paramterMapping中的property属性即可 171 if (isPrimitiveOrPrimitiveWrapper(parameterObjectClass)) { 172 propertyValue = parameterObject.toString(); 173 } else { 174 String propertyName = parameterMapping.getProperty(); 175 176 Field field = parameterObjectClass.getDeclaredField(propertyName); 177 // 要获取Field中的属性值，这里必须将私有属性的accessible设置为true 178 field.setAccessible(true); 179 propertyValue = String.valueOf(field.get(parameterObject)); 180 if (parameterMapping.getJavaType().isAssignableFrom(String.class)) { 181 propertyValue = "\\"" + propertyValue + "\\""; 182 } 183 } 184 185 sql = sql.replaceFirst("\\\\?", propertyValue); 186 } 187 188 return sql; 189 } 190 191 /** 192 * 是否基本数据类型或者基本数据类型的包装类 193 */ 194 private boolean isPrimitiveOrPrimitiveWrapper(Class<?> parameterObjectClass) { 195 return parameterObjectClass.isPrimitive() || 196 (parameterObjectClass.isAssignableFrom(Byte.class) || parameterObjectClass.isAssignableFrom(Short.class) || 197 parameterObjectClass.isAssignableFrom(Integer.class) || parameterObjectClass.isAssignableFrom(Long.class) || 198 parameterObjectClass.isAssignableFrom(Double.class) || parameterObjectClass.isAssignableFrom(Float.class) || 199 parameterObjectClass.isAssignableFrom(Character.class) || parameterObjectClass.isAssignableFrom(Boolean.class)); 200 } 201 202 /** 203 * 是否DefaultSqlSession的内部类StrictMap 204 */ 205 private boolean isStrictMap(Class<?> parameterObjectClass) { 206 return parameterObjectClass.isAssignableFrom(StrictMap.class); 207 } 208 209 /** 210 * 是否List的实现类 211 */ 212 private boolean isList(Class<?> clazz) { 213 Class<?>[] interfaceClasses = clazz.getInterfaces(); 214 for (Class<?> interfaceClass : interfaceClasses) { 215 if (interfaceClass.isAssignableFrom(List.class)) { 216 return true; 217 } 218 } 219 220 return false; 221 } 222 223 /** 224 * 是否Map的实现类 225 */ 226 private boolean isMap(Class<?> parameterObjectClass) { 227 Class<?>[] interfaceClasses = parameterObjectClass.getInterfaces(); 228 for (Class<?> interfaceClass : interfaceClasses) { 229 if (interfaceClass.isAssignableFrom(Map.class)) { 230 return true; 231 } 232 } 233 234 return false; 235 } 236 237 }
分析一下这段代码（这个是改良过的版本，主要是增加了对select * from xxx where id in <foreach collection="list">...</foreach>这种写法占位符替换为真正参数的支持）。
首先是注解@Intercepts与@Signature，这两个注解是必须的，因为Plugin的wrap方法会取这两个注解里面参数。@Intercepts中可以定义多个@Signature，一个@Signature表示符合如下条件的方法才会被拦截：
- 接口必须是type定义的类型
- 方法名必须和method一致
- 方法形参的Class类型必须和args定义Class类型顺序一致
接着的一个问题是：有四个接口可以拦截，为什么使用StatementHandler去拦截？根据名字来看ParameterHandler和ResultSetHandler，前者处理参数，后者处理结果是不可能使用的，剩下的就是Executor和StatementHandler了。拦截StatementHandler的原因是而不是用Executor的原因是：
- Executor的update与query方法可能用到MyBatis的一二级缓存从而导致统计的并不是真正的SQL执行时间
- StatementHandler的update与query方法无论如何都会统计到PreparedStatement的execute方法执行时间，尽管也有一定误差（误差主要来自会将处理结果的时间也算上），但是相差不大
接着讲一下setProperties方法，可以将一些配置属性配置在<plugin></plugin>的子标签<property />中，所有的配置属性会在形参Properties中，setProperties方法可以拿到配置的属性进行需要的处理。
接着讲一下plugin方法，这里是为目标接口生成代理，不需要也没必要自己去写生成代理的方法，MyBatis的Plugin类已经为我们提供了wrap方法（当然如果自己有自己的逻辑也可以在Plugin.wrap方法前后加入，但是最终一定要使用Plugin.wrap方法生成代理），看一下该方法的实现：
1 public static Object wrap(Object target, Interceptor interceptor) { 2 Map<Class<?>, Set<Method>> signatureMap = getSignatureMap(interceptor); 3 Class<?> type = target.getClass(); 4 Class<?>[] interfaces = getAllInterfaces(type, signatureMap); 5 if (interfaces.length > 0) { 6 return Proxy.newProxyInstance( 7 type.getClassLoader(), 8 interfaces, 9 new Plugin(target, interceptor, signatureMap)); 10 } 11 return target; 12 }
因为这里的target一定是一个接口，因此可以放心使用JDK本身提供的Proxy类，这里相当于就是如果该接口满足方法签名那么就为之生成一个代理。
最后就是intercept方法了，这里就是拦截器的核心代码了，方法的逻辑我就不解释了，可以自己看一下，唯一要注意的一点就是无论如何最终一定要返回invocation.proceed()，保证拦截器的层层调用。
xml文件配置即效果演示
写完了插件，只需要在config.xml文件中进行一次配置即可，非常简单：
1 <plugins> 2 <plugin interceptor="org.xrq.mybatis.plugin.SqlCostInterceptor" /> 3 </plugins>
这里每个<plugin>子标签代表一个插件，interceptor表示拦截器的完整路径，每个人的不同。
有了类和这段配置，就可以使用SqlCostInterceptor了，SqlCostInterceptor是通用的，但是每个人的CRUD是不同的，我打印一下我这里CRUD执行的结果：
SQL：[insert into mail(id, create_time, modify_time, web_id, mail, use_for) values(null, now(), now(), "1", "123@sina.com", "个人使用");]执行耗时[1ms]
SQL：[insert into mail(id, create_time, modify_time, web_id, mail, use_for) values(null, now(), now(), "2", "123@qq.com", "企业使用");]执行耗时[1ms]
SQL：[insert into mail(id, create_time, modify_time, web_id, mail, use_for) values(null, now(), now(), "3", "123@sohu.com", "注册账号使用");]执行耗时[0ms]
看到打印了完整的SQl语句以及SQL语句执行时间。
不过要说明一点，这个插件只是一个简单的Demo，我并没有完整测试过，应该是无法覆盖所有场景的，所以如果想用这段代码片段打印真正的SQL及其执行时间的朋友，还需要在这个基础上做修改，不过即使不改代码，这个插件起到美化SQL的作用，去除一些换行符还是没问题的。
至于MyBatis插件的实现原理，会在我【MyBatis源码分析】系列文章中详细解读，文章地址为【MyBatis源码分析】插件实现原理。
后记
MyBatis插件机制非常有用，用得好可以解决很多问题，不只是这里的打印SQL语句以及记录SQL语句执行时间，分页、分表都可以通过插件来实现。用好插件的关键是我开头就列举的，这里再列一次：
- Executor（update、query、flushStatements、commint、rollback、getTransaction、close、isClosed）
- ParameterHandler（getParameterObject、setParameters）
- ResultSetHandler（handleResultSets、handleOutputParameters）
- StatementHandler（prepare、parameterize、batch、update、query）
只有理解这四个接口及相关方法是干什么的，才能写出好的拦截器，开发出符合预期的功能。
以上是关于MyBatis插件及示例----打印每条SQL语句及其执行时间的主要内容，如果未能解决你的问题，请参考以下文章
springboot整合mybatis在控制台打印sql语句的办法及MyBatis Log Plugin插件的安装与使用
springboot整合mybatis在控制台打印sql语句的办法及MyBatis Log Plugin插件的安装与使用