Hi folks,
I'm trying to add a second levele cache and query cache to my project, I follow the ehcache tutorial at
http://ehcache.sourceforge.net/document ... rnate.html and googled a lot (really.. a lot). Probably I'm missing something but I cannot see what.
Spring 2.5.6
Hibernate: 3.3.1.GA
Hibernate Annotations: 3.4.0.GA
EhCache: 1.6.0-beta5 (1.5.0 tried too, but with the same results)
spring configuration:
Code:
<bean id="sessionFactory" class="org.springframework.orm.hibernate3.annotation.AnnotationSessionFactoryBean">
<property name="dataSource" ref="dataSource"/>
<property name="packagesToScan" value="org.danysoft.hibcache"/>
<property name="hibernateProperties">
<props>
<prop key="hibernate.dialect">${hibernate.dialect}</prop>
<prop key="hibernate.show_sql">true</prop>
<prop key="hibernate.cache.use_second_level_cache">true</prop>
<prop key="hibernate.cache.use_query_cache">true</prop>
<prop key="hibernate.cache.provider_class">net.sf.ehcache.hibernate.EhCacheProvider</prop>
<prop key="hibernate.generate_statistics">true</prop>
</props>
</property>
</bean>
ehcache configuration
Code:
<ehcache>
<diskStore path="java.io.tmpdir" />
<defaultCache maxElementsInMemory="20" eternal="false"
timeToIdleSeconds="300" timeToLiveSeconds="600" overflowToDisk="true"
diskPersistent="false" diskExpiryThreadIntervalSeconds="300"
memoryStoreEvictionPolicy="LRU" />
<cache name="org.danysoft.hibcache.User" maxElementsInMemory="50"
eternal="false" timeToLiveSeconds="60" overflowToDisk="true" />
<cache name="org.hibernate.cache.StandardQueryCache"
maxElementsInMemory="5" eternal="false" timeToLiveSeconds="120"
overflowToDisk="true" />
<cache name="org.hibernate.cache.UpdateTimestampsCache"
maxElementsInMemory="50" eternal="false" timeToLiveSeconds="160"
overflowToDisk="true" />
</ehcache>
my domain object
Code:
package org.danysoft.hibcache;
import java.sql.Timestamp;
import javax.persistence.Entity;
import javax.persistence.Id;
import javax.persistence.Version;
import org.hibernate.annotations.Cache;
import org.hibernate.annotations.CacheConcurrencyStrategy;
@Entity
@Cache(usage=CacheConcurrencyStrategy.READ_WRITE)
public class User {
@Id
public Long id;
public String name;
public String email;
@Version
public Timestamp version;
}
my test
Code:
@Test
public void cache() throws Exception {
logger.debug("Start test...");
SessionFactory sf = (SessionFactory) applicationContext.getBean("sessionFactory");
Session session = sf.openSession();
session.setFlushMode(FlushMode.AUTO);
session.setCacheMode(CacheMode.NORMAL);
User user = new User();
user.id = 1L;
user.name = "test";
user.email = "test";
session.save(user);
session.flush();
logger.debug("INSERT DONE!");
user = (User) session.createQuery("FROM User WHERE id = :id").setLong("id", 1L)
.setCacheable(true).uniqueResult();
logger.debug("QUERY 1 DONE!");
Assert.assertNotNull(user);
user = (User) session.createQuery("FROM User WHERE id = :id").setLong("id", 1L)
.setCacheable(true).uniqueResult();
logger.debug("QUERY 2 DONE!");
Assert.assertNotNull(user);
session.close();
session = sf.openSession();
user = (User) session.createQuery("FROM User WHERE id = :id").setLong("id", 1L)
.setCacheable(true).uniqueResult();
logger.debug("QUERY 3 DONE!");
Assert.assertNotNull(user);
System.out.println(sf.getStatistics());
Assert.assertEquals(1, sf.getStatistics().getSecondLevelCachePutCount());
Assert.assertEquals(0, sf.getStatistics().getSecondLevelCacheHitCount());
Assert.assertEquals(0, sf.getStatistics().getSecondLevelCacheMissCount());
Assert.assertEquals(3, sf.getStatistics().getQueryCachePutCount());
Assert.assertEquals(0, sf.getStatistics().getQueryCacheHitCount());
Assert.assertEquals(3, sf.getStatistics().getQueryCacheMissCount());
Assert.assertEquals(3, sf.getStatistics().getQueryExecutionCount());
logger.debug("... end test!");
}
debug log
Code:
2009-05-22 17:06:33,572 INFO [org.springframework.beans.factory.xml.XmlBeanDefinitionReader] - Loading XML bean definitions from class path resource [hib-cache.appctx.xml]
2009-05-22 17:06:34,142 INFO [org.springframework.context.support.GenericApplicationContext] - Refreshing org.springframework.context.support.GenericApplicationContext@204f80d6: display name [org.springframework.context.support.GenericApplicationContext@204f80d6]; startup date [Fri May 22 17:06:34 CEST 2009]; root of context hierarchy
2009-05-22 17:06:34,142 INFO [org.springframework.context.support.GenericApplicationContext] - Bean factory for application context [org.springframework.context.support.GenericApplicationContext@204f80d6]: org.springframework.beans.factory.support.DefaultListableBeanFactory@3acafb56
2009-05-22 17:06:34,183 INFO [org.springframework.beans.factory.config.PropertyPlaceholderConfigurer] - Loading properties file from class path resource [hib-cache.properties]
2009-05-22 17:06:34,222 INFO [org.springframework.beans.factory.support.DefaultListableBeanFactory] - Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@3acafb56: defining beans [propertyConfigurer,dataSource,sessionFactory,org.springframework.context.annotation.internalPersistenceAnnotationProcessor,org.springframework.context.annotation.internalCommonAnnotationProcessor,org.springframework.context.annotation.internalAutowiredAnnotationProcessor,org.springframework.context.annotation.internalRequiredAnnotationProcessor]; root of factory hierarchy
2009-05-22 17:06:34,236 INFO [com.mchange.v2.log.MLog] - MLog clients using log4j logging.
2009-05-22 17:06:34,319 INFO [com.mchange.v2.c3p0.C3P0Registry] - Initializing c3p0-0.9.1.2 [built 21-May-2007 15:04:56; debug? true; trace: 10]
2009-05-22 17:06:34,438 INFO [org.hibernate.cfg.annotations.Version] - Hibernate Annotations 3.4.0.GA
2009-05-22 17:06:34,446 INFO [org.hibernate.cfg.Environment] - Hibernate 3.3.1.GA
2009-05-22 17:06:34,448 INFO [org.hibernate.cfg.Environment] - hibernate.properties not found
2009-05-22 17:06:34,451 INFO [org.hibernate.cfg.Environment] - Bytecode provider name : javassist
2009-05-22 17:06:34,457 INFO [org.hibernate.cfg.Environment] - using JDK 1.4 java.sql.Timestamp handling
2009-05-22 17:06:34,504 INFO [org.hibernate.annotations.common.Version] - Hibernate Commons Annotations 3.1.0.GA
2009-05-22 17:06:34,589 INFO [org.hibernate.cfg.AnnotationBinder] - Binding entity from annotated class: org.danysoft.hibcache.User
2009-05-22 17:06:34,637 INFO [org.hibernate.cfg.annotations.EntityBinder] - Bind entity org.danysoft.hibcache.User on table User
2009-05-22 17:06:34,673 INFO [org.hibernate.cfg.AnnotationConfiguration] - Hibernate Validator not found: ignoring
2009-05-22 17:06:34,673 INFO [org.springframework.orm.hibernate3.annotation.AnnotationSessionFactoryBean] - Building new Hibernate SessionFactory
2009-05-22 17:06:34,729 INFO [org.hibernate.connection.ConnectionProviderFactory] - Initializing connection provider: org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider
2009-05-22 17:06:34,843 INFO [com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource] - Initializing c3p0 pool... com.mchange.v2.c3p0.ComboPooledDataSource [ acquireIncrement -> 3, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, dataSourceName -> z8kflt81t3eqovy96e90|7f4d1d41, debugUnreturnedConnectionStackTraces -> false, description -> null, driverClass -> com.mysql.jdbc.Driver, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> z8kflt81t3eqovy96e90|7f4d1d41, idleConnectionTestPeriod -> 0, initialPoolSize -> 3, jdbcUrl -> jdbc:mysql://localhost:4040/hibcache?useUnicode=true&characterEncoding=utf8, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 0, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 15, maxStatements -> 0, maxStatementsPerConnection -> 0, minPoolSize -> 3, numHelperThreads -> 3, numThreadsAwaitingCheckoutDefaultUser -> 0, preferredTestQuery -> null, properties -> {user=******, password=******}, propertyCycle -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 0, usesTraditionalReflectiveProxies -> false ]
2009-05-22 17:06:34,992 INFO [org.hibernate.cfg.SettingsFactory] - RDBMS: MySQL, version: 5.0.75-0ubuntu10.2
2009-05-22 17:06:34,992 INFO [org.hibernate.cfg.SettingsFactory] - JDBC driver: MySQL-AB JDBC Driver, version: mysql-connector-java-5.1.6 ( Revision: ${svn.Revision} )
2009-05-22 17:06:35,003 INFO [org.hibernate.dialect.Dialect] - Using dialect: org.hibernate.dialect.MySQL5InnoDBDialect
2009-05-22 17:06:35,006 INFO [org.hibernate.transaction.TransactionFactoryFactory] - Transaction strategy: org.springframework.orm.hibernate3.SpringTransactionFactory
2009-05-22 17:06:35,006 INFO [org.hibernate.transaction.TransactionManagerLookupFactory] - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
2009-05-22 17:06:35,007 INFO [org.hibernate.cfg.SettingsFactory] - Automatic flush during beforeCompletion(): disabled
2009-05-22 17:06:35,007 INFO [org.hibernate.cfg.SettingsFactory] - Automatic session close at end of transaction: disabled
2009-05-22 17:06:35,007 INFO [org.hibernate.cfg.SettingsFactory] - JDBC batch size: 15
2009-05-22 17:06:35,007 INFO [org.hibernate.cfg.SettingsFactory] - JDBC batch updates for versioned data: disabled
2009-05-22 17:06:35,007 INFO [org.hibernate.cfg.SettingsFactory] - Scrollable result sets: enabled
2009-05-22 17:06:35,007 INFO [org.hibernate.cfg.SettingsFactory] - JDBC3 getGeneratedKeys(): enabled
2009-05-22 17:06:35,007 INFO [org.hibernate.cfg.SettingsFactory] - Connection release mode: auto
2009-05-22 17:06:35,008 INFO [org.hibernate.cfg.SettingsFactory] - Maximum outer join fetch depth: 2
2009-05-22 17:06:35,008 INFO [org.hibernate.cfg.SettingsFactory] - Default batch fetch size: 1
2009-05-22 17:06:35,008 INFO [org.hibernate.cfg.SettingsFactory] - Generate SQL with comments: disabled
2009-05-22 17:06:35,008 INFO [org.hibernate.cfg.SettingsFactory] - Order SQL updates by primary key: disabled
2009-05-22 17:06:35,008 INFO [org.hibernate.cfg.SettingsFactory] - Order SQL inserts for batching: disabled
2009-05-22 17:06:35,008 INFO [org.hibernate.cfg.SettingsFactory] - Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
2009-05-22 17:06:35,009 INFO [org.hibernate.hql.ast.ASTQueryTranslatorFactory] - Using ASTQueryTranslatorFactory
2009-05-22 17:06:35,009 INFO [org.hibernate.cfg.SettingsFactory] - Query language substitutions: {}
2009-05-22 17:06:35,009 INFO [org.hibernate.cfg.SettingsFactory] - JPA-QL strict compliance: disabled
2009-05-22 17:06:35,009 INFO [org.hibernate.cfg.SettingsFactory] - Second-level cache: enabled
2009-05-22 17:06:35,009 INFO [org.hibernate.cfg.SettingsFactory] - Query cache: enabled
2009-05-22 17:06:35,012 INFO [org.hibernate.cfg.SettingsFactory] - Cache region factory : org.hibernate.cache.impl.bridge.RegionFactoryCacheProviderBridge
2009-05-22 17:06:35,012 INFO [org.hibernate.cache.impl.bridge.RegionFactoryCacheProviderBridge] - Cache provider: net.sf.ehcache.hibernate.EhCacheProvider
2009-05-22 17:06:35,014 INFO [org.hibernate.cfg.SettingsFactory] - Optimize cache for minimal puts: disabled
2009-05-22 17:06:35,014 INFO [org.hibernate.cfg.SettingsFactory] - Structured second-level cache entries: disabled
2009-05-22 17:06:35,014 INFO [org.hibernate.cfg.SettingsFactory] - Query cache factory: org.hibernate.cache.StandardQueryCacheFactory
2009-05-22 17:06:35,017 INFO [org.hibernate.cfg.SettingsFactory] - Echoing all SQL to stdout
2009-05-22 17:06:35,021 INFO [org.hibernate.cfg.SettingsFactory] - Statistics: enabled
2009-05-22 17:06:35,021 INFO [org.hibernate.cfg.SettingsFactory] - Deleted entity synthetic identifier rollback: disabled
2009-05-22 17:06:35,022 INFO [org.hibernate.cfg.SettingsFactory] - Default entity-mode: pojo
2009-05-22 17:06:35,022 INFO [org.hibernate.cfg.SettingsFactory] - Named query checking : enabled
2009-05-22 17:06:35,044 INFO [org.hibernate.search.Version] - Hibernate Search 3.1.0.GA
2009-05-22 17:06:35,093 INFO [org.hibernate.impl.SessionFactoryImpl] - building session factory
2009-05-22 17:06:35,298 INFO [org.hibernate.impl.SessionFactoryObjectFactory] - Not binding factory to JNDI, no JNDI name configured
2009-05-22 17:06:35,299 INFO [org.hibernate.cache.UpdateTimestampsCache] - starting update timestamps cache at region: org.hibernate.cache.UpdateTimestampsCache
2009-05-22 17:06:35,302 INFO [org.hibernate.cache.StandardQueryCache] - starting query cache at region: org.hibernate.cache.StandardQueryCache
...
2009-05-22 17:06:35,498 DEBUG [org.danysoft.AbstractHibernateTest] - Start test...
2009-05-22 17:06:35,514 DEBUG [org.hibernate.cache.UpdateTimestampsCache] - Pre-invalidating space [User]
Hibernate: insert into User (email, name, version, id) values (?, ?, ?, ?)
2009-05-22 17:06:35,548 DEBUG [org.danysoft.AbstractHibernateTest] - INSERT DONE!
2009-05-22 17:06:35,696 DEBUG [org.hibernate.cache.StandardQueryCache] - checking cached query results in region: org.hibernate.cache.StandardQueryCache
2009-05-22 17:06:35,696 DEBUG [org.hibernate.cache.StandardQueryCache] - query results were not found in cache
Hibernate: select user0_.id as id0_, user0_.email as email0_, user0_.name as name0_, user0_.version as version0_ from User user0_ where user0_.id=?
2009-05-22 17:06:35,715 DEBUG [org.hibernate.cache.StandardQueryCache] - caching query results in region: org.hibernate.cache.StandardQueryCache; timestamp=5091347642359808
2009-05-22 17:06:35,716 DEBUG [org.hibernate.cache.UpdateTimestampsCache] - Invalidating space [User], timestamp: 5091347643252737
2009-05-22 17:06:35,717 DEBUG [org.danysoft.AbstractHibernateTest] - QUERY 1 DONE!
2009-05-22 17:06:35,719 DEBUG [org.hibernate.cache.StandardQueryCache] - checking cached query results in region: org.hibernate.cache.StandardQueryCache
2009-05-22 17:06:35,719 DEBUG [org.hibernate.cache.StandardQueryCache] - Checking query spaces for up-to-dateness: [User]
2009-05-22 17:06:35,719 DEBUG [org.hibernate.cache.UpdateTimestampsCache] - [User] last update timestamp: 5091347643252737, result set timestamp: 5091347642359808
2009-05-22 17:06:35,719 DEBUG [org.hibernate.cache.StandardQueryCache] - cached query results were not up to date
Hibernate: select user0_.id as id0_, user0_.email as email0_, user0_.name as name0_, user0_.version as version0_ from User user0_ where user0_.id=?
2009-05-22 17:06:35,721 DEBUG [org.hibernate.cache.StandardQueryCache] - caching query results in region: org.hibernate.cache.StandardQueryCache; timestamp=5091347642359808
2009-05-22 17:06:35,721 DEBUG [org.danysoft.AbstractHibernateTest] - QUERY 2 DONE!
2009-05-22 17:06:35,725 DEBUG [org.hibernate.cache.StandardQueryCache] - checking cached query results in region: org.hibernate.cache.StandardQueryCache
2009-05-22 17:06:35,725 DEBUG [org.hibernate.cache.StandardQueryCache] - Checking query spaces for up-to-dateness: [User]
2009-05-22 17:06:35,725 DEBUG [org.hibernate.cache.UpdateTimestampsCache] - [User] last update timestamp: 5091347643252737, result set timestamp: 5091347642359808
2009-05-22 17:06:35,725 DEBUG [org.hibernate.cache.StandardQueryCache] - cached query results were not up to date
Hibernate: select user0_.id as id0_, user0_.email as email0_, user0_.name as name0_, user0_.version as version0_ from User user0_ where user0_.id=?
2009-05-22 17:06:35,728 DEBUG [org.hibernate.cache.StandardQueryCache] - caching query results in region: org.hibernate.cache.StandardQueryCache; timestamp=5091347643285504
2009-05-22 17:06:35,728 DEBUG [org.danysoft.AbstractHibernateTest] - QUERY 3 DONE!
Statistics[start time=1243004795091,sessions opened=3,sessions closed=1,transactions=1,successful transactions=0,optimistic lock failures=0,flushes=1,connections obtained=2,statements prepared=4,statements closed=4,second level cache puts=1,second level cache hits=0,second level cache misses=0,entities loaded=1,entities updated=0,entities inserted=1,entities deleted=0,entities fetched=0,collections loaded=0,collections updated=0,collections removed=0,collections recreated=0,collections fetched=0,queries executed to database=3,query cache puts=3,query cache hits=0,query cache misses=3,max query time=17]
2009-05-22 17:06:35,729 DEBUG [org.danysoft.AbstractHibernateTest] - ... end test!
2009-05-22 17:06:35,873 INFO [org.apache.ddlutils.platform.mysql.MySqlPlatform] - Executed 1 SQL command(s) with 0 error(s)
2009-05-22 17:06:35,878 INFO [org.springframework.context.support.GenericApplicationContext] - Closing org.springframework.context.support.GenericApplicationContext@204f80d6: display name [org.springframework.context.support.GenericApplicationContext@204f80d6]; startup date [Fri May 22 17:06:34 CEST 2009]; root of context hierarchy
2009-05-22 17:06:35,878 INFO [org.springframework.beans.factory.support.DefaultListableBeanFactory] - Destroying singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@3acafb56: defining beans [propertyConfigurer,dataSource,sessionFactory,org.springframework.context.annotation.internalPersistenceAnnotationProcessor,org.springframework.context.annotation.internalCommonAnnotationProcessor,org.springframework.context.annotation.internalAutowiredAnnotationProcessor,org.springframework.context.annotation.internalRequiredAnnotationProcessor]; root of factory hierarchy
2009-05-22 17:06:35,884 INFO [org.springframework.orm.hibernate3.annotation.AnnotationSessionFactoryBean] - Closing Hibernate SessionFactory
2009-05-22 17:06:35,884 INFO [org.hibernate.impl.SessionFactoryImpl] - closing
As you can see the queries does not properly return data from cache.
I see my code so many times that now I'm a bit confused about all the change made to try different setting, but I'm not be able to see what is wrong or missing.
I hope that someone can help a little noob :D
Login
FAQ
Search
