2010-10-22 23 views
6

que tienen lo que supongo que es una configuración bastante estándar ... Spring, JPA (hibernación) y estoy tratando de añadir ehcache.Spring, JPA (Hibernate) y Ehcache degradación de las prestaciones

Lo tengo todo configurado y verificado que está funcionando ... Estoy registrando las sentencias sql de hibernación y las instrucciones de caché y puedo ver que la caché está siendo invocada y que una vez que el objeto está en la caché, cuando intento para volver a cargarlo, la instrucción SQL no está escrita (es decir, no está llegando a la base de datos).

Sin embargo, el rendimiento es terrible ... es más o menos el mismo rendimiento si consigo el objeto de la caché o desde el PP. Sospecho que tal vez el problema es que la primavera se vacíe automáticamente en la sesión de hibernación, o tal vez la sobrecarga se deba a transacciones (que he intentado desactivar para ese método), o quizás mi agrupación de conexiones usando c3p0 no esté funcionando bien suficiente. En cualquier caso, estoy en un poco de una pérdida ..

Voy a publicar toda la información relevante que tengo y es de esperar que algún genio aquí me puede ayudar a cabo por lo demás estoy atascado.

En primer lugar, mi primavera config:

<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&amp;useUnicode=true&amp;characterEncoding=UTF-8&amp;jdbcCompliantTruncation=false&amp;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" /> 

Mi archivo ehcache es el siguiente

<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" />    

Mi objeto en caché que está anotado con el fin de invocar la memoria caché es el siguiente:

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; 
    } 


} 

y mi aplicación de mi interfaz que se utiliza para guardar y sacar el objeto SystemProperty con el método @Transactional primavera es el siguiente:

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); 
    } 

} 

Tenga en cuenta que @Transactional es sólo en el método save. Finalmente, he llenado la base de datos mysql con 3000 objetos de propiedades del sistema y luego he escrito un pequeño archivo de prueba, que los carga dos veces.

La primera vez que los carga, puedo ver el SQL que se genera y que el caché no está siendo golpeado. La segunda vez, la memoria caché recibe un golpe y el sql no se genera.

Test Unit:

@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"); 
} 

El archivo de registro tiene un montón de información. Publicaré la sección del archivo de registro en el área de "inicio de temporización 1". Esto corresponde a lo que ocurre solamente para el primer objeto que se carga cuando no está en la memoria caché:

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 [email protected] [managed: 5, unused: 4, excluded: 0] (e.g. [email protected]) 
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 [[email protected]] 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 [[email protected]] for key [org[email protected]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 [[email protected]] for key [org[email protected]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 [email protected] [managed: 5, unused: 4, excluded: 0] (e.g. [email protected]) 
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 [[email protected]] for key [org[email protected]11b99c4] from thread [main] 
DEBUG 2010-10-22 11:57:49,612 [main][] org.springframework.transaction.support.TransactionSynchronizationManager - Removed value [[email protected]] 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 

Se puede ver que se está haciendo cargado en la memoria caché, se abrió la sesión de hibernación y se cierra y enrojecida.

voy a publicar mi segundo archivo de registro en un comentario más abajo como he golpeado la longitud máxima ya de esta cuestión. El punto principal es que todo parece estar bien, el único problema real es que es muy lento.

Cuando cargo 3000 objetos por primera vez (es decir, golpeando el db) que tarda casi exactamente el mismo que teh segunda vez (es decir, golpeando el caché).Como dije, ¿es porque la sobrecarga está abriendo y cerrando la conexión, enjuagando la sesión, tratando transacciones? No estoy seguro. Pero es bastante brutal en cualquier caso. Ayúdame stackoverflow ... eres mi única esperanza :)

+0

Parece que no puedo agregar otro comentario que muestra suficientes detalles de mi segundo archivo de registro. Basta con decir que es exactamente igual a la primera vez, excepto que golpea la caché. Por ejemplo, snippit: – Brian

+0

Si necesita adjuntar más registros/código, http://pastebin.com/ es muy útil – skaffman

+0

org.hibernate.engine.StatefulPersistenceContext - inicialización de colecciones no perezosas org.hibernate.event.def.DefaultLoadEventListener - Objeto resuelto en caché de segundo nivel: [com.model.SystemProperty # name_0] org.springframework.transaction.interceptor.TransactionInterceptor - Realización de transacción para [com.service.SystemPropertyManager.find] org.hibernate.transaction.JDBCTransaction - commit org.hibernate.impl.SessionImpl - sesión de vaciado automático – Brian

Respuesta

2

El punto principal es que todo se ve bien, el único problema real es que es muy lento.

Maldita lenta es una unidad de medida subjetiva :)

Cuando cargo 3000 objetos por primera vez (es decir, golpeando el db) que tarda casi exactamente el mismo que el segundo tiempo (es decir, presionar la caché).

Mostrar métricas, sin toda la sobrecarga de registro (y también sin P6Spy), utilizando System.nanoTime()

long startTime = System.nanoTime(); 
// ... the code being measured ... 
long estimatedTime = System.nanoTime() - startTime; 

Tal vez también tratar de realizar la prueba dentro de una sola transacción, utilizando un único EntityManager, sólo para ver cómo se comportan las cosas en estas condiciones.

Como dije, ¿es porque la sobrecarga está abriendo y cerrando la conexión, enjuagando la sesión, tratando las transacciones? No estoy seguro. Pero es bastante brutal en cualquier caso.

No se puede decir, debe perfilar su código para ver dónde se gasta el tiempo (y también controlar la actividad del GC).

Pero en teoría:

  • El connection en un Session es perezoso (obtendrá adquirida sólo cuando es necesario)
  • la adquisición de una connection de C3P0 debe ser bastante rápida (insignificante)
  • Desde sus entidades se almacenan en caché como de solo lectura, el flush debe ser bastante rápido

En otras palabras, no lo haría Espero que las operaciones anteriores sean costosas (así que me centraría en las partes circundantes). Pero como dije, perfilé (y supervisaré la actividad de GC).

+0

Todos los puntos buenos de Pascal. Ok, para la ejecución 1 (golpear la base de datos), el tiempo promedio para cada carga en los 3.000 en nanosegundos 18.029.219 versus para la ejecución 2: 16.610.083. Ahora, si elimino las transacciones de primavera, se convierte en: 2,520,817 para la ejecución 1 frente a 498,435 para la ejecución 2, que muestra buenas mejoras. Pero básicamente, implica que agregar transacciones de primavera es una sobrecarga significativa. Voy a perfilar la aplicación como sugirió para confirmar. Muchas gracias – Brian

+0

@Brian Bueno, al menos sabes lo que ** no ** toma tiempo ahora. Me sorprende que las transacciones de primavera sean muy costosas, especialmente dado que su método de lectura no está anotado con '@ Transactional'. Como nota al margen, es posible que disfrutes [Estrategias de transacción: comprender las trampas de las transacciones] (http://www.ibm.com/developerworks/java/library/j-ts1.html) (esto no te ayudará, pero es una buena lectura). –

+1

Hola Pascal, gracias por tus comentarios sobre este. También me sorprendió que fueran tan caros. El perfil confirmó que las transacciones eran una cuestión costosa. Cambiar el parámetro de propagación a Admite desde Requires_New ayudó un poco. Aprecia toda tu ayuda. Brian – Brian

4

Sugiero tratar de reemplazar ese uso de caché de segundo nivel con caché de aplicación simple. Cuando probé el rendimiento de caché de segundo nivel de Hibernate en el pasado, noté que no era muy efectivo. Esto se debe a la forma en que los datos en caché están estructurados, de forma similar a un conjunto de resultados, es decir, los datos tabulares son almacenados y no objetos. Esto significa muchas solicitudes de caché, que resultan caras.

Para separar el código de caché de la lógica de persistencia, uso AOP. Como usas Spring esto debería ser fácil.

+0

Las mediciones realizadas por el OP muestran que el caché L2 está haciendo su trabajo de manera efectiva. Ese no es el problema en absoluto. Y aunque tener que rehidratar entidades con datos tabulares de la memoria caché (frente a almacenar entidades en una memoria caché) puede tener un poco de sobrecarga, esto es ciertamente insignificante frente a un acceso a la base de datos (incluso local). Me gustaría tener detalles sobre tu banco, la implementación de caché utilizada, la configuración, el orden de magnitud ... Según mi experiencia, la API de caché Hibernate L2 es bastante efectiva. –

+0

@Pascal, en mi anterior lugar de trabajo, realizamos varias pruebas: almacenamiento en caché del segundo nivel de almacenamiento en caché de Hibernate VS utilizando un interceptor de AOP que escribimos, además de nuestra capa de servicio. Es decir, el almacenamiento en caché también impidió iniciar un TX y adquirir una conexión.Realicé una de estas pruebas, después de que otro desarrollador informara un mal rendimiento de la memoria caché de segundo nivel. Los resultados fueron bastante similares a lo que OP está describiendo, y la estrategia de caché aplicativo mostró un rendimiento superior, en un orden de magnitud. Ya no tengo acceso a los resultados, pero es fácil recrear ... –

+0

@Eran Muy interesante, agregando esto a mi lista de tareas pendientes (aunque sigo pensando que el problema está más relacionado con la demarcación de TX). Gracias por responder. –

2

¿Estás seguro de que no estás llegando a la base de datos en tu caché? habilite hibernate sql debug logger para ver si está haciendo lo correcto. Nunca utilicé el administrador de entidades antes. Siempre uso la sesión de hibernación. Si habilita la caché de consultas, aún tiene que hacer setCache (verdadero) en la consulta de hibernación. De lo contrario, todavía golpeará el db. La anotación @Cache en la entidad solo lo almacena en caché por id en ehcache. Cuando configura su consulta para que sea almacenable en caché, la clave de caché es su consulta y el resultado es el ID de la entidad, luego intentará resolver la entidad en el ehcache mediante id.

2

Su prueba utiliza el EntityManager directamente sin una transacción. Un EntityManager tiene un alcance de una sola unidad de trabajo, generalmente una sola transacción. Probablemente estés forzando una nueva transacción incl. la búsqueda en el grupo de una conexión de base de datos para cada invocación de búsqueda.

Esto es lo que sugeriría:

  • uso transacciones de sólo lectura para los métodos no ahorrar en vez de ninguna demarcación TX
  • envolver su grano de origen de datos en un LazyConnectionDataSourceProxy para evitar una conexión si no realmente necesita hablar con su base de datos (es decir, en caso de un golpe de caché)
  • actualice su prueba para hablar con su bean de servicio en lugar de usar directamente un EntityManager.
Cuestiones relacionadas