# Hibernate performs n+1 selects instead of 1 when using query cache

**URL:** <https://discourse.hibernate.org/t/hibernate-performs-n-1-selects-instead-of-1-when-using-query-cache/2288>\
**Category:** Hibernate ORM\
**Created:** [February 14, 2019, 8:41am UTC](https://discourse.hibernate.org/t/hibernate-performs-n-1-selects-instead-of-1-when-using-query-cache/2288 "2019-02-14T08:41:59Z")\
**Posts on this page:** 2\
**Page:** 1

<div class="post-metadata">

**Author:** ![Kirill](https://avatars.discourse-cdn.com/v4/letter/k/a9a28c/32.png) [@Kirill](https://discourse.hibernate.org/u/Kirill)\
**Post date:** [February 14, 2019, 8:42am UTC](https://discourse.hibernate.org/t/hibernate-performs-n-1-selects-instead-of-1-when-using-query-cache/2288/1 "2019-02-14T08:42:00Z")

</div>

I’ve posted this question at SO already but haven’t got any answers yet - [java - Hibernate performs N+1 selects instead of 1 query when using the Query Cache - Stack Overflow](https://stackoverflow.com/questions/54674418/hibernate-performs-n1-selects-instead-of-1-when-using-query-cache).

I use query cache + second-level cache and I want to cache results for 10 seconds properly. So here is my

**ehcache.xml** :

```
<ehcache xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:noNamespaceSchemaLocation="../config/ehcache.xsd">
    <diskStore path="java.io.tmpdir"/>

    <cache name = "TestEntity"
           maxElementsInMemory="100"
           eternal="false"
           timeToLiveSeconds="10"
           memoryStoreEvictionPolicy="LRU">
    </cache>

    <cache name="org.hibernate.cache.internal.StandardQueryCache"
           maxElementsInMemory="100"
           eternal="false"
           timeToLiveSeconds="10"
           memoryStoreEvictionPolicy="LRU">
    </cache>

    <defaultCache
            maxElementsInMemory="10000"
            eternal="false"
            timeToLiveSeconds="120"
            maxElementsOnDisk="100"
            diskExpiryThreadIntervalSeconds="120"
            memoryStoreEvictionPolicy="LRU">
        <persistence strategy="localTempSwap"/>
    </defaultCache>
</ehcache>

```

First, I populate my database using the _insert()_ method.  
Then, I call my _select()_ method to get data for the first time. Everything works fine - query and the entities become cached and if I call the _select()_ method 2 seconds later I’ll get the data without any requests to the database.  
Then I wait for 11 seconds (in order for cache to expire completely), call _select()_ and 2 seconds after call _select()_ again. And that’s where I get n+1 selects:

> 2019-02-13 18:52:17,101 [DEBUG]  
> org.hibernate.engine.jdbc.spi.SqlStatementLogger.logStatement(SqlStatementLogger.java:92)  
> select testentity0\_.id as id1\_0\_0\_, testentity0\_.value as value2\_0\_0\_  
> from test testentity0\_ where testentity0\_.id=? 2019-02-13 18:52:17,107  
> [DEBUG]  
> org.hibernate.engine.jdbc.spi.SqlStatementLogger.logStatement(SqlStatementLogger.java:92)  
> select testentity0\_.id as id1\_0\_0\_, testentity0\_.value as value2\_0\_0\_  
> from test testentity0\_ where testentity0\_.id=? 2019-02-13 18:52:17,108  
> [DEBUG]  
> org.hibernate.engine.jdbc.spi.SqlStatementLogger.logStatement(SqlStatementLogger.java:92)  
> select testentity0\_.id as id1\_0\_0\_, testentity0\_.value as value2\_0\_0\_  
> from test testentity0\_ where testentity0\_.id=? 2019-02-13 18:52:17,108  
> [DEBUG]  
> org.hibernate.engine.jdbc.spi.SqlStatementLogger.logStatement(SqlStatementLogger.java:92)  
> select testentity0\_.id as id1\_0\_0\_, testentity0\_.value as value2\_0\_0\_  
> from test testentity0\_ where testentity0\_.id=? 2019-02-13 18:52:17,109  
> [DEBUG]  
> org.hibernate.engine.jdbc.spi.SqlStatementLogger.logStatement(SqlStatementLogger.java:92)  
> select testentity0\_.id as id1\_0\_0\_, testentity0\_.value as value2\_0\_0\_  
> from test testentity0\_ where testentity0\_.id=?

I know that these requests are made because query cache caches only ids and it seems that entities for these ids are missing in the second level cache. But why are they missing? When I enable full logging I see that after third call to _select()_ there are log entries like

> Adding entity to second-level cache: [TestEntity#1]

So if entities are added to second level cache and they should expire only in 10 seconds, why are they missing just after 2?

Part of my **pom.xml** :

```
<dependencies>
    <dependency>
        <groupId>com.h2database</groupId>
        <artifactId>h2</artifactId>
        <version>1.4.194</version>
    </dependency>

    <dependency>
        <groupId>org.hibernate</groupId>
        <artifactId>hibernate-core</artifactId>
        <version>5.2.7.Final</version>
    </dependency>

    <dependency>
        <groupId>org.hibernate</groupId>
        <artifactId>hibernate-ehcache</artifactId>
        <version>5.2.7.Final</version>
    </dependency>

    <dependency>
        <groupId>org.hibernate</groupId>
        <artifactId>hibernate-c3p0</artifactId>
        <version>5.2.7.Final</version>
    </dependency>
</dependencies>

```

**persistence.xml** :

```
<persistence xmlns="http://java.sun.com/xml/ns/persistence"
             xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
             xsi:schemaLocation="http://java.sun.com/xml/ns/persistence http://java.sun.com/xml/ns/persistence/persistence_2_0.xsd"
             version="2.0">
    <persistence-unit name="main">
        <class>TestEntity</class>

        <exclude-unlisted-classes>true</exclude-unlisted-classes>

        <properties>
            <property name="hibernate.hbm2ddl.auto" value="create-drop"/>
            <property name="hibernate.use_sql_comments" value="true"/>
            <property name="hibernate.cache.use_second_level_cache" value="true"/>
            <property name="hibernate.cache.region.factory_class" value="org.hibernate.cache.ehcache.EhCacheRegionFactory"/>
            <property name="hibernate.cache.use_query_cache" value="true"/>
            <property name="net.sf.ehcache.configurationResourceName" value="ehcache.xml"/>
        </properties>
    </persistence-unit>
</persistence>

```

**TestEntity.java** :

```
import org.hibernate.annotations.CacheConcurrencyStrategy;

import javax.persistence.*;

/**
 * User: Kirill Smirnov (k.smirnov@sirena2000.ru)
 * Date: 18.12.18
 * Time: 19:20
 */
@Entity
@Table(name = "test")
@Cacheable
@org.hibernate.annotations.Cache(usage = CacheConcurrencyStrategy.READ_ONLY)
public class TestEntity {
    @Id
    @GeneratedValue(generator = "test_seq")
    @SequenceGenerator(name = "test_seq", sequenceName="TEST_SEQ")
    @Column(name = "id")
    private int id;

    @Column(name = "value", nullable = false)
    private String value;

    public TestEntity() {
    }

    public TestEntity(String value) {
        this.value = value;
    }

    public int getId() {
        return id;
    }

    public void setId(int id) {
        this.id = id;
    }

    public String getValue() {
        return value;
    }

    public void setValue(String value) {
        this.value = value;
    }
}

```

**Main.java** :

```
import javax.persistence.EntityManager;
import javax.persistence.EntityManagerFactory;
import javax.persistence.Persistence;
import javax.persistence.TypedQuery;
import java.util.Properties;

/**
 * User: Kirill Smirnov (k.smirnov@sirena2000.ru)
 * Date: 14.11.14
 * Time: 15:55
 */
public class Main {
    public static void main(String[] args) throws Exception {
        Properties entityManagerFactoryProperties = new Properties();

        entityManagerFactoryProperties.setProperty("javax.persistence.jdbc.driver", "org.h2.Driver");
        entityManagerFactoryProperties.setProperty("javax.persistence.jdbc.url", "jdbc:h2:mem:");
        entityManagerFactoryProperties.setProperty("javax.persistence.jdbc.user", "sa");
        entityManagerFactoryProperties.setProperty("javax.persistence.jdbc.password", "");
        entityManagerFactoryProperties.setProperty("hibernate.c3p0.min_size", "" + 1);
        entityManagerFactoryProperties.setProperty("hibernate.c3p0.max_size", "" + 1);
        entityManagerFactoryProperties.setProperty("hibernate.c3p0.timeout", "" + 5000);

        EntityManagerFactory entityManagerFactory = Persistence.createEntityManagerFactory("main", entityManagerFactoryProperties);

        insert(entityManagerFactory);

        select(entityManagerFactory);
        Thread.sleep(2000);
        select(entityManagerFactory);

        Thread.sleep(11000);

        select(entityManagerFactory);
        Thread.sleep(2000);
        select(entityManagerFactory);

        entityManagerFactory.close();
    }

    private static void insert(EntityManagerFactory entityManagerFactory) {
        EntityManager entityManager = entityManagerFactory.createEntityManager();

        entityManager.getTransaction().begin();
        try {
            entityManager.persist(new TestEntity("1"));
            entityManager.persist(new TestEntity("2"));
            entityManager.persist(new TestEntity("3"));
            entityManager.persist(new TestEntity("4"));
            entityManager.persist(new TestEntity("5"));
            entityManager.getTransaction().commit();
        } catch (Exception e) {
            entityManager.getTransaction().rollback();
            throw e;
        } finally {
            entityManager.close();
        }
    }

    private static void select(EntityManagerFactory entityManagerFactory) {
        EntityManager entityManager = entityManagerFactory.createEntityManager();

        entityManager.getTransaction().begin();
        try {
            String queryText = "FROM TestEntity";

            TypedQuery<TestEntity> query = entityManager.createQuery(queryText, TestEntity.class).setHint("org.hibernate.cacheable", true);
            query.getResultList();
            entityManager.getTransaction().commit();
        } catch (Exception e) {
            entityManager.getTransaction().rollback();
            throw e;
        } finally {
            entityManager.close();
        }
    }
}

```

---

<div class="post-metadata">

**Author:** ![vlad](https://yyz1.discourse-cdn.com/flex035/user_avatar/discourse.hibernate.org/vlad/32/658_2.png) [@vlad](https://discourse.hibernate.org/u/vlad)\
**Post date:** [February 14, 2019, 9:33am UTC](https://discourse.hibernate.org/t/hibernate-performs-n-1-selects-instead-of-1-when-using-query-cache/2288/2 "2019-02-14T09:33:04Z")

</div>

I answered the question on Stack Overflow.

> <https://stackoverflow.com/questions/54674418/hibernate-performs-n1-selects-instead-of-1-when-using-query-cache/54687050#54687050>