How to enable L2 cache with JBoss TreecacheProvider?

[Sab]

Hi All,

I've defined TreeCacheProvider for second-level caching and enabled the query caching.... when i tried executing a query operation on a cache enabled object, its not fetching from the L2 cache, instead everytime its triggers a SQL and fetching it.

Can anyone help me to solve this problem.....

Am using Spring 2.0 M4, Hibernate 3 and JBossCache 1.2.4.....

Here's my spring configuration....

<beans>
<bean id="dataSource" class="org.apache.commons.dbcp.BasicDataSource" destroy-method="close">
<property name="driverClassName" value="com.mysql.jdbc.Driver" />
<property name="url" value="jdbc:mysql://indbgl-w00063:3306/poc" />
<property name="username" value="poc" />
<property name="password" value="poc" />
</bean>
<bean id="sessionFactory" class="org.springframework.orm.hibernate3.LocalSes sionFactoryBean">
<property name="dataSource">
<ref bean="dataSource" />
</property>
<property name="mappingResources">
<list>
<value>test/string/Contact.hbm.xml</value>
<value>test/string/Patient.hbm.xml</value>
</list>
</property>
<property name="hibernateProperties">
<props>
<prop key="hibernate.show_sql">true</prop>
<prop key="hibernate.cache.provider_class">org.hibernate .cache.TreeCacheProvider</prop>
<prop key="hibernate.cache.use_query_cache">true</prop>
<prop key="hibernate.dialect">org.hibernate.dialect.MySQ LDialect</prop>
<prop key="hibernate.cache.use_structured_entries">true</prop>
<prop key="hibernate.generate_statistics">true</prop>
</props>
</property>
</bean>
<bean id="cacheTestTarget" class="test.CacheTest">
<property name="sessionFactory" ref="sessionFactory" />
</bean>
<bean id="txManager" class="org.springframework.orm.hibernate3.Hibernat eTransactionManager">
<property name="sessionFactory" ref="sessionFactory" />
</bean>
<bean id="cacheTest" class="org.springframework.transaction.interceptor .TransactionProxyFactoryBean">
<property name="transactionManager" ref="txManager" />
<property name="target" ref="cacheTestTarget" />
<property name="transactionAttributes">
<props><prop key="find*">PROPAGATION_REQUIRED,readOnly</prop>
<prop key="*">PROPAGATION_REQUIRED</prop>
</props>
</property>
</bean>
</beans>

Mapping files:
Patient.hbm.xml

<hibernate-mapping>
<class name="test.string.Patient" table="patient" catalog="test">
<cache usage="transactional" region="iba"/>
<id name="patientId" type="string">
<column name="patient_id" length="10" />
<generator class="assigned" />
</id>
<property name="name" type="string">
<column name="name" length="45" not-null="true" />
</property>
<set name="contacts" inverse="true">
<key>
<column name="patient_id" length="10" />
</key>
<one-to-many class="test.string.Contact" />
</set>
</class>
</hibernate-mapping>

and the test program....

<%WebApplicationContext ctx = WebApplicationContextUtils .getWebApplicationContext(config.getServletContext ());
DAO test = (DAO) ctx.getBean("cacheTest");
showResults(test.getRecords(),out);
showResults(test.getRecords(),out);
%>
<%!
public void showResults(List records,JspWriter out) throws Exception{
//Iterates and renders the records
}%>

and here's the log:

...
2006-07-12 18:17:43,882 DEBUG Found thread-bound Session for HibernateTemplate
2006-07-12 18:17:43,882 DEBUG Retrieved value [org.springframework.orm.hibernate3.SessionHolder@1 d91364] for key [org.hibernate.impl.SessionFactoryImpl@4e194f] bound to thread [http8080-Processor24]
2006-07-12 18:17:43,882 DEBUG about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2006-07-12 18:17:43,882 DEBUG select this_.patient_id as patient1_1_0_, this_.name as name1_0_ from test.patient this_
2006-07-12 18:17:43,882 DEBUG preparing statement
2006-07-12 18:17:43,882 DEBUG about to open ResultSet (open ResultSets: 0, globally: 0)
2006-07-12 18:17:43,882 DEBUG processing result set
2006-07-12 18:17:43,882 DEBUG result set row: 0
2006-07-12 18:17:43,882 DEBUG returning '1' as column: patient1_1_0_
2006-07-12 18:17:43,882 DEBUG result row: EntityKey[test.string.Patient#1]
2006-07-12 18:17:43,882 DEBUG Initializing object from ResultSet: [test.string.Patient#1]
2006-07-12 18:17:43,882 DEBUG Hydrating entity: [test.string.Patient#1]
2006-07-12 18:17:43,882 DEBUG returning 'uuuuuu' as column: name1_0_
2006-07-12 18:17:43,882 DEBUG result set row: 1
..
..
2006-07-12 18:17:43,898 DEBUG about to close ResultSet (open ResultSets: 1, globally: 1)
2006-07-12 18:17:43,898 DEBUG about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2006-07-12 18:17:43,898 DEBUG closing statement
2006-07-12 18:17:43,898 DEBUG total objects hydrated: 3
2006-07-12 18:17:43,898 DEBUG resolving associations for [test.string.Patient#1]
2006-07-12 18:17:43,898 DEBUG creating collection wrapper:[test.string.Patient.contacts#1]
2006-07-12 18:17:43,898 DEBUG adding entity to second-level cache: [test.string.Patient#1]
2006-07-12 18:17:43,898 DEBUG item already cached: test.string.Patient#1
2006-07-12 18:17:43,898 DEBUG done materializing entity [test.string.Patient#1]
2006-07-12 18:17:43,898 DEBUG resolving associations for [test.string.Patient#2]
2006-07-12 18:17:43,898 DEBUG creating collection wrapper:[test.string.Patient.contacts#2]
2006-07-12 18:17:43,898 DEBUG adding entity to second-level cache: [test.string.Patient#2]
2006-07-12 18:17:43,898 DEBUG item already cached: test.string.Patient#2
2006-07-12 18:17:43,898 DEBUG done materializing entity [test.string.Patient#2]
2006-07-12 18:17:43,898 DEBUG resolving associations for [test.string.Patient#3]
2006-07-12 18:17:43,898 DEBUG creating collection wrapper:[test.string.Patient.contacts#3]
2006-07-12 18:17:43,898 DEBUG adding entity to second-level cache: [test.string.Patient#3]
2006-07-12 18:17:43,898 DEBUG item already cached: test.string.Patient#3
2006-07-12 18:17:43,898 DEBUG done materializing entity [test.string.Patient#3]
2006-07-12 18:17:43,898 DEBUG initializing non-lazy collections
2006-07-12 18:17:43,898 DEBUG Not closing pre-bound Hibernate Session after HibernateTemplate
2006-07-12 18:17:43,898 DEBUG Retrieved value [org.springframework.orm.hibernate3.SessionHolder@1 d91364] for key [org.hibernate.impl.SessionFactoryImpl@4e194f] bound to thread [http8080-Processor24]
2006-07-12 18:17:43,898 DEBUG Retrieved value [org.springframework.orm.hibernate3.SessionHolder@1 d91364] for key [org.hibernate.impl.SessionFactoryImpl@4e194f] bound to thread [http8080-Processor24]
2006-07-12 18:17:43,898 DEBUG Found thread-bound Session for HibernateTemplate
2006-07-12 18:17:43,898 DEBUG flushing session
2006-07-12 18:17:43,898 DEBUG processing flush-time cascades
2006-07-12 18:17:43,898 DEBUG dirty checking collections
2006-07-12 18:17:43,898 DEBUG Flushing entities and processing referenced collections
2006-07-12 18:17:43,898 DEBUG Collection found: [test.string.Patient.contacts#1], was: [test.string.Patient.contacts#1] (uninitialized)
2006-07-12 18:17:43,898 DEBUG Collection found: [test.string.Patient.contacts#2], was: [test.string.Patient.contacts#2] (uninitialized)
2006-07-12 18:17:43,898 DEBUG Collection found: [test.string.Patient.contacts#3], was: [test.string.Patient.contacts#3] (uninitialized)
2006-07-12 18:17:43,898 DEBUG Processing unreferenced collections
2006-07-12 18:17:43,898 DEBUG Scheduling collection removes/(re)creates/updates
2006-07-12 18:17:43,898 DEBUG Flushed: 0 insertions, 0 updates, 0 deletions to 3 objects
2006-07-12 18:17:43,898 DEBUG Flushed: 0 (re)creations, 0 updates, 0 removals to 3 collections
2006-07-12 18:17:43,898 DEBUG listing entities:
2006-07-12 18:17:43,898 DEBUG test.string.Patient{contacts=<uninitialized>, patientId=1, name=uuuuuu}
2006-07-12 18:17:43,898 DEBUG test.string.Patient{contacts=<uninitialized>, patientId=3, name=Z}
2006-07-12 18:17:43,898 DEBUG test.string.Patient{contacts=<uninitialized>, patientId=2, name=Y}
2006-07-12 18:17:43,898 DEBUG executing flush
2006-07-12 18:17:43,898 DEBUG registering flush begin
2006-07-12 18:17:43,898 DEBUG registering flush end
2006-07-12 18:17:43,898 DEBUG post flush
2006-07-12 18:17:43,898 DEBUG Not closing pre-bound Hibernate Session after HibernateTemplate
2006-07-12 18:17:43,898 DEBUG Invoking commit for transaction on test.DAO.getRecords
2006-07-12 18:17:43,898 DEBUG Triggering beforeCommit synchronization
2006-07-12 18:17:43,898 DEBUG Triggering beforeCompletion synchronization
2006-07-12 18:17:43,898 DEBUG Initiating transaction commit
2006-07-12 18:17:43,898 DEBUG Committing Hibernate transaction on Session [org.hibernate.impl.SessionImpl@10ce397]
2006-07-12 18:17:43,898 DEBUG commit
2006-07-12 18:17:43,898 DEBUG automatically flushing session
2006-07-12 18:17:43,898 DEBUG flushing session

according to the log the objects are available in the L2 cache, instead of retrieving it from the cache dont know why its firing the SQL statement.

can anyone tell wats wrong in this....

Kindly find the detailed log in the attachement...

Thanks in advace

Regards
Sab

[Marten Deinum]

Can you post the code for the DAO?

For what I recall is that when using (might be wrong)

getHibernateTemplate().get(......) it always calls the database
getHibernateTemplate().load(......) it may use the cache.

Also set the property hibernate.cache.use_second_level_cache to true.

[Sab]

am using getHibernateTemplate.loadAll() and here s my DAO and its impl code....

DAO Interface

package test;

import java.util.List;

public interface DAO {
    public List getRecords();
} 

DAO Implementation

package test;

import java.util.List;
import java.util.Map;

import org.hibernate.CacheMode;
import org.hibernate.Query;
import org.hibernate.Session;
import org.springframework.orm.hibernate3.support.HibernateDaoSupport;

import test.string.Patient;

public class CacheTest extends HibernateDaoSupport implements DAO {
    public List getRecords() {
        return getHibernateTemplate().loadAll(Patient.class);
    }
} 

and also i tried setting hibernate.cache.use_second_level_cache to true but it didnt work.... according to the doc if any of the mapping has <cache> tag then its enabled by default....

-Sab

[Marten Deinum]

According to the docs:

19.2.5. Strategy: transactional
The transactional cache strategy provides support for fully transactional cache providers such as JBoss TreeCache. Such a cache may only be used in a JTA environment and you must specify hibernate.transaction.manager_lookup_class.

I cannot see from your configuration that you are running in a JTA environment, because you use a local transactionmanager (HibernateTransactionManager) and not a JtaTranactionManager.

Next I also do not see a 'hibernate.transaction.manager_lookup_class' property in your setup of your LocalSessionFactory.

You also may find this thread interesting.

[Sab]

Thanx a lot Marten... i'll try using JtaTransactionManager and will get back if any problem....

Regards
Sab

[Sab]

Hi

I've defined a JTA Transaction and running using a JOTM transaction, but i couldnt see any changes. Still its not fetching the records from the cache...

here s the configuration and the log....

Hibernate Cache Configuration

<property name="hibernateProperties">
<props>
<prop key="hibernate.show_sql">true</prop>
<prop key="hibernate.dialect">org.hibernate.dialect.MySQ LDialect</prop>

<prop key="jta.UserTransaction">java:comp/UserTransaction</prop>
<prop key="hibernate.transaction.manager_lookup_class">o rg.hibernate.transaction.JOTMTransactionManagerLoo kup</prop>
<prop key="hibernate.transaction.factory_class">org.hibe rnate.transaction.JTATransactionFactory</prop>

<prop key="hibernate.cache.provider_class">org.hibernate .cache.TreeCacheProvider</prop>
<prop key="hibernate.cache.use_query_cache">true</prop>
<prop key="hibernate.cache.use_second_level_cache">true</prop>

<prop key="hibernate.cache.use_structured_entries">true</prop>
<prop key="hibernate.generate_statistics">true</prop>
<prop key="hibernate.cache.use_minimal_puts">true</prop>
</props>
</property>

Transaction Manager:

<bean id="JotmTransactionFactory" class="org.springframework.transaction.jta.JotmFac toryBean" />
<bean id="txManager" class="org.springframework.transaction.jta.JtaTran sactionManager">
<property name="userTransaction">
<ref local="JotmTransactionFactory" />
</property>
</bean>

Transaction proxy bean definition:

<bean id="cacheTest" class="org.springframework.transaction.interceptor .TransactionProxyFactoryBean">
<property name="transactionManager" ref="txManager" />
<property name="target" ref="cacheTestTarget" />
<property name="transactionAttributes">
<props>
<prop key="*">PROPAGATION_REQUIRED</prop>
</props>
</property>
</bean>

Log

2006-07-13 16:35:19,707 INFO Transaction strategy: org.hibernate.transaction.JTATransactionFactory
2006-07-13 16:35:19,723 INFO JNDI InitialContext properties:{}
2006-07-13 16:35:19,723 INFO instantiating TransactionManagerLookup: org.hibernate.transaction.JOTMTransactionManagerLo okup
2006-07-13 16:35:19,738 INFO instantiated TransactionManagerLookup
2006-07-13 16:35:19,738 INFO Automatic flush during beforeCompletion(): disabled
2006-07-13 16:35:19,738 INFO Automatic session close at end of transaction: disabled
2006-07-13 16:35:19,738 INFO JDBC batch size: 15
2006-07-13 16:35:19,738 INFO JDBC batch updates for versioned data: disabled
2006-07-13 16:35:19,738 INFO Scrollable result sets: enabled
2006-07-13 16:35:19,738 DEBUG Wrap result sets: disabled
2006-07-13 16:35:19,738 INFO JDBC3 getGeneratedKeys(): enabled
2006-07-13 16:35:19,738 INFO Connection release mode: on_close
2006-07-13 16:35:19,738 INFO Maximum outer join fetch depth: 2
2006-07-13 16:35:19,738 INFO Default batch fetch size: 1
2006-07-13 16:35:19,738 INFO Generate SQL with comments: disabled
2006-07-13 16:35:19,738 INFO Order SQL updates by primary key: disabled
2006-07-13 16:35:19,738 INFO Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
2006-07-13 16:35:19,754 INFO Using ASTQueryTranslatorFactory
2006-07-13 16:35:19,754 INFO Query language substitutions: {}
2006-07-13 16:35:19,754 INFO Second-level cache: enabled
2006-07-13 16:35:19,754 INFO Query cache: enabled
2006-07-13 16:35:19,754 INFO Cache provider: org.hibernate.cache.TreeCacheProvider
2006-07-13 16:35:19,770 INFO Optimize cache for minimal puts: enabled
2006-07-13 16:35:19,770 INFO Structured second-level cache entries: enabled
2006-07-13 16:35:19,770 INFO Query cache factory: org.hibernate.cache.StandardQueryCacheFactory
.....
.....
2006-07-13 16:35:29,504 DEBUG Getting transaction for test.DAO.getRecords
2006-07-13 16:35:29,504 DEBUG Using transaction object [org.springframework.transaction.jta.JtaTransaction Object@24bfaa]
2006-07-13 16:35:29,504 DEBUG Current.getStatus()
2006-07-13 16:35:29,520 DEBUG threadTx.get= java.lang.ThreadLocal@17d7c7f
2006-07-13 16:35:29,520 DEBUG Transaction ret= null
2006-07-13 16:35:29,520 DEBUG Creating new transaction with name [test.DAO.getRecords]
...
...
2006-07-13 16:35:29,926 DEBUG Found thread-bound Session for HibernateTemplate
2006-07-13 16:35:29,957 DEBUG Retrieved value [org.springframework.orm.hibernate3.SessionHolder@9 f3e95] for key [org.hibernate.impl.SessionFactoryImpl@c5d9c1] bound to thread [http8080-Processor4]
2006-07-13 16:35:29,973 DEBUG about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2006-07-13 16:35:29,973 DEBUG opening JDBC connection
2006-07-13 16:35:30,004 DEBUG select this_.patient_id as patient1_1_0_, this_.name as name1_0_ from test.patient this_
2006-07-13 16:35:30,004 DEBUG preparing statement
2006-07-13 16:35:30,035 DEBUG about to open ResultSet (open ResultSets: 0, globally: 0)
2006-07-13 16:35:30,035 DEBUG processing result set
2006-07-13 16:35:30,035 DEBUG result set row: 0
2006-07-13 16:35:30,035 DEBUG returning '1' as column: patient1_1_0_
2006-07-13 16:35:30,051 DEBUG result row: EntityKey[test.string.Patient#1]
2006-07-13 16:35:30,051 DEBUG Initializing object from ResultSet: [test.string.Patient#1]
2006-07-13 16:35:30,066 DEBUG Hydrating entity: [test.string.Patient#1]
2006-07-13 16:35:30,066 DEBUG returning 'rtretret' as column: name1_0_
2006-07-13 16:35:30,066 DEBUG result set row: 1
2006-07-13 16:35:30,066 DEBUG returning '2' as column: patient1_1_0_
2006-07-13 16:35:30,066 DEBUG result row: EntityKey[test.string.Patient#2]
2006-07-13 16:35:30,066 DEBUG Initializing object from ResultSet: [test.string.Patient#2]
2006-07-13 16:35:30,066 DEBUG Hydrating entity: [test.string.Patient#2]
2006-07-13 16:35:30,066 DEBUG returning 'Y' as column: name1_0_
2006-07-13 16:35:30,066 DEBUG result set row: 2
2006-07-13 16:35:30,066 DEBUG returning '3' as column: patient1_1_0_
2006-07-13 16:35:30,066 DEBUG result row: EntityKey[test.string.Patient#3]
2006-07-13 16:35:30,066 DEBUG Initializing object from ResultSet: [test.string.Patient#3]
2006-07-13 16:35:30,066 DEBUG Hydrating entity: [test.string.Patient#3]
2006-07-13 16:35:30,066 DEBUG returning 'Z' as column: name1_0_
2006-07-13 16:35:30,066 DEBUG done processing result set (3 rows)
2006-07-13 16:35:30,066 DEBUG about to close ResultSet (open ResultSets: 1, globally: 1)
2006-07-13 16:35:30,066 DEBUG about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2006-07-13 16:35:30,066 DEBUG closing statement
2006-07-13 16:35:30,082 DEBUG total objects hydrated: 3
2006-07-13 16:35:30,082 DEBUG resolving associations for [test.string.Patient#1]
2006-07-13 16:35:30,098 DEBUG creating collection wrapper:[test.string.Patient.contacts#1]
2006-07-13 16:35:30,113 DEBUG adding entity to second-level cache: [test.string.Patient#1]
2006-07-13 16:35:30,223 DEBUG getRegions(): size of region 1
2006-07-13 16:35:30,238 DEBUG item already cached: test.string.Patient#1
2006-07-13 16:35:30,238 DEBUG done materializing entity [test.string.Patient#1]
2006-07-13 16:35:30,238 DEBUG resolving associations for [test.string.Patient#2]
2006-07-13 16:35:30,238 DEBUG creating collection wrapper:[test.string.Patient.contacts#2]
2006-07-13 16:35:30,238 DEBUG adding entity to second-level cache: [test.string.Patient#2]
2006-07-13 16:35:30,238 DEBUG caching: test.string.Patient#2
2006-07-13 16:35:30,238 DEBUG done materializing entity [test.string.Patient#2]
2006-07-13 16:35:30,238 DEBUG resolving associations for [test.string.Patient#3]
2006-07-13 16:35:30,238 DEBUG creating collection wrapper:[test.string.Patient.contacts#3]
2006-07-13 16:35:30,238 DEBUG adding entity to second-level cache: [test.string.Patient#3]
2006-07-13 16:35:30,238 DEBUG caching: test.string.Patient#3
2006-07-13 16:35:30,254 DEBUG done materializing entity [test.string.Patient#3]
2006-07-13 16:35:30,254 DEBUG initializing non-lazy collections
2006-07-13 16:35:30,254 DEBUG after autocommit
2006-07-13 16:35:30,254 DEBUG transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
2006-07-13 16:35:30,254 DEBUG after transaction completion
2006-07-13 16:35:30,254 DEBUG Not closing pre-bound Hibernate Session after HibernateTemplate
2006-07-13 16:35:30,254 DEBUG Invoking commit for transaction on test.DAO.getRecords
2006-07-13 16:35:30,254 DEBUG Triggering beforeCommit synchronization
2006-07-13 16:35:30,254 DEBUG Flushing Hibernate Session on transaction synchronization
2006-07-13 16:35:30,254 DEBUG flushing session
2006-07-13 16:35:30,254 DEBUG processing flush-time cascades
2006-07-13 16:35:30,269 DEBUG dirty checking collections
2006-07-13 16:35:30,269 DEBUG Flushing entities and processing referenced collections
2006-07-13 16:35:30,301 DEBUG Collection found: [test.string.Patient.contacts#1], was: [test.string.Patient.contacts#1] (uninitialized)
2006-07-13 16:35:30,301 DEBUG Collection found: [test.string.Patient.contacts#2], was: [test.string.Patient.contacts#2] (uninitialized)
2006-07-13 16:35:30,301 DEBUG Collection found: [test.string.Patient.contacts#3], was: [test.string.Patient.contacts#3] (uninitialized)
2006-07-13 16:35:30,301 DEBUG Processing unreferenced collections
2006-07-13 16:35:30,301 DEBUG Scheduling collection removes/(re)creates/updates
2006-07-13 16:35:30,301 DEBUG Flushed: 0 insertions, 0 updates, 0 deletions to 3 objects
2006-07-13 16:35:30,301 DEBUG Flushed: 0 (re)creations, 0 updates, 0 removals to 3 collection

according to the log its doing the second level cache but cahce retrieval is not happening... dont know whether im missing something in the configuration??


Regards
Sab