Spring JCache logging cache hits

Question

I have a method on which I added a cache by adding the @CacheResult annotation (I actual created a proxy because I can't change the original implementation of SomethingService):

@Service
public class SomethingServiceProxyImpl implements SomethingService {

    @Autowired
    @Qualifier("somethingService")
    SomethingService somethingService;

    @Override
    @CacheResult(cacheName = "somethingCache", exceptionCacheName = "somethingExceptionCache", cachedExceptions = { SomeException.class })
    public SomePojo someMethod(String someArg) {
        return somethingService.someMethod(someArg);
    }
}

What I need now, is to be able to log cache hits, meaning cases where the result returned was the one from the cache. I've looked at Spring Cache, at JCache and EHCache (the implementation I use) and I've only found way to listen (with listeners) to the following events: CREATED, UPDATED, REMOVED, EVICTED, EXPIRED but none of them have an event for when the cache returned a result (not null).

I don't really want to have to change the implementation to use the cache programatically instead of using the annotations (I actually have a lot of services to change, not just the one), is there a good way to log those events anyway?

JCache does not produce an event for each cache hit. I think you can only track cache hits if you own the code that invokes `cache.get`. — Vassilis Bekiaris, Feb 27 '19 at 21:05
That what I came to find out, sadly the code that does the cache.get is inside of the Spring Framework, it's CacheResultInterceptor and it's a package-private class. — Nyamiou The Galeanthrope, Feb 28 '19 at 13:14
Do you have business logic around a cache hit? If not, you could enable stats to get the accumulated metrics. — Ben Manes, Feb 28 '19 at 19:27
The client wants cache hits in the logs of the application, so via our ELK he can get those metrics on our Kibana. Finally I told the client to substract request from cache creations to get cache hits. — Nyamiou The Galeanthrope, Mar 01 '19 at 13:31

score 1 · Accepted Answer · answered Mar 19 '19 at 02:39

Thoughts about that topic. Probably, the first two are the most relevant:

Don't: The code that gets executed in Spring and the respective cache on a cache hit, is the most performance critical one. That's why it is not so clever to let call additional code in that case, or even have an option for that. Wiring in a log will impact your performance massively. Usually there is already logging in an application for everything that leads to a cache request (e.g. incoming web requests). To get an idea whether the cache is working correctly, a counter of the hits is enough. That is available via the JCache JMX Statistics.

Logging adapter: Using Spring, you can write a Cache adapter which does the logging as you need it and wire it in via configuration. Rough idea: Look at the CacheManager and Cache interfaces. Wrap the CacheManager create cache method and return a wrapped cache with logging.

Hack via ExpiryPolicy: When a custom ExpiryPolicy is specified a JCache implementation calls the method getExpiryForAccess on every cache access. However, you don't get any information on the actual key being requested. I also recommend staying away from own ExpiryPolicy implementations, because of performance reasons. So this is just for completeness.

Logging cache / log every access: In case you specify multiple caches, Spring calls them one after another. You could wire in a dummy cache as first cache, which just logs the access.

Thank you this is really helpful. – Nyamiou The Galeanthrope Mar 19 '19 at 11:15 — Nyamiou The Galeanthrope, Mar 19 '19 at 11:15

Spring JCache logging cache hits

1 Answers1