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
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*
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 ?