版权声明：如果觉得文章对你有用，转载不需要联系作者，但请注明出处 https://blog.csdn.net/jinxin70/article/details/86551416
说实话，日志难看，在排查问题时会不爽。
线上出现问题，经常需要看数据库里面的数据有没有问题，是不是sql查询的时候就查错了，所以需要查看sql语句的日志，但是mybatis打印的日志都是占位符，还有很多换行符，非常不友好，druid默认的statementLogEnabled参数配置也有这个问题。
一开始为了解决这个痛点，没想到druid有提供可以打印可执行的sql的配置，功夫花在mybatis插件开发上，代码基于仓颉大佬博客中提到的内容，解决了使用参数值代替占位符时，实际参数字段有可能是ParameterObject的父类的这种情况，无法打印可执行SQL的问题，
Myabtis插件优化SQL语句输出
通过Myabtis插件优化SQL语句输出，具体代码如下：
import org.apache.ibatis.executor.statement.StatementHandler;
import org.apache.ibatis.mapping.BoundSql;
import org.apache.ibatis.mapping.ParameterMapping;
import org.apache.ibatis.plugin.*;
import org.apache.ibatis.session.ResultHandler;
import org.apache.ibatis.session.defaults.DefaultSqlSession.StrictMap;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import java.lang.reflect.Field;
import java.sql.Statement;
import java.util.Collection;
import java.util.List;
import java.util.Map;
import java.util.Properties;
/**
* Sql执行时间记录拦截器
*/
@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 {
private static final Logger logger = LoggerFactory.getLogger(SqlCostInterceptor.class);
@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 {
long endTime = System.currentTimeMillis();
long sqlCost = endTime - startTime;
BoundSql boundSql = statementHandler.getBoundSql();
String sql = boundSql.getSql();
Object parameterObject = boundSql.getParameterObject();
List<ParameterMapping> parameterMappingList = boundSql.getParameterMappings();
// 格式化Sql语句，去除换行符，替换参数
sql = formatSql(sql, parameterObject, parameterMappingList);
logger.info("SQL：[" + sql + "]执行耗时[" + sqlCost + "ms]");
}
}
@Override
public Object plugin(Object target) {
return Plugin.wrap(target, this);
}
@Override
public void setProperties(Properties properties) {
}
@SuppressWarnings("unchecked")
private String formatSql(String sql, Object parameterObject, List<ParameterMapping> parameterMappingList) {
// 输入sql字符串空判断
if (sql == null || sql.length() == 0) {
return "";
}
// 美化sql
sql = beautifySql(sql);
// 不传参数的场景，直接把Sql美化一下返回出去
if (parameterObject == null || parameterMappingList == null || parameterMappingList.size() == 0) {
return sql;
}
// 定义一个没有替换过占位符的sql，用于出异常时返回
String sqlWithoutReplacePlaceholder = sql;
try {
if (parameterMappingList != null) {
Class<?> parameterObjectClass = parameterObject.getClass();
// 如果参数是StrictMap且Value类型为Collection，获取key="list"的属性，这里主要是为了处理<foreach>循环时传入List这种参数的占位符替换
// 例如select * from xxx where id in <foreach collection="list">...</foreach>
if (isStrictMap(parameterObjectClass)) {
StrictMap<Collection<?>> strictMap = (StrictMap<Collection<?>>)parameterObject;
if (isList(strictMap.get("list").getClass())) {
sql = handleListParameter(sql, strictMap.get("list"));
}
} else if (isMap(parameterObjectClass)) {
// 如果参数是Map则直接强转，通过map.get(key)方法获取真正的属性值
// 这里主要是为了处理<insert>、<delete>、<update>、<select>时传入parameterType为map的场景
Map<?, ?> paramMap = (Map<?, ?>) parameterObject;
sql = handleMapParameter(sql, paramMap, parameterMappingList);
} else {
// 通用场景，比如传的是一个自定义的对象或者八种基本数据类型之一或者String
sql = handleCommonParameter(sql, parameterMappingList, parameterObjectClass, parameterObject);
}
}
} catch (Exception e) {
// 占位符替换过程中出现异常，则返回没有替换过占位符但是格式美化过的sql，这样至少保证sql语句比BoundSql中的sql更好看
return sqlWithoutReplacePlaceholder;
}
return sql;
}
/**
* 美化Sql
*/
private String beautifySql(String sql) {
// sql = sql.replace("\n", "").replace("\t", "").replace(" ", " ").replace("( ", "(").replace(" )", ")").replace(" ,", ",");
sql = sql.replaceAll("[\\s\n ]+"," ");
return sql;
}
/**
* 处理参数为List的场景
*/
private String handleListParameter(String sql, Collection<?> col) {
if (col != null && col.size() != 0) {
for (Object obj : col) {
String value = null;
Class<?> objClass = obj.getClass();
// 只处理基本数据类型、基本数据类型的包装类、String这三种
// 如果是复合类型也是可以的，不过复杂点且这种场景较少，写代码的时候要判断一下要拿到的是复合类型中的哪个属性
if (isPrimitiveOrPrimitiveWrapper(objClass)) {
value = obj.toString();
} else if (objClass.isAssignableFrom(String.class)) {
value = "\"" + obj.toString() + "\"";
}
sql = sql.replaceFirst("\\?", value);
}
}
return sql;
}
/**
* 处理参数为Map的场景
*/
private String handleMapParameter(String sql, Map<?, ?> paramMap, List<ParameterMapping> parameterMappingList) {
for (ParameterMapping parameterMapping : parameterMappingList) {
Object propertyName = parameterMapping.getProperty();
Object propertyValue = paramMap.get(propertyName);
if (propertyValue != null) {
if (propertyValue.getClass().isAssignableFrom(String.class)) {
propertyValue = "\"" + propertyValue + "\"";
}
sql = sql.replaceFirst("\\?", propertyValue.toString());
}
}
return sql;
}
/**
* 处理通用的场景
*/
private String handleCommonParameter(String sql, List<ParameterMapping> parameterMappingList, Class<?> parameterObjectClass,
Object parameterObject) throws Exception {
for (ParameterMapping parameterMapping : parameterMappingList) {
String propertyValue = null;
// 基本数据类型或者基本数据类型的包装类，直接toString即可获取其真正的参数值，其余直接取paramterMapping中的property属性即可
if (isPrimitiveOrPrimitiveWrapper(parameterObjectClass)) {
propertyValue = parameterObject.toString();
} else {
String propertyName = parameterMapping.getProperty();
Field field = null;
try{
field = parameterObjectClass.getDeclaredField(propertyName);
}catch (NoSuchFieldException e){
//如果当前类或者父类是Object，快速抛出错误
if(parameterObjectClass.isAssignableFrom(Object.class)
|| parameterObjectClass.getSuperclass().isAssignableFrom(Object.class)){
throw e;
}
field = getField(parameterObjectClass, propertyName, field);
}
// 要获取Field中的属性值，这里必须将私有属性的accessible设置为true
field.setAccessible(true);
propertyValue = String.valueOf(field.get(parameterObject));
if (parameterMapping.getJavaType().isAssignableFrom(String.class)) {
propertyValue = "\"" + propertyValue + "\"";
}
}
sql = sql.replaceFirst("\\?", propertyValue);
}
return sql;
}
//处理当propertyName是parameterObjectClass的父类时不生效的情况
private Field getField(Class<?> parameterObjectClass, String propertyName, Field field) throws NoSuchFieldException {
//获取当前类的父类
Class superClass = parameterObjectClass.getSuperclass();
if(superClass.isAssignableFrom(Object.class)){
throw new NoSuchFieldException();
}
//遍历父类的字段
for(Field f : superClass.getDeclaredFields()){
if(f.getName().equals(propertyName)){
//如果父类的属性名找到了，赋值给field，结束循环，返回field
field = f;
break;
}
}
if(field == null){
//如果循环父类没有找到，递归调用当前方法，直到找到为止,找到顶级父类Object还是找不到，会抛出NoSuchFieldException
getField(superClass,propertyName,field);
}
return field;
}
/**
* 是否基本数据类型或者基本数据类型的包装类
*/
private boolean isPrimitiveOrPrimitiveWrapper(Class<?> parameterObjectClass) {
return parameterObjectClass.isPrimitive() ||
(parameterObjectClass.isAssignableFrom(Byte.class) || parameterObjectClass.isAssignableFrom(Short.class) ||
parameterObjectClass.isAssignableFrom(Integer.class) || parameterObjectClass.isAssignableFrom(Long.class) ||
parameterObjectClass.isAssignableFrom(Double.class) || parameterObjectClass.isAssignableFrom(Float.class) ||
parameterObjectClass.isAssignableFrom(Character.class) || parameterObjectClass.isAssignableFrom(Boolean.class));
}
/**
* 是否DefaultSqlSession的内部类StrictMap
*/
private boolean isStrictMap(Class<?> parameterObjectClass) {
return parameterObjectClass.isAssignableFrom(StrictMap.class);
}
/**
* 是否List的实现类
*/
private boolean isList(Class<?> clazz) {
Class<?>[] interfaceClasses = clazz.getInterfaces();
for (Class<?> interfaceClass : interfaceClasses) {
if (interfaceClass.isAssignableFrom(List.class)) {
return true;
}
}
return false;
}
/**
* 是否Map的实现类
*/
private boolean isMap(Class<?> parameterObjectClass) {
Class<?>[] interfaceClasses = parameterObjectClass.getInterfaces();
for (Class<?> interfaceClass : interfaceClasses) {
if (interfaceClass.isAssignableFrom(Map.class)) {
return true;
}
}
return false;
}
/**
* 获取对象中的字段
* @param obj which object you want to find filed
* @param fieldName the field name you want to find
* @return the field you want tofind
* @throws Throwable
* @throws NoSuchFieldException
*/
protected Field getField(Object obj,String fieldName) throws NoSuchFieldException {
Class clzz = obj.getClass();
Field[] fields = clzz.getDeclaredFields();
Field dest = null;
while (!hasField(fields,fieldName) && !clzz.getName().equalsIgnoreCase("java.lang.Object")) {
clzz = clzz.getSuperclass();
fields = clzz.getDeclaredFields();
}
if (hasField(fields,fieldName)) {
dest = clzz.getDeclaredField(fieldName);
} else {
throw new NoSuchFieldException("类中没有此字段");
}
return dest;
}
/**
* 判断对象中是否有要找的字段
* @param fields the fields which you want to find
* @param fieldName the field name you want to find
* @return if the field in field return true else return false
*/
private boolean hasField(Field[] fields, String fieldName) {
for (int i = 0; i < fields.length ;i ++) {
if (fields[i].getName().equals(fieldName)) {
return true;
}
}
return false;
}
}烦人的问题：为什么会有两条带占位符的SQL语句
当我写的插件可以打印可执行SQL后，看到在可执行SQL前后，还是会有带占位符的SQL语句打印（原来项目中的），即现在系统里，执行一条SQL语句，会打印两条带占位符的语句，和一条可执行SQL语句，总共打印三条SQL语句。
为什么会有两条带占位符的SQL语句？？？通过后面对Druid源码的分析。默认druid的statementLogEnabled参数是true，如果配置了log4j的filter，在sql执行的时候会打印一条带占位符的SQL，在SQL执行完，druid又会打印一次带占位符的SQL。
Druid的SQL打印逻辑
Druid的SQL打印逻辑所在的类如下：
FilterEventAdapter类中：
LogFilter类中：
第一次配置修改
那两条占位符的SQL对我们看日志来说没什么用，于是想着怎么过滤掉不显示，根据官网wiki的提示，加了如下配置：
<bean id="log-filter" class="com.alibaba.druid.filter.logging.Log4jFilter">
<property name="resultSetLogEnabled" value="false" />
<property name="statementLogEnabled" value="false"/>
<property name="statementExecuteAfterLogEnabled" value="false"/>
<property name="statementExecutableSqlLogEnable" value="true"/>
</bean>将过滤器加到数据源配置中：
<bean id="dataSource" class="com.alibaba.druid.pool.DruidDataSource"
init-method="init" destroy-method="close">
省略其他属性配置
<property name="proxyFilters">
<list>
<ref bean="log-filter"/>
</list>
</property>
</bean>将mybatis插件注释掉，不需要用了：
这样启动项目后，每次执行一条SQL，还是会打印两条带占位符和一条可执行的SQL语句，那一条可执行的SQL语句说明druid的statementExecutableSqlLogEnable配置生效了，但是为什么还是会打印两条带占位符的？
数据源中的原配置搞的鬼
先直接看为什么，因为数据源配置中配置了这个：
<property name="filters" value="stat,log4j,config" />配置了三个过滤器，其中一个就是log4j。。。。
stat是监控，config是为了数据库加密
在debug追源码发现，DruidDataSource中的filter是4个，两个Log4jFilter：
两个Log4j，一个是上面的默认配置，一个是自定义的log4j配置。
最终配置修改：
所以解决方法就是把默认的配置去掉就可以了：
<property name="filters" value="stat,config" />目前的SQl日志可以看了。
如果遇到线上问题需要排查，直接复制到plsql中执行就行了，不用替换占位符了。
总结：
1、这次的问题解决，首先自己关注了下项目中对于开发不友好的部分，SQL打印难看，给定位问题带来一些不便。
2、在解决这个问题的时候，主要资源是官网wiki和源码。在之前花了很多时间分析过Spring源码、Mybatis源码等后，分析Druid源码还是很轻松的。源码中找到的答案是最真实的。
3、debug能力更加巩固了，依然确信，源码分析没有捷径，就是自己debug，网上的分析的都是别人的，不是自己的，两个效果不一样。
4、准备有时间把Druid源码的运行逻辑和一些思路记录下，毕竟花了宝贵的时间，放脑子里保质期太短，不利于总结提炼。（****）
5、项目中的日志打印，除了SQL，其他的还是很乱，后续继续优化。（****）
6、打算专门写一篇，Druid中责任链模式的应用。（*****）
延伸阅读：
这篇文章一开始在介绍字段属性，然后我就没看了，发现自己debug找答案更快。但是等我回头看这篇文章，还是有很多共鸣的，总之可以参考，但是一定要先自己debug看源码。
作者的其他文章看起来也不错，日后闲暇翻阅