Arthas實踐--使用redefine排查應用奇怪的日誌來源
摘要：
隨著應用越來越複雜，依賴越來越多，日誌系統越來越混亂，有時會出現一些奇怪的日誌，比如：
[] [] [] No credential found
那麼怎樣排查這些奇怪的日誌從哪裡打印出來的呢？因為搞不清楚是什麼logger打印出來的，所以想定位...
隨著應用越來越複雜，依賴越來越多，日誌系統越來越混亂，有時會出現一些奇怪的日誌，比如：
[] [] [] No credential found
那麼怎樣排查這些奇怪的日誌從哪裡打印出來的呢？因為搞不清楚是什麼logger打印出來的，所以想定位就比較頭疼。
下面介紹用Alibaba開源的應用診斷利器Arthas的redefine命令快速定位奇怪日誌來源。
- Arthas:ofollow,noindex">https://github.com/alibaba/arthas
- redefine命令：https://alibaba.github.io/arthas/redefine.html
修改StringBuilder
首先在java程式碼裡，字串拼接基本都是通過StringBuilder
來實現的。比如下面的程式碼：
public static String hello(String world) {
return "hello " + world;
}
實際上生成的位元組碼也是用StringBuilder
來拼接的：
public static java.lang.String hello(java.lang.String); descriptor: (Ljava/lang/String;)Ljava/lang/String; flags: ACC_PUBLIC, ACC_STATIC Code: stack=3, locals=1, args_size=1 0: new#22// class java/lang/StringBuilder 3: dup 4: ldc#24// String hello 6: invokespecial #26// Method java/lang/StringBuilder."<init>":(Ljava/lang/String;)V 9: aload_0 10: invokevirtual #29// Method java/lang/StringBuilder.append:(Ljava/lang/String;)Ljava/lang/StringBuilder; 13: invokevirtual #33// Method java/lang/StringBuilder.toString:()Ljava/lang/String; 16: areturn
在java的logger系統裡，輸出日誌時通常也是StringBuilder
來實現的，最終會呼叫StringBuilder.toString()
，那麼我們可以修改StringBuilder
的程式碼來檢測到日誌來源。
StringBuilder.toString()
的原生實現是：
@Override
public String toString() {
// Create a copy, don't share the array
return new String(value, 0, count);
}
修改為：
@Override
public String toString() {
// Create a copy, don't share the array
String result = new String(value, 0, count);
if(result.contains("No credential found")) {
System.err.println(result);
new Throwable().printStackTrace();
}
return result;
}
增加的邏輯是：
當String裡包含No credential found
時打印出當前棧，這樣子就可以定位日誌輸出來源了。
編繹修改過的StringBuilder
其實很簡單，在IDE裡把StringBuilder
的程式碼複製一份，然後貼到任意一個工程裡，然後編繹即可。
也可以直接用javac來編繹：
javac StringBuilder.java
啟動應用，使用Arthas redefine修改過的StringBuilder
啟動應用後，在奇怪日誌輸出之前，先使用arthas attach應用，再redefine StringBuilder:
$ redefine -p /tmp/StringBuilder.class redefine success, size: 1
當執行到輸出[] [] [] No credential found
的logger程式碼時，會列印當前棧。實際執行結果是：
[] [] [] No credential found java.lang.Throwable at java.lang.StringBuilder.toString(StringBuilder.java:410) at com.taobao.middleware.logger.util.MessageUtil.getMessage(MessageUtil.java:26) at com.taobao.middleware.logger.util.MessageUtil.getMessage(MessageUtil.java:15) at com.taobao.middleware.logger.slf4j.Slf4jLogger.info(Slf4jLogger.java:77) at com.taobao.spas.sdk.common.log.SpasLogger.info(SpasLogger.java:18) at com.taobao.spas.sdk.client.identity.CredentialWatcher.loadCredential(CredentialWatcher.java:128) at com.taobao.spas.sdk.client.identity.CredentialWatcher.access$200(CredentialWatcher.java:18) at com.taobao.spas.sdk.client.identity.CredentialWatcher$1.run(CredentialWatcher.java:58) at java.util.TimerThread.mainLoop(Timer.java:555) at java.util.TimerThread.run(Timer.java:505)
可以看到是spas.sdk
打印出了[] [] [] No credential found
的日誌。
總結
- logger最終會用StringBuilder來輸出
- 修改StringBuilder來定位輸出特定日誌的地方
- 使用Arthas redefine命令來載入修改過的StringBuilder
- redefine命令實際上實現了任意程式碼線上debug的功能，可以隨意本地修改程式碼重新編繹，然後線上redefine載入
- redefine的功能過於強大，所以請小心使用:)
Arthas實踐系列
- 使用Arthas抽絲剝繭排查線上應用日誌打滿問題
- 深入Spring Boot：利用Arthas排查NoSuchMethodError