Can't add javaagent for AspectJ

Viewed 537

I have an old Java6 Application, and I'm trying to add some automatic and global log for tracing every call in every method. It runs on a JBoss 4.2.3.

I follow this example : https://docs.spring.io/spring-framework/docs/current/reference/html/core.html#aop-aj-ltw-first-example

I have my profiling class :

package com.al6.borneIntranet.business.log;

import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Pointcut;
import org.springframework.util.StopWatch;
import org.springframework.core.annotation.Order;

@Aspect
public class ProfilingAspect {

    @Around("methodsToBeProfiled()")
    public Object profile(ProceedingJoinPoint pjp) throws Throwable {
        StopWatch sw = new StopWatch(getClass().getSimpleName());
        try {
            sw.start(pjp.getSignature().getName());
            return pjp.proceed();
        } finally {
            sw.stop();
            System.out.println(sw.prettyPrint());
        }
    }

    @Pointcut("execution(public * com.al6.borneIntranet..*.*(..))")
    public void methodsToBeProfiled(){}
}

I create a META-INF/aop.xml file :

<!DOCTYPE aspectj PUBLIC "-//AspectJ//DTD//EN" "https://www.eclipse.org/aspectj/dtd/aspectj.dtd">
<aspectj>

    <weaver>
        <!-- only weave classes in our application-specific packages -->
        <include within="com.al6.*"/>
    </weaver>

    <aspects>
        <!-- weave in just this aspect -->
        <aspect name="com.al6.borneIntranet.business.log.ProfilingAspect"/>
    </aspects>

</aspectj>

I add this line in my bean definitions xml :

<context:load-time-weaver/>

And I have this dependencies :

<dependency>
    <groupId>org.springframework</groupId>
    <artifactId>spring-core</artifactId>
    <version>4.0.6.RELEASE</version>
</dependency>
<dependency>
    <groupId>org.springframework</groupId>
    <artifactId>spring-context</artifactId>
    <version>4.0.6.RELEASE</version>
</dependency>
<dependency>
    <groupId>org.springframework</groupId>
    <artifactId>spring-context-support</artifactId>
    <version>4.0.6.RELEASE</version>
</dependency>
<dependency>
    <groupId>org.springframework</groupId>
    <artifactId>spring-aop</artifactId>
    <version>4.0.6.RELEASE</version>
</dependency>
<dependency>
    <groupId>org.aspectj</groupId>
    <artifactId>aspectjrt</artifactId>
    <version>1.8.9</version>
</dependency>
<dependency>
    <groupId>org.aspectj</groupId>
    <artifactId>aspectjweaver</artifactId>
    <version>1.8.9</version>
</dependency>
<dependency>
  <groupId>org.springframework</groupId>
  <artifactId>spring-instrument</artifactId>
  <version>4.0.6.RELEASE</version>
</dependency>

It almost works, but I have this error at startup when I use the application :

2021-04-29 18:41:46,960 ERROR [STDERR] org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'org.springframework.context.weaving.AspectJWeavingEnabler#0': Initialization of bean failed; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'loadTimeWeaver': Initialization of bean failed; nested exception is java.lang.IllegalStateException: ClassLoader [org.jboss.mx.loading.UnifiedClassLoader3] does NOT provide an 'addTransformer(ClassFileTransformer)' method. Specify a custom LoadTimeWeaver or start your Java virtual machine with Spring's agent: -javaagent:org.springframework.instrument.jar 

I download the spring-instrument-4.0.6.RELEASE.jar file from maven repository, then I add the javaagent part in the run startup script :

/opt/jdk/bin/java -Dprogram.name=run.sh -javaagent:/opt/jboss/lib/org.springframework.instrument.jar -server -Xms2048m -Xmx2048m -XX:MaxPermSize=256M ...

But the error still appear, like I'm doing nothing.

Is there a way to not add this option at startup easily ? Why even when I add it it is not used ?

EDIT :

I try to add the adspectj launch agent, didn't work either, same error, it looks like the option is not detected by the application :

/bin/sh /opt/jboss/bin/run.sh -c commandes -b 0.0.0.0 -Djboss.partition.name=jboss-commande-preprod1-partition 
admin    22263 47.6 76.7 4911056 4023536 pts/0 Sl   16:03   2:14 /opt/jdk/bin/java -Dprogram.name=run.sh -javaagent:/opt/jboss/lib/aspectjweaver-1.8.9.jar -javaagent:/opt/jboss/lib/org.springframework.instrument.jar -server -Xms3500m -Xmx
3500m -XX:MaxPermSize=512M -Dfile.encoding=UTF-8 -Djava.awt.headless=true -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=9999 -Dc
om.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false -XX:+UseG1GC -Xrunjdwp:transport=dt_socket,address=8787,server=y,suspend=n -Djava.net.prefer
IPv4Stack=true -Djava.endorsed.dirs=/opt/jboss/lib/endorsed -classpath /opt/jboss/bin/run.jar:/opt/jdk/lib/tools.jar org.jboss.Main -c commandes -b 0.0.0.0 -Djboss.partition.name=jboss-commande-preprod1-partition

EDIT 2 :

Try few things :

  • Using Jboss timeweaver :

    Error creating bean with name 'loadTimeWeaver': Instantiation of bean failed; nested exception is org.springframework.beans.BeanInstantiationException: Could not instantiate bean class [org.springframework.instrument.classloading.jboss.JBossLoadTimeWeaver]: Constructor threw exception; nested exception is java.lang.IllegalStateException: Could not initialize JBoss LoadTimeWeaver because the JBoss 6 API classes are not available

Of course, I'm on Jboss 4.3.2

  • Adding "-verbose -showWeaveInfo -debug" in aop.xml :

The file is detected because I have this lines at startup :

2021-05-03 15:11:42,267 ERROR [STDERR] [UnifiedClassLoader3@341a736] info AspectJ Weaver Version 1.8.9 built on Monday Mar 14, 2016 at 21:18:16 GMT
2021-05-03 15:11:43,253 ERROR [STDERR] [UnifiedClassLoader3@341a736] info register classloader org.jboss.mx.loading.UnifiedClassLoader3@341a736
2021-05-03 15:11:43,253 ERROR [STDERR] [UnifiedClassLoader3@341a736] info using configuration file:/opt/jboss-4.2.3.GA/server/weldom_commandes/tmp/deploy/tmp6458410370486804467BorneIntranetServeurMetier.ear-contents/BorneIntranetServeurMetier.jar!/META-INF/aop.xml
2021-05-03 15:11:43,253 ERROR [STDERR] [UnifiedClassLoader3@341a736] info using configuration file:/opt/jboss-4.2.3.GA/server/weldom_commandes/tmp/deploy/tmp6458410370486804467BorneIntranetServeurMetier.ear-contents/spring-aspects-4.0.6.RELEASE.jar!/META-INF/aop.xml
2021-05-03 15:11:43,259 ERROR [STDERR] [UnifiedClassLoader3@341a736] info register aspect com.al6.borneIntranet.business.log.ProfilingAspect
2021-05-03 15:11:43,474 ERROR [STDERR] [UnifiedClassLoader3@341a736] info register aspect org.springframework.beans.factory.aspectj.AnnotationBeanConfigurerAspect
2021-05-03 15:11:43,520 ERROR [STDERR] [UnifiedClassLoader3@341a736] info register aspect org.springframework.scheduling.aspectj.AnnotationAsyncExecutionAspect
2021-05-03 15:11:43,536 ERROR [STDERR] [UnifiedClassLoader3@341a736] info register aspect org.springframework.transaction.aspectj.AnnotationTransactionAspect
2021-05-03 15:11:43,544 ERROR [STDERR] [UnifiedClassLoader3@341a736] info register aspect org.springframework.cache.aspectj.AnnotationCacheAspect
2021-05-03 15:11:43,559 ERROR [STDERR] [UnifiedClassLoader3@341a736] debug not weaving 'com.al6.borneIntranet.business.ServiceArchiveEntryPointBean'
...
  • When I put :

    <context:load-time-weaver
              weaver-class="org.springframework.instrument.classloading.InstrumentationLoadTimeWeaver"/>
    

I have a slightly different error, but same result :

2021-05-03 15:15:03,475 ERROR [STDERR] java.lang.IllegalStateException: Must start with Java agent to use InstrumentationLoadTimeWeaver. See Spring documentation.
2021-05-03 15:15:03,476 ERROR [STDERR]  at org.springframework.instrument.classloading.InstrumentationLoadTimeWeaver.addTransformer(InstrumentationLoadTimeWeaver.java:88)

But I already add it :

-javaagent:/opt/jboss/lib/org.springframework.instrument.jar

ls -lrt /opt/jboss/lib : 
-rwxrwxrwx 1 admin users 7244 2021-04-30 16:03 /opt/jboss/lib/org.springframework.instrument.jar*
2 Answers

Can't find why load-time weaving don't work.

So, somebody at my work just ask me why I want to do loadtime weaving, why don't just do "compile time weaving".

I just add this in my pom.xml :

<plugin>
    <groupId>org.codehaus.mojo</groupId>
    <artifactId>aspectj-maven-plugin</artifactId>
    <version>1.7</version>
    <configuration>
        <complianceLevel>1.6</complianceLevel>
        <source>1.6</source>
        <target>1.6</target>
        <showWeaveInfo>true</showWeaveInfo>
        <verbose>true</verbose>
        <Xlint>ignore</Xlint>
        <encoding>UTF-8 </encoding>
    </configuration>
    <executions>
        <execution>
            <goals>
                <!-- use this goal to weave all your main classes -->
                <goal>compile</goal>
            </goals>
        </execution>
    </executions>
</plugin>

I delete javaagent things.

Build, run, and tada, it's working.

I can't understand why almost nobody talk about this method, which does not require adding anything in startup arguments, anything complex, and it works much much easier.

Is there a big inconvenient at this ? In fact, I wonder if it's not even better, because it weave classes at compile time, so it will be using less system ressource ?

I am not a Spring user, but when answering AspectJ LTW questions here I often noticed a certain discrepancy between the Spring documentation mentioning the need for the Spring Instrument Java agent only and the real situation in which there are ways to configure Spring like that, but it is tricky. The simplest approach by far is to also add the AspectJ Weaver agent to the command line, i.e. to use something like (on a single line, of course)

# AspectJ LTW
-javaagent:/path/to/aspectjweaver.jar
# Spring Instrument
-javaagent:/path/to/org.springframework.instrument.jar

Maybe the AspectJ Weaver is enough already, it depends on your use case.


Update after the OP updated his question:

  • Do you see any sign of the AspectJ weaver being loaded in your application server log? Scan for strings like AspectJ Weaver Version, register classloader or using configuration .../aop.xml. If you correctly added aspectjweaver.jar and META-INF/aop.xml to the project, you should see something like that, even if for some reason the aspect does not get triggered.
  • Make sure that META-INF/aop.xml is found by the Java process. It is located via Classloader.getResource() by AspectJ. So whatever location or JAR you put it in, make sure that location is on the classpath. Experimentally, you could add a local directory to the classpath and see if the JVM finds the XML file there. Then, you can start to refine your approach if it is found this way.
  • BTW, I see <include within="com.al6.*"/> which would only match classes directly in package com.al6. If you want to include subpackages, you need to use the .. syntax, i.e. <include within="com.al6..*"/>.
  • Furthermore, you linked to a how-to in the latest Spring manual with regard to native AspectJ + LTW configuration. You should rather use the Spring 4.0.6 documentation, because you use that legacy version. I already sent you a link in my comment under your previous question.

Please, first try to get the strings I mentioned in the first bullet point displayed by adding -javaagent:/path/to/aspectjweaver.jar, before you try anything else. Only then, you might want to optimise or fine-tune:

For JBoss there is a special JBossLoadTimeWeaver. It should be auto-detected, but you could also specify it manually, see this table of default weavers.

Related