Search code examples
javaehcachespring-cache

Ehcache: unexpected behavior when evicting cache elements

I have two cached methods:

@Cacheable(value = CacheName.CACHE_STATIC, key="'getImageUserLayer'.concat(':').concat(#layerId)")
public byte[] getImageUserLayer(int layerId) {

and

@Cacheable(value = CacheName.CACHE_STATIC, key="'getLastModifiedUserLayer'.concat(':').concat(#layerId)")
@Override
public String getLastModifiedUserLayer(int layerId) {

also I have method for evicting of element:

@Caching(evict = {
        @CacheEvict(value = CacheName.CACHE_STATIC, key = "'getImageUserLayer'.concat(':').concat(#layerId)"),
        @CacheEvict(value = CacheName.CACHE_STATIC, key = "'getLastModifiedUserLayer'.concat(':').concat(#layerId)")
})
public void updateLayer(UserLayer layer, int layerId) {

Why after calling updateLayer(5510461), I get next weird behavior:

2020-02-10 16:47:07.065 [http-nio-8080-exec-9] TRACE o.s.c.i.CacheInterceptor - Computed cache key 'getLastModifiedUserLayer:4900061' for operation Builder[public java.lang.String com.prognoz.smkoob.data.dao.ImageServiceImpl.getLastModifiedUserLayer(int)] caches=[cacheStatic] | key=''getLastModifiedUserLayer'.concat(':').concat(#layerId)' | keyGenerator='' | cacheManager='' | cacheResolver='' | condition='' | unless='' | sync='false'
2020-02-10 16:48:32.695 [http-nio-8080-exec-7] TRACE o.s.c.i.CacheInterceptor - Invalidating cache key [getImageUserLayer:5510461] for operation Builder[public void com.prognoz.smkoob.data.dao.meta.UserLayerServiceImpl.updateLayer(com.prognoz.smkoob.domain.UserLayer.UserLayer,int)] caches=[cacheStatic] | key=''getImageUserLayer'.concat(':').concat(#layerId)' | keyGenerator='' | cacheManager='' | cacheResolver='' | condition='',false,false on method public void com.prognoz.smkoob.data.dao.meta.UserLayerServiceImpl.updateLayer(com.prognoz.smkoob.domain.UserLayer.UserLayer,int)
2020-02-10 16:48:32.701 [http-nio-8080-exec-7] TRACE o.s.c.i.CacheInterceptor - Invalidating cache key [getLastModifiedUserLayer:5510461] for operation Builder[public void com.prognoz.smkoob.data.dao.meta.UserLayerServiceImpl.updateLayer(com.prognoz.smkoob.domain.UserLayer.UserLayer,int)] caches=[cacheStatic] | key=''getLastModifiedUserLayer'.concat(':').concat(#layerId)' | keyGenerator='' | cacheManager='' | cacheResolver='' | condition='',false,false on method public void com.prognoz.smkoob.data.dao.meta.UserLayerServiceImpl.updateLayer(com.prognoz.smkoob.domain.UserLayer.UserLayer,int)
2020-02-10 16:48:33.591 [http-nio-8080-exec-4] TRACE o.s.c.i.CacheInterceptor - Computed cache key 'getLastModifiedUserLayer:5510461' for operation Builder[public java.lang.String com.prognoz.smkoob.data.dao.ImageServiceImpl.getLastModifiedUserLayer(int)] caches=[cacheStatic] | key=''getLastModifiedUserLayer'.concat(':').concat(#layerId)' | keyGenerator='' | cacheManager='' | cacheResolver='' | condition='' | unless='' | sync='false'
2020-02-10 16:48:33.591 [http-nio-8080-exec-4] TRACE o.s.c.i.CacheInterceptor - No cache entry for key 'getLastModifiedUserLayer:5510461' in cache(s) [cacheStatic]
2020-02-10 16:48:33.909 [http-nio-8080-exec-3] TRACE o.s.c.i.CacheInterceptor - Computed cache key 'getLastModifiedUserLayer:4900061' for operation Builder[public java.lang.String com.prognoz.smkoob.data.dao.ImageServiceImpl.getLastModifiedUserLayer(int)] caches=[cacheStatic] | key=''getLastModifiedUserLayer'.concat(':').concat(#layerId)' | keyGenerator='' | cacheManager='' | cacheResolver='' | condition='' | unless='' | sync='false'
2020-02-10 16:48:33.909 [http-nio-8080-exec-3] TRACE o.s.c.i.CacheInterceptor - No cache entry for key 'getLastModifiedUserLayer:4900061' in cache(s) [cacheStatic]
2020-02-10 16:48:33.909 [http-nio-8080-exec-8] TRACE o.s.c.i.CacheInterceptor - No cache entry for key 'getLastModifiedUserLayer:5129071' in cache(s) [cacheStatic]
2020-02-10 16:48:33.910 [http-nio-8080-exec-8] TRACE o.s.c.i.CacheInterceptor - Computed cache key 'getLastModifiedUserLayer:5129071' for operation Builder[public java.lang.String com.prognoz.smkoob.data.dao.ImageServiceImpl.getLastModifiedUserLayer(int)] caches=[cacheStatic] | key=''getLastModifiedUserLayer'.concat(':').concat(#layerId)' | keyGenerator='' | cacheManager='' | cacheResolver='' | condition='' | unless='' | sync='false'

Why it also invalidates another keys??? For example 4900061.

my ehcache.xml:

<cache name="cacheStatic"
       maxBytesLocalHeap="128M"
       maxBytesLocalDisk="2G"
       eternal="false"
       timeToLiveSeconds="7200"
       memoryStoreEvictionPolicy="LFU"
       transactionalMode="off">
    <persistence strategy="localTempSwap"/>
</cache>
Solution

  • According to the logs, there are only two invalidatings made in thread http-nio-8080-exec-7:

    2020-02-10 16:48:32.695 [http-nio-8080-exec-7] TRACE o.s.c.i.CacheInterceptor - Invalidating cache key [getImageUserLayer:5510461] for operation Builder[public void com.prognoz.smkoob.data.dao.meta.UserLayerServiceImpl.updateLayer(com.prognoz.smkoob.domain.UserLayer.UserLayer,int)] caches=[cacheStatic] | key=''getImageUserLayer'.concat(':').concat(#layerId)' | keyGenerator='' | cacheManager='' | cacheResolver='' | condition='',false,false on method public void com.prognoz.smkoob.data.dao.meta.UserLayerServiceImpl.updateLayer(com.prognoz.smkoob.domain.UserLayer.UserLayer,int)
2020-02-10 16:48:32.701 [http-nio-8080-exec-7] TRACE o.s.c.i.CacheInterceptor - Invalidating cache key [getLastModifiedUserLayer:5510461] for operation Builder[public void com.prognoz.smkoob.data.dao.meta.UserLayerServiceImpl.updateLayer(com.prognoz.smkoob.domain.UserLayer.UserLayer,int)] caches=[cacheStatic] | key=''getLastModifiedUserLayer'.concat(':').concat(#layerId)' | keyGenerator='' | cacheManager='' | cacheResolver='' | condition='',false,false on method public void com.prognoz.smkoob.data.dao.meta.UserLayerServiceImpl.updateLayer(com.prognoz.smkoob.domain.UserLayer.UserLayer,int)

    What's about actions with 4900061 in thread http-nio-8080-exec-3, it seems just like a attempt to find cached value made during a call of method getLastModifiedUserLayer:

    2020-02-10 16:48:33.909 [http-nio-8080-exec-3] TRACE o.s.c.i.CacheInterceptor - Computed cache key 'getLastModifiedUserLayer:4900061' for operation Builder[public java.lang.String com.prognoz.smkoob.data.dao.ImageServiceImpl.getLastModifiedUserLayer(int)] caches=[cacheStatic] | key=''getLastModifiedUserLayer'.concat(':').concat(#layerId)' | keyGenerator='' | cacheManager='' | cacheResolver='' | condition='' | unless='' | sync='false'
2020-02-10 16:48:33.909 [http-nio-8080-exec-3] TRACE o.s.c.i.CacheInterceptor - No cache entry for key 'getLastModifiedUserLayer:4900061' in cache(s) [cacheStatic]