一、問題描述
聽同事反饋,通過發(fā)布平臺發(fā)布了一個新版本,總共發(fā)布到了多臺機器,但是只有其中一臺報了NoSuchMethodError的錯誤,堆棧信息如下:
java.lang.NoSuchMethodError: org.apache.log4j.MDC.put(Ljava/lang/String;Ljava/lang/String;)V
at com.tencent.fit.oms.framework.aspect.ControllerAccLogAspect.doBefore(ControllerAccLogAspect.java:52)
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.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:627)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:609)
at org.springframework.aop.aspectj.AspectJMethodBeforeAdvice.before(AspectJMethodBeforeAdvice.java:43)
at org.springframework.aop.framework.adapter.MethodBeforeAdviceInterceptor.invoke(MethodBeforeAdviceInterceptor.java:55)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.aop.framework.adapter.AfterReturningAdviceInterceptor.invoke(AfterReturningAdviceInterceptor.java:55)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
許多"有經驗"的開發(fā)人員一眼就知道是什么問題---基本上可以斷定是版本沖突。
而且本來就不建議使用具體的日志實現(xiàn)類來加日志,推薦使用slf4j,所以我們應該為自己的錯誤買單。
二、問題解決思路
仔細對比了一下機器的lib,發(fā)現(xiàn)該機器和其它機器都是相同的。而且也排除開發(fā)人員二次開發(fā)log4j,然后deploy到了公共私服的可能(md5值相同)。既然對比包解決不了,就只能看具體的代碼實現(xiàn)了。
來到IDEA,搜索下MDC,確實發(fā)現(xiàn)有兩個實現(xiàn),一個是log4j下的,一個是log4j-over-slf4j下的。并且log4j下的MDC并沒有put(String,String)方法,而是put(String,Object)?；旧峡梢詳喽ㄊ羌虞d了錯誤的log4j,但是即使沒有put(String,String)也不應該報錯才對啊？畢竟String也屬于Object.先不糾結這個問題,直接線上驗證下MDC再說。
直接上Arthas,通過jad org.apache.log4j.MDC查看字節(jié)碼,發(fā)現(xiàn)內存中確實是log4j1.2.17的實現(xiàn),沒有put(String,String)方法,而且通過sc -d org.apache.log4j.MDC查看類加載信息,發(fā)現(xiàn)該類來自于log4j1.2.17,而正常的機器該類卻來自于log4j-over-slf4j.解決問題要緊,趕緊刪了log4j1.2.17,然后重新啟動,問題解決。
三、問題延伸
今天也比較糾結,和一些"高端玩家"討論了jvm加載相同package、類名class的順序問題,也沒有個所以然,大概有這么幾類說法:
- 不知道,沒了解過springboot類加載機制
因為我們這是springboot應用 - 順序加載,誰在前面就加載誰
問題:怎么判斷前后？jar名字?系統(tǒng)時間戳？ - 隨機加載
感覺不太可信,如果是隨機加載,感覺java語言本身就存在漏洞。 - 使用層面的問題,就不應該用log4j.MDC,應該使用slf4j.MDC
的確是這樣。但是任何項目都是有歷史原因的,而且感覺是為自己不了解jvm的加載順序機制找個理由"開脫",開個玩笑,別當真~
回過頭來再看為什么會拋出NoSuchMethodError這個錯誤,明明是put(String,Object)卻不能接收put(String,String),看似很奇怪,其實是編譯器給我們施了一個障眼法.當我們編譯的時候MDC.put(xx,xx)被編譯成了MDC.put(String,String),當我們啟動的時候卻錯誤的加載了put(String,Object),導致方法簽名不兼容,從而拋出了這個錯誤。下面我們來演示一下:
新建一個MyMDC.java：
public class MyMDC {
public static void main(String[] args) {
put("jerrik","handsome");
}
private static void put(String jerrik, String world) {
System.out.println("string");
MDC.put("ok",world);
}
}
編譯后,將MyMDC.class復制出來保存,然后去掉log4j.over.slf4j的依賴,加上log4j1.2.17的依賴。防止編譯器給我們重新編譯,用之前保存的MyMDC.class覆蓋掉當前MyMDC.class,然后在命令行使用java MyMDC運行,就會出錯:
Exception in thread "main" java.lang.NoSuchMethodError: org.apache.log4j.MDC.put(Ljava/lang/String;Ljava/lang/String;)V
at MyMDC.put(MyMDC.java:18)
at MyMDC.main(MyMDC.java:13)
終于真相大白了,也是今天群里一哥們@liufor給了我一個思路,表示感謝。這里也是我們的一個推斷,不代表完全正確,希望讀者也有自己的思考。
四、最后
不了解arthas的童鞋,可以去arthas官網學習一下Arthas,線上問題定位的利器。btrace,housemd感覺復雜度還是太高了,這個完全是傻瓜式的。不過如果要定位高大上的問題,估計還是得派上用場。今天這個問題如果沒有arthas協(xié)助的話,可以增加一個jvm參數--XX:+TraceClassLoading,將類加載信息打出來,也能知道MDC具體來自哪個jar包,是不是美滋滋？ 還想多說幾句,今天知道了幾個工具:po轉vo的mapStruct和微服務腳手架JHipster,有興趣的童鞋可以研究下。
