曹工雜談--使用mybatis的同窗，進來看看怎麼在日誌打印完整sql吧，在數據庫可執行那種

時間  2020-01-02
標籤 雜談 使用 mybatis 同窗 進來 看看 怎麼 日誌 打印 完整 sql 數據庫 可執行 那種 欄目 MyBatis 简体版
原文   原文鏈接

前言

今天新年第一天，給你們拜個年，祝你們新的一年裏，技術突突突，頭髮長長長！html

我們搞技術的，比較直接，那就開始吧。我給你們看看我demo工程的效果（代碼下邊會給你們的）：java

技術棧是mybatis/mybatis plus，spring boot ，日誌是logback。git

其實這個痛點吧，我是一直有的，測試或者開發時，日誌裏每次打印的都是帶?的sql，而後還得本身手動一個參數一個參數地貼過去，這真是一個體力活。雖然是體力活，仍是作了這麼多年了，此次，終於決定不忍了。web

在弄這個以前呢，我知道idea裏有個插件能夠實現這個功能，mybatis-log-plugin，但我這邊idea一直用不起，具體緣由不明，反正就是完整sql打印不出來。spring

而後我剛搜了下，mybatis plus也支持，加下面這樣一行配置便可：sql

mybatis-plus:
  configuration:
    log-impl: org.apache.ibatis.logging.stdout.StdOutImpl

但我注意到，這個是打印到控制檯的，我試了下，效果以下：
apache

我以爲，這樣挺好的，可是有優化空間：api

  1. console打印，不適用於開發環境和測試環境；本地調試還不錯；
  2. 本地調試時，通常我只掛起當前線程，若是請求多了，這裏的打印會很亂；分不清哪一個日誌是我這個請求的，而不是其餘線程打印的

我本身這個項目也用的mybatis-plus，所以，我最終配置是下面這樣：緩存

mybatis-plus:
  configuration:
    log-impl: org.apache.ibatis.logging.slf4j.Slf4jImpl

使用slf4j打印，而不是console直接print。但這依然沒有解決：拼裝完整sql，並打印到日誌的需求。mybatis

大致思路

由於是本身瞎摸索出來的方案，不保證是最優的，只能說：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/...的時候，攔截之。

攔截後的邏輯，以下：

  1. 當打印的語句，以==> Preparing:開頭時，將當前語句存放到線程局部變量中，假設爲A；
  2. 當打印的語句，以==> 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的包名，你們以爲有幫助，請點個贊哈，大過年的，哈哈！

相關文章
相關標籤/搜索
每日一句
    每一个你不满意的现在，都有一个你没有努力的曾经。
本站公眾號
   歡迎關注本站公眾號,獲取更多信息
聯繫我們 最近搜索 最新文章 沪ICP备13005482号-10 MyBatis教程 SQL 教程 MySQL教程 Java 教程 Thymeleaf 教程 Hibernate教程 Spring教程 Redis教程