java - 为什么Spring在配置时并不总是使用批量插入/更新？

Question

在我的基于 Spring JpaRepository 的项目中，我有一个方法，它总是从调用 saveAll(List list) 的方法中逐一加载记录...当我使用 List 来创建对象并将它们添加到列表中时。下面的代码大约需要 5 分钟...

<小时/>

@Transactional(readOnly = false)
public List<Data> saveAll(List<Data> dataList) throws Exception {
 try {
        for(Data d : dataList){

            if(d.getCol04() == null)
                d.setCol04("TEST");
            else
                d.setCol04(null);

            log.info(new Gson().toJson(d));

        }

        return dataRepository.saveAll(dataList);

    }catch (Exception e) {
        log.error("Unexpected error.", e);
        return null;
    }

}

2019-10-30 09:07:11 DEBUG org.hibernate.loader.Loader - Result set row: 0 2019-10-30 09:07:11 DEBUG org.hibernate.loader.Loader - Result row: EntityKey[ com.test.Data#component[batchSeq,batchId]{batchSeq=866, batchId=6012113450}] 2019-10-30 09:07:11 DEBUG o.h.engine.internal.TwoPhaseLoad - Resolving associations for [com.test.Data#component[batchSeq,batchId]{batchSeq=866, batchId=6012113450}] 2019-10-30 09:07:11 DEBUG o.h.engine.internal.TwoPhaseLoad - Done materializing entity [com.test.Data#component[batchSeq,batchId]{batchSeq=866, batchId=6012113450}] 2019-10-30 09:07:11 DEBUG org.hibernate.loader.Loader - Done entity load 2019-10-30 09:07:11 DEBUG org.hibernate.loader.Loader - Loading entity: [com.test.Data#component[batchSeq,batchId]{batchSeq=867, batchId=6012113450}] 2019-10-30 09:07:11 DEBUG org.hibernate.SQL - select datae0_.batch_seq as batch_seq1_0_0_, datae0_.batch_id as batch_id2_0_0_, datae0_.col01 as col3_0_0_, datae0_.col02 as col4_0_0_, datae0_.col03 as col5_0_0_, datae0_.col04 as col6_0_0_, datae0_.col05 as col7_0_0_, datae0_.col06 as col8_0_0_, datae0_.col07 as col9_0_0_, datae0_.col08 as col10_0_0_, datae0_.col09 as col11_0_0_, datae0_.col10 as col12_0_0_, datae0_.group_id as group_id13_0_0_, datae0_.parent_trans_id as parent_trans_id14_0_0_, datae0_.result_message as result_message15_0_0_, datae0_.result_status as result_status16_0_0_, datae0_.tn as tn17_0_0_, datae0_.tn_quantity_assigned as tn_quantity_assig18_0_0_, datae0_.tn_quantity_requested as tn_quantity_reque19_0_0_, datae0_.xml_data as xml_data20_0_0_ from owner.batch_data datae0_ where datae0_.batch_seq=? and datae0_.batch_id=? 2019-10-30 09:07:12 DEBUG org.hibernate.loader.Loader - Result set row: 0 2019-10-30 09:07:12 DEBUG org.hibernate.loader.Loader - Result row: EntityKey[com.test.Data#component[batchSeq,batchId]{batchSeq=867, batchId=6012113450}] 2019-10-30 09:07:12 DEBUG o.h.engine.internal.TwoPhaseLoad - Resolving associations for [com.test.Data#component[batchSeq,batchId]{batchSeq=867, batchId=6012113450}] 2019-10-30 09:07:12 DEBUG o.h.engine.internal.TwoPhaseLoad - Done materializing entity [com.test.Data#component[batchSeq,batchId]{batchSeq=867, batchId=6012113450}] 2019-10-30 09:07:12 DEBUG org.hibernate.loader.Loader - Done entity load 2019-10-30 09:07:12 DEBUG org.hibernate.loader.Loader - Loading entity: [com.test.Data#component[batchSeq,batchId]{batchSeq=868, batchId=6012113450}] 2019-10-30 09:07:12 DEBUG org.hibernate.SQL - . . . 2019-10-30 09:10:34 DEBUG o.h.e.j.b.internal.AbstractBatchImpl - Reusing batch statement 2019-10-30 09:10:34 DEBUG org.hibernate.SQL - update owner.batch_data set col01=?, col02=?, col03=?, col04=?, col05=?, col06=?, col07=?, col08=?, col09=?, col10=?, group_id=?, parent_trans_id=?, result_message=?, result_status=?, tn=?, tn_quantity_assigned=?, tn_quantity_requested=?, xml_data=? where batch_seq=? and batch_id=? 2019-10-30 09:10:34 DEBUG o.h.e.j.batch.internal.BatchingBatch - Executing batch size: 500 2019-10-30 09:10:36 DEBUG o.s.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [SessionImpl(2081270212)] after transaction 2019-10-30 09:10:36 INFO o.h.e.i.StatisticalLoggingSessionEventListener - Session Metrics { 77841799 nanoseconds spent acquiring 1 JDBC connections; 0 nanoseconds spent releasing 0 JDBC connections; 89273975 nanoseconds spent preparing 1501 JDBC statements; 250886005163 nanoseconds spent executing 1500 JDBC statements; 4812997147 nanoseconds spent executing 3 JDBC batches; 0 nanoseconds spent performing 0 L2C puts; 0 nanoseconds spent performing 0 L2C hits; 0 nanoseconds spent performing 0 L2C misses; 5462588455 nanoseconds spent executing 1 flushes (flushing a total of 1500 entities and 0 collections); 0 nanoseconds spent executing 0 partial-flushes (flushing a total of 0 entities and 0 collections) } 2019-10-30 09:10:36 DEBUG o.h.e.j.internal.JdbcCoordinatorImpl - HHH000420: Closing un-released batch 2019-10-30 09:10:36 DEBUG o.s.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findById]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly 2019-10-30 09:10:36 DEBUG o.s.orm.jpa.JpaTransactionManager - Opened new EntityManager [SessionImpl(1953492703)] for JPA transaction 2019-10-30 09:10:36 DEBUG o.s.jdbc.datasource.DataSourceUtils - Setting JDBC Connection [HikariProxyConnection@113673215 wrapping oracle.jdbc.driver.T4CConnection@5f71a000] read-only 2019-10-30 09:10:36 DEBUG o.h.e.t.internal.TransactionImpl - On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false 2019-10-30 09:10:36 DEBUG o.h.e.t.internal.TransactionImpl - begin

当我查询findAll(List id)并使用返回的列表作为saveAll的参数时，SaveAll(List list)会批量加载。下面的代码大约需要 8 秒。

<小时/>

//Working method

@Transactional(readOnly = false)
public List<Data> saveAll() throws Exception {

    try {
        List<Data> dataList2 = dataRepository.findAllByBatchId(6000000L);

        for(Data d : dataList2){

            if(d.getCol04() == null)
                d.setCol04("TEST");
            else
                d.setCol04(null);

            log.info(new Gson().toJson(d));

        }

        return dataRepository.saveAll(dataList2);

    }catch (Exception e) {
        log.error("Unexpected error.", e);
        return null;
    }

}

. . . 2019-10-30 09:00:25 DEBUG o.h.e.j.batch.internal.BatchingBatch - Executing batch size: 500 2019-10-30 09:00:27 DEBUG o.s.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [SessionImpl(2038854767)] after transaction 2019-10-30 09:00:27 INFO o.h.e.i.StatisticalLoggingSessionEventListener - Session Metrics { 89300419 nanoseconds spent acquiring 1 JDBC connections; 0 nanoseconds spent releasing 0 JDBC connections; 1037028 nanoseconds spent preparing 2 JDBC statements; 330435552 nanoseconds spent executing 1 JDBC statements; 6423148647 nanoseconds spent executing 3 JDBC batches; 0 nanoseconds spent performing 0 L2C puts; 0 nanoseconds spent performing 0 L2C hits; 0 nanoseconds spent performing 0 L2C misses; 7100764566 nanoseconds spent executing 1 flushes (flushing a total of 1500 entities and 0 collections); 2082345 nanoseconds spent executing 1 partial-flushes (flushing a total of 0 entities and 0 collections) } 2019-10-30 09:00:27 DEBUG o.h.e.j.internal.JdbcCoordinatorImpl - HHH000420: Closing un-released batch 2019-10-30 09:00:27 DEBUG o.s.w.s.m.m.a.HttpEntityMethodProcessor - Using 'application/json', given [/] and supported [application/json] 2019-10-30 09:00:27 DEBUG o.s.w.s.m.m.a.HttpEntityMethodProcessor - Writing ["{"data":0}"] 2019-10-30 09:00:27 DEBUG o.s.o.j.s.OpenEntityManagerInViewInterceptor - Closing JPA EntityManager in OpenEntityManagerInViewInterceptor

有什么想法为什么会发生这种情况吗？

Answer 1

这可能是因为脏检查功能，在第一种方法中，当您在保存数据之前保存 dataList 时，hibernate 可能会加载内存中的所有数据以检查哪些数据已被修改。这可能是为什么它需要时间和如果数据(实体)进一步与其他实体相关联，那么这将按时累加。在第二种方法中，dataList2 在保存到数据库之前被预加载，因此在保存时不会进行任何解析。为了测试这个理论，您可以急切地加载所有数据(以及关联的实体)然后保存，如果它花费的时间与第二种方法相同，那么我们可能会得出这样的结论。另请参阅此链接 https://forum.hibernate.org/viewtopic.php?f=1&t=994162&view=previous ，这可能会有所帮助