作者：Sharehub
來源：blog.xiaohansong.com/JAVA-log-confict-solve.html
前言
Java 有很多的日志框架可以選擇，當同一個項目中出現多種日志框架時就很容易出現日志框架沖突的問題，導致日志打印不出來。本文將以一次典型的日志沖突排查問題為例，提供排查步驟和思路，最后分析日志框架沖突的原因。
一般行文思路都是先講 Why，再講 How，這里我顛倒了，因為一般遇到問題的時候我們對問題背后的根本原因是一無所知的，如果我們已經知道問題的原因，那么問題也就迎刃而解了。
因此我希望先復現我當時在對日志框架了解不多的情況下排查問題的思路和步驟，如何在面對未知問題找到破題思路是非常重要的技能。
一次典型的日志沖突排查
問題背景
在 A 工程中，日志框架配置選用了 Log4j2，master 分支上日志打印正常，但開發分支增加了代碼之后日志打印不出來。項目的依賴中包含了 Log4j2、Logback 等日志框架。
排查思路與過程
排查問題的時候首先必須要有明確的思路，即大膽假設，小心求證，不能像無頭蒼蠅一樣亂試。從問題的現象看，直覺上可以得出幾個假設：
- 服務器環境有問題
- 開發分支的 Log4j2 配置有問題
接下來就是驗證假設，首先多申請幾臺機器部署項目分支，發現問題仍然存在，可以排除第一個假設。其次找到另一個工程 B 跟 A 工程對比 Log4j2 的配置，也沒有發現明細的差異，可以排除第二個假設。
在已有假設都驗證失敗的情況下，需要收集更多的信息作出判斷，接下來就是要用對照實驗收集信息。于是我分別斷點了 A 和 B 兩個工程，觀察它們日志實體的類型是否一致。結果發現兩者的日志實體類型不一樣，A 的日志實現是 Logback，B 的日志實現是 Log4j2，很明顯 A 打印不出日志是因為日志實體不對，但是兩者都是用的同一個 LoggerFactory 創建 Logger 的。
從對照實驗的結果來看，可以得出一個假設：依賴沖突導致了 A 運行時使用日志實體不是 Log4j2。
至此我們已經找到了問題的大致方向，接下來就是要排包。排包一般有兩種思路：
- 暴力求解：把所有可能沖突的日志包排掉，一個個試。
- 精準爆破：利用類加載的信息判斷運行時加載的具體是哪個 jar
暴力求解的方式太花費時間了，所以我用的第二種方式。
獲取日志實體的方式如下：
privatestaticfinalLoggerLOGGER=LoggerFactory.getLogger(xxx.class);
LoggerFactory 的代碼如下：
從代碼上可以發現，getLog方法是來自父類LogFactory，當我去嘗試獲取LogFactory的實現時候，發現竟然有 3 個 jar 中都有同樣包名的LogFactory實現。于是我斷點了 A 和 B 工程的代碼，用 IDEA 的運行代碼功能執行以下命令獲取LogFactory的加載信息。
結果發現 B 工程使用是spring-jcl，A 使用的是jcl-over-slf4j，然后排除掉 A 中jcl-over-slf4j，問題解決。
上面的排查過程中，關鍵的地方有兩點：
- 定位到問題的根源是類加載沖突，確定排查方向。
- 通過斷點獲取沖突類的加載信息，快速定位到沖突的 jar。
為什么日志框架會沖突
問題至此就解決了，但是還有一個更深入的問題沒有解決：為什么同時存在多個日志框架的時候就會出現沖突呢？在解決完問題之后，我深入研究了日志框架的歷史和設計，發現原來這跟日志框架的實現機制有關系。
日志框架的歷史
首先要從日志框架的發展歷史開始說起。
- 首先登場是Java Util Log，簡稱JUL，是JDK 中自帶的 log 功能。雖然是官方自帶的，JUL 的使用卻不廣泛，主要是因為功能比較簡單，不好用。
- 然后Log4j 1.x就登場了：它是 Gülcü 設計實現的日志框架，設計非常優秀，是非常廣泛使用的框架。
- Commons Logging：簡稱 JCL，是 Apache 的項目。JCL 是一個 Log Facade，只提供 Log API，不提供實現，用 Adapter 來使用 Log4j 或者 JUL 作為 Log Implementation。目的是統一日志接口規范，適配多種日志實現。
- SLF4J/Logback：SLF4J(The Simple Logging Facade for Java) 和 Logback 也是 Gülcü 創立的項目，其創立主要是為了提供更高性能的實現。其中，SLF4j 是類似于JCL 的Log Facade，Logback 是類似于Log4j 的 Log Implementation。這老哥覺得 JCL 的接口設計不好，所以重新設計了一套。
- Log4j2：維護 Log4j 的人為了不讓 Log4j 的用戶被 SLF4J/Logback 搶走，所以搞出了新的日志框架。Log4j2 和 Log4j1.x 并不兼容，設計上很大程度上模仿了 SLF4J/Logback，性能上也獲得了很大的提升。Log4j2 也做了 Facade/Implementation 分離的設計，分成了 log4j-api 和 log4j-core。
至此我們已經有了三個的 Log 接口和四個 Log 實現，果然程序員真的是愛造輪子。出現這么多框架之后，有人開始搞各個框架之間的橋接，你兼容我，我兼容你，如下圖所示。
因為很多 jar 使用的日志框架不同，所以經常會出現引入 jar 包之后導致日志類沖突，前面我們排查的那個問題就是因為引入了 jcl-over-slf4j 的橋接包。
動態加載日志實現
前面我們提到日志框架分為日志接口和日志實現，只要我們代碼中使用的是日志接口（JCL、SLF4J），我們可以隨時替換日志的實現。
SLF4J 加載日志實現的方式
SLF4J 加載日志實現分為兩個步驟：
- 獲取 ILoggerFactory 日志工廠
- 根據 ILoggerFactory 獲取 Logger
SLF4J 要求日志實現 jar 包都要實現 StaticLoggerBinder 這個類，而且要放在指定目錄：org/slf4j/impl/StaticLoggerBinder.class，SLF4J 的LoggerFactory會去掃描所有 jar 包中的這個地址，參考下面的代碼。
雖然它掃描了多個日志實現，但實際上同名類 JVM 只能存在一個，它這里掃描的目的是為了打印日志告訴用戶有多少個日志實現在依賴包中。下面的代碼返回的是最終使用的日志實現。
你可能要問了，同時存在多個日志實現類的時候，到底是用的是哪個？答案很簡單，因為 SLF4J 利用了靜態類來加載日志工程，實際上就是讓 JVM 決定使用哪個類：哪個被先加載到 JVM 中就用哪個。為了搞清楚這個問題的答案，我特地去看了URLClassPath加載類的實現，它就是按照 jar 加入到 URLClassPath的順序遍歷掃描，找到第一個符合條件的就返回。
JCL 加載日志實現的方式
相比 SLF4J 比較任性的加載方式（依賴 JVM 加載類的順序），JCL 提供了更多的配置能力，可以指定使用哪一個日志工程類。
類似的，JCL 也分為兩個步驟加載日志實現：
- 獲取 LogFactory 日志工廠類
- 根據 LogFactory 獲取 Logger
首先是獲取 LogFactory：
- 先從系統屬性中讀取系統屬性System.getProperty("org.apache.commons.logging.LogFactory")
- 使用 Java 的 SPI 機制，來搜尋對應的實現：META-INF/services/org.apache.commons.logging.LogFactory，這里就不對 SPI 進行過多介紹了，簡單來說就是搜尋哪些 jar 包中含有搜尋含有上述文件，該文件中指明了對應的 LogFactory 實現
- 從 commons-logging 的配置文件中 commons-logging.properties 尋找org.apache.commons.logging.LogFactory的值
- 最后還沒找到的話，使用默認的org.apache.commons.logging.impl.LogFactoryImpl
找到 LogFactory 之后就根據 LogFactory 獲取 Logger，這個根據不同的 LogFactory 實現有不同的方式。前面我遇到那個問題就是因為類沖突導致使用了 SLJ4J 的 LogFactory ，加載了錯誤的 Logger。
總結
開發過程中總會遇到奇奇怪怪的問題，有無處下手的感覺時先穩住心態，按照大膽假設，小心求證的方式進行排查，實在沒有思路往往是因為基礎還不扎實。
像這次日志打印不出來的問題，如果了解日志框架的加載實現，很容易就能定位到問題；差一點的像我不了解日志框架的實現，但是我可以根據之前對類加載機制的了解也能解決問題；如果對類加載機制不了解，那基本上是無解了。
因此，要把問題當做學習機會，不光要解決問題，還要深挖背后的原理，做好總結，這樣才能為解決更多的問題打下扎實基礎。
