ehcache: only populates cache, never reads from cache...

rbell · **Joined:** Mon Mar 26, 2007 9:11 am **Posts:** 4

I'm trying to make use of ehcache with hibernate. According to SecondLevelCacheStatistics the cache is only populated and hibernate never tries to read anything from the cache. According to my novice eyes, the configuration and usage of hibernate/ehcache looks correct, so I need some more experienced eyes to tell me what may be wrong.

Edit: I'm using hibernate 3.2.0.cr4 and ehcache 1.2 (and spring 2.0 and Oracle 10g)

the test-POJO:

Code:

package my.test;

public class Dummy {
    private String name;
    private String description;
    private Long id;

    public Dummy() {}

    // vanilla getter/setter methods removed for clarity
}

hibernate-mapping:

Code:

    <class name="my.test.Dummy">
        <cache usage="read-write"/>
        <id name="id" type="long"/>
        <property name="description" type="string"/>
        <property name="name" type="string"/>
    </class>

ehcache.xml (which is located in my classpath):

Code:

<ehcache>
    <diskStore path="java.io.tmpdir"/>
    <defaultCache
        maxElementsInMemory="5000"
        eternal="false"
        overflowToDisk="false"
        timeToIdleSeconds="50000"
        timeToLiveSeconds="50000"
        diskPersistent="false"
        diskExpiryThreadIntervalSeconds="50000"
        />
    <cache name="my.test.Dummy"
        maxElementsInMemory="10"
        eternal="true"
        overflowToDisk="false"
        />
</ehcache>

relevant properties for the hibernate session (which is configured by spring):

Code:

hibernate.cache.provider_class=org.hibernate.cache.EhCacheProvider
hibernate.cache.use_second_level_cache=true
hibernate.cache.use_query_cache=false

(As you see, I've turned query-cache off.)

testclass/method:

Code:

    public void testDummyCache() {
        System.out.println("cacheStats = " + sessionFactory.getStatistics().getSecondLevelCacheStatistics("my.test.Dummy").toString());
        for (int i = 1; i < 4; i++) {
            Session session = sessionFactory.openSession();
            session.setCacheMode(CacheMode.NORMAL);
            Transaction tx = session.beginTransaction();
            now = System.currentTimeMillis();
            Collection dummies = session.createQuery("from Dummy as d order by d.name").list();
            System.out.print("time run " + i + ": " + (System.currentTimeMillis() - now));
            System.out.println(", cacheStats = " + sessionFactory.getStatistics().getSecondLevelCacheStatistics("my.test.Dummy").toString());
            System.out.println("trying to load: " + session.load(Dummy.class, new Long(i)));
            tx.commit();
            session.close();
            assertNotNull(dummies);
            assertEquals(3, dummies.size());
        }
        System.out.println("final cacheStats = " + sessionFactory.getStatistics().getSecondLevelCacheStatistics("my.test.Dummy").toString());
    }

result/output when running the testclass:

Code:

cacheStats = SecondLevelCacheStatistics[hitCount=0,missCount=0,putCount=0,elementCountInMemory=0,elementCountOnDisk=0,sizeInMemory=0]
time run 1: 16, cacheStats = SecondLevelCacheStatistics[hitCount=0,missCount=0,putCount=0,elementCountInMemory=3,elementCountOnDisk=0,sizeInMemory=3399]
trying to load: my.test.Dummy@1bb3a11
time run 2: 0, cacheStats = SecondLevelCacheStatistics[hitCount=0,missCount=0,putCount=0,elementCountInMemory=3,elementCountOnDisk=0,sizeInMemory=3399]
trying to load: my.test.Dummy@facfa5
time run 3: 0, cacheStats = SecondLevelCacheStatistics[hitCount=0,missCount=0,putCount=0,elementCountInMemory=3,elementCountOnDisk=0,sizeInMemory=3399]
trying to load: my.test.Dummy@4ee543
final cacheStats = SecondLevelCacheStatistics[hitCount=0,missCount=0,putCount=0,elementCountInMemory=3,elementCountOnDisk=0,sizeInMemory=3399]

As you see in the output, the SecondLevelCacheStatistics reports that the 3 elements located in the "DUMMY" Oracle table are stored in the second level cache. However, it seems that Hibernate always accesses the DB directly and never attempts to read anything from the cache. (hitCount=0, missCount=0). How do I make Hibernate try to look in the cache?

jba · **Joined:** Fri Oct 28, 2005 9:08 am **Posts:** 12

Hibernate reads from the second level cache when you use the get/load methods on the Session. In other case, Hibernate bypass the cache but put the result in cache.

Otherwise, you have to enable the query_cache to cache the result of specific requests.

rbell · **Joined:** Mon Mar 26, 2007 9:11 am **Posts:** 4

I am executing a specific session.load(...) in my test-class, without any particular evidence that the second level cache is hit/missed. The session.load(...) returns with a correct instance of the class, but it does not (in my eyes) look as if it is read from the cache.

and I disabled the query-cache to make sure that hibernate did not retrieve the result from the query-cache and skipped looking in the 2nd level cache....

christian · **Posted:** Wed May 09, 2007 12:35 pm

session.load() returns a proxy...

rbell · **Joined:** Mon Mar 26, 2007 9:11 am **Posts:** 4

ok, but how should I proceed to make hibernate retrieve objects from the 2nd level cache? From what I have seen of examples etc. what I do should work. But it does not. So I must be doing something wrong, and I can't see what that is...

christian · **Posted:** Wed May 09, 2007 1:30 pm

Maybe use session.get() instead or initialize the proxy?

rbell · **Joined:** Mon Mar 26, 2007 9:11 am **Posts:** 4

I've tried with both session.get() and made sure the proxy is initialized, but I have still not seen anything in SecondLevelCacheStatistics which should imply that the cache has been accessed in any other way than to just store data there.

If I set hibernate.show_sql to true, more statements are printed the first time I load things than later times. So based on the sql-logging it appears that the application retrieves data from some kind of cache. The statistics, however, are not updated other than with the number of items stored there etc.

The sql-logs not present the second time I load data correspond to the data I have marked as cacheable. If I turn caching off, the same sql-queries are logged every time. So, it appears that I actually have some kind of caching, but the SecondLevelCacheStatistics is not updated with info regarding hits and misses... Is there some other way to retrieve that kind of information?

rahul dongre · **Posted:** Mon Jun 04, 2007 5:23 pm

Yes, you'll not get the cache hit and miss counts.

Try.

1) After session close you try to load the data with the specific Id.
2) Check your hbm.xml file, for usage of the cache.
3) Make sure your default-cascade attribute is being set properly on the hbm.xml file hibernate settings.

You'll definetly see the hit and miss count if you follow the above points, hope so :)

if not let me know, i had this problem earlier now solved and showing the hit and miss ratio on statistics as well and jconsole as well.

As chiristian told the cache will hit only with the get() method. Remember.

rally25rs · **Joined:** Tue Jun 12, 2007 12:36 pm **Posts:** 6

rbell, did you ever figure this one out? I basically have the same issue, but my query cache is on...

Spring 1.2.8
Hibernate 3
EhCache 1.1

spring config:
(yep, using HibernateTemplate, sorry!)

Code:

   <bean id="rwSessionFactory" class="org.springframework.orm.hibernate3.LocalSessionFactoryBean">
      <property name="dataSource">
         <ref bean="rwDataSource"/>
      </property>
      <property name="hibernateProperties">
         <props>
            <prop key="hibernate.dialect">com.proquest.pbs.epc.utils.TransbaseDialect</prop>
            <prop key="hibernate.cache.use_query_cache">true</prop>
            <prop key="hibernate.cache.use_second_level_cache">true</prop>
            <prop key="hibernate.cache.provider_class">org.hibernate.cache.EhCacheProvider</prop>
         </props>
      </property>
      <!--  OR mapping files. -->
      <property name="mappingResources">
         <ref bean="maceHibernateMappingFiles"/>
      </property>
   </bean>

   <bean id="rwHibernateAccessor" class="my.class.that.extends.HibernateTemplate">
      <property name="sessionFactory">
         <ref bean="rwSessionFactory"/>
      </property>
      <property name="cacheQueries">
         <value>true</value>
      </property>
   </bean>

   <bean id="rwCacheManager" class="org.springframework.cache.ehcache.EhCacheManagerFactoryBean">
   </bean>

   <bean id="UserNoteCache" class="org.springframework.cache.ehcache.EhCacheFactoryBean">
      <property name="cacheManager"><ref local="rwCacheManager"/></property>
      <property name="cacheName"><value>com.proquest.pbs.mace.note.domain.NoteBean</value></property>
      <property name="maxElementsInMemory"><value>20000</value></property>
      <property name="overflowToDisk"><value>false</value></property>
      <property name="eternal"><value>true</value></property>
   </bean>

Hibernate mapping:
(most columns removed for brevity)

Code:

<hibernate-mapping>

   <class name="com.proquest.pbs.mace.note.domain.NoteBean" table="user_note_v">
      <cache usage="read-write"/>
      <composite-id>
         <key-property name="accountId" column="account_id"/>
         <key-property name="noteId" column="note_id"/>
      </composite-id>
         
           <property name="attribute1" column="attribute1"/>
 ...
           <property name="attribute10" column="attribute10"/>     
        </class>

</hibernate-mapping>

ORM class that hits Hibernate:

Code:

String hql = "from NoteBean where (to_ansi_date(expireDate) >= current_ansi_date() or expireDate is null) and accountId = 'testId'";

resultList = this.getHibernateAccessor().find(hql.toString());  // getHibernateAccessor() returns a HibernateTemplate instance

After the 1st run and for every consecutive execution, I get the same stats: objects loaded but no put/hit/miss numbers:

Code:

Region name: org.hibernate.cache.StandardQueryCache
    Puts: 0
    Hits: 0 Misses: 0
    Elements In Mem: 2
    Elements On Disk: 0
    Size In Mem: 4036


Region name: com.proquest.pbs.mace.note.domain.NoteBean
    Puts: 0
    Hits: 0 Misses: 0
    Elements In Mem: 2
    Elements On Disk: 0
    Size In Mem: 9476


Region name: org.hibernate.cache.UpdateTimestampsCache
    Puts: 0
    Hits: 0 Misses: 0
    Elements In Mem: 1
    Elements On Disk: 0
    Size In Mem: 291

I also confirmed the app is executing the SELECT query against the DB each time using DB logging.

Using the .get() method was suggested, but I don't see how that is possible without knowing the IDs ahead of time.

Also, the HibernateTemplate.find() method just calls session.createQuery(queryString).list()

What am I doing wrong?

hhenschel · **Joined:** Thu Jun 28, 2007 1:47 pm **Posts:** 1

I got the statistics once I set Hibernate property hibernate.generate_statistics to true.

Irons UK · **Posted:** Sun Jan 27, 2008 6:12 am

I know this answer comes 6+ months late, but I found this thread while looking for answers to my own cache problem and thought I'd post my thoughts for anyone that finds this thread in the future.

Let me first say I'm NOT an expert on hibernate OR caching!

To the OP. I would not expect your test case to hit the 2nd level cache. This is because you are using session.load() inside the same open session as session.createQuery().list(). What I think would be happening is hibernate finds the entity in the 1st level cache, so doesn't need to bother looking in the 2nd level cache. Ensure that you close and create a new session before calling session.load(), as this will not be able to use the 1st level cache.

The only thing that makes me question my answer is that a Hibernate Team member has posted on this thread and not noticed this. At first guess I'd say he didn't read your code.

To rally25rs,

When you are searching for entities by some criteria, the 2nd level cache is never used. This is a technical limitation of hibernate, and a reasonable one if you think about it as your query requires a database hit to filter your data.

Irons UK · **Posted:** Sun Jan 27, 2008 6:13 am

sorry double post

vinay076 · **Joined:** Thu Apr 10, 2008 3:17 pm **Posts:** 3

Sorry for replying to this post which is so old but I got stuck in exactly the same issue that I was not able to read the stats although caching was turned on.
So I am posting here to help the fellow members if they are stuck.

When ever you are testing for statistics make sure you have turned them on.

It is NOT on by default

getSessionFactory().getStatistics().
setStatisticsEnabled(true);

or

<prop key="hibernate.generate_statistics">true</prop>

HTH

Gangadhar · **Joined:** Thu Jun 13, 2013 2:11 am **Posts:** 1

@ Rahul Dongare,
could you please help me out the steps you said i tried but still every time a database hit happens
I used ehcache 2.4.3.jar & hibernate 4.0.0.jar
Full code is here
http://stackoverflow.com/questions/17046830/hibernate-4-0-ehcache-2-4-3-always-miss-cache-hit