又到週末了,周更選手申請出站~
這次分享一下上個月碰到的離奇的問題。一個簡單的問題,硬是因為異常被悄咪咪吃掉,過關難度直線提升,導致小黑哥排查一個晚上。
這個美好的晚上,本想著開兩把 LOL 無限火力,在召喚師峽谷來個五殺的~
哎,就這樣沒了啊!我知道,你們一定能理解這種五殺被搶的感覺~
下次,真的,誰再讓我看到悄咪咪的吃掉異常,我真的要上去一 Jio 了!
好了,本文可不是水文,看完本篇文章,你可以學到以下知識點:
- Arthas 排查技巧
- 啥是 NoClassDefFoundError
- Dubbo 異常內部處理方式
好了,同學們,開啟小本子,準備記好知識點~
先贊後看養成習慣,微信搜尋「程式通事」,關注就完事了
起因
我們有個業務系統,應用之間呼叫鏈如下所示:
A 應用是業務發生起始應用,在這個應用中將會根據一定規則選擇最後的通訊渠道 C,然後將這個渠道標識傳遞給 B 應用。
B 應用的功能類似閘道器,這個應用將會根據 A 應用傳遞過來的渠道標識,將會請求路由下發到具體的 C 應用,起到服務路由的功能。
C 應用是與外部應用互動的應用,我們將其稱為渠道通訊機。
假設一次業務中,A 應用根據規則選擇 C2 的渠道標識,然後傳遞給 B 應用。B 應用根據這個標識選擇使用 C2 進行通訊,最後 C2 呼叫外部應用完成一次業務呼叫。
上述所有應用都基於 Dubbo 進行遠端通訊,B 應用實現原理在小黑哥之前文章「支付路由系統演進史」中有寫過,感興趣的同學可以檢視一下。
介紹完業務的基本情況,現在我們來看下到底發生了啥事。
一次業務需求中,需要改動 C2 應用,這次改動功能點真的很小,很快就完成了。小黑哥想著閒著也是閒著,於是就把之前 C2 應用中列印的日誌中一些沒有脫敏的資訊,進行脫敏處理。
由於之前日誌框架脫敏處理存在一些問題,於是就將日誌框架從 Log4j 升級為 LogBack。升級之後,為了防止不同日誌框架中之間的產生衝突,於是使用 IDEA Maven Helper 外掛,統一將應用中所有的 Log4j 相關依賴都給排除了。
改動完成之後,將 C2 應用釋出到測試環境,再次從 A 應用發起測試, B 應用返回異常提示未找到 C2 應用。
B 應用業務程式碼類似如下:
public Response pay(Request req) {
try {
if (!isSupport(req.getChnlCode())) {
return new Response("ERROR", "未找到相關渠道應用");
}
return doPay(req);
} catch (Exception e) {
return new Response("ERROR", "未找到相關渠道應用");
}
}
正常情況下,若是配置存在問題,B 應用將會返回未找到具體渠道,請求也會在 B 應用結束,不會呼叫到 C2 應用(也沒辦法呼叫)。
然而此次配置什麼都沒問題, 而且最詭異的是 C2 應用居然收到了請求,並且成功處理了業務請求。
排查問題
由於 B 應用異常處理時,將異常吃掉了,我們沒辦法得知這個過程到底發生了啥事,所以第一要緊的事獲取異常資訊。
最簡單的辦法就是,將 B 應用改造一下,加入列印異常日誌。不過當時比較懶,不想改造應用,就想獲取異常資訊,於是想到使用 Arthas。
Arthas 排錯技巧
Arthas
是Alibaba開源的Java診斷工具,這裡就不再詳細介紹這個工具,主要講下這次排錯用到的命令-watch。
watch 命令可以方便觀察指定方的呼叫情況,可以具體觀察方法的返回值
、丟擲異常
、入參
,另外還可以通過 OGNL表示式檢視對應的變數。
這裡我們主要為了檢視方法丟擲的異常資訊,執行命令如下:
watch com.dubbo.example.DemoService doPay -e -x 2 '{params,throwExp}'
上述命令將會在方法異常之後觀察方法的入參以及異常資訊。
注意,我們需要檢視
doPay
方法,而不是pay
方法。這是因為pay
方法中我們將異常捕獲,不太可能會丟擲異常哦~
異常資訊如下所示:
真正引起此次錯誤的異常資訊為:
java.lang.NoClassDefFoundError: Could not initialize class xx.xxx.xx.GELogger
由於此次 B 應用不存在改動,所以推測這個異常實際發生在 C2 應用,於是在 C2 應用處再次使用 Arthas watch 命令,同樣觀察到相同的錯誤資訊。
NoClassDefFoundError
NoClassDefFound,從名字上我們可以推測是因為類不存在,從而引發的這個錯誤。按照這個思路,我們首先可以簡單檢視一下 B 應用中是否存在 GELogger
相關類。
檢視 B 應用相關依賴包,從中發現了這個類檔案,這說明這個類確實存在。
在 IDEA 反編譯檢視 GELogger
類相關原始碼,從中發現了問題。
private static Logger logger;
static {
System.out.println("static init");
logger = Logger.getLogger(NoClassDefFoundErrorTestService.class);
System.out.println("Logger init success");
}
GELogger
存在一個靜態程式碼塊,用於初始化一個 org.apache.log4j.Logger
日誌類。
然後在上面改動中,全部的 Log4j
依賴都被排除了,所以這裡執行時應該會丟擲另外一個找到 org.apache.log4j.Logger
錯誤。
執行以下程式碼,模擬拋錯過程。
System.out.println("模擬第一次 Error");
try {
NoClassDefFoundErrorTestService noClassDefFoundErrorTestService=new NoClassDefFoundErrorTestService();
} catch (Throwable e) {
e.printStackTrace();
}
System.out.println("模擬第二次 Error");
try {
NoClassDefFoundErrorTestService noClassDefFoundErrorTestService=new NoClassDefFoundErrorTestService();
} catch (Throwable e) {
e.printStackTrace();
}
異常資訊如下所示:
第一次建立 NoClassDefFoundErrorTestService
例項時,Java 虛擬機器讀取載入時,將會初始化靜態程式碼塊時。由於 org.apache.log4j.Logger
類不存在,靜態程式碼塊執行異常,從而導致類載入失敗。
第二次再建立 NoClassDefFoundErrorTestService
例項時,Java 虛擬機器不會再次讀取載入,所以直接返回了以下異常。
java.lang.NoClassDefFoundError: Could not initialize class com.dubbo.example.NoClassDefFoundErrorTestService
找到問題真正原因,解決辦法也很簡單,直接排除 GELogger
所在依賴包。
Dubbo 內部異常處理
雖然問題到此解決了,但是這裡還有一個疑問,為何 C2 應用發生了異常,卻沒有相關錯誤日誌,並且 C2 業務邏輯也正常處理完成。
這就要說到 Dubbo 內部異常錯誤處理方式,上面 GELogger
其實作用在一個 Dubbo 自定義 Filter 中,用來記錄結果,模擬程式碼如下:
@Activate(
group = {"provider", "consumer"}
)
public class ErrorFilter implements Filter {
@Override
public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
Result result = invoker.invoke(invocation);
NoClassDefFoundErrorTestService noClassDefFoundErrorTestService=new NoClassDefFoundErrorTestService();
// 處理業務邏輯
return result;
}
}
這個自定義 Filter 中首先執行 invoker
方法,這個方法將會呼叫真正的業務方法,這就是為什麼 C2 應用邏輯是正常處理完成。
業務方法處理完成之後,然後執行後續邏輯。由於 NoClassDefFoundErrorTestService
將會丟擲 Error
,最終這個 Error
,將會在 HeaderExchangeHandler#handleRequest
被捕獲,然後將會把相關異常資訊返回給呼叫 Dubbo 消費者。
而在 Dubbo 消費者接受到服務提供者返回資訊之後,將會在 DefaultFuture#doReceived
轉化成 RemotingException
。
而 RemotingException
最終將會在 FailoverClusterInvoker#doInvoke
轉換成 RpcException
返回給業務程式碼。
總結
好了,說了這麼多,總結一下本文知識點
- 異常捕獲之後,一定要記得列印日誌,並且要記得輸出堆疊資訊。
- 執行時類不存在,將會導致
NoClassDefFoundError
,類載入過程失敗,也會導致NoClassDefFoundError
。 - 對外提供的二方包,最好不要依賴特定日誌框架,如 Log4j,Logback 等,應該使用 Slf4j 框架。
幫助
2、java.lang.NoClassDefFoundError 的解決方法一例
3、noclassdeffounderror-could-not-initialize-class-error
歡迎關注我的公眾號:程式通事,獲得日常乾貨推送。如果您對我的專題內容感興趣,也可以關注我的部落格:studyidea.cn