從解決一個java.lang.NoSuchMethodError想到的


今天在發布系統部署一個web app的時候,發現應用服務器(tomcat 7.0.26)不能正常啟動,於是遠程登陸到服務器上查看應用服務器的啟動日志,在tomcat_home的logs/localhost.log.2014-03-17上發現了一段如下錯誤信息: 

java.lang.NoSuchMethodError: org.slf4j.spi.LocationAwareLogger.log(Lorg/slf4j/Marker;Ljava/lang/String;ILjava/lang/String;[Ljava/lang/Object;Ljava/lang/Throwable;)V
at org.apache.commons.logging.impl.SLF4JLocationAwareLog.error(SLF4JLocationAwareLog.java:225)
at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:319)
at com.alibaba.citrus.webx.context.WebxComponentsLoader.initWebApplicationContext(WebxComponentsLoader.java:117)
at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:112)
at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4779)
at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5273)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:895)
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:871)
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:615)
at com.taobao.tomcat.deploy.TomcatHostConfig.deployDirectory(TomcatHostConfig.java:482)
at com.taobao.tomcat.deploy.TomcatHostConfig.deployWarDirectory(TomcatHostConfig.java:366)
at com.taobao.tomcat.deploy.TomcatHostConfig.deployDirectories(TomcatHostConfig.java:339)

...后面的錯誤信息省略。 

分析思路: 

1、這是一個tomcat啟動時的方法調用棧信息,結合web.xml中配置信息,發現配置了一個webx(一個阿里開源的webx框架)的WebxContextLoaderListener ,這個類的主要作用是在應用服務器啟動的時候,初始化webapp的applicationContext,為webx的組件初始化提供支持。

(這不是我們敘述的重點,所以不重點講述) 。 

 分析棧信息,定位到org.springframework.web.context.ContextLoader類的319行,

logger.error("Context initialization failed", ex);

這是一個捕獲RuntimeException的catch塊寫error日志,這個logger對象的創建在270行

Log logger = LogFactory.getLog(ContextLoader.class);

 查看類的import 聲明 import org.apache.commons.logging.LogFactory  ,結合對java日志知識的復習(點擊這里) 。

可以知道采用的是commons-logging的日志接口(有可能是commons-logging,或者是jcl-over-slf4j的包引入的) ,

於是查看一下webapp的maven依賴樹 ,把和日志相關的jar包都提取出來: 

1、接口API包:

org.slf4j.slf4j-api-1.5.6.jar

slf4j-api-1.7.5.jar

 

2、日志框架包: 

logback-core-1.0.13.jar

logback-classic-1.0.13.jar

jakarta.log4j-1.2.15.jar
apache-log4j-log4j-1.2.15.jar
log4j-log4j-1.2.15.jar

 

3、日志適配器包: 

org.slf4j.slf4j-log4j12-1.5.6.jar

4、其他日志到slf4j日志的橋接包:

jcl-over-slf4j-1.7.5.jar

 

從以上包來看, 可以分析出一下結論: 

1、slf4j-api有兩個不同的版本 。

2、系統中既有logback,也有log4j,但是slf4j-api在靜態綁定選擇時,因為有slf4j-log4j包的存在,會出現多個綁定的問題。

3、commons-logging日志接口被jcl-over-slf4j橋接到slf4j日志接口了。

出現的異常是否和這個結論有關系呢 ?

回到棧信息 ,可以看到Log logger = LogFactory.getLog(ContextLoader.class);   這一行獲取日志器的日志器工廠LogFactory 應該是在JCL-over-slf4j包內定義的, 查看源碼, 

public Log getInstance(String name) throws LogConfigurationException {
Log instance = loggerMap.get(name);
if (instance != null) {
return instance;
} else {
Log newInstance;
Logger slf4jLogger = LoggerFactory.getLogger(name);
if (slf4jLogger instanceof LocationAwareLogger) {
newInstance = new SLF4JLocationAwareLog((LocationAwareLogger) slf4jLogger);
} else {
newInstance = new SLF4JLog(slf4jLogger);
}
Log oldInstance = loggerMap.putIfAbsent(name, newInstance);
return oldInstance == null ? newInstance : oldInstance;
}
}

我們可以看到代碼進入了標紅的這一行,也就是利用一個適配器模式,把slf4jLogger轉換成了org.apache.commons.logging.Log, 最后由這個LocationAwareLogger 拋出了一個錯誤信息,

java.lang.NoSuchMethodError: org.slf4j.spi.LocationAwareLogger.log(Lorg/slf4j/Marker;Ljava/lang/String;ILjava/lang/String;[Ljava/lang/Object;Ljava/lang/Throwable;)V

LocationAwareLogger 這個類是在slf4j-api中定義的,前面的分析我們看到打包后的WEB-INF下有兩個slf4j-api的包 ,

其中在slf4j-api-1.5.6中的定義是這樣的: 

 void log(org.slf4j.Marker marker, java.lang.String s, int i, java.lang.String s1, java.lang.Throwable throwable);

而在slf4j-api-1.7.5中的定義是這樣的:

 void log(org.slf4j.Marker marker, java.lang.String s, int i, java.lang.String s1, java.lang.Object[] objects, java.lang.Throwable throwable);

回顧《深入理解jvm》里面關於字節描述符的知識,我們知道錯誤信息提示的是需要找

log(Marker,String,int,String,Object[],Throwable) 這樣的一個方法,但是沒有找到,

說明編譯時和運行時采用了不一樣的jar . 

再通過maven依賴樹,查詢到org.slf4j.slf4j-api-1.5.6.jar是被一個單點登錄的jar依賴間接引入的,於是在父工程里面排除掉

org.slf4j.slf4j-api-1.5.6.jar間接依賴(順便也排除掉了org.slf4j.slf4j-log4j12-1.5.6.jar這個適配器包) ,問題得到解決。

 

事后,我們再回顧出現的錯誤信息 ,java.lang.NoSuchMethodError ,其實這個類的繼承體系結構

java.lang.Object
  

extended by

java.lang.Throwable
      

extended by

java.lang.Error
          

extended by

java.lang.LinkageError
              

extended by

java.lang.IncompatibleClassChangeError
                  

extended by

java.lang.NoSuchMethodError



就已經告訴了我們出問題的線索了 ,比如ImcompatibleClassChangeError的英文注釋是這么說的:
Thrown when an incompatible class change has occurred to some class definition. The definition of some class, on which the currently executing method depends, has since changed.
(大意是:當不兼容的類變化作用在了類的定義時,異常拋出。當前執行方法依賴的類定義發生了改變) 。

所以在查找問題時,異常本身的注釋也是我們找問題的一個好辦法。


 

----------------------------------------------------------------

 

回顧整個問題的解決過程,發現這次解決問題是采用   源碼分析+maven依賴樹的靜態分析方法,我們有什么辦法知道有問題的Class文件是jvm加載的哪個jar的么? 

 

1)方法1:

jvm里面有一個跟蹤classload的參數: 

-XX:+TraceClassLoading

我們修改catalina.sh , 加上這個參數JAVA_OPTS=$JAVA_OPTS" "-XX:+TraceClassLoading ,然后把標准輸出重定向到一個臨時日志文件:

1>/tmp/logs/tomcat.log

在這個臨時日志中,我們找到了

[Loaded org.slf4j.spi.LocationAwareLogger from file:~/eclipse_workspace/webapp/target/exploded/webapp.war/WEB-INF/lib/org.slf4j.slf4j-api-1.5.6.jar]

說明運行時的確是使用到了slf4j-1.5.6版本的Jar包,和編譯classpath使用的jar包版本不一致。

2)方法2:

阿里的聚石寫了一個housemd的工具 ,安裝方法可以點擊這里(https://github.com/CSUG/HouseMD) , 啟動后運行如下命令attach到tomcat進程:

housemd `jps|grep Bootstrap|awk '{print $1}'`

 然后loaded classname 就可以得到運行時類所在的jar .

 要自己實現的話,比如我們要獲取一個Test.class類是被哪個jar導入的,可以這樣

URL url =  Log.class.getClassLoader().getResource("Test.class");  

 url.getFile(); 

另外,還可以用loaded -h 命令查看類加載器樹, 

要自己實現的話可以這樣:

for(ClassLoader cl = Log.class.getClassLoader(); cl  != null ; cl = cl.getParent()){

  System.out.println(cl.getName()); 

}

 

那么我們能否在應用打包的時候,就分析出存在jar沖突的地方呢 ?我的思路是這樣的: 

1、在應用打包成功以后,把應用的class的jar包拷貝到一個臨時文件夾。

2、對這些jar包中的字節碼文件,做如下操作:

1)使用asm分析出class 導入的class .

2)對每一個導入的class獲取 build classpath下的jar列表,如果jar的個數大於等於2 ,則表明有jar沖突。 

3)輸出jar沖突信息到控制台。

目前,我已經在本機mac環境下實現了基本功能, 接下來的計划是做成maven插件,放到整個maven應用的build cycle中去。

 

 

 

 


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM