我有我认为是一个非常标准的设置...spring，jpa( hibernate )，我正在尝试添加ehcache。
我已全部配置并验证它是否正常工作...我正在记录 hibernate sql 语句和缓存语句，并且可以看到缓存正在被调用，并且一旦对象在缓存中，当我尝试再次加载它时, sql 语句没有写出(即它没有命中数据库)。
但是，性能很糟糕......如果我从缓存或数据库中获取对象，性能几乎相同。我怀疑问题可能与 spring 自动刷新 hibernate session 有关，或者开销可能是由于事务(我试图为该方法关闭)，或者我使用 c3p0 的连接池工作不正常足够。无论如何，我有点茫然..
我将发布我拥有的所有相关信息，希望这里的一些天才可以帮助我，否则我会被卡住。
首先，我的 Spring 配置:
<beans xmlns="http://www.springframework.org/schema/beans"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xmlns:aop="http://www.springframework.org/schema/aop"
xmlns:tx="http://www.springframework.org/schema/tx"
xmlns:hprof="http://www.nhprof.com/schema/hprof"
xsi:schemaLocation="
http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans-2.0.xsd
http://www.springframework.org/schema/tx http://www.springframework.org/schema/tx/spring-tx-2.0.xsd
http://www.springframework.org/schema/aop http://www.springframework.org/schema/aop/spring-aop-2.0.xsd
http://www.nhprof.com/schema/hprof http://www.nhprof.com/schema/hprof/hprof.xsd">
<bean class="org.springframework.orm.jpa.support.PersistenceAnnotationBeanPostProcessor" />
<bean id="systemPropertyManager" class="com.service.impl.SystemPropertyManagerImpl" />
<bean id="entityManagerFactory" class="org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean">
<property name="dataSource" ref="mysql" />
<property name="jpaVendorAdapter">
<bean
class="org.springframework.orm.jpa.vendor.HibernateJpaVendorAdapter">
<property name="database" value="MYSQL" />
<property name="showSql" value="true" />
</bean>
</property>
<property name="jpaProperties">
<props>
<prop key="hibernate.dialect">org.hibernate.dialect.MySQLDialect</prop>
<!-- always puts logging out to the console...we want it in the log file -->
<prop key="hibernate.connection.show_sql">false</prop>
<prop key="hibernate.hbm2ddl.auto">update</prop>
<prop key="hibernate.cache.provider_class">net.sf.ehcache.hibernate.SingletonEhCacheProvider</prop>
<prop key="net.sf.ehcache.configurationResourceName">ehcache.xml</prop>
<prop key="hibernate.cache.use_second_level_cache">true</prop>
<prop key="hibernate.cache.use_structured_entries">true</prop>
<prop key="hibernate.cache.use_query_cache">true</prop>
<prop key="hibernate.generate_statistics">true</prop>
<prop key="hibernate.default_batch_fetch_size">500</prop>
<prop key="hibernate.max_fetch_depth">5</prop>
<prop key="hibernate.jdbc.batch_size">1000</prop>
<prop key="hibernate.use_outer_join">true</prop>
</props>
</property>
<!-- <hprof:profiler /> -->
</bean>
<bean id="mysql" class="com.mchange.v2.c3p0.ComboPooledDataSource" destroy-method="close">
<property name="driverClass" value="com.mysql.jdbc.Driver" />
<property name="jdbcUrl" value="jdbc:mysql://localhost/daily?relaxAutoCommit=true&useUnicode=true&characterEncoding=UTF-8&jdbcCompliantTruncation=false&emulateLocators=true" />
<property name="user" value="root" />
<property name="password" value="" />
<property name="initialPoolSize"><value>5</value></property>
<property name="minPoolSize"><value>5</value></property>
<property name="maxPoolSize"><value>50</value></property>
<property name="idleConnectionTestPeriod"><value>200</value></property>
<property name="acquireIncrement"><value>3</value></property>
<property name="numHelperThreads"><value>3</value></property>
</bean>
<bean id="transactionManager" class="org.springframework.orm.jpa.JpaTransactionManager">
<property name="entityManagerFactory" ref="entityManagerFactory" />
</bean>
<tx:annotation-driven transaction-manager="transactionManager" />
我的ehcache文件如下
<ehcache>
<diskStore path="c:/cache"/>
<defaultCache eternal="false"
overflowToDisk="false"
maxElementsInMemory="50000"
timeToIdleSeconds="30"
timeToLiveSeconds="6000"
memoryStoreEvictionPolicy="LRU"
/>
<cache name="com.model.SystemProperty"
maxElementsInMemory="5000"
eternal="true"
overflowToDisk="false"
memoryStoreEvictionPolicy="LFU" />
为了调用缓存而注释的我的缓存对象如下:
package com.model;
import javax.persistence.*;
import org.hibernate.annotations.Cache;
import org.hibernate.annotations.CacheConcurrencyStrategy;
@Entity
@Cache(usage = CacheConcurrencyStrategy.READ_ONLY, region="com.model.SystemProperty", include="non-lazy")
@EntityListeners(com.util.GenericEntityLogger.class)
public class SystemProperty extends BaseObject{
private String name;
private String value;
// default constructor
public SystemProperty(){
}
public SystemProperty(String name, String value){
this.name = name;
this.value = value;
}
@Id
public String getName() {
return name;
}
public void setName(String name) {
this.name = name;
}
public String getValue() {
return value;
}
public void setValue(String value) {
this.value = value;
}
@Override
public boolean equals(Object o) {
// TODO Auto-generated method stub
return false;
}
@Override
public int hashCode() {
// TODO Auto-generated method stub
return 0;
}
@Override
public String toString() {
// TODO Auto-generated method stub
return null;
}
}
我使用spring @Transactional 方法保存和获取SystemProperty对象的接口(interface)实现如下:
package com.service.impl;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.springframework.transaction.annotation.Transactional;
import com.model.SystemProperty;
import com.service.SystemPropertyManager;
public class SystemPropertyManagerImpl extends BaseManagerImpl implements SystemPropertyManager {
// logging
protected final Log log = LogFactory.getLog(getClass());
public SystemProperty find(String name){
return (SystemProperty) super.entityManager.find(SystemProperty.class, name);
}
@Transactional
public SystemProperty save(SystemProperty prop){
return (SystemProperty) super.save(prop);
}
}
请注意，@Transactional 仅在 save 方法上。
最后，我用 3000 个系统属性对象填充了 mysql 数据库，然后编写了一个小测试文件，将它们加载了两次。
第一次加载它们时，我可以看到正在生成的 sql 并且缓存没有被命中。第二次，缓存确实被命中并且没有生成 sql。
单元测试:
@Test
public void testGetCachedUser1(){
log.debug("starting testGetCachedUser");
SystemPropertyManager mgr = ManagerFactory.getSystemPropertyManager();
EntityManager em = mgr.getEntityManager();
log.debug("start timing 1");
for(int i = 0; i<3000; i ++){
mgr.find("name_"+i);
}
log.debug("end timing 1");
log.debug("start timing 2");
for(int i = 0; i<3000; i ++){
mgr.find("name_"+i);
}
log.debug("end timing 2");
}
日志文件有很多信息。我将在“开始计时 1”区域中发布日志文件中的部分。这对应于仅在加载的第一个对象不在缓存中时发生的情况:
DEBUG 2010-10-22 11:57:49,533 [main][] org.springframework.transaction.annotation.AnnotationTransactionAttributeSource - Adding transactional method [find] with attribute [PROPAGATION_REQUIRED,ISOLATION_DEFAULT]
DEBUG 2010-10-22 11:57:49,533 [main][] org.hibernate.impl.SessionImpl - opened session at timestamp: 5274603804807168
DEBUG 2010-10-22 11:57:49,533 [main][] org.hibernate.transaction.JDBCTransaction - begin
DEBUG 2010-10-22 11:57:49,533 [main][] org.hibernate.jdbc.ConnectionManager - opening JDBC connection
DEBUG 2010-10-22 11:57:49,533 [main][] com.mchange.v2.resourcepool.BasicResourcePool - trace com.mchange.v2.resourcepool.BasicResourcePool@4e2f0a [managed: 5, unused: 4, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@1631573)
DEBUG 2010-10-22 11:57:49,533 [main][] org.hibernate.transaction.JDBCTransaction - current autocommit status: true
DEBUG 2010-10-22 11:57:49,533 [main][] org.hibernate.transaction.JDBCTransaction - disabling autocommit
DEBUG 2010-10-22 11:57:49,533 [main][] org.hibernate.jdbc.JDBCContext - after transaction begin
DEBUG 2010-10-22 11:57:49,549 [main][] org.springframework.transaction.support.TransactionSynchronizationManager - Bound value [org.springframework.jdbc.datasource.ConnectionHolder@5fbbf3] for key [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 -> 31ghzi8b1mphf1c19l14qo|149105b, debugUnreturnedConnectionStackTraces -> false, description -> null, driverClass -> com.p6spy.engine.spy.P6SpyDriver, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> 31ghzi8b1mphf1c19l14qo|149105b, idleConnectionTestPeriod -> 200, initialPoolSize -> 5, jdbcUrl -> jdbc:mysql://localhost/daily?relaxAutoCommit=true&useUnicode=true&characterEncoding=UTF-8&jdbcCompliantTruncation=false&emulateLocators=true, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 0, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 50, maxStatements -> 0, maxStatementsPerConnection -> 0, minPoolSize -> 5, numHelperThreads -> 3, numThreadsAwaitingCheckoutDefaultUser -> 0, preferredTestQuery -> null, properties -> {user=******, password=******}, propertyCycle -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 0, usesTraditionalReflectiveProxies -> false ]] to thread [main]
DEBUG 2010-10-22 11:57:49,549 [main][] org.springframework.transaction.support.TransactionSynchronizationManager - Bound value [org.springframework.orm.jpa.EntityManagerHolder@1bb03ee] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@11b99c4] to thread [main]
DEBUG 2010-10-22 11:57:49,549 [main][] org.springframework.transaction.support.TransactionSynchronizationManager - Initializing transaction synchronization
DEBUG 2010-10-22 11:57:49,549 [main][] org.springframework.transaction.interceptor.TransactionInterceptor - Getting transaction for [com.service.SystemPropertyManager.find]
DEBUG 2010-10-22 11:57:49,549 [main][] org.springframework.transaction.support.TransactionSynchronizationManager - Retrieved value [org.springframework.orm.jpa.EntityManagerHolder@1bb03ee] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@11b99c4] bound to thread [main]
DEBUG 2010-10-22 11:57:49,549 [main][] org.hibernate.event.def.DefaultLoadEventListener - loading entity: [com.model.SystemProperty#name_0]
DEBUG 2010-10-22 11:57:49,549 [main][] org.hibernate.event.def.DefaultLoadEventListener - attempting to resolve: [com.model.SystemProperty#name_0]
DEBUG 2010-10-22 11:57:49,549 [main][] org.hibernate.event.def.DefaultLoadEventListener - object not resolved in any cache: [com.model.SystemProperty#name_0]
DEBUG 2010-10-22 11:57:49,549 [main][] org.hibernate.persister.entity.AbstractEntityPersister - Fetching entity: [com.model.SystemProperty#name_0]
DEBUG 2010-10-22 11:57:49,549 [main][] org.hibernate.loader.Loader - loading entity: [com.model.SystemProperty#name_0]
DEBUG 2010-10-22 11:57:49,549 [main][] org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
DEBUG 2010-10-22 11:57:49,549 [main][] org.hibernate.SQL - select systemprop0_.name as name11_0_, systemprop0_.value as value11_0_ from SystemProperty systemprop0_ where systemprop0_.name=?
DEBUG 2010-10-22 11:57:49,549 [main][] org.hibernate.jdbc.AbstractBatcher - preparing statement
DEBUG 2010-10-22 11:57:49,580 [main][] org.hibernate.type.StringType - binding 'name_0' to parameter: 1
DEBUG 2010-10-22 11:57:49,580 [main][] org.hibernate.jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 0, globally: 0)
DEBUG 2010-10-22 11:57:49,580 [main][] org.hibernate.loader.Loader - processing result set
DEBUG 2010-10-22 11:57:49,580 [main][] org.hibernate.loader.Loader - result set row: 0
DEBUG 2010-10-22 11:57:49,580 [main][] org.hibernate.loader.Loader - result row: EntityKey[com.model.SystemProperty#name_0]
DEBUG 2010-10-22 11:57:49,580 [main][] org.hibernate.loader.Loader - Initializing object from ResultSet: [com.model.SystemProperty#name_0]
DEBUG 2010-10-22 11:57:49,580 [main][] org.hibernate.persister.entity.AbstractEntityPersister - Hydrating entity: [com.model.SystemProperty#name_0]
DEBUG 2010-10-22 11:57:49,580 [main][] org.hibernate.type.StringType - returning 'value_0' as column: value11_0_
DEBUG 2010-10-22 11:57:49,580 [main][] org.hibernate.loader.Loader - done processing result set (1 rows)
DEBUG 2010-10-22 11:57:49,580 [main][] org.hibernate.jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 1, globally: 1)
DEBUG 2010-10-22 11:57:49,580 [main][] org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
DEBUG 2010-10-22 11:57:49,580 [main][] org.hibernate.jdbc.AbstractBatcher - closing statement
DEBUG 2010-10-22 11:57:49,580 [main][] org.hibernate.loader.Loader - total objects hydrated: 1
DEBUG 2010-10-22 11:57:49,580 [main][] org.hibernate.engine.TwoPhaseLoad - resolving associations for [com.model.SystemProperty#name_0]
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.engine.TwoPhaseLoad - adding entity to second-level cache: [com.model.SystemProperty#name_0]
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.cache.ReadOnlyCache - Caching: com.model.SystemProperty#name_0
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.engine.TwoPhaseLoad - done materializing entity [com.model.SystemProperty#name_0]
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.engine.StatefulPersistenceContext - initializing non-lazy collections
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.loader.Loader - done entity load
DEBUG 2010-10-22 11:57:49,596 [main][] org.springframework.transaction.interceptor.TransactionInterceptor - Completing transaction for [com.service.SystemPropertyManager.find]
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.transaction.JDBCTransaction - commit
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.impl.SessionImpl - automatically flushing session
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.event.def.AbstractFlushingEventListener - flushing session
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.event.def.AbstractFlushingEventListener - processing flush-time cascades
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.engine.Cascade - processing cascade ACTION_PERSIST_ON_FLUSH for: com.model.SystemProperty
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.engine.Cascade - done processing cascade ACTION_PERSIST_ON_FLUSH for: com.model.SystemProperty
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.event.def.AbstractFlushingEventListener - dirty checking collections
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.event.def.AbstractFlushingEventListener - Flushing entities and processing referenced collections
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.event.def.AbstractFlushingEventListener - Processing unreferenced collections
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.event.def.AbstractFlushingEventListener - Scheduling collection removes/(re)creates/updates
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.event.def.AbstractFlushingEventListener - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.event.def.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.pretty.Printer - listing entities:
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.pretty.Printer - com.model.SystemProperty{name=name_0, value=value_0}
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.event.def.AbstractFlushingEventListener - executing flush
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.jdbc.ConnectionManager - registering flush begin
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.jdbc.ConnectionManager - registering flush end
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.event.def.AbstractFlushingEventListener - post flush
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.jdbc.JDBCContext - before transaction completion
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.impl.SessionImpl - before transaction completion
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.transaction.JDBCTransaction - re-enabling autocommit
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.transaction.JDBCTransaction - committed JDBC Connection
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.jdbc.JDBCContext - after transaction completion
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.jdbc.ConnectionManager - aggressively releasing JDBC connection
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
DEBUG 2010-10-22 11:57:49,596 [main][] com.mchange.v2.resourcepool.BasicResourcePool - trace com.mchange.v2.resourcepool.BasicResourcePool@4e2f0a [managed: 5, unused: 4, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@1631573)
DEBUG 2010-10-22 11:57:49,596 [main][] org.hibernate.impl.SessionImpl - after transaction completion
DEBUG 2010-10-22 11:57:49,596 [main][] org.springframework.transaction.support.TransactionSynchronizationManager - Clearing transaction synchronization
DEBUG 2010-10-22 11:57:49,596 [main][] org.springframework.transaction.support.TransactionSynchronizationManager - Removed value [org.springframework.orm.jpa.EntityManagerHolder@1bb03ee] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@11b99c4] from thread [main]
DEBUG 2010-10-22 11:57:49,612 [main][] org.springframework.transaction.support.TransactionSynchronizationManager - Removed value [org.springframework.jdbc.datasource.ConnectionHolder@5fbbf3] for key [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 -> 31ghzi8b1mphf1c19l14qo|149105b, debugUnreturnedConnectionStackTraces -> false, description -> null, driverClass -> com.p6spy.engine.spy.P6SpyDriver, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> 31ghzi8b1mphf1c19l14qo|149105b, idleConnectionTestPeriod -> 200, initialPoolSize -> 5, jdbcUrl -> jdbc:mysql://localhost/daily?relaxAutoCommit=true&useUnicode=true&characterEncoding=UTF-8&jdbcCompliantTruncation=false&emulateLocators=true, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 0, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 50, maxStatements -> 0, maxStatementsPerConnection -> 0, minPoolSize -> 5, numHelperThreads -> 3, numThreadsAwaitingCheckoutDefaultUser -> 0, preferredTestQuery -> null, properties -> {user=******, password=******}, propertyCycle -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 0, usesTraditionalReflectiveProxies -> false ]] from thread [main]
DEBUG 2010-10-22 11:57:49,612 [main][] org.hibernate.impl.SessionImpl - closing session
DEBUG 2010-10-22 11:57:49,612 [main][] org.hibernate.jdbc.ConnectionManager - connection already null in cleanup : no action
您可以看到它被加载到缓存中， hibernate session 被打开和关闭并刷新。
我将在下面的评论中发布我的第二个日志文件，因为我已经达到了这个问题的最大长度。重点是，一切看起来都不错，唯一真正的问题是它太慢了。
当我第一次加载 3000 个对象(即命中数据库)时，它与第二次加载几乎完全相同(即命中缓存)。就像我说的那样，开销是打开和关闭连接、刷新 session 、处理事务吗？我不知道。但无论如何，这都是相当残酷的。帮我stackoverflow...你是我唯一的希望:)
最佳答案
我建议尝试用普通的应用缓存替换二级缓存的使用。当我过去测试 Hibernate 的二级缓存性能时，我发现它不是很有效。这是由于缓存数据的结构方式——类似于结果集——即存储的是表格数据，而不是对象。这意味着许多缓存请求，结果证明是昂贵的。
为了将缓存代码与持久化逻辑分离，我使用了 AOP。由于您使用 Spring，这应该很容易。
关于performance - Spring、JPA (Hibernate) 和 Ehcache 性能不佳，我们在Stack Overflow上找到一个类似的问题： https://stackoverflow.com/questions/3997072/