曹工杂谈--使用mybatis的同学,进来看看怎么在日志打印完整sql吧,在数据库可执行那种
前言
今天新年第一天,给大家拜个年,祝大家新的一年里,技术突突突,头发长长长!
咱们搞技术的,比较直接,那就开始吧。我给大家看看我demo工程的效果(代码下边会给大家的):
技术栈是
mybatis/mybatis plus,
spring boot,日志是
logback。
其实这个痛点吧,我是一直有的,测试或者开发时,日志里每次打印的都是带?的sql,然后还得自己手动一个参数一个参数地贴过去,这真是一个体力活。虽然是体力活,还是做了这么多年了,这次,终于决定不忍了。
在弄这个之前呢,我知道idea里有个插件可以实现这个功能,
mybatis-log-plugin,但我这边idea一直用不起,具体原因不明,反正就是完整sql打印不出来。
然后我刚搜了下,mybatis plus也支持,加下面这样一行配置即可:
mybatis-plus: configuration: log-impl: org.apache.ibatis.logging.stdout.StdOutImpl
但我注意到,这个是打印到控制台的,我试了下,效果如下:
我觉得,这样挺好的,但是有优化空间:
- console打印,不适用于开发环境和测试环境;本地调试还不错;
- 本地调试时,一般我只挂起当前线程,如果请求多了,这里的打印会很乱;分不清哪个日志是我这个请求的,而不是其他线程打印的
我自己这个项目也用的
mybatis-plus,因此,我最终配置是下面这样:
mybatis-plus: configuration: log-impl: org.apache.ibatis.logging.slf4j.Slf4jImpl
使用
slf4j打印,而不是
console直接
大体思路
因为是自己瞎摸索出来的方案,不保证是最优的,只能说:it works。
大家再看看,正常情况下,是会打印下面这样的sql的(mybatis默认支持):
[http-nio-8083-exec-1] DEBUG c.e.w.mapper.AppealDisposalOnOffMapper.selectList - ==> Preparing: SELECT appeal_disposal_on_off_id,disposal_on_off_status,appeal_on_off_status,user_id FROM appeal_disposal_on_off WHERE (disposal_on_off_status = ?) [BaseJdbcLogger.java:143] [http-nio-8083-exec-1] DEBUG c.e.w.mapper.AppealDisposalOnOffMapper.selectList - ==> Parameters: 0(Integer) [BaseJdbcLogger.java:143]
即,默认打印出:一行
preparedStatement的语句,带?;下一行就是对应的参数。
我的方案是,对
logger进行动态代理,当调用
logger.info/debug/...的时候,拦截之。
拦截后的逻辑,如下:
- 当打印的语句,以
==> Preparing:
开头时,将当前语句存放到线程局部变量中,假设为A; - 当打印的语句,以
==> Parameters:
开头时,将当前线程局部变量中的A拿出来,和当前语句一起,拼成一个完整的sql,然后调用当前方法(记住,我们动态代理了logger.info等方法)打印之。
画图解决:
上面的逻辑图,大家看着没问题吧,其实问题的关键变成了,怎么去生成这个logger的动态代理,且最重要的是,你生成的动态代理对象要怎么生效。
具体实现分析
要讲解这部分,我们只能切入细节了,毕竟我们得找到一个切入点,去使用我们的动态代理logger。
大家应该记得,我们平时使用slf4j时,生成logger是不是下面这样写(现在虽然用lombok了,本质没变):
private static final Logger logger = LoggerFactory.getLogger(A.class);
public static Logger getLogger(String name) { ILoggerFactory iLoggerFactory = getILoggerFactory(); return iLoggerFactory.getLogger(name); }
这一行里,
getILoggerFactory就要去获取classpath中绑定的日志实现了,具体的过程,我在另一篇里也有讲:
曹工改bug--这次,我遇到了一个难缠的栈溢出bug,还是日志相关的,真的难
因为我们用的logback,所以这里会进入到logback包内的(包名怎么是slf4j的?没错,这就是slf4j-api怎么去找实现类的核心,类似java的SPI机制,具体看上面的博文):
logback-classic包内的: org.slf4j.impl.StaticLoggerBinder#getSingleton public static StaticLoggerBinder getSingleton() { return SINGLETON; } 进入上面代码前,会先执行静态代码: private static StaticLoggerBinder SINGLETON = new StaticLoggerBinder(); static { SINGLETON.init(); }
上面的静态代码块中,进行初始化:
void init() { try { new ContextInitializer(defaultLoggerContext).autoConfig(); } catch (JoranException je) { Util.report("Failed to auto configure default logger context", je); } //核心代码 contextSelectorBinder.init(defaultLoggerContext, KEY); initialized = true; }
ch.qos.logback.classic.util.ContextSelectorStaticBinder#init public void init(LoggerContext defaultLoggerContext, Object key) { if (this.key == null) { this.key = key; } // 这个contextSelector很重要,loggerFactory就是调用它的方法来生成 String contextSelectorStr = OptionHelper.getSystemProperty(ClassicConstants.LOGBACK_CONTEXT_SELECTOR); if (contextSelectorStr == null) { contextSelector = new DefaultContextSelector(defaultLoggerContext); } else if (contextSelectorStr.equals("JNDI")) { contextSelector = new ContextJNDISelector(defaultLoggerContext); } else { contextSelector = dynamicalContextSelector(defaultLoggerContext, contextSelectorStr); } }
经过我多方调试,发现这里的
contextSelector,发现它很关键。它是个接口,方法如下:
/** * An interface that provides access to different contexts. * * It is used by the LoggerFactory to access the context * it will use to retrieve loggers. * * @author Ceki Gülcü * @author Sébastien Pennec */ public interface ContextSelector { // 获取LoggerContext,这个LoggerContext其实就是LoggerFactory LoggerContext getLoggerContext(); LoggerContext getLoggerContext(String name); LoggerContext getDefaultLoggerContext(); LoggerContext detachLoggerContext(String loggerContextName); List<String> getContextNames(); }
大家注意,这个类的方法,
LoggerContext getLoggerContext();,返回值是
LoggerContext,这个返回值类型比较牛逼,因为它其实就是
LoggerFactory。
public class LoggerContext extends ContextBase implements ILoggerFactory, LifeCycle
大家看到了,这个
LoggerContext实现了
ILoggerFactory:
public interface ILoggerFactory { // 这个东西,大家熟悉了噻,logger工厂啊 public Logger getLogger(String name); }
综上分析,我们要换Logger,可能没那么容易,因为Logger,是
ILoggerFactory调用
getLogger获得的。
那么,我们只能把原始的
ILoggerFactory(假设为A)给它换了,生成一个
ILoggerFactory的动态代理(假A),保证每次调用
A的getLogger时,就会被假A拦截。然后我们在拦截的逻辑中,先使用A获取到原始logger,然后生成对原始logger进行动态代理的logger。
所以,现在完整的逻辑是这样:
问题,现在就变成了,怎么去生成
org.slf4j.ILoggerFactory的动态代理,因为我们需要这个原始的factory,不然我们作为动态代理,自己也不知道怎么去生成Logger。
前面大家也看到了,
LoggerContext满足要求,那我们只要在能拿到
LoggerContext的地方,处理下就行了。
能拿到
LoggerContext的地方,就是
ContextSelector。
大家回头再看看之前那段代码:
public void init(LoggerContext defaultLoggerContext, Object key) throws ClassNotFoundException, NoSuchMethodException, InstantiationException, IllegalAccessException, InvocationTargetException { if (this.key == null) { this.key = key; } //扩展点就在这里了,这里会去取环境变量,如果取不到,就用默认的,取到了,就用环境变量里的类 String contextSelectorStr = OptionHelper.getSystemProperty(ClassicConstants.LOGBACK_CONTEXT_SELECTOR); if (contextSelectorStr == null) { A: contextSelector = new DefaultContextSelector(defaultLoggerContext); } else if (contextSelectorStr.equals("JNDI")) { B: contextSelector = new ContextJNDISelector(defaultLoggerContext); } else { C: contextSelector = dynamicalContextSelector(defaultLoggerContext, contextSelectorStr); } }
这里就是扩展点,我们自己设置一个环境变量
ClassicConstants.LOGBACK_CONTEXT_SELECTOR,就不会走A逻辑,而是走上面的C逻辑。具体的里面很简单,就是根据环境变量的值,去new一个对应的
contextSelector。
具体实现步骤1--指定环境变量
@SpringBootApplication @MapperScan("com.example.webdemo.mapper") public class WebDemoApplicationUsingMybatisPlus { private static Logger log= null; static { // 这里设置环境变量,指向我们自定义的class System.setProperty(ClassicConstants.LOGBACK_CONTEXT_SELECTOR,"com.example.webdemo.util.CustomDefaultContextSelector"); log = LoggerFactory.getLogger(WebDemoApplicationUsingMybatisPlus.class); } public static void main(String[] args) { ConfigurableApplicationContext context = SpringApplication.run(WebDemoApplicationUsingMybatisPlus.class, args); } }
具体实现步骤2--实现自定义的context-selector
package com.example.webdemo.util; import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.LoggerContext; import ch.qos.logback.classic.selector.ContextSelector; import org.springframework.cglib.proxy.Enhancer; import org.springframework.cglib.proxy.MethodInterceptor; import org.springframework.cglib.proxy.MethodProxy; public class CustomDefaultContextSelector implements ContextSelector, MethodInterceptor { private LoggerContext defaultLoggerContext; private LoggerContext proxyedDefaultLoggerContext; private static ConcurrentHashMap<String, org.slf4j.Logger> cachedLogger = new ConcurrentHashMap<>(1000); public CustomDefaultContextSelector(LoggerContext context) { //1:原始的LoggerContext,框架会传进来 this.defaultLoggerContext = context; } @Override public LoggerContext getLoggerContext() { return getDefaultLoggerContext(); } @Override public LoggerContext getDefaultLoggerContext() { if (proxyedDefaultLoggerContext == null) { //2:我们这里,将原始的LogegrContext进行代理,这里返回代理过的对象,完成偷天换日的效果,callback就设为自己 Enhancer enhancer = new Enhancer(); enhancer.setSuperclass(defaultLoggerContext.getClass()); enhancer.setCallback(this); proxyedDefaultLoggerContext = (LoggerContext) enhancer.create(); } return proxyedDefaultLoggerContext; } @Override public Object intercept(Object o, Method method, Object[] args, MethodProxy methodProxy) throws Throwable { Object result; result = methodProxy.invokeSuper(o,args); //3:当原始的LoggerContext的getLogger被调用时,生成一个动态代理的Logger,会组装sql日志那种 if (Objects.equals(method.getReturnType().getName(), org.slf4j.Logger.class.getName()) && Objects.equals(method.getName(), "getLogger")) { org.slf4j.Logger logger = (org.slf4j.Logger) result; String loggerName = logger.getName(); /** * 只关心mybatis层的logger,mybatis层的logger的包名,我们这边是固定的包下面 * 如果不是这个包下的,直接返回 */ if (!loggerName.startsWith("com.example.webdemo.mapper")) { return result; } /** * 对mybatis mapper的log,需要进行代理;代理后的对象,我们暂存一下,免得每次都创建代理对象 * 从缓存获取代理logger */ if (cachedLogger.get(loggerName) != null) { return cachedLogger.get(loggerName); } CustomLoggerInterceptor customLoggerInterceptor = new CustomLoggerInterceptor(); customLoggerInterceptor.setLogger((Logger) result); Object newProxyInstance = Proxy.newProxyInstance(result.getClass().getClassLoader(), result.getClass().getInterfaces(), customLoggerInterceptor); cachedLogger.put(loggerName, (org.slf4j.Logger) newProxyInstance); return newProxyInstance; } return result; } }
这里做了一点优化,将代理Logger进行了缓存,同名的logger只会有一个。
具体实现步骤3--logger的动态代理的逻辑
//摘录了一部分,因为处理字符串比较麻烦,所以代码多一点,这里就不贴出来了,大家自己去clone哈 private String assemblyCompleteMybatisQueryLog(Object[] args) { if (args != null && args.length > 1) { if (!(args[0] instanceof BasicMarker)) { return null; } /** * marker不匹配,直接返回 */ BasicMarker arg = (BasicMarker) args[0]; if (!Objects.equals(arg.getName(), "MYBATIS")) { return null; } String message = null; for (int i = (args.length - 1); i >= 0 ; i--) { if (args[i] != null && args[i] instanceof String) { message = (String) args[i]; break; } } if (message == null) { return null; } // 这里就是判断当前打印的sql是啥,进行对应的处理 if (message.startsWith("==> Preparing:")) { String newMessage = message.substring("==> Preparing:".length()).trim(); SQL_LOG_VO_THREAD_LOCAL.get().setPrepareSqlStr(newMessage); } else if (message.startsWith("==> Parameters:")) { try { return populateSqlWithParams(message); } catch (Exception e) { logger.error("{}",e); }finally { SQL_LOG_VO_THREAD_LOCAL.remove(); } } } return null; }
总结
源码地址奉上,大家deug一下,马上就明白了。
针对
mybatis的:
https://gitee.com/ckl111/all-simple-demo-in-work/tree/master/log-complete-sql-demo-mybatis
针对
mybatis-plus的:
https://gitee.com/ckl111/all-simple-demo-in-work/tree/master/log-complete-sql-demo-mybatis-plus
具体就这么多吧,大家把3个工具类拷过去基本就能用了,然后改为自己mapper的包名,大家觉得有帮助,请点个赞哈,大过年的,哈哈!
- 使用mybatis时 有一个sql查询不到结果 日志也显示查询为o 但是从日志中取出执行的sql到数据库客户端手动执行,可以查到数据
- log4j2 配置Mybatis的SQL打印、日志文件保存路径、日志信息保存数据库和日志信息发送邮件等等
- Mybatis 的多个参数的使用和 sql日志的打印
- Mybatis中在log日志或控制台打印执行的sql
- mybaits(查询与别名、日志框架显示sql语句、对象属性和数据库表字段不匹配resultMap使用、mysql数据查询分页、执行sql和存储过程、动态SQL语句)
- mybatis如何在控制台或者tomcat日志中打印出执行的sql语句
- 使用log4jdbc实现打印完整带参数的sql语句日志
- mybatis下使用log4j打印sql语句和执行结果
- mybatis下使用log4j打印sql语句和执行结果
- Spring4.0.2使用p6spy打印mybatis执行SQL
- mybatis下使用log4j打印sql语句和执行结果
- [置顶] 【p6spy】程序员开发利器P6spy——打印执行sql语句,mybatis、ibatis、Hibernate均可使用
- 使用mybatis执行对应的SQL Mapper配置中的insert、update、delete等标签操作,数据库记录不变
- 解决mybatis继承SqlSessionDaoSupport方式操作数据库不打印sql日志的问题。
- 使用p6spy 打印 oracle,mysql 等数据库完整带参数 sql
- 使用sql语句建立与删除链接服务器及执行数据库操作
- 使用log4jdbc,打印输出完整的sql
- Mybatis3.3.x技术内幕(十一):执行一个Sql命令的完整流程
- Mybatis+SpringMVC打印纯SQL日志
- 使用SSH添加数据时执行了SQL语句数据库却什么都没有?