AspectJ with jar classloader

Question

I am trying to instrument Oracle Rest Data Service (ORDS) which is built on Jetty. The aspect should trace JDBC calls. I do not see the weaving happening.

I have tried AspectJ in a different standalone application which used JDBC and also profiled Servlet calls in an application running in standalone Jetty and all this worked for me. But in this case there is an exception and it does not look that weaving is happening. Application itself works as expected with all AspectJ configurations applied.

Two options have been tried:

aspect class and aop configuration file were put into jar and this jar was placed inside WEB-INF/lib. aspectjrt.jar was copied into this directory as well.
the aspect class and aspect config were copied into WEB-INF/classes like this

   ├── WEB-INF
   │   ├── beans.xml
   │   ├── classes
   │   │   ├── META-INF
   │   │   │   ├── MANIFEST.MF
   │   │   │   └── aop-ajc.xml
   │   │   └── WhereTheStatementTimeGo.class

There was an exception like below in both cases.

Here is the command line and the exception:

$JAVA_HOME/bin/java -javaagent:/DATA/PROJECTS/ASPECTJ19/lib/aspectjweaver.jar -Dorg.aspectj.tracing.enabled=true -Dorg.aspectj.tracing.factory=defaug.aspectj.tracing.messages=true   -jar ords.war standalone

[JarClassLoader@17f052a3] warning parse definitions failed -- (IllegalStateException) sun.misc.Launcher$AppClassLoader@18b4aac2
sun.misc.Launcher$AppClassLoader@18b4aac2
java.lang.IllegalStateException: sun.misc.Launcher$AppClassLoader@18b4aac2
    at oracle.dbtools.jarcl.NestedResourceHandler.jarClassLoader(NestedResourceHandler.java:36)
    at oracle.dbtools.jarcl.NestedResourceHandler.openConnection(NestedResourceHandler.java:23)
    at java.net.URL.openConnection(URL.java:979)
    at java.net.URL.openStream(URL.java:1045)
    at org.aspectj.weaver.loadtime.definition.DocumentParser.saxParsing(DocumentParser.java:157)
    at org.aspectj.weaver.loadtime.definition.DocumentParser.parse(DocumentParser.java:123)
    at org.aspectj.weaver.loadtime.ClassLoaderWeavingAdaptor.parseDefinitions(ClassLoaderWeavingAdaptor.java:290)
    at org.aspectj.weaver.loadtime.DefaultWeavingContext.getDefinitions(DefaultWeavingContext.java:130)
    at org.aspectj.weaver.loadtime.ClassLoaderWeavingAdaptor.initialize(ClassLoaderWeavingAdaptor.java:174)
    at org.aspectj.weaver.loadtime.Aj$ExplicitlyInitializedClassLoaderWeavingAdaptor.initialize(Aj.java:337)
    at org.aspectj.weaver.loadtime.Aj$ExplicitlyInitializedClassLoaderWeavingAdaptor.getWeavingAdaptor(Aj.java:342)
    at org.aspectj.weaver.loadtime.Aj$WeaverContainer.getWeaver(Aj.java:316)
    at org.aspectj.weaver.loadtime.Aj.preProcess(Aj.java:108)
    at org.aspectj.weaver.loadtime.ClassPreProcessorAgentAdapter.transform(ClassPreProcessorAgentAdapter.java:51)
    at sun.instrument.TransformerManager.transform(TransformerManager.java:188)
    at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:428)
    at java.lang.ClassLoader.defineClass1(Native Method)
    at java.lang.ClassLoader.defineClass(ClassLoader.java:763)
    at java.lang.ClassLoader.defineClass(ClassLoader.java:642)
    at oracle.dbtools.jarcl.JarClassLoader.findClass(JarClassLoader.java:77)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
    at oracle.dbtools.jarcl.Entrypoint.invoke(Entrypoint.java:50)
    at oracle.dbtools.jarcl.Entrypoint.main(Entrypoint.java:77)

2019-07-02 16:47:29.822:INFO::main: Logging initialized @3375ms to org.eclipse.jetty.util.log.StdErrLog
Jul 02, 2019 4:47:29 PM  
INFO: HTTP and HTTP/2 cleartext listening on port: 8080
Jul 02, 2019 4:47:29 PM  
INFO: Disabling document root because the specified folder does not exist: /Users/slinetsk/Downloads/ORDS/ords/standalone/doc_root
2019-07-02 16:47:30.632:INFO:oejs.Server:main: jetty-9.4.z-SNAPSHOT; built: 2019-02-20T15:50:58.683Z; git: 3285c4dd4bb00caddcded77f8e44e72c61b9ab72; jvm 1.8.0_211-b12
2019-07-02 16:47:30.693:INFO:oejs.session:main: DefaultSessionIdManager workerName=node0
2019-07-02 16:47:30.693:INFO:oejs.session:main: No SessionScavenger set, using defaults
2019-07-02 16:47:30.694:INFO:oejs.session:main: node0 Scavenging every 600000ms

There was no any AspectJ tracing related info in the output

Welcome to SO, Sergey. This is how it works here: First you learn what an [MCVE](http://stackoverflow.com/help/mcve) is and then you provide one, either inline in your question (click "edit") or you can add a link to a GitHub repository containing the MCVE (remove copyright-protected stuff first and just leave enough for me to build and run the application, e.g. via Maven, and reproduce the problem). The error log only is not enough for me to answer your question. — kriegaex, Jul 03 '19 at 03:22
Thank you. I do have an example but it does not qualify for the MCVE. It is VirtualBox's VM with Oracle DB and ORDS inside. The problem is that the VM images's size is 26GB. I hoped that the issue with the Jar classloader is already known. — Sergey Linetskiy, Jul 03 '19 at 20:44
I am sure that a simple Jetty setup also runs outside a container. And maybe the problem is also reproducible with another 3rd party library which does not require Oracle DB in the background. And even if it does need an Oracle library, probably the error occurs before a real DB access is being made, the stacktrace suggests classloading time. That should be reproducible. You want help? Help your potential helpers! By creating an MCVE you usually even learn more about your own problem. — kriegaex, Jul 04 '19 at 01:36
Everything worked fine with Jetty itself and I'll try to get access to the source of the ORDS to see how oracle.dbtools.jarcl is used (the part oracle.dbtools.jarcl.JarClassLoader.findClass(JarClassLoader.java:77 in the call stack) to create MCVE — Sergey Linetskiy, Jul 05 '19 at 16:26
Actually I downloaded ORDS and can reproduce the error. It looks like the Oracle's custom JAR classloader does something that the AspectJ weaving agent does not like but have no solution ready. I tried excluding the classloader via `-Daj.weaving.loadersToSkip=oracle.dbtools.jarcl.JarClassLoader`. This works, but then the weaver will not weave anything inside the library JARs anymore. You could create a custom WAR with the libraries of interest unzipped inside it. Ugly, but at least the weaver would find the target classes. — kriegaex, Jul 06 '19 at 03:51

kriegaex · Accepted Answer · 2019-07-08T07:17:23.660

I found a workaround which lets me run the server without problems and also use different types of aspect pointcuts on all sorts of classes such as internal Jetty classes:

Copy the AspectJ weaver and your aspect library (JAR containing aspects and META-INF/aop.xml) to a subdirectory lib of where you are starting your ords.war. Then append the aspect library to the JVM boot classpath. You need to use a JRE/JDK version like Java 8 which actually still supports the boot classpath. (Actually I just checked, JDK 11 still supports it.) I don't know how to do this with modularised JREs. Then start your WAR like this:

java -Xbootclasspath/a:lib/aspect.jar -javaagent:lib/aspectjweaver.jar -jar ords.war standalone

One more time, with line breaks inserted:

java
  -Xbootclasspath/a:lib/aspect.jar
  -javaagent:lib/aspectjweaver.jar
  -jar ords.war standalone

This approach makes sure that the weaver is attached and its as well as the aspect classes are found before the Oracle JAR classloader does its entry point magic.

Please note that you do not need to modify the WAR file at all here.

Update: As an alternative you could attach the AspectJ weaving agent dynamically instead of via -javaagent, see

I quickly tested it, it works. It is kind of tricky, though:

You would have to put your own main class similar to the one in the AspectJ read-me into the WAR as main class. That class would attach the weaver and then start the JAR classloader. Now the weaver is already in place and everything works as expected.
A caveat is that you need to start the JVM with tools.jar, myaspect.jar and aspectjweaver.jar on the classpath,
- either on boot classpath if you want to start the application with java -jar my.war
- or on the normal classpath You if it is okay to start the application with -cp ...;my.war my.own.MainClass.
Also since Java 9 there is no tools.jar anymore but you need to make your own entry point class dependent on the module jdk.attach and also make sure that you actually run the application with a JDK, not a JRE. Otherwise you cannot use the API for dynamically attaching agents.

All in all I still favour the original solution, it is much easier to implement.

I have created the MCVE which is the stripped version of the ORDS having only classloader components. It can be downloaded from here https://github.com/lsa5521/AJCUSTLOADERTEST. I have confirmed with this code that the proposed workaround does work. Thank you! — Sergey Linetskiy, Jul 08 '19 at 00:35
Then I would be happy to see you accept + upvote my answer, Sergey. Interesting question, it was my Sunday morning puzzle while drinking tea. ;-) — kriegaex, Jul 08 '19 at 01:51
I just updated the answer. I played around with another solution and verified it with my own project using another JAR classloader (because the problem is the same there in connection with load-time weaving). — kriegaex, Jul 08 '19 at 03:35
Another update: The original solution does not need the weaving agent JAR on the boot classpath, the aspect JAR is enough because the weaver is found via `-javaagent:lib\aspectjweaver.jar` anyway. — kriegaex, Jul 08 '19 at 07:11
I definitely accept the answer, as I have already mentioned, but I do not see how I can do it on the site. It seems that I do not have enough reputation points yet to do so — Sergey Linetskiy, Jul 08 '19 at 18:21
Below each question's vote counter should be a grey check mark. The question author can click on the one she wants to accept and make it go green. — kriegaex, Jul 09 '19 at 00:22

AspectJ with jar classloader

1 Answers1