Hibernate 在使用查询缓存时执行 N+1 个选择而不是 1 个查询

Posted

技术标签:

【中文标题】Hibernate 在使用查询缓存时执行 N+1 个选择而不是 1 个查询【英文标题】:Hibernate performs N+1 selects instead of 1 query when using the Query Cache 【发布时间】:2019-07-07 12:52:20 【问题描述】:

我遇到了一个问题,我真的很迷茫,不知道该怎么办。我使用查询缓存+二级缓存,我想将结果正确缓存10秒。所以这是我的

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="11"
           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>

首先,我使用 insert() 方法填充我的数据库。 然后,我第一次调用我的 select() 方法来获取数据。一切正常 - 查询和实体被缓存,如果我在 2 秒后调用 select() 方法,我将在没有任何请求数据库的情况下获取数据。 然后我等待 12 秒(为了让缓存完全过期),调用 select() 并在再次调用 select() 后等待 2 秒。这就是我得到 n+1 选择的地方:

2019-02-13 18:52:17,101 [调试] org.hibernate.engine.jdbc.spi.SqlStatementLogger.logStatement(SqlStatementLogger.java:92) 选择 testentity0_.id 作为 id1_0_0_, testentity0_.value 作为 value2_0_0_ 从测试 testentity0_ where testentity0_.id=? 2019-02-13 18:52:17,107 [调试] org.hibernate.engine.jdbc.spi.SqlStatementLogger.logStatement(SqlStatementLogger.java:92) 选择 testentity0_.id 作为 id1_0_0_, testentity0_.value 作为 value2_0_0_ 从测试 testentity0_ where testentity0_.id=? 2019-02-13 18:52:17,108 [调试] org.hibernate.engine.jdbc.spi.SqlStatementLogger.logStatement(SqlStatementLogger.java:92) 选择 testentity0_.id 作为 id1_0_0_, testentity0_.value 作为 value2_0_0_ 从测试 testentity0_ where testentity0_.id=? 2019-02-13 18:52:17,108 [调试] org.hibernate.engine.jdbc.spi.SqlStatementLogger.logStatement(SqlStatementLogger.java:92) 选择 testentity0_.id 作为 id1_0_0_, testentity0_.value 作为 value2_0_0_ 从测试 testentity0_ where testentity0_.id=? 2019-02-13 18:52:17,109 [调试] org.hibernate.engine.jdbc.spi.SqlStatementLogger.logStatement(SqlStatementLogger.java:92) 选择 testentity0_.id 作为 id1_0_0_, testentity0_.value 作为 value2_0_0_ 来自测试 testentity0_ where testentity0_.id=?

我知道发出这些请求是因为查询缓存仅缓存 id,而二级缓存中似乎缺少这些 id 的实体。但为什么他们失踪了?当我启用完整日志记录时,我看到在第三次调用 select() 后会有像

这样的日志条目

将实体添加到二级缓存:[TestEntity#1]

那么,如果实体被添加到二级缓存并且它们应该只在 11 秒后过期,为什么它们会在 2 秒后丢失?

我的 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(12000);

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

附:我猜这个问题的原因是 Hibernate 中的一个错误。如果我从 5.2 升级到 5.4,问题就会消失。不过,我接受 Vlad 的回答,因为它通常包含有用的信息。

【问题讨论】:

【参考方案1】:

这是臭名昭著的N+1 Query Cache issue

您必须确保实体缓存区域的 TTL(生存时间)高于查询缓存或集合缓存的 TTL。

否则,Hibernate 将在查询缓存或集合缓存中找到实体标识符,并假定实体已存储在实体缓存区域中。但是如果实体缓存中没有找到实体,则只能从数据库中获取,因此会触发 N+1 查询问题。

现在,回到您的设置。这是您为实体缓存区域设置的内容:

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

请注意,timeToLiveSeconds 仅设置为 10 秒。

QueryCache 是这样设置的:

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

因此timeToLiveSeconds 也设置为10 秒,并确保实体查询缓存未设置为比查询缓存和关联的集合缓存更早过期。

接下来,将TestEntitytimeToLiveSeconds 提高到60120 秒。或者将其设为eternal = true 并禁用TTL,因为实体正在使用CacheConcurrencyStartegy.READ_ONLY

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

【讨论】:

我在问这个问题之前已经阅读了你的文章,但我不确定这就是这里的问题。在第三次调用 select() 之前,缓存是完全空的——查询缓存和集合缓存。在日志中,我看到在第三次调用后两个缓存都被填充了。但是,如果我在得到 n+1 个选择后两秒调用 select(),这让我感到惊讶,因为仅仅过了两秒。我试图使 Collection 缓存的 TTL 更高 - 11 秒而不是 10 秒,并将查询缓存的 TTL 保留 10 秒并休眠 12 秒。我仍然得到这种行为:( 请稍等,我将用新的 TTL 重写我的帖子以证明问题仍然存在。 我什至尝试了 60 秒 TTL 实体和 10 秒查询(并将睡眠时间增加到 61 秒以使缓存完全过期) - 问题仍然存在...... 向我发送一个拉取请求,其中包含证明问题的测试用例。使用QueryCacheNPlus1Test 作为模板。 嗯,5.2.7好像有个bug。我在您的项目中进行了测试,一切正常。然后我在我的项目中尝试了你的 5.4.1 版本,一切都变得正常了。但是使用 5.2.7 在您的项目中进行测试非常困难,缺少很多导入。

以上是关于Hibernate 在使用查询缓存时执行 N+1 个选择而不是 1 个查询的主要内容,如果未能解决你的问题,请参考以下文章

Hibernate第三次测试错题解析

Hibernate中的HQL查询与缓存机制

Hibernate的缓存

Hibernate缓存

hibernate N+1 查询

Hibernate 缓存