LTW run via Unit Test not working

[gib]

Hi, been trying out the profiling example in the spring docs to weave private methods. Running via the main method the aspect is weaved into the code. Running via a unit test the aspect is not weaved.

The code is

package foo;

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

@Aspect
public class ProfilingAspect {
//    @Around("execution(* foo..*.*(..))")
    @Around("execution(* *.doSomethingPrivate(..))")
    public Object profile(ProceedingJoinPoint pjp) throws Throwable {
		System.out.println("Entered profiling aspect");
        StopWatch sw = new StopWatch(getClass().getSimpleName());
        try {
            sw.start(pjp.getSignature().getName());
            return pjp.proceed();
        } finally {
            sw.stop();
            System.out.println(sw.prettyPrint());
        }
    }
}

package foo;

import org.springframework.stereotype.Component;

@Component("Service")
public class Service {

	public void doSomethingPublic(){
		doSomethingPrivate();
	}

	private void doSomethingPrivate(){
		System.out.println("Hi there !");
	}
}

package foo;

import org.springframework.context.ApplicationContext;
import org.springframework.context.support.ClassPathXmlApplicationContext;

public final class Main {

	public static void main(String[] args) {

		ApplicationContext ctx = new ClassPathXmlApplicationContext("spring-config.xml");

			Service service	= (Service)ctx.getBean("Service");

			service.doSomethingPublic();
	}
}

package foo;

import javax.annotation.Resource;

import org.junit.Test;
import org.junit.runner.RunWith;
import org.springframework.test.context.ContextConfiguration;
import org.springframework.test.context.junit4.SpringJUnit4ClassRunner;

@RunWith(SpringJUnit4ClassRunner.class)
@ContextConfiguration(locations={"classpath:/spring-config.xml"})
public class FooTest {

	@Resource
	private Service service;

	@Test
	public final void testService(){
		service.doSomethingPublic();
	}
}

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0"
		 xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
		 xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
	<modelVersion>4.0.0</modelVersion>

	<groupId>SpringAOP</groupId>
	<artifactId>SpringAOP</artifactId>
	<version>1.0</version>
	<dependencies>
		<dependency>
			<groupId>org.springframework</groupId>
			<artifactId>spring-core</artifactId>
			<version>3.0.5.RELEASE</version>
		</dependency>
		<dependency>
			<groupId>org.springframework</groupId>
			<artifactId>spring-aspects</artifactId>
			<version>3.0.5.RELEASE</version>
		</dependency>
		<dependency>
			<groupId>org.springframework</groupId>
			<artifactId>spring-aop</artifactId>
			<version>3.0.5.RELEASE</version>
		</dependency>
		<dependency>
			<groupId>org.aspectj</groupId>
			<artifactId>aspectjrt</artifactId>
			<version>1.6.11</version>
		</dependency>
		<dependency>
			<groupId>org.aspectj</groupId>
			<artifactId>aspectjweaver</artifactId>
			<version>1.6.11</version>
		</dependency>
		<dependency>
			<groupId>org.springframework</groupId>
			<artifactId>spring-context</artifactId>
			<version>3.0.5.RELEASE</version>
		</dependency>
		<dependency>
			<groupId>org.springframework</groupId>
			<artifactId>spring-context-support</artifactId>
			<version>3.0.5.RELEASE</version>
		</dependency>
		<dependency>
			<groupId>org.springframework</groupId>
			<artifactId>spring-tx</artifactId>
			<version>3.0.5.RELEASE</version>
		</dependency>
		<dependency>
			<groupId>junit</groupId>
			<artifactId>junit</artifactId>
			<version>4.8.2</version>
			<scope>test</scope>
		</dependency>

	</dependencies>

	<build>
		<plugins>
			<plugin>
				<artifactId>maven-compiler-plugin</artifactId>
				<version>2.3.2</version>
				<configuration>
					<source>1.6</source>
					<target>1.6</target>
					<encoding>US-ASCII</encoding>
				</configuration>
			</plugin>
		</plugins>
	</build>

</project>

<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans"
	   xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:aop="http://www.springframework.org/schema/aop"
	   xmlns:context="http://www.springframework.org/schema/context"
	   xsi:schemaLocation="http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans.xsd http://www.springframework.org/schema/aop http://www.springframework.org/schema/aop/spring-aop-2.0.xsd http://www.springframework.org/schema/context http://www.springframework.org/schema/context/spring-context.xsd">

	<context:component-scan base-package="foo"/>
	<context:annotation-config/>

	<!-- Switches on aspectj via spring -->
	<aop:aspectj-autoproxy/>

	<!-- this switches on the load-time weaving -->
	<context:load-time-weaver/>

</beans>

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

	<weaver options="-showWeaveInfo -verbose">
		<!-- only weave classes in our application-specific packages -->
		<include within="foo.*"/>
	</weaver>

	<aspects>
		<!-- weave in just this aspect -->
		<aspect name="foo.ProfilingAspect"/>
	</aspects>

</aspectj>

Turning on verbose for the weaver I can see it finds the aop.xml and is registering the aspect as in

INFO: Found Spring's JVM agent for instrumentation
[AppClassLoader@130c19b] info AspectJ Weaver Version 1.6.11 built on Tuesday Mar 15, 2011 at 15:31:04 GMT
[AppClassLoader@130c19b] info register classloader sun.misc.Launcher$AppClassLoader@130c19b
[AppClassLoader@130c19b] info using configuration /C:/Working/dev/work/Research/SpringAOP/target/classes/META-INF/aop.xml
[AppClassLoader@130c19b] info using configuration file:/C:/Working/dev/mavenrepository/org/springframework/spring-aspects/3.0.5.RELEASE/spring-aspects-3.0.5.RELEASE.jar!/META-INF/aop.xml
[AppClassLoader@130c19b] info register aspect foo.ProfilingAspect
[AppClassLoader@130c19b] info register aspect org.springframework.beans.factory.aspectj.AnnotationBeanConfigurerAspect
[AppClassLoader@130c19b] info register aspect org.springframework.scheduling.aspectj.AnnotationAsyncExecutionAspect
[AppClassLoader@130c19b] info register aspect org.springframework.transaction.aspectj.AnnotationTransactionAspect
29-Sep-2011 09:00:24 org.springframework.beans.factory.support.DefaultListableBeanFactory preInstantiateSingletons
INFO: Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@11e1e67: defining beans [Service,org.springframework.context.annotation.internalConfigurationAnnotationProcessor,org.springframework.context.annotation.internalAutowiredAnnotationProcessor,org.springframework.context.annotation.internalRequiredAnnotationProcessor,org.springframework.context.annotation.internalCommonAnnotationProcessor,org.springframework.aop.config.internalAutoProxyCreator,org.springframework.context.weaving.AspectJWeavingEnabler#0,org.springframework.context.config.internalBeanConfigurerAspect,loadTimeWeaver]; root of factory hierarchy
Hi there !

But it's missing the actual weave from

INFO: Found Spring's JVM agent for instrumentation
[AppClassLoader@130c19b] info AspectJ Weaver Version 1.6.11 built on Tuesday Mar 15, 2011 at 15:31:04 GMT
[AppClassLoader@130c19b] info register classloader sun.misc.Launcher$AppClassLoader@130c19b
[AppClassLoader@130c19b] info using configuration /C:/Working/dev/work/Research/SpringAOP/target/classes/META-INF/aop.xml
[AppClassLoader@130c19b] info using configuration file:/C:/Working/dev/mavenrepository/org/springframework/spring-aspects/3.0.5.RELEASE/spring-aspects-3.0.5.RELEASE.jar!/META-INF/aop.xml
[AppClassLoader@130c19b] info register aspect foo.ProfilingAspect
[AppClassLoader@130c19b] info register aspect org.springframework.beans.factory.aspectj.AnnotationBeanConfigurerAspect
[AppClassLoader@130c19b] info register aspect org.springframework.scheduling.aspectj.AnnotationAsyncExecutionAspect
[AppClassLoader@130c19b] info register aspect org.springframework.transaction.aspectj.AnnotationTransactionAspect
29-Sep-2011 09:06:52 org.springframework.beans.factory.support.DefaultListableBeanFactory preInstantiateSingletons
INFO: Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@89cf1e: defining beans [Service,org.springframework.context.annotation.internalConfigurationAnnotationProcessor,org.springframework.context.annotation.internalAutowiredAnnotationProcessor,org.springframework.context.annotation.internalRequiredAnnotationProcessor,org.springframework.context.annotation.internalCommonAnnotationProcessor,org.springframework.aop.config.internalAutoProxyCreator,org.springframework.context.weaving.AspectJWeavingEnabler#0,org.springframework.context.config.internalBeanConfigurerAspect,loadTimeWeaver]; root of factory hierarchy
[AppClassLoader@130c19b] weaveinfo Join point 'method-execution(void foo.Service.doSomethingPrivate())' in Type 'foo.Service' (Service.java:13) advised by around advice from 'foo.ProfilingAspect' (ProfilingAspect.java)
Entered profiling aspect
Hi there !
StopWatch 'ProfilingAspect': running time (millis) = 0
-----------------------------------------
ms     %     Task name
-----------------------------------------
00000  �  doSomethingPrivate

Any ideas why this isn't working ?

Thanks

[Enrico Pizzi]

Have you correctly activated instrumentation (javaagent) for JUnit execution of your tests? Most of the time people forget this fundamental step...

[gib]

Well I provided -javaagent:C:/dev/tools/spring-framework-3.0.6.RELEASE/dist/org.springframework.instrument-3.0.6.RELEASE.jar

I assumed without this you wouldn't see any logging such as INFO: Found Spring's JVM agent for instrumentation etc

[Enrico Pizzi]

Correct, sorry I didn't read through the logs you posted. The javaagent is there but it seems that JUnit is using a different classloader to execute the tests. If AppClassLoader@130c19b was used this would 100% result in the aspect being correctly applied since it's been loaded. How are you executing the tests? Through the IDE (Eclipse, NetBeans), through Maven Surefire, or directly by command line?

[gib]

IDE - Intellij

[gib]

Appears to fail running via the maven surefile plugin with

<plugin>
<groupId>org.apache.maven.plugins</groupId>
<artifactId>maven-surefire-plugin</artifactId>
<version>2.4</version>
<configuration>
<forkMode>once</forkMode>
<argLine>
-javaagent:C:/dev/tools/spring-framework-3.0.6.RELEASE/dist/org.springframework.instrument-3.0.6.RELEASE.jar
</argLine>
<useSystemClassloader>true</useSystemClassloader>
</configuration>
</plugin>
</plugins>

[Enrico Pizzi]

I would try to execute the tests standalone. My guess is that the ide is somehow interfering and using its own classloaders to execute the tests (even though the instrumented classloader gets correctly instantiated by JUnit).

On a side note I suggest the use of Maven to handle your project's lifecycle, including the tests.

[Enrico Pizzi]

To do AspectJ unit tests with Maven correctly you should follow this guide.

[gib]

Not sure I really follow that, why would you use the maven aspect plugin when you are using LTW ?