Recently I use BTrace to check exceptions that are thrown inside glassfish VM. I use script:
@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;
}
}
}
When I attach to GF 4.1.1 (build 1) with BTrace v.1.3.10.2 (20180129) using '-v' flag the following stracktrace is generated by GF and I see no console output thrown by 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$1]]
btrace DEBUG: starting client command handler thread]]
btrace DEBUG: skipping transform for BTrace class com/sun/btrace/agent/Main$3]]
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$000(Main.java:60)
at com.sun.btrace.agent.Main$2.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$3.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$6]]
The thing I am confused about is the glassfish exception. When btrace is being attached there is already an application deployed on GF that serves HTTP requests.
If there is a webapp (CDI/REST/JPA) deployed that uses web container why 'the container has not been started' is raised?
I finally found out whats going on - looking again on this Ex:
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)
One of the methods I analyzed in BTrace code is:
com.sun.btrace.agent.Client.retransformLoaded
which looks like:
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) throws this Exception. It uses method from 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;
}
And the constructor of ClassInfo:
ClassInfo(ClassCache cache, ClassLoader cl, ClassName cName) {
this.cache = cache;
cLoaderId = (cl != null ? cl.toString() : "<null>");
classId = cName;
215 loadExternalClass(cl, cName);
}
and finally constructor's loadExternalClass method:
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 is taken using ClassLoader.getSystemClassLoader(). This is actually WebappClassLoader which is the main actor in the exception. I noticed that exception is thrown by CDI/JPA classes (after catching and printing classes that throw the 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
Can somone can tell me why only these classes throw EX when instrumenting them?
My BTrace script is taken from samples and looks like:
@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;
}
}
To solve this and get output from BTrace I can just wrap line 451 in com.sun.btrace.agent.Client.retransformLoaded with try-catch block and everything is working fine and output is generated.
I wonder just why this exception is thrown? SYS_CL is a default classloader (CL) and I've read that in Glassfish every webapp has its own newly created CL. These CDI/JPA classes are loaded with WebappClassLoader (cl variable is not null - 262 in ClassInfo.class and I truly checked that cl='WebappClassLoader (delegate=true)') so why they are not willling to be instrumented ?
The moral is U just cannot use BTrace with every script U want coz enviroment frameworks can interfere the probing.