btrace 与 glassfish 网络容器

btrace with glassfish web container

最近我使用 BTrace 来检查 glassfish VM 中抛出的异常。 我使用脚本:

@BTrace public class OnThrow {    
    // store current exception in a thread local
    // variable (@TLS annotation). Note that we can't
    // store it in a global variable!
    @TLS static Throwable currentException;

    // introduce probe into every constructor of java.lang.Throwable
    // class and store "this" in the thread local variable.
    @OnMethod(
        clazz="java.lang.Throwable",
        method="<init>"
    )
    public static void onthrow(@Self Throwable self) {
        currentException = self;
    }

    @OnMethod(
        clazz="java.lang.Throwable",
        method="<init>"
    )
    public static void onthrow1(@Self Throwable self, String s) {
        currentException = self;
    }

    @OnMethod(
        clazz="java.lang.Throwable",
        method="<init>"
    )
    public static void onthrow1(@Self Throwable self, String s, Throwable cause) {
        currentException = self;
    }

    @OnMethod(
        clazz="+java.lang.Throwable",
        method="<init>"
    )
    public static void onthrow2(@Self Throwable self, Throwable cause) {
        currentException = self;
    }

    // when any constructor of java.lang.Throwable returns
    // print the currentException's stack trace.
    @OnMethod(
        clazz="java.lang.Throwable",
        method="<init>",
        location=@Location(Kind.RETURN)
    )
    public static void onthrowreturn() {
        if (currentException != null) {
            Threads.jstack(currentException);
            println("=====================");
            currentException = null;
        }
    }
}

当我使用“-v”标志通过 BTrace v.1.3.10.2 (20180129) 附加到 GF 4.1.1(build 1)时,GF 生成了以下 stracktrace,我没有看到 BTrace 抛出任何控制台输出:

btrace DEBUG: parsed command line arguments]]  
btrace DEBUG: Bootstrap ClassPath: .]]
btrace DEBUG: ignoring boot classpath element '.' - only jar files allowed]]
btrace DEBUG: System ClassPath: /usr/lib/jvm/java-8-oracle/jre/../lib/tools.jar]]
btrace DEBUG: debugMode is true]]
btrace DEBUG: probe descriptor path is .]]
btrace DEBUG: stdout is false]]
btrace DEBUG: starting agent thread]]
btrace DEBUG: Agent init took: 10482105ns]]
btrace DEBUG: starting server at 2020]]
btrace DEBUG: waiting for clients]]
btrace DEBUG: client accepted    Socket[addr=/127.0.0.1,port=43496,localport=2020]]]
btrace DEBUG: got instrument command]]
btrace DEBUG: loading BTrace class]]
btrace DEBUG: verifying BTrace class ...]]
btrace DEBUG: BTrace class com.sun.btrace.samples.OnThrow  verified]]
btrace DEBUG: preprocessing BTrace class com.sun.btrace.samples.OnThrow ...]]
btrace DEBUG: ... preprocessed]]  
btrace DEBUG: loaded 'com.sun.btrace.samples.OnThrow' successfully]]
btrace DEBUG: creating BTraceRuntime instance for com.sun.btrace.samples.OnThrow]]
btrace DEBUG: created BTraceRuntime instance for com.sun.btrace.samples.OnThrow]]
btrace DEBUG: sending Okay command]]
btrace DEBUG: client com.sun.btrace.samples.OnThrow: got com.sun.btrace.comm.OkayCommand@26cab401]]
btrace DEBUG: about to defineClass com/sun/btrace/samples/OnThrow]]
btrace DEBUG: defineClass succeeded for com.sun.btrace.samples.OnThrow]]
btrace DEBUG: skipping transform for BTrace class com/sun/btrace/agent/RemoteClient]]
btrace DEBUG: starting client command handler thread]]
btrace DEBUG: skipping transform for BTrace class com/sun/btrace/agent/Main]]
btrace DEBUG: new Client created com.sun.btrace.agent.RemoteClient@44c6c5b2]]
btrace DEBUG: retransforming loaded classes]]
btrace DEBUG: filtering loaded classes]]
btrace DEBUG: skipping transform for BTrace class com/sun/btrace/runtime/ClassCache$Singleton]]
btrace DEBUG: skipping transform for BTrace class com/sun/btrace/runtime/ClassInfo$ClassName]]
btrace DEBUG: skipping transform for BTrace class com/sun/btrace/runtime/ClassInfo$JavaClassName]]
btrace DEBUG: skipping transform for BTrace class com/sun/btrace/runtime/ClassInfo$BaseClassName]]
btrace DEBUG: skipping transform for BTrace class com/sun/btrace/runtime/ClassInfo$InternalClassName]]
btrace DEBUG: skipping transform for BTrace class com/sun/btrace/runtime/BTraceClassReader$BailoutExceptio]]
btrace DEBUG: java.util.concurrent.ExecutionException: java.lang.IllegalStateException: This web container has not yet been started]]

java.util.concurrent.ExecutionException: java.lang.IllegalStateException:    This web container has not yet been started
at java.util.concurrent.FutureTask.report(FutureTask.java:122)
at java.util.concurrent.FutureTask.get(FutureTask.java:192)
at com.sun.btrace.agent.Main.startServer(Main.java:674)
at com.sun.btrace.agent.Main.access[=11=]0(Main.java:60)
at com.sun.btrace.agent.Main.run(Main.java:125)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.IllegalStateException: This web container has not yet been started
at org.glassfish.web.loader.WebappClassLoader.findResourceInternal(WebappClassLoader.java:2827)
at org.glassfish.web.loader.WebappClassLoader.findResource(WebappClassLoader.java:1320)
at org.glassfish.web.loader.WebappClassLoader.getResourceAsStream(WebappClassLoader.java:1528)
at com.sun.btrace.runtime.ClassInfo.loadExternalClass(ClassInfo.java:262)
at com.sun.btrace.runtime.ClassInfo.<init>(ClassInfo.java:215)
at com.sun.btrace.runtime.ClassCache.get(ClassCache.java:70)
at com.sun.btrace.runtime.ClassCache.get(ClassCache.java:62)
at com.sun.btrace.runtime.ClassCache.get(ClassCache.java:51)
at com.sun.btrace.agent.Client.retransformLoaded(Client.java:451)
at com.sun.btrace.agent.Main.run(Main.java:693)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
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)

btrace DEBUG: waiting for clients]]
btrace DEBUG: skipping transform for BTrace class sun/security/ssl/ServerNameExtension]]
btrace DEBUG: skipping transform for BTrace class sun/security/ssl/UnknownExtension]]  
btrace DEBUG: skipping transform for BTrace class sun/security/provider/PolicyFile]]

让我感到困惑的是 glassfish 异常。当附加 btrace 时,已经在 GF 上部署了一个服务于 HTTP 请求的应用程序。

如果部署了一个使用 Web 容器的 Web 应用程序 (CDI/REST/JPA),为什么会出现“容器尚未启动”?

我终于知道是怎么回事了——再看一遍这个例子:

org.glassfish.web.loader.WebappClassLoader.getResourceAsStream(WebappClassLoader.java:1528)
at com.sun.btrace.runtime.ClassInfo.loadExternalClass(ClassInfo.java:262)
at com.sun.btrace.runtime.ClassInfo.<init>(ClassInfo.java:215)
at com.sun.btrace.runtime.ClassCache.get(ClassCache.java:70)
at com.sun.btrace.runtime.ClassCache.get(ClassCache.java:62)
at com.sun.btrace.runtime.ClassCache.get(ClassCache.java:51)
at com.sun.btrace.agent.Client.retransformLoaded(Client.java:451)

我在BTrace代码中分析的方法之一是:

com.sun.btrace.agent.Client.retransformLoaded

看起来像:

void retransformLoaded() throws UnmodifiableClassException {
        if (runtime != null) {
            if (probe.isTransforming() && settings.isRetransformStartup()) {
                ArrayList<Class> list = new ArrayList<>();
                debugPrint("retransforming loaded classes");
                debugPrint("filtering loaded classes");
                ClassCache cc = ClassCache.getInstance();
                for (Class c : inst.getAllLoadedClasses()) {
                    if (c != null) {                                
451                     cc.get(c);
                        }
                        if (inst.isModifiableClass(c) &&  isCandidate(c)) 
                            debugPrint("candidate " + c + " added");
                            list.add(c);
                        }
...other stuff

cc.get(c) 抛出此异常。 它使用来自 ClassCache 的方法:

 ClassInfo get(ClassLoader cl, ClassName className) {
        Map<ClassName, ClassInfo> infos = getInfos(cl);

        ClassInfo ci = infos.get(className);
        if (ci == null) {
70          ci = new ClassInfo(this, cl, className);
            infos.put(className, ci);
        }
        return ci;
    }

以及ClassInfo的构造函数:

  ClassInfo(ClassCache cache, ClassLoader cl, ClassName cName) {
        this.cache = cache;
        cLoaderId = (cl != null ? cl.toString() : "<null>");
        classId = cName;
215     loadExternalClass(cl, cName);
    }

最后是构造函数的 loadExternalClass 方法:

 private void loadExternalClass(final ClassLoader cl, final ClassName className) {
        String resourcePath = className.getResourcePath();

262 InputStream typeIs = cl == null ? SYS_CL.getResourceAsStream(resourcePath) : cl.getResourceAsStream(resourcePath);
        if (typeIs != null) {
            try {
            BTraceClassReader cr = new BTraceClassReader(cl, typeIs);
            ...

SYS_CL 是使用 ClassLoader.getSystemClassLoader() 获取的。这实际上是WebappClassLoader,它是异常中的主要参与者。我注意到 CDI/JPA 类 抛出异常(在捕获并打印抛出 EX 的 类 之后):

  btrace DEBUG: Class class some.package.EntityManagerWrapper -> EX thrown: This web container has not yet been started]]
  btrace DEBUG: Class class some.package.AsyncAuditFacade -> EX thrown: This web container has not yet been started]]
  btrace DEBUG: Class class some.package.OperationAuditFacade -> EX thrown: This web container has not yet been started]]
  btrace DEBUG: Class class some.package.FacadeConfigFactory -> EX thrown: This web container has not yet been started

有人能告诉我为什么只有这些 类 在检测它们时抛出 EX 吗?

我的 BTrace 脚本取自样本,看起来像:

  @TLS static Throwable currentException;
  @OnMethod(
        clazz="+java.lang.Throwable",
        method="<init>"
    )
    public static void onthrow2(@Self Throwable self, Throwable cause) {
        currentException = self;
    }
      @OnMethod(
            clazz="java.lang.Throwable",
            method="<init>",
            location=@Location(Kind.RETURN)
        )
    public static void onthrowreturn() {
        if (currentException != null) {
            Threads.jstack(currentException);
            println("=====================");
            currentException = null;
        }
    }

为了解决这个问题并从 BTrace 获取输出,我可以用 try-catch 块将 com.sun.btrace.agent.Client.retransformLoaded 中的第 451 行换行,一切正常并生成输出。

我想知道为什么会抛出这个异常? SYS_CL 是默认的类加载器 (CL),我在 Glassfish 中了解到每个 webapp 都有自己新创建的 CL。 这些 CDI/JPA 类 加载了 WebappClassLoader(cl 变量不为空 - ClassInfo.class 中的 262 我确实检查过 cl='WebappClassLoader (delegate=true)')所以他们为什么不愿意检测 ?

道德是你不能在你想要的每个脚本中使用 BTrace,因为环境框架会干扰探测。