Why EhCache not caching this query?

1.5k views Asked by At

Looking at Hibernate metrics, it appears that there is no use of second level cache for specific query:

org.hibernate.HibernateException: More than one row with the given identifier was found: 1242, for class: com.hibernate.query.performance.persistence.model.Store
INFO: Session Metrics {
    28572828 nanoseconds spent acquiring 1 JDBC connections;
    0 nanoseconds spent releasing 0 JDBC connections;
    6518980126 nanoseconds spent preparing 1396 JDBC statements;
    9007649169 nanoseconds spent executing 1396 JDBC statements;
    0 nanoseconds spent executing 0 JDBC batches;
    77148015 nanoseconds spent performing 1486 L2C puts;
    0 nanoseconds spent performing 0 L2C hits;
    71112 nanoseconds spent performing 1 L2C misses;
    0 nanoseconds spent executing 0 flushes (flushing a total of 0 entities and 0 collections);
    0 nanoseconds spent executing 0 partial-flushes (flushing a total of 0 entities and 0 collections)
}
org.hibernate.HibernateException: More than one row with the given identifier was found: 1242, for class: com.hibernate.query.performance.persistence.model.Store
org.hibernate.engine.internal.StatisticalLoggingSessionEventListener end
INFO: Session Metrics {
    25857570 nanoseconds spent acquiring 1 JDBC connections;
    0 nanoseconds spent releasing 0 JDBC connections;
    3010741744 nanoseconds spent preparing 1396 JDBC statements;
    8950885558 nanoseconds spent executing 1396 JDBC statements;
    0 nanoseconds spent executing 0 JDBC batches;
    54506271 nanoseconds spent performing 1486 L2C puts;
    0 nanoseconds spent performing 0 L2C hits;
    20938 nanoseconds spent performing 1 L2C misses;
    0 nanoseconds spent executing 0 flushes (flushing a total of 0 entities and 0 collections);
    0 nanoseconds spent executing 0 partial-flushes (flushing a total of 0 entities and 0 collections)
}

Code:

@Override
    public List<Customer> getFilteredCustomers(String filter) {
        Session session = null;
        List<Customer> customers = new ArrayList<>();
            try {
                session = sessionFactory.openSession();
                Query query = session.createQuery("select c " +
                        " from Rental r, Customer c join fetch c.address address " +
                        " where r.customer = c " +
                        " and r.returnDate is null");
                query.setCacheable(true);
                customers = (List<Customer>)query.list();
            }catch (Exception e){
                System.out.println(e);
            }finally {
                if (session!=null) session.close();
            }

        return customers;
    }

Configuration:

import net.sf.ehcache.config.CacheConfiguration;
import org.springframework.cache.CacheManager;
import org.springframework.cache.annotation.CachingConfigurer;
import org.springframework.cache.annotation.EnableCaching;
import org.springframework.cache.ehcache.EhCacheCacheManager;
import org.springframework.cache.interceptor.CacheErrorHandler;
import org.springframework.cache.interceptor.CacheResolver;
import org.springframework.cache.interceptor.KeyGenerator;
import org.springframework.cache.interceptor.SimpleKeyGenerator;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;

@Configuration
@EnableCaching
public class CachingConfig implements CachingConfigurer {

    @Bean(destroyMethod="shutdown")
    public net.sf.ehcache.CacheManager ehCacheManager() {
        CacheConfiguration cacheConfiguration = new CacheConfiguration();
        cacheConfiguration.setName("theEHCache");
        cacheConfiguration.setMemoryStoreEvictionPolicy("LRU");
        cacheConfiguration.setMaxElementsInMemory(1000);

        net.sf.ehcache.config.Configuration config = new net.sf.ehcache.config.Configuration();
        config.addCache(cacheConfiguration);

        return net.sf.ehcache.CacheManager.create(config);
    }

    @Bean
    @Override
    public CacheManager cacheManager() {
        return new EhCacheCacheManager(ehCacheManager());
    }

    @Override
    public CacheResolver cacheResolver() {
        return null;
    }

    @Bean
    @Override
    public KeyGenerator keyGenerator() {
        return new SimpleKeyGenerator();
    }

    @Override
    public CacheErrorHandler errorHandler() {
        return null;
    }
}

ApplicationConfig:

    @Configuration
@EnableTransactionManagement
@EnableJpaRepositories (basePackages = { "com.hibernate.query.performance.persistence" }, transactionManagerRef = "hibernateTransactionManager")
@EnableJpaAuditing
@PropertySource({ "classpath:persistence-postgresql.properties" })
@ComponentScan(basePackages = { "com.hibernate.query.performance" })
@EnableCaching
public class ApplicationConfig {

    @Autowired
    private Environment env;

    public ApplicationConfig() {
        super();
    }

    @Bean
    public LocalSessionFactoryBean sessionFactory() {
        final LocalSessionFactoryBean sessionFactory = new LocalSessionFactoryBean();
        sessionFactory.setDataSource(applicationDataSource());
        sessionFactory.setPackagesToScan(new String[] { "com.hibernate.query.performance.persistence.model" });
        sessionFactory.setHibernateProperties(hibernateProperties());

        return sessionFactory;
    }

    @Bean
    public LocalContainerEntityManagerFactoryBean entityManagerFactory() {
        final LocalContainerEntityManagerFactoryBean emf = new LocalContainerEntityManagerFactoryBean();
        emf.setDataSource(applicationDataSource());
        emf.setPackagesToScan(new String[] { "com.hibernate.query.performance.persistence.model" });

        final JpaVendorAdapter vendorAdapter = new HibernateJpaVendorAdapter();
        emf.setJpaVendorAdapter(vendorAdapter);
        emf.setJpaProperties(hibernateProperties());

        return emf;
    }

    @Primary
    @Bean
    public DriverManagerDataSource applicationDataSource() {
        final DriverManagerDataSource dataSource = new DriverManagerDataSource();
        dataSource.setDriverClassName(Preconditions.checkNotNull(env.getProperty("jdbc.driverClassName")));
        dataSource.setUrl(Preconditions.checkNotNull(env.getProperty("jdbc.url")));
        dataSource.setUsername(Preconditions.checkNotNull(env.getProperty("jdbc.user")));
        dataSource.setPassword(Preconditions.checkNotNull(env.getProperty("jdbc.pass")));
        return dataSource;
    }

    @Bean
    @Autowired
    @Primary
    public HibernateTransactionManager hibernateTransactionManager(SessionFactory sessionFactory) {
        final HibernateTransactionManager transactionManager = new HibernateTransactionManager();
        transactionManager.setSessionFactory(sessionFactory().getObject());
        transactionManager.setDataSource(applicationDataSource());
        return transactionManager;
    }

    /**
     * JTA (usually through JtaTransactionManager) is necessary for accessing multiple transactional resources within the same transaction.
     * The DataSource that Hibernate uses needs to be JTA-enabled in such a scenario (see container setup).
     * http://stackoverflow.com/questions/26562787/hibernateexception-couldnt-obtain-transaction-synchronized-session-for-current
     * @return
     */
    @Bean
    public PlatformTransactionManager jpaTransactionManager() {
        final JpaTransactionManager transactionManager = new JpaTransactionManager();
        transactionManager.setEntityManagerFactory(entityManagerFactory().getObject());
        return transactionManager;
    }

    @Bean
    public PersistenceExceptionTranslationPostProcessor exceptionTranslation() {
        return new PersistenceExceptionTranslationPostProcessor();
    }

    private final Properties hibernateProperties() {
        final Properties hibernateProperties = new Properties();
        hibernateProperties.setProperty("hibernate.dialect", env.getProperty("hibernate.dialect"));
        hibernateProperties.setProperty("hibernate.show_sql", env.getProperty("hibernate.show_sql"));
        hibernateProperties.setProperty("hibernate.format_sql", env.getProperty("hibernate.format_sql"));
        hibernateProperties.setProperty("hibernate.generate_statistics", env.getProperty("hibernate.generate_statistics"));
        hibernateProperties.setProperty("hibernate.cache.use_second_level_cache", env.getProperty("hibernate.cache.use_second_level_cache"));
        hibernateProperties.setProperty("hibernate.cache.use_query_cache", env.getProperty("hibernate.cache.use_query_cache"));
        hibernateProperties.setProperty("hibernate.cache.region.factory_class", env.getProperty("hibernate.cache.region.factory_class"));
        hibernateProperties.setProperty("hibernate.current_session_context_class", "managed"); // https://docs.jboss.org/hibernate/core/3.3/reference/en-US/html/architecture.html#architecture-current-session
        hibernateProperties.setProperty("hibernate.current_session_context_class", "org.hibernate.context.internal.ThreadLocalSessionContext");
        hibernateProperties.setProperty("hibernate.cache.region_prefix", env.getProperty("hibernate.cache.region_prefix"));
        return hibernateProperties;
    }
    @Bean
    public EhCacheCacheManager cacheManager() {
        return new EhCacheCacheManager(ehCacheCacheManager().getObject());
    }

    @Bean
    public EhCacheManagerFactoryBean ehCacheCacheManager() {
        EhCacheManagerFactoryBean cmfb = new EhCacheManagerFactoryBean();
        cmfb.setConfigLocation(new ClassPathResource("ehcache.xml"));
        cmfb.setShared(true);
        return cmfb;
    }
}

ehcache.xml

<ehcache xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns=""
         xsi:noNamespaceSchemaLocation="ehcache.xsd"
         updateCheck="true"
         monitoring="autodetect"
         dynamicConfig="true"
         maxBytesLocalHeap="150M">

    <diskStore path="java.io.tmpdir" />


    <cache name="customerCache"
           maxElementsInMemory="10000"
           maxElementsOnDisk="1000"
           eternal="false"
           diskSpoolBufferSizeMB="20"
           timeToIdleSeconds="300" timeToLiveSeconds="600"
           memoryStoreEvictionPolicy="LFU"
           transactionalMode="off">
    </cache>

    <defaultCache
           maxElementsInMemory="10000"
           maxElementsOnDisk="1000"
           eternal="false"
           diskSpoolBufferSizeMB="20"
           timeToIdleSeconds="300" timeToLiveSeconds="600"
           memoryStoreEvictionPolicy="LFU"
           transactionalMode="off">
    </defaultCache>
</ehcache>

persistence-postgresql.properties

hibernate.dialect=org.hibernate.dialect.PostgreSQLDialect
hibernate.show_sql=false
hibernate.format_sql=false
hibernate.generate_statistics=true
hibernate.cache.use_second_level_cache=true
hibernate.cache.region.factory_class=org.hibernate.cache.ehcache.EhCacheRegionFactory
hibernate.cache.use_query_cache=true
hibernate.cache.region_prefix=""

Console:

    INFO: HCANN000001: Hibernate Commons Annotations {4.0.5.Final}
54  org.hibernate.dialect.Dialect <init>
INFO: HHH000400: Using dialect: org.hibernate.dialect.PostgreSQLDialect
54  org.hibernate.engine.jdbc.internal.LobCreatorBuilder useContextualLobCreation
INFO: HHH000424: Disabling contextual LOB creation as createClob() method threw error : java.lang.reflect.InvocationTargetException
55  org.hibernate.hql.internal.ast.ASTQueryTranslatorFactory <init>
INFO: HHH000397: Using ASTQueryTranslatorFactory
55  org.hibernate.cache.spi.UpdateTimestampsCache <init>
INFO: HHH000250: Starting update timestamps cache at region: "".org.hibernate.cache.spi.UpdateTimestampsCache
55  org.hibernate.cache.ehcache.AbstractEhcacheRegionFactory getCache
WARN: HHH020003: Could not find a specific ehcache configuration for cache named ["".org.hibernate.cache.spi.UpdateTimestampsCache]; using defaults.
55  org.hibernate.cache.internal.StandardQueryCache <init>
INFO: HHH000248: Starting query cache at region: "".org.hibernate.cache.internal.StandardQueryCache
55  org.hibernate.cache.ehcache.AbstractEhcacheRegionFactory getCache
WARN: HHH020003: Could not find a specific ehcache configuration for cache named ["".org.hibernate.cache.internal.StandardQueryCache]; using defaults.
55  org.hibernate.validator.internal.util.Version <clinit>
INFO: HV000001: Hibernate Validator 5.2.2.Final
57  org.hibernate.cache.ehcache.AbstractEhcacheRegionFactory getCache
WARN: HHH020003: Could not find a specific ehcache configuration for cache named ["".customerCache]; using defaults.
58  org.hibernate.dialect.Dialect <init>
INFO: HHH000400: Using dialect: org.hibernate.dialect.PostgreSQLDialect
58  org.hibernate.engine.jdbc.internal.LobCreatorBuilder useContextualLobCreation
INFO: HHH000424: Disabling contextual LOB creation as createClob() method threw error : java.lang.reflect.InvocationTargetException
58  org.hibernate.engine.transaction.internal.TransactionFactoryInitiator initiateService
INFO: HHH000399: Using default transaction strategy (direct JDBC transactions)
58  org.hibernate.hql.internal.ast.ASTQueryTranslatorFactory <init>
INFO: HHH000397: Using ASTQueryTranslatorFactory
58  org.hibernate.cache.spi.UpdateTimestampsCache <init>
INFO: HHH000250: Starting update timestamps cache at region: "".org.hibernate.cache.spi.UpdateTimestampsCache
58  org.hibernate.cache.ehcache.AbstractEhcacheRegionFactory getCache
WARN: HHH020003: Could not find a specific ehcache configuration for cache named ["".org.hibernate.cache.spi.UpdateTimestampsCache]; using defaults.
58  org.hibernate.cache.internal.StandardQueryCache <init>
INFO: HHH000248: Starting query cache at region: "".org.hibernate.cache.internal.StandardQueryCache
58  org.hibernate.cache.ehcache.AbstractEhcacheRegionFactory getCache
WARN: HHH020003: Could not find a specific ehcache configuration for cache named ["".org.hibernate.cache.internal.StandardQueryCache]; using defaults.
59  org.hibernate.cache.ehcache.AbstractEhcacheRegionFactory getCache
WARN: HHH020003: Could not find a specific ehcache configuration for cache named ["".customerCache]; using defaults.
:03  org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring FrameworkServlet 'SpringDispatcher'
:03  org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-bio-8080"]

UPDATE

Based on a few unit tests I came to conclusion derived from results of test:

The given query is not cached in both cases: where there is present join fetch c.address address or not. However, join fetch c.address address speeds up the query more than 2x times. If anyone can explain why underlying frameworks think the query is not worth caching I would be glad.

0

There are 0 answers