使用btrace进行运行时异常原因分析

BTrace是Java的安全可靠的动态跟踪工具。 他的工作原理是通过 instrument + asm 来对正在运行的java程序中的class类进行动态增强, 加入检测代码在运行时对应用进行分析和跟踪。

当线上应用抛出一个异常，我们该如何使用btrace进行分析呢？

异常堆栈

java.io.NotSerializableException: com.xxx.UserServiceImpl
    at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1184)
    at java.io.ObjectOutputStream.defaultWriteFields(ObjectOutputStream.java:1548)
    at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1509)
    at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1432)
    at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1178)
    at java.io.ObjectOutputStream.defaultWriteFields(ObjectOutputStream.java:1548)
    at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1509)
    at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1432)
    at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1178)
    at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:348)
    at de.javakaffee.web.msm.JavaSerializationTranscoder.writeAttributes(JavaSerializationTranscoder.java:139)
    at de.javakaffee.web.msm.JavaSerializationTranscoder.serializeAttributes(JavaSerializationTranscoder.java:100)
    at de.javakaffee.web.msm.TranscoderService.serializeAttributes(TranscoderService.java:151)
    at de.javakaffee.web.msm.BackupSessionTask.serializeAttributes(BackupSessionTask.java:179)
    at de.javakaffee.web.msm.BackupSessionTask.call(BackupSessionTask.java:109)
    at de.javakaffee.web.msm.BackupSessionTask.call(BackupSessionTask.java:50)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

使用btrace脚本进行运行时检测

根据异常堆栈信息，对发生异常的代码进行探测。location=@Location(Kind.ERROR) 表明 在发生未被捕获的异常结束时执行。

import com.sun.btrace.annotations.*;
import static com.sun.btrace.BTraceUtils.*;

@BTrace public class WriteObjectErrDetect {

    @OnMethod(
        clazz="java.io.ObjectOutputStream",
        method="writeObject0",
     location=@Location(Kind.ERROR)
    )
    public static void detect(@ProbeClassName String probeClass, @ProbeMethodName String probeMethod,@TargetInstance Throwable err
,Object obj, boolean unshared) {
        print("#####1");
        println(str(obj));
    }

}

控制台输出：

#####org.springframework.security.core.context.SecurityContextImpl@29fefc4f
#####com.xxx.UserServiceImpl@10681811

从输出看基本上可以断定是SecurityContextImpl类的对象引用了UserServiceImpl对象，导致序列化失败。因为UserServiceImpl对象不可序列化。

结合应用代码逻辑，输出对象属性看看：

import java.lang.reflect.Field;
import com.sun.btrace.annotations.*;
import static com.sun.btrace.BTraceUtils.*;


@BTrace public class WriteObjectErr {
    @OnMethod(
        clazz="java.io.ObjectOutputStream",
        method="writeObject",
     location=@Location(Kind.ERROR)
    )
    public static void detect(@ProbeClassName String probeClass, @ProbeMethodName String probeMethod,@TargetInstance Throwable err
,Object obj) {
        println("#####1");
        println(str(obj));
    printFields(obj);
        println("");
    Field field = field(classOf(obj), "authentication", false);
    if(field!=null) {
            println("#####2");
            Object auth = get(field, obj);
            printFields(auth);
        println("");
    }
    }
}

控制台输出

#####1

org.springframework.security.core.context.SecurityContextImpl@109497a3

{authentication=com.xxx.UserServiceImpl$3@4cdcf97c, }

#####2

{val$loginUser=com.xxx.User@2dc609e6, this$0=com.xxx.UserServiceImpl@10681811, }

从输出可以看到，对象中属性this$0引用了UserServiceImpl对象，证明了之前的猜想。

this$0是什么属性？ 它其实是匿名类或非静态内部类对外部对象的应用。因此外部对象不可序列化，导致了该序列化异常。

注意：在对线上环境进行分析的时候，最好在测试环境对btrace脚本进行验证。btrace脚本有可能会导致线上jvm进程异常退出。此次就碰到了， 在使用location=@Location(Kind.ERROR)的时候， 方法签名上没有@TargetInstance Throwable err，直接导致jvm进程退出了。