曹工雜談--使用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直接print。但這依然沒有解決：拼裝完整sql，並列印到日誌的需求。
大體思路
因為是自己瞎摸索出來的方案，不保證是最優的，只能說：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的包名，大家覺得有幫助，請點個贊哈，大過年的，哈哈