Spring: Do I need @EnableAspectJAutoProxy with Compile time weaving?

Question

I've looked around the internet and found a few suggestions, and also tried different configurations, but I'm totally unsure if it works correctly.

pom.xml (full pom.xml: http://pastebin.com/5Y2qksTH ):

<build>
    <pluginManagement>
        <plugins>
            <plugin>
                <groupId>org.eclipse.m2e</groupId>
                <artifactId>lifecycle-mapping</artifactId>
                <version>1.0.0</version>
                <configuration>
                    <lifecycleMappingMetadata>
                        <pluginExecutions>
                            <pluginExecution>
                                <pluginExecutionFilter>
                                    <groupId>org.codehaus.mojo</groupId>
                                    <artifactId>aspectj-maven-plugin</artifactId>
                                    <versionRange>[1.0,)</versionRange>
                                    <goals>
                                        <goal>test-compile</goal>
                                        <goal>compile</goal>
                                    </goals>
                                </pluginExecutionFilter>
                                <action>
                                    <execute>
                                        <runOnConfiguration>true</runOnConfiguration>
                                        <runOnIncremental>true</runOnIncremental>
                                    </execute>
                                </action>
                            </pluginExecution>
                        </pluginExecutions>
                    </lifecycleMappingMetadata>
                </configuration>
            </plugin>
        </plugins>
    </pluginManagement>

    <plugins>
        <plugin>
            <groupId>org.codehaus.mojo</groupId>
            <artifactId>aspectj-maven-plugin</artifactId>
            <version>1.5</version>
            <configuration>
                <Xlint>warning</Xlint>
                <complianceLevel>1.7</complianceLevel>
                <source>1.7</source>
                <target>1.7</target>
                <encoding>UTF-8</encoding>
                <aspectLibraries>
                    <aspectLibrary>
                        <groupId>org.springframework</groupId>
                        <artifactId>spring-aspects</artifactId>
                    </aspectLibrary>
                </aspectLibraries>
            </configuration>
            <executions>
                <execution>
                    <goals>
                        <goal>compile</goal>
                        <goal>test-compile</goal>
                    </goals>
                </execution>
            </executions>
        </plugin>
    </plugins>
</build>

I've added

<execute>
    <runOnConfiguration>true</runOnConfiguration>
    <runOnIncremental>true</runOnIncremental>
</execute>

because before it seemed like I always had to do Project -> Clean in Eclipse and afterwards Tomcat -> Clean. Else it always executed my cached method. Now it seems to work automatically.

CacheableConfig.java:

@EnableCaching(mode = AdviceMode.ASPECTJ)
public class CacheableConfig implements CachingConfigurer {
    @Override
    public CacheManager cacheManager() {
        return new ConcurrentMapCacheManager("testCache");
    }

    @Override
    public KeyGenerator keyGenerator() {
        return new SimpleKeyGenerator();
    }
}

AppConfig.java:

@EnableAspectJAutoProxy
public class AppConfig {}

Without @EnableAspectJAutoProxy it didn't work at all.

MyTestServiceImpl.java:

@Service
public class MyTestServiceImpl implements MyTestService {
    @Scheduled(initialDelay=10000, fixedDelay=30000)
    public void a() {
        long time = System.currentTimeMillis();
        System.out.println("START");
        System.out.println("returned: " + b(0));
        System.out.println("returned: " + b(1));
        System.out.println("returned: " + b(0));
        System.out.println("returned: " + b(1));
        System.out.println("returned: " + b(2));
        System.out.println("END: " + (System.currentTimeMillis() - time));
    }

    @Cacheable("testCache")
    public int b(int i) {
        System.out.println("INSIDE CACHED METHOD");
        i++;
        try {
            Thread.sleep(2000);
        } catch(InterruptedException ex) {}
        return i;
    }
}

Note: I just use @Scheduled in order to automatically invoke the method multiple times.

Output:

START
2014-03-01 15:53:25,796 DEBUG    o.s.c.annotation.AnnotationCacheOperationSource: 109 - Adding cacheable method 'b' with attribute: [CacheableOperation[public int MyTestServiceImpl.b(int)] caches=[testCache] | key='' | condition='' | unless='']
2014-03-01 15:53:25,797 TRACE            o.s.cache.aspectj.AnnotationCacheAspect: 318 - Computed cache key 0 for operation CacheableOperation[public int MyTestServiceImpl.b(int)] caches=[testCache] | key='' | condition='' | unless=''
INSIDE CACHED METHOD
returned: 1
2014-03-01 15:53:27,798 TRACE            o.s.cache.aspectj.AnnotationCacheAspect: 318 - Computed cache key 1 for operation CacheableOperation[public int MyTestServiceImpl.b(int)] caches=[testCache] | key='' | condition='' | unless=''
INSIDE CACHED METHOD
returned: 2
2014-03-01 15:53:29,799 TRACE            o.s.cache.aspectj.AnnotationCacheAspect: 318 - Computed cache key 0 for operation CacheableOperation[public int MyTestServiceImpl.b(int)] caches=[testCache] | key='' | condition='' | unless=''
2014-03-01 15:53:29,799 TRACE            o.s.cache.aspectj.AnnotationCacheAspect: 318 - Computed cache key 0 for operation CacheableOperation[public int MyTestServiceImpl.b(int)] caches=[testCache] | key='' | condition='' | unless=''
returned: 1
2014-03-01 15:53:29,799 TRACE            o.s.cache.aspectj.AnnotationCacheAspect: 318 - Computed cache key 1 for operation CacheableOperation[public int MyTestServiceImpl.b(int)] caches=[testCache] | key='' | condition='' | unless=''
2014-03-01 15:53:29,799 TRACE            o.s.cache.aspectj.AnnotationCacheAspect: 318 - Computed cache key 1 for operation CacheableOperation[public int MyTestServiceImpl.b(int)] caches=[testCache] | key='' | condition='' | unless=''
returned: 2
2014-03-01 15:53:29,799 TRACE            o.s.cache.aspectj.AnnotationCacheAspect: 318 - Computed cache key 2 for operation CacheableOperation[public int MyTestServiceImpl.b(int)] caches=[testCache] | key='' | condition='' | unless=''
INSIDE CACHED METHOD
returned: 3
END: 6018

START
2014-03-01 15:54:01,801 TRACE            o.s.cache.aspectj.AnnotationCacheAspect: 318 - Computed cache key 0 for operation CacheableOperation[public int MyTestServiceImpl.b(int)] caches=[testCache] | key='' | condition='' | unless=''
2014-03-01 15:54:01,801 TRACE            o.s.cache.aspectj.AnnotationCacheAspect: 318 - Computed cache key 0 for operation CacheableOperation[public int MyTestServiceImpl.b(int)] caches=[testCache] | key='' | condition='' | unless=''
returned: 1
2014-03-01 15:54:01,801 TRACE            o.s.cache.aspectj.AnnotationCacheAspect: 318 - Computed cache key 1 for operation CacheableOperation[public int MyTestServiceImpl.b(int)] caches=[testCache] | key='' | condition='' | unless=''
2014-03-01 15:54:01,801 TRACE            o.s.cache.aspectj.AnnotationCacheAspect: 318 - Computed cache key 1 for operation CacheableOperation[public int MyTestServiceImpl.b(int)] caches=[testCache] | key='' | condition='' | unless=''
returned: 2
2014-03-01 15:54:01,801 TRACE            o.s.cache.aspectj.AnnotationCacheAspect: 318 - Computed cache key 0 for operation CacheableOperation[public int MyTestServiceImpl.b(int)] caches=[testCache] | key='' | condition='' | unless=''
2014-03-01 15:54:01,802 TRACE            o.s.cache.aspectj.AnnotationCacheAspect: 318 - Computed cache key 0 for operation CacheableOperation[public int MyTestServiceImpl.b(int)] caches=[testCache] | key='' | condition='' | unless=''
returned: 1
2014-03-01 15:54:01,802 TRACE            o.s.cache.aspectj.AnnotationCacheAspect: 318 - Computed cache key 1 for operation CacheableOperation[public int MyTestServiceImpl.b(int)] caches=[testCache] | key='' | condition='' | unless=''
2014-03-01 15:54:01,802 TRACE            o.s.cache.aspectj.AnnotationCacheAspect: 318 - Computed cache key 1 for operation CacheableOperation[public int MyTestServiceImpl.b(int)] caches=[testCache] | key='' | condition='' | unless=''
returned: 2
2014-03-01 15:54:01,802 TRACE            o.s.cache.aspectj.AnnotationCacheAspect: 318 - Computed cache key 2 for operation CacheableOperation[public int MyTestServiceImpl.b(int)] caches=[testCache] | key='' | condition='' | unless=''
2014-03-01 15:54:01,802 TRACE            o.s.cache.aspectj.AnnotationCacheAspect: 318 - Computed cache key 2 for operation CacheableOperation[public int MyTestServiceImpl.b(int)] caches=[testCache] | key='' | condition='' | unless=''
returned: 3
END: 1

This basically looks okay:

• First call of a() takes 6 seconds, because b() gets called effectively 3 times.
• Second call of a() takes 1ms, because everything comes from cache.
• Return values are okay.

Questions:

1. Why are those TRACE logs Computed cache key x for operation ... there always two times? Looks to me like the computation method gets called twice?!

2. Is the configuration okay? Because I'm not really sure if this will always work as expected, especially because I had to use Project -> Clean and Tomcat -> Clean sometimes. (else it just ignored the @Cacheable annotation and simple called the method)

Thank you!

Answer 1

First of all your current setup will never work with @EnableAspectJAutoProxy. Spring AOP uses proxies to apply aspects. Your @Scheduled calls the method internally and as such will never pass through the proxy and you will never have caching.

Next to that you use compile time weaving so you shouldn't use @EnableAspectJAutoProxy as the aspects are already weaved in. If that isn't working you have a problem in the setup of your pom together with your Eclipse.

Trying to get Eclipse and Maven working together is (or can be) a daunting task. Regarding AspectJ and Maven see aspectj-maven-plugin not covered by lifecycle in Kepler and this blog might also be helpful.