Closed
Description
背景
随着应用越来越复杂，依赖越来越多，日志系统越来越混乱，有时会出现一些奇怪的日志，比如：
[] [] [] No credential found
那么怎样排查这些奇怪的日志从哪里打印出来的呢？因为搞不清楚是什么logger打印出来的，所以想定位就比较头疼。
下面介绍用arthas的redefine命令快速定位奇怪日志来源。
- Arthas: 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 /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的功能过于强大，所以请小心使用:)
Activity
JikkEmqqy commentedon Nov 6, 2018
很6
jinlisu1987 commentedon Nov 18, 2018
666
xujunhua555 commentedon Nov 26, 2018
6666666
xujunhua555 commentedon Nov 26, 2018
redefine error! java.lang.UnsupportedOperationException: class redefinition failed: attempted to change the schema (add/remove fields)
hengyunabc commentedon Nov 27, 2018
@xujunhua555 redefine不能改field，只能改函数体
xujunhua555 commentedon Nov 27, 2018
好的
amao12580 commentedon Apr 12, 2019
66666666666666666666
yylingyun commentedon Sep 17, 2019
秀，学到了
amao12580 commentedon Oct 25, 2019
666
Jameslin007 commentedon Jan 12, 2020
没想到居然是直接改jdk源码。。这操作真是太骚了！！
anpbszzz commentedon Apr 10, 2020
优秀
anpbszzz commentedon Apr 10, 2020
redefine -p执行报错， 不带p可以正常执行。
hengyunabc commentedon Apr 10, 2020
redefine 命令更新过，不再需要
-p了，谢谢指出。2 remaining items