Jar 包依賴衝突排查思路和解決方法（logback + slf4j-log4j12）

時間  2019-11-30
標籤 jar 依賴 衝突 排查 思路 解決 方法 logback slf4j slf log4j12 log 欄目 設計模式 简体版
原文   原文鏈接

Jar 包依賴衝突排查思路和解決方法

[TOC]html

原由

喜大普奔，本期發佈中，咱們的應用從 jdk7 升級到 jdk8，終於能夠用上新特性的語法進行代碼編寫，經過幾輪開發、測試和驗證後，在上預發環境時，應用忽然沒法啓動，查看 tomcat 報錯緣由，發現是 類轉換失敗 ClassCastExceptionjava

報錯緣由①

Class path contains multiple SLF4J bindingnode

23-May-2019 16:04:25.300 INFO [localhost-startStop-1] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/home/admin/xxx/WEB-INF/lib/slf4j-log4j12-1.6.1.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/home/admin/xxx/WEB-INF/lib/logback-classic-1.1.3.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual binding is of type [org.slf4j.impl.Log4jLoggerFactory]
複製代碼

報錯緣由②

org.slf4j.impl.Log4jLoggerFactory cannot be cast to ch.qos.logback.classic.LoggerContextlinux

org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'cn.com.xxx.framework.log.integration.LogbackInitializer#0' defined in class path resource [spring/spring-log-init.xml]: Invocation of init method failed; nested exception is java.lang.ClassCastException: org.slf4j.impl.Log4jLoggerFactory cannot be cast to ch.qos.logback.classic.LoggerContext
    ...    
Caused by: java.lang.ClassCastException: org.slf4j.impl.Log4jLoggerFactory cannot be cast to ch.qos.logback.classic.LoggerContext
    # 出問題的加載地方
	at ch.qos.logback.ext.spring.LogbackConfigurer.initLogging(LogbackConfigurer.java:72)
	at cn.com.xxx.framework.log.integration.LogbackInitializer.init(LogbackInitializer.java:49)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeCustomInitMethod(AbstractAutowireCapableBeanFactory.java:1706)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1645)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1574)
	... 26 more
23-May-2019 15:59:12.398 SEVERE [localhost-startStop-1] org.apache.catalina.core.StandardContext.startInternal One or more listeners failed to start. Full details will be found in the appropriate container log file
複製代碼

查看報錯代碼

public static void initLogging(String location) throws FileNotFoundException, JoranException {
   String resolvedLocation = SystemPropertyUtils.resolvePlaceholders(location);
   URL url = ResourceUtils.getURL(resolvedLocation);
   LoggerContext loggerContext = (LoggerContext)StaticLoggerBinder.getSingleton().getLoggerFactory();
   loggerContext.reset();
   new ContextInitializer(loggerContext).configureByResource(url);
}
複製代碼

能夠看到，經過 StaticLoggerBinder.getSingleton().getLoggerFactory() 獲取 logger 上下文這段代碼報錯了，經過仔細定位，發現了有兩個 StaticLoggerBinder 類git

更重要的是，他們兩兄弟居然雖然不是同一個 jar 包，可是包路徑和名稱都如出一轍！！！github

因爲咱們須要的是 logback 包，而不是 slf4j-log4j12 包，因此須要排除掉 slf4j-log4j12 依賴。spring

解決方法

① 經過 POM 文件排查包衝突apache

② 安裝 IDEA 的插件 Maven Helperbootstrap

③ 定位到編譯 WAR 包的 POM 文件（咱們框架定義的在 Deploy 模塊中）centos

④ 在搜索框中，輸入搜索內容，點擊右鍵能夠看到選項框

  • Jump To Source（跳轉到源文件處）
  • Exclude（排除掉）

例如我點擊了 Exclude ，就能看到 pom 文件中，這個依賴就被排除掉了

<dependency>
    <groupId>cn.com.xxx</groupId>
    <artifactId>framework-conf-client</artifactId>
    <version>${xqy.framework.version}</version>
    <exclusions>
        <exclusion>
            <artifactId>slf4j-log4j12</artifactId>
            <groupId>org.slf4j</groupId>
        </exclusion>
    </exclusions>
</dependency>
複製代碼

排除依賴後，提交代碼，從新打包，部署一條龍，順利啓動~

思考

包衝突解決是簡單的，經過 maven 插件能夠精確找到依賴，而後進行 Exclude，但是在本地開發、測試環境都沒有出現的問題，卻在預發環境出現了，因此排除了業務邏輯代碼的緣由，簡單考慮了幾個因素和緣由：

  • jdk 版本
  • tomcat 版本
  • 類加載機制
  • 第三方 jar 互相依賴

因爲 jdk 和 tomcat 這二者沒有明顯的報錯緣由，因此先去排查類的加載機制

類加載機制

複習一下類加載機制

咱們寫的 Java 應用代碼，通常是經過 App ClassLoader 應用加載器進行加載，它不會本身先去加載它，而是經過 Extension ClassLoader 擴展類加載器進行加載（其中擴展類加載器又會去找 Bootstrap ClassLoader 啓動類加載器進行加載），只有父加載器沒法加載狀況下，纔會讓下級加載器進行加載。

引用自zthgreat

當一個ClassLoader實例須要加載某個類時，它會試圖親自搜索某個類以前，先把這個任務委託給它的父類加載器，這個過程是由上至下依次檢查的，首先由最頂層的類加載器Bootstrap ClassLoader試圖加載，若是沒加載到，則把任務轉交給Extension ClassLoader試圖加載，若是也沒加載到，則轉交給App ClassLoader 進行加載，若是它也沒有加載獲得的話，則返回給委託的發起者，由它到指定的文件系統或網絡等URL中加載該類。若是它們都沒有加載到這個類時，則拋出ClassNotFoundException異常。

ClassLoader

Java 使用的是雙親委派加載機制，經過查看 ClassLoader 類，能夠對此有所瞭解。

類被成功加載後，將被放入到內存中，內存中存放 Class 實例對象。

protected Class<?> loadClass(String name, boolean resolve)
    throws ClassNotFoundException
{
    synchronized (getClassLoadingLock(name)) {
        // First, check if the class has already been loaded
        // 首先，檢查 class 是否已經被加載
        Class<?> c = findLoadedClass(name);
        if (c == null) {
            // 若是沒有被加載
            long t0 = System.nanoTime();
            try {
                if (parent != null) {
                    // 尋找 parent 加載器
                    c = parent.loadClass(name, false);
                } else {
                    // 若是父加載器不存在，則委託給啓動類加載器加載
                    c = findBootstrapClassOrNull(name);
                }
            } catch (ClassNotFoundException e) {
                // ClassNotFoundException thrown if class not found
                // from the non-null parent class loader
            }

            if (c == null) {
                // If still not found, then invoke findClass in order
                // to find the class.
                // 若是仍然沒法加載，纔會嘗試自身加載
                long t1 = System.nanoTime();
                c = findClass(name);

                // this is the defining class loader; record the stats
                sun.misc.PerfCounter.getParentDelegationTime().addTime(t1 - t0);
                sun.misc.PerfCounter.getFindClassTime().addElapsedTimeFrom(t1);
                sun.misc.PerfCounter.getFindClasses().increment();
            }
        }
        if (resolve) {
            resolveClass(c);
        }
        return c;
    }
}
複製代碼

類加載順序

從代碼中瞭解到，若是某個名字的類被加載後，類加載器是不會再從新加載，因此咱們的問題根本緣由能夠是出如今：

先加載了 org.slf4j 包的 org.slf4j.impl.StaticLoggerBinder，同名的 ch.qos.logback 包下的 StaticLoggerBinder 類沒有被加載

經過查閱文章：

跟JAR文件的文件名有關。按照字母的順序加載JAR文件。有了這個類之後，後面的類則不會加載了。

jvm 加載包名和類名相同的類時，先加載classpath中jar路徑放在前面的，包名類名都相同，那jvm無法區分了，若是使用ide通常狀況下是會提示發生衝突而報錯，若不報錯，只有第一個包被引入（在classpath路徑下排在前面的包），第二個包會在classloader加載類時判斷重複而忽略。

查看加載順序

在 jvm 啓動腳本中，添加 -verbose 參數或者 -XX:+TraceClassLoading

[Loaded java.lang.CloneNotSupportedException from /Users/jingqi/.jrebel/bootcache/jrebel-bootstrap-89f567048120ef32b965233b5ba2f7ca.jar]
[Loaded java.lang.Thread$State from /Users/jingqi/.jrebel/bootcache/jrebel-bootstrap-89f567048120ef32b965233b5ba2f7ca.jar]
[Loaded java.util.TreeMap$NavigableSubMap from /Users/jingqi/.jrebel/bootcache/jrebel-bootstrap-89f567048120ef32b965233b5ba2f7ca.jar]
[Loaded java.util.TreeMap$AscendingSubMap from /Users/jingqi/.jrebel/bootcache/jrebel-bootstrap-89f567048120ef32b965233b5ba2f7ca.jar]
[Loaded java.util.TreeMap$NavigableSubMap$EntrySetView from /Users/jingqi/.jrebel/bootcache/jrebel-bootstrap-89f567048120ef32b965233b5ba2f7ca.jar]
[Loaded java.util.TreeMap$AscendingSubMap$AscendingEntrySetView from /Users/jingqi/.jrebel/bootcache/jrebel-bootstrap-89f567048120ef32b965233b5ba2f7ca.jar]
[Loaded java.util.TreeMap$NavigableSubMap$SubMapIterator from /Users/jingqi/.jrebel/bootcache/jrebel-bootstrap-89f567048120ef32b965233b5ba2f7ca.jar]
[Loaded java.util.TreeMap$NavigableSubMap$SubMapEntryIterator from /Users/jingqi/.jrebel/bootcache/jrebel-bootstrap-89f567048120ef32b965233b5ba2f7ca.jar]
複製代碼

以前在本地開發中，IDEA 優化先加載了 ch.qos.logback 的 StaticLoggerBinder 類，而後後面的 org.slf4j 包下的同名類就沒有被加載。

但這樣也有個不明白，按理說加載順序按照字母順序加載，預發環境仍是可以跟本地開發同樣，加載到咱們須要的類。實際上，加載器加載到的是另外一個類，致使應用沒法啓動。

經過查找資料

問題就是jar的加載順序問題，而這個順序其實是由文件系統決定的，linux內部是用inode來指示文件的。

這種儲存文件元信息的區域就叫作inode，中文譯名爲"索引節點"。每個文件都有對應的inode，裏面包含了與該文件有關的一些信息。

Unix/linux系統內部不使用文件名，而使用inode號碼來識別文件。對於系統來講，文件名只是inode號碼便於識別的別稱或者綽號。

爲了驗證 inode 是不是問題的緣由，我作了如下測試：

inode 測試加載順序

本地 Tomcat8 測試（正常啓動）

將以前在 uat 環境有問題的代碼版本從新打包，不使用 idea 工具，直接用 tomcat8 啓動，而且在 catalina.sh 腳本中加入類加載打印參數 -XX:+TraceClassLoading

catalina.sh

# Register custom URL handlers
# Do this here so custom URL handles (specifically 'war:...') can be used in the security policy
JAVA_OPTS="$JAVA_OPTS -XX:+TraceClassLoading"
複製代碼

查看 catalina.out 輸入日誌，發現先加載的是 logback 包中 StaticLoggerBinder

在 WEB-INF/lib 下比較 inode 大小（正常解壓和啓動 logback < slf4j)

ll -i logback-classic-1.1.3.jar slf4j-log4j12-1.6.1.jar
34153162 -rw-r-----  1 jingqi  staff   274K  8  1  2018 logback-classic-1.1.3.jar
34153180 -rw-r-----  1 jingqi  staff   9.5K 10 17  2018 slf4j-log4j12-1.6.1.jar
複製代碼

本地 Tomcat8 測試（刪包，先添加 slf4j，後添加 logback）

  • 清理掉 catalina.out
  • 從新上傳包
  • 比較 inode 大小
  • 從新啓動，查看類加載日誌

比較 inode 大小（發現 slf4j < logback)

# ll -i logback-classic-1.1.3.jar slf4j-log4j12-1.6.1.jar
34162396 -rw-r--r--  1 jingqi  staff   274K  8  1  2018 logback-classic-1.1.3.jar
34162361 -rw-r--r--  1 jingqi  staff   9.5K 10 17  2018 slf4j-log4j12-1.6.1.jar
複製代碼

從新啓動後，查看 catalina.out 日誌，發現類加載順序與以前的一致，應用也能正常啓動，因此本地開發沒法復現 =-=

在 uat 環境服務器測試

在 WEB-INF/lib 路徑下，先將這兩個包刪掉，嘗試有不一樣的上傳順序，模擬 tomcat 解壓 war 包

[admin@uat-96-0-248 lib]$ rm logback-classic-1.1.3.jar  slf4j-log4j12-1.6.1.jar
[admin@uat-96-0-248 lib]$ rz
[admin@uat-96-0-248 lib]$ # Received /Users/jingqi/Downloads/slf4j-log4j12-1.6.1.jar
[admin@uat-96-0-248 lib]$ rz
[admin@uat-96-0-248 lib]$ # Received /Users/jingqi/Downloads/logback-classic-1.1.3.jar
# 第一次上傳順序 一、slf4j-log4j12-1.6.1.jar 二、logback-classic-1.1.3.jar
# inode 比較：slf4j < logback
[admin@uat-96-0-248 lib]$ ll -i logback-classic-1.1.3.jar slf4j-log4j12-1.6.1.jar
396731 -rw-r--r-- 1 admin admin 280928 8月   1 2018 logback-classic-1.1.3.jar
394075 -rw-r--r-- 1 admin admin   9753 10月 17 2018 slf4j-log4j12-1.6.1.jar
[admin@uat-96-0-248 lib]$ rm logback-classic-1.1.3.jar  slf4j-log4j12-1.6.1.jar
[admin@uat-96-0-248 lib]$ rz
[admin@uat-96-0-248 lib]$ # Received /Users/jingqi/Downloads/logback-classic-1.1.3.jar
[admin@uat-96-0-248 lib]$ rz
[admin@uat-96-0-248 lib]$ # Received /Users/jingqi/Downloads/slf4j-log4j12-1.6.1.jar
# 第二次上傳順序 一、logback-classic-1.1.3.jar 二、slf4j-log4j12-1.6.1.jar
# inode 比較：logback < slf4j
[admin@uat-96-0-248 lib]$ ll -i logback-classic-1.1.3.jar slf4j-log4j12-1.6.1.jar
394075 -rw-r--r-- 1 admin admin 280928 8月   1 2018 logback-classic-1.1.3.jar
396731 -rw-r--r-- 1 admin admin   9753 10月 17 2018 slf4j-log4j12-1.6.1.jar
複製代碼

分別測試了兩種場景，發現只要這兩個包都存在的狀況下，不管 inode 二者的大小，都是先加載了 slf4j 包的類，致使啓動報錯

測試結束

經過多種測試場景，發現本地開發、測試環境都沒法復現的問題，在 uat 環境下，只要這兩個包同時存在，都會啓動報錯，系統版本是這個：

[admin@uat-96-0-248 lib]$ cat /proc/version
Linux version 3.10.0-514.26.2.el7.x86_64 (builder@kbuilder.dev.centos.org) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-11) (GCC) ) #1 SMP Tue Jul 4 15:04:05 UTC 2017
# jdk 和 tomcat 版本
Server version: Apache Tomcat/8.5.34
Server built:   Sep 4 2018 22:28:22 UTC
Server number:  8.5.34.0
OS Name:        Linux
OS Version:     3.10.0-514.26.2.el7.x86_64
Architecture:   amd64
JVM Version:    1.8.0_192-b12
JVM Vendor:     Oracle Corporation
複製代碼

最後在官方文檔發現這個：

The order in which the JAR files in a directory are enumerated in the expanded class path is not specified and may vary from platform to platform and even from moment to moment on the same machine. A well-constructed application should not depend upon any particular order. If a specific order is required, then the JAR files can be enumerated explicitly in the class path.

大意爲：同一個目錄下，jvm加載jar包順序是沒法保證的，每一個系統的都不同，甚至同一個系統不一樣的時刻加載都不同。

因而乎，我也不糾結某臺服務器上的類加載順序，在開發階段就先將這個包衝突的狀況，給提早解決掉~

總結

衝突提示信息

  • java.lang.ClassNotFoundException：類型轉換錯誤，這個報錯跟我此次遇到的同樣，本應該引入的是 logback 包的類，可是實際引入的是 slf4j 下的同名類，致使類型轉換錯誤
  • java.lang.NoSuchMethodError：找不到特定方法，若是有兩個同名的包可是不一樣版本，例如 xxx-1.1和 xxx-1.2包同時存在，先加載了 1.1 版本的類，可是 1.2 版本中才提供了新方法，致使提示找不到特定方法
  • java.lang.NoClassDefFoundError，java.lang.LinkageError

排查思路

一、查看 catalina.sh 堆棧信息，找到有問題的類

二、經過 IDEA ，在打包的 POM 文件中，使用 Maven Helper 插件找出衝突的依賴，肯定項目須要的 jar 包，Exclude 掉不須要的依賴。

提早預防

一、使用工具檢查依賴衝突

衝突檢測插件 ：maven-enforcer-plugin

引用新的第三方依賴（工具包或者框架包），經過 Maven 插件檢查一下 conflict 依賴，提早進行 Exclude

二、統一服務器版本

在測試階段，準備好和生產環境同樣的服務器，提早進行測試，避免依賴衝突的 WAR 包上傳到生產環境，例如咱們有一臺 UAT 服務器，與生產環境同樣配置，提早測試，暴露風險和解決問題~

我的博客項目地址

但願各位幫忙點個star，給我加個小星星✨

參考資料

一、log4j與logback包衝突緣由及解決，不可忽視的Warning

二、深刻理解ClassLoader工做機制（jdk1.8）

三、同包同名的類的時候，使用哪一個，哪一個優先

四、jvm加載包名和類名相同的類的規則，以及如何加載包名和類名相同的類

五、vm加載jar包的順序

六、從新看待Jar包衝突問題及解決方案

七、一第二天志打印錯亂引出對jvm加載jar包順序的研究

八、Java文檔提示

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