Ehcache says it caches but it doesn't look it's the case...

qmaster · **Joined:** Sat Jan 07, 2006 8:30 pm **Posts:** 68

This is interesting... all the info are below.
Briefly here's what's happening. I'm looking up a SystemConstant object by name. All that works file. I decided to put ehcache to work. Configuring ehcache was very smooth and I was happy to see that the cache was hit but then I paid more attention when I changed the value for systemConstant object and on the second call at 1 minute apart the new value was showing... Is this a missconfiguration issue ?

Hibernate version: 3.1.3

Debug level Hibernate log excerpt:

Code:

->first call

2006-04-30 14:07:55,156  DEBUG  org.hibernate.jdbc.AbstractBatcher.log(AbstractBatcher.java:346) - select systemcons0_.id as id14_, systemcons0_.name as name14_, systemcons0_.type as type14_, systemcons0_.class as class14_, systemcons0_.description as descript5_14_, systemcons0_.value as value14_, systemcons0_.display_order as display7_14_, systemcons0_.date_created as date8_14_, systemcons0_.date_modified as date9_14_, systemcons0_.created_by as created10_14_, systemcons0_.modified_by as modified11_14_, systemcons0_.version as version14_ from public.system_constant systemcons0_ where (name=? ) 
2006-04-30 14:07:55,203  DEBUG  org.hibernate.cache.ReadWriteCache.put(ReadWriteCache.java:148) - Caching: domain.SystemConstant#1 
2006-04-30 14:07:55,203  DEBUG  org.hibernate.cache.EhCache.get(EhCache.java:104) - key: domain.SystemConstant#1 
2006-04-30 14:07:55,203  DEBUG  org.hibernate.cache.ReadWriteCache.put(ReadWriteCache.java:169) - Item was already cached: domain.SystemConstant#1 

->second call, 1 minute apart...( here I change manually the value for SystemConstant#1 and the change is reflected right away when the following code is complete - this is not expected....

2006-04-30 14:09:20,515  DEBUG  org.hibernate.jdbc.AbstractBatcher.log(AbstractBatcher.java:346) - select systemcons0_.id as id14_, systemcons0_.name as name14_, systemcons0_.type as type14_, systemcons0_.class as class14_, systemcons0_.description as descript5_14_, systemcons0_.value as value14_, systemcons0_.display_order as display7_14_, systemcons0_.date_created as date8_14_, systemcons0_.date_modified as date9_14_, systemcons0_.created_by as created10_14_, systemcons0_.modified_by as modified11_14_, systemcons0_.version as version14_ from public.system_constant systemcons0_ where (name=? ) 
2006-04-30 14:09:20,531  DEBUG  org.hibernate.cache.ReadWriteCache.put(ReadWriteCache.java:148) - Caching: domain.SystemConstant#1 
2006-04-30 14:09:20,546  DEBUG  org.hibernate.cache.EhCache.get(EhCache.java:104) - key: domain.SystemConstant#1 
2006-04-30 14:09:20,562  DEBUG  org.hibernate.cache.ReadWriteCache.put(ReadWriteCache.java:169) - Item was already cached: domain.SystemConstant#1 

EhCache.xml

Code:

<ehcache>

   <diskStore path="java.io.tmpdir" />
   
   <defaultCache
        maxElementsInMemory="10000" 
        eternal="false" 
        timeToIdleSeconds="1200" 
        timeToLiveSeconds="1200" 
        overflowToDisk="true" 
        diskPersistent="false" 
        diskExpiryThreadIntervalSeconds="1200" 
        /> 

    <cache name="domain.SystemConstant" 
        maxElementsInMemory="25" 
        eternal="false" 
        timeToIdleSeconds="7200" 
        timeToLiveSeconds="7200" 
        overflowToDisk="false" 
        />
        
</ehcache>

tenwit · **Joined:** Thu Dec 23, 2004 9:08 pm **Posts:** 2008

I don't see any glaring misconfiguration issues. How did you do the intermediate update? Did you use the object you retrieved from the first select? Even if you don't call Session.update, changes to that object are reflected in the cache, so you'd immediately see the changes.

qmaster · **Joined:** Sat Jan 07, 2006 8:30 pm **Posts:** 68

Thanks for replying...

I go manually in the database and flip the value from UP to DOWN ... and I been expecting to see the change reflected in 2 hours (7200secs) not in second minute... that's the reason I'm saying the cache is not really caching...

The code only does a read... if the systemConstant value is UP the site will stay up, if is DOWN the site will display a down page...

Do you see anything unusual since the ehcache.xml specifically says that the variables should be cached for 2 hours. I only have 10 such variables so there won't be evicted from cache due overflows...

tenwit · **Joined:** Thu Dec 23, 2004 9:08 pm **Posts:** 2008

Are you using session.get/load? That uses the session cache, and as far as I know, that's not named. Still, your configuration specifies a 20 minute wait for that. That's the risk with WeakReferences I guess.. sometimes they get GCed.

How are you making use of the domain.SystemConstant cache? Simply configuring it doesn't mean that it'll get used. Configuring your SystemConstant mapping with <cache region="domain.SystemConstant"/> means that Hibernate will use that named region for the 2nd level cache. The 2nd level cache is used for lookups by id that aren't found in the sesion cache, and also for the query cache (if you have it set up). If you're looking the object up in different ways (once by id, once by a different query) then the cache won't be hit as frequently: it may be that your second access to the item is looking in the other cache, which hasn't yet loaded it.

qmaster · **Joined:** Sat Jan 07, 2006 8:30 pm **Posts:** 68

I found my problem....

hibernate.cache.use_query_cache had a bloody typo :(((

Thanks much for looking and help!