Saturday, January 19, 2013

More fun with @Cacheable


I am assuming the audience has already got themselves familiar with the previous post where vanilla cache operations were demonstrated. The scope of this post will be:
  • Using multiple cache managers in a context
  • Using aspectj to cache self calls
  • Using cache:advice to cache non-owned calls
Using multiple cache managers in a context
So continuing from the fibonacci example from before, let's say that I wish to use both the simple cache manager as well as the ehcache cache manager? As with the pitfalls in using tx:annotation-driven, only one manager can effectively parade the annotations in the desired way. In tx:annotation-driven, we specify the transaction manager to use in the annotation itself, whereas such a thing is not available in the cache:annotation-driven (yet). Hence, when two cache managers wish to operate in tandem, enter org.springframework.cache.support.CompositeCacheManager. This specifies the list of cache managers that need to be used.
    <bean id="compositeCacheManager" class="org.springframework.cache.support.CompositeCacheManager">
        <property name="cacheManagers">
            <array>
                <ref bean="ehcacheManager" />
                <ref bean="concurrentMapCacheManager" />
            </array>
        </property>
    </bean>
The directive to process the annotation will refer to this compositeCacheManager as the sole manager
    <cache:annotation-driven cache-manager="compositeCacheManager" proxy-target-class="true"
        />
The output can be verified as showing each of the two cache managers operating without treading on each other's toes.
[ 2013-01-18 15:28:36,226 [main] driver.SpringCacheTesterDriver.doHeavyLifting():52  INFO ]: com.kilo.driver.ConcurrentMapFibonacciServiceImpl$$EnhancerByCGLIB$$a3241f9a took 7.586 seconds
[ 2013-01-18 15:28:36,227 [main] driver.SpringCacheTesterDriver.doHeavyLifting():52  INFO ]: com.kilo.driver.ConcurrentMapFibonacciServiceImpl$$EnhancerByCGLIB$$a3241f9a took 0.001 seconds
[ 2013-01-18 15:28:36,227 [main] driver.SpringCacheTesterDriver.doHeavyLifting():52  INFO ]: com.kilo.driver.ConcurrentMapFibonacciServiceImpl$$EnhancerByCGLIB$$a3241f9a took 0.0 seconds
[ 2013-01-18 15:28:36,227 [main] driver.ConcurrentMapFibonacciServiceImpl.flushFibonacciCache():30  INFO ]: Royal ConcurrentMap flush
[ 2013-01-18 15:28:43,797 [main] driver.SpringCacheTesterDriver.doHeavyLifting():52  INFO ]: com.kilo.driver.ConcurrentMapFibonacciServiceImpl$$EnhancerByCGLIB$$a3241f9a took 7.569 seconds
[ 2013-01-18 15:28:43,797 [main] driver.ConcurrentMapFibonacciServiceImpl.flushFibonacciCache():30  INFO ]: Royal ConcurrentMap flush
[ 2013-01-18 15:28:51,247 [main] driver.SpringCacheTesterDriver.doHeavyLifting():52  INFO ]: com.kilo.driver.EhcacheFibonacciServiceImpl$$EnhancerByCGLIB$$73a5e038 took 7.449 seconds
[ 2013-01-18 15:28:51,247 [main] driver.SpringCacheTesterDriver.doHeavyLifting():52  INFO ]: com.kilo.driver.EhcacheFibonacciServiceImpl$$EnhancerByCGLIB$$73a5e038 took 0.0 seconds
[ 2013-01-18 15:28:51,247 [main] driver.SpringCacheTesterDriver.doHeavyLifting():52  INFO ]: com.kilo.driver.EhcacheFibonacciServiceImpl$$EnhancerByCGLIB$$73a5e038 took 0.0 seconds
[ 2013-01-18 15:28:51,253 [main] driver.EhcacheFibonacciServiceImpl.flushFibonacciCache():30  INFO ]: Royal Ehcache flush
[ 2013-01-18 15:28:58,850 [main] driver.SpringCacheTesterDriver.doHeavyLifting():52  INFO ]: com.kilo.driver.EhcacheFibonacciServiceImpl$$EnhancerByCGLIB$$73a5e038 took 7.597 seconds
[ 2013-01-18 15:28:58,853 [main] driver.EhcacheFibonacciServiceImpl.flushFibonacciCache():30  INFO ]: Royal Ehcache flush
Using aspectj to cache self calls
Now let's get into some AspectJ magic! It would be worthwhile to spend a few minutes knowing how load time weaving (LTW) lends itself to processing annotations. There is anentire section in the Spring documentation that outlines the interactions in detail. In a nutshell, contrasting with the proxy based approach, the logic before/after/around a call is embedded in the bytecode of the class as the class is being loaded into the JVM. The JVM provides hook-ins via the java.lang.instrument.ClassFileTransformers route which can be configured per classloader. Since this logic is now part of the bytecode loaded in the JVM itself, any and all calls will have access to the logic coded for before/after/around calls. We will discover more as we take the tour. In our example for the concurrent map and ehcache based cached services, we were only storing the results for the fibonacci with index 45 and not the ones preceding it - and we gave the reason as the mode being proxy which doesn't support self calls (recursive or public/private/protected). Let's say we do want to achieve the benefits of the intermediate fetches as well, we should switch over to using the aspectj mode. Here are the set of steps you need to do and why:
Add maven dependencies for spring-aspects (which pulls in aspectj related jars)
        <!-- for mode aspectj -->
        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-aspects</artifactId>
            <version>${spring.version}</version>
        </dependency>
        <dependency>
            <groupId>org.aspectj</groupId>
            <artifactId>aspectjweaver</artifactId>
            <version>1.6.11</version>
            <scope>runtime</scope>
        </dependency>
    <cache:annotation-driven cache-manager="compositeCacheManager" mode="aspectj" />
Informs Spring that we need to use aspectj for processing the annotations.
    <context:load-time-weaver/>
Inform spring to load time weave the bytecode for the beans that have been annotated. IMHO, specifying #2 should have automatically caused #3, but it is not - so we live with it.
-javaagent:/u/baigm/winnt/.m2/repository/org/springframework/spring-instrument/3.1.3.RELEASE/spring-instrument-3.1.3.RELEASE.jar
Specify the javaagent that will do the actual work of instrumenting the bytecode. From Java 5 onwards, java has built in support for agents that can help with instrumentation related activities which come out-of-the-box in most JEE containers. If you are not running in a JEE container (like Tomcat) or running a standalone java application, Spring provides a lightweight instrumentation jar that provides the implementation of a LoadTimeWeaver (viz. InstrumentationLoadTimeWeaver). So you need to add this to your launch configuration in your eclipse or to your invocation if outside eclipse.
And you are all set! Run the driver to see that the initial run itself now finishes in much under a second.
[ 2013-01-18 16:05:10,306 [main] driver.SpringCacheTesterDriver.doHeavyLifting():52  INFO ]: com.kilo.driver.ConcurrentMapFibonacciServiceImpl took 0.074 seconds
[ 2013-01-18 16:05:10,306 [main] driver.SpringCacheTesterDriver.doHeavyLifting():52  INFO ]: com.kilo.driver.ConcurrentMapFibonacciServiceImpl took 0.0 seconds
[ 2013-01-18 16:05:10,306 [main] driver.SpringCacheTesterDriver.doHeavyLifting():52  INFO ]: com.kilo.driver.ConcurrentMapFibonacciServiceImpl took 0.0 seconds
[ 2013-01-18 16:05:10,313 [main] driver.ConcurrentMapFibonacciServiceImpl.flushFibonacciCache_aroundBody2():30  INFO ]: Royal ConcurrentMap flush
[ 2013-01-18 16:05:10,317 [main] driver.SpringCacheTesterDriver.doHeavyLifting():52  INFO ]: com.kilo.driver.ConcurrentMapFibonacciServiceImpl took 0.004 seconds
[ 2013-01-18 16:05:10,317 [main] driver.ConcurrentMapFibonacciServiceImpl.flushFibonacciCache_aroundBody2():30  INFO ]: Royal ConcurrentMap flush
[ 2013-01-18 16:05:10,354 [main] driver.SpringCacheTesterDriver.doHeavyLifting():52  INFO ]: com.kilo.driver.EhcacheFibonacciServiceImpl took 0.037 seconds
[ 2013-01-18 16:05:10,355 [main] driver.SpringCacheTesterDriver.doHeavyLifting():52  INFO ]: com.kilo.driver.EhcacheFibonacciServiceImpl took 0.001 seconds
[ 2013-01-18 16:05:10,355 [main] driver.SpringCacheTesterDriver.doHeavyLifting():52  INFO ]: com.kilo.driver.EhcacheFibonacciServiceImpl took 0.0 seconds
[ 2013-01-18 16:05:10,387 [main] driver.EhcacheFibonacciServiceImpl.flushFibonacciCache_aroundBody2():30  INFO ]: Royal Ehcache flush
[ 2013-01-18 16:05:10,397 [main] driver.SpringCacheTesterDriver.doHeavyLifting():52  INFO ]: com.kilo.driver.EhcacheFibonacciServiceImpl took 0.008 seconds
[ 2013-01-18 16:05:10,400 [main] driver.EhcacheFibonacciServiceImpl.flushFibonacciCache_aroundBody2():30  INFO ]: Royal Ehcache flush
The call after the flush however returns faster than the first call - which may be due the the instrumentation stuff bootstrapping and subsequent calls reusing cached instrumented code.
Using cache:advice to cache non-owned calls
The annotation route is good when we are owning the services that need caching. If you don't own the services that vend out the data, you are forced to wrap it in a facade and place your annotation on this facade. The other route may be to use the cache:advice directive. This is similar to the tx:advice which we use to wrap calls around certain pointcuts based on fully qualified classnames, methods, arguments and argument types. So first off, we define a separate concurrent cache to be used for this external service.
    <bean id="externalConcurrentMapFibonacci"
        class="org.springframework.cache.concurrent.ConcurrentMapCacheFactoryBean" />
    <bean id="externalConcurrentMapFibonacciCacheManager"
        class="org.springframework.cache.support.SimpleCacheManager">
        <property name="caches">
            <set>
                <ref bean="externalConcurrentMapFibonacci" />
            </set>
        </property>
    </bean>
Then we define a cache advice (pointcut) with the cache manager to be used and defining which methods need to be cached and which backing cache store is to be used.
    <cache:advice id="externalFibonacciCacheAdvice" cache-manager="externalConcurrentMapFibonacciCacheManager">
        <cache:caching>
            <cache:cacheable method="*" cache="externalConcurrentMapFibonacci" />
        </cache:caching>
    </cache:advice>
Here we are asking Spring to cache all methods (via *) using the externalConcurrentMapFibonacciCacheManager cache manager and to use the externalConcurrentMapFibonacci cache as the underlying store.
    <aop:config proxy-target-class="true">
        <aop:pointcut id="externalFibonacciCacheOperation" expression="execution(* com.kilo.external..*.*(..))"/>
        <aop:advisor advice-ref="externalFibonacciCacheAdvice" pointcut-ref="externalFibonacciCacheOperation"/>
    </aop:config>
Now, we ask aop to to bind the pointcut to work on all beans of package com.kilo.external and use the advice defined before. We have to give the proxy-target-class="true" to use CGLIB based proxies (we can choose to use aspectj mode for reasons mentioned before).
You may verify the working via the output:
[ 2013-01-18 17:20:50,374 [main] driver.SpringCacheTesterDriver.doHeavyLifting():55  INFO ]: com.kilo.driver.SimpletonFibonacciServiceImpl took 7.248 seconds
[ 2013-01-18 17:20:57,615 [main] driver.SpringCacheTesterDriver.doHeavyLifting():55  INFO ]: com.kilo.driver.SimpletonFibonacciServiceImpl took 7.241 seconds
[ 2013-01-18 17:21:04,863 [main] driver.SpringCacheTesterDriver.doHeavyLifting():55  INFO ]: com.kilo.driver.SimpletonFibonacciServiceImpl took 7.247 seconds
[ 2013-01-18 17:21:04,863 [main] driver.SimpletonFibonacciServiceImpl.flushFibonacciCache():27  INFO ]: No-op
[ 2013-01-18 17:21:12,119 [main] driver.SpringCacheTesterDriver.doHeavyLifting():55  INFO ]: com.kilo.driver.SimpletonFibonacciServiceImpl took 7.255 seconds
[ 2013-01-18 17:21:12,119 [main] driver.SimpletonFibonacciServiceImpl.flushFibonacciCache():27  INFO ]: No-op
[ 2013-01-18 17:21:12,161 [main] driver.SpringCacheTesterDriver.doHeavyLifting():55  INFO ]: com.kilo.driver.ConcurrentMapFibonacciServiceImpl took 0.042 seconds
[ 2013-01-18 17:21:12,161 [main] driver.SpringCacheTesterDriver.doHeavyLifting():55  INFO ]: com.kilo.driver.ConcurrentMapFibonacciServiceImpl took 0.0 seconds
[ 2013-01-18 17:21:12,161 [main] driver.SpringCacheTesterDriver.doHeavyLifting():55  INFO ]: com.kilo.driver.ConcurrentMapFibonacciServiceImpl took 0.0 seconds
[ 2013-01-18 17:21:12,167 [main] driver.ConcurrentMapFibonacciServiceImpl.flushFibonacciCache_aroundBody2():30  INFO ]: Royal ConcurrentMap flush
[ 2013-01-18 17:21:12,172 [main] driver.SpringCacheTesterDriver.doHeavyLifting():55  INFO ]: com.kilo.driver.ConcurrentMapFibonacciServiceImpl took 0.004 seconds
[ 2013-01-18 17:21:12,172 [main] driver.ConcurrentMapFibonacciServiceImpl.flushFibonacciCache_aroundBody2():30  INFO ]: Royal ConcurrentMap flush
[ 2013-01-18 17:21:12,210 [main] driver.SpringCacheTesterDriver.doHeavyLifting():55  INFO ]: com.kilo.driver.EhcacheFibonacciServiceImpl took 0.038 seconds
[ 2013-01-18 17:21:12,211 [main] driver.SpringCacheTesterDriver.doHeavyLifting():55  INFO ]: com.kilo.driver.EhcacheFibonacciServiceImpl took 0.0 seconds
[ 2013-01-18 17:21:12,211 [main] driver.SpringCacheTesterDriver.doHeavyLifting():55  INFO ]: com.kilo.driver.EhcacheFibonacciServiceImpl took 0.0 seconds
[ 2013-01-18 17:21:12,242 [main] driver.EhcacheFibonacciServiceImpl.flushFibonacciCache_aroundBody2():30  INFO ]: Royal Ehcache flush
[ 2013-01-18 17:21:12,250 [main] driver.SpringCacheTesterDriver.doHeavyLifting():55  INFO ]: com.kilo.driver.EhcacheFibonacciServiceImpl took 0.008 seconds
[ 2013-01-18 17:21:12,253 [main] driver.EhcacheFibonacciServiceImpl.flushFibonacciCache_aroundBody2():30  INFO ]: Royal Ehcache flush
[ 2013-01-18 17:21:19,873 [main] driver.SpringCacheTesterDriver.doHeavyLifting():55  INFO ]: com.kilo.external.ExternalFibonacciServiceImpl$$EnhancerByCGLIB$$6337baf took 7.62 seconds
[ 2013-01-18 17:21:19,874 [main] driver.SpringCacheTesterDriver.doHeavyLifting():55  INFO ]: com.kilo.external.ExternalFibonacciServiceImpl$$EnhancerByCGLIB$$6337baf took 0.0 seconds
[ 2013-01-18 17:21:19,874 [main] driver.SpringCacheTesterDriver.doHeavyLifting():55  INFO ]: com.kilo.external.ExternalFibonacciServiceImpl$$EnhancerByCGLIB$$6337baf took 0.0 seconds
[ 2013-01-18 17:21:19,874 [main] external.ExternalFibonacciServiceImpl.flushFibonacciCache():28  INFO ]: No-op
[ 2013-01-18 17:21:19,874 [main] driver.SpringCacheTesterDriver.doHeavyLifting():55  INFO ]: com.kilo.external.ExternalFibonacciServiceImpl$$EnhancerByCGLIB$$6337baf took 0.0 seconds
Hope this helps!
There is one gotcha with the cache mapping that I will try to cover in a new post.
References:
  • http://static.springsource.org/spring/docs/3.1.0.M1/spring-framework-reference/html/aop.html#aop-aj-ltw
  • http://www.eclipse.org/aspectj/doc/released/devguide/ltw.html
  • http://stackoverflow.com/questions/8658789/using-spring-cache-annotation-in-multiple-modules
  • Test bed available at https://github.com/kilokahn/spring-testers/tree/master/spring-cache-tester

No comments:

Post a Comment