java - JPA批量插入并不能提高性能

Question

我想通过 JPA 批量插入来提高 postgresql 插入的性能。

我正在使用:

• spring-boot-starter-data-jpa 2.1.3.RELEASE
• postgresql 42.2.5(jdbc 驱动程序)。
• 数据库是 PostgreSQL 9.6.2

我已经成功激活了JPA的批量插入，但是性能根本没有提高。

• 我在实体中使用 @GenerateValue(strategy = GenerationType.SEQUENCE)

• 我在 jdbc 连接字符串中使用 reWriteBatchedInserts=true

• 我设置了以下属性:

spring.jpa.properties.hibernate.jdbc.batch_size=100
spring.jpa.properties.hibernate.order_inserts=true
spring.jpa.properties.hibernate.generate_statistics=true

• 我使用 saveAll(collection) 方法
• 我尝试在每批处理后刷新并清理我的entityManager
• 我尝试使用 100 和 1000 的批量大小，对每个批处理进行刷新，没有明显的变化。

我可以在日志中看到 hibernate 确实使用批量插入，但不确定我的数据库是否使用批量插入(我正在尝试获取日志，文件夹权限待定)。

@Service
@Configuration
@Transactional
public class SecteurGeographiqueServiceImpl implements SecteurGeographiqueService {

    private static final Logger logger = LoggerFactory.getLogger(SecteurGeographiqueServiceImpl.class);

@Value("${spring.jpa.properties.hibernate.jdbc.batch_size}")
private int batchSize;

@PersistenceContext
private EntityManager entityManager;

@Autowired
private SecteurGeographiqueRepository secteurGeographiqueRepository;

    @Override
    public List<SecteurGeographique> saveAllSecteurGeographiquesISOs(List<SecteurGeographique> listSecteurGeographiques) {
    logger.warn("BATCH SIZE : " + this.batchSize);
    final List<SecteurGeographique> tempList = new ArrayList<>();
    final List<SecteurGeographique> savedList = new ArrayList<>();
    for (int i = 0; i < listSecteurGeographiques.size(); i++) {
        if ((i % this.batchSize) == 0) {
            savedList.addAll(this.secteurGeographiqueRepository.saveAll(tempList));
            tempList.clear();
            this.entityManager.flush();
            this.entityManager.clear();
        }
        tempList.add(listSecteurGeographiques.get(i));
    }
    savedList.addAll(this.secteurGeographiqueRepository.saveAll(tempList));
    tempList.clear();
    this.entityManager.flush();
    this.entityManager.clear();
    return savedList;
    }

}

...

@Entity
public class SecteurGeographique {

    private static final long serialVersionUID = 1L;

    @Id
    @GeneratedValue(strategy = GenerationType.SEQUENCE)
    @Column(name = "id")
    public Long id;
...

我的存储库实现是:

org.springframework.data.jpa.repository.JpaRepository<SecteurGeographique, Long>

application.properties(连接部分):

spring.datasource.url=jdbc:postgresql://xx.xx.xx.xx:5432/bddname?reWriteBatchedInserts=true
spring.jpa.properties.hibernate.default_schema=schema
spring.datasource.username=xxxx
spring.datasource.password=xxxx
spring.datasource.driverClassName=org.postgresql.Driver
spring.jpa.properties.hibernate.dialect=org.hibernate.dialect.PostgreSQLDialect
spring.jpa.properties.hibernate.jdbc.lob.non_contextual_creation=true
spring.jpa.properties.hibernate.jdbc.batch_size=100
spring.jpa.properties.hibernate.order_inserts=true
spring.jpa.properties.hibernate.generate_statistics=true

以及在插入我的 16073 个实体后的日志中(此测试不包括刷新):

13:31:40.882 [restartedMain] INFO  o.h.e.i.StatisticalLoggingSessionEventListener - Session Metrics {
    15721506 nanoseconds spent acquiring 1 JDBC connections;
    0 nanoseconds spent releasing 0 JDBC connections;
    121091067 nanoseconds spent preparing 16074 JDBC statements;
    240144821872 nanoseconds spent executing 16073 JDBC statements;
    3778202166 nanoseconds spent executing 161 JDBC batches;
    0 nanoseconds spent performing 0 L2C puts;
    0 nanoseconds spent performing 0 L2C hits;
    0 nanoseconds spent performing 0 L2C misses;
    4012929596 nanoseconds spent executing 1 flushes (flushing a total of 16073 entities and 0 collections);
    0 nanoseconds spent executing 0 partial-flushes (flushing a total of 0 entities and 0 collections)
}

请注意，这只是一张表，没有约束/外键。只是表格中的基本数据，没什么花哨的。

从日志来看确实存在问题:

240144821872 nanoseconds spent executing <b>16073 JDBC statements</b>;
3778202166 nanoseconds spent executing 161 JDBC batches;

如果一切都在批处理中，不应该是“执行161 JDBC语句”吗？

使用刷新进行测试，批量大小为 100 然后 1000:

15:32:17.612 [restartedMain] WARN  f.g.j.a.r.s.i.SecteurGeographiqueServiceImpl - BATCH SIZE : 100
15:36:46.206 [restartedMain] INFO  o.h.e.i.StatisticalLoggingSessionEventListener - Session Metrics {
    15416324 nanoseconds spent acquiring 1 JDBC connections;
    0 nanoseconds spent releasing 0 JDBC connections;
    105369002 nanoseconds spent preparing 16234 JDBC statements;
    262388696401 nanoseconds spent executing 16073 JDBC statements;
    3669253410 nanoseconds spent executing 161 JDBC batches;
    0 nanoseconds spent performing 0 L2C puts;
    0 nanoseconds spent performing 0 L2C hits;
    0 nanoseconds spent performing 0 L2C misses;
    3956493726 nanoseconds spent executing 161 flushes (flushing a total of 16073 entities and 0 collections);
    0 nanoseconds spent executing 0 partial-flushes (flushing a total of 0 entities and 0 collections)
}

15:43:54.155 [restartedMain] WARN  f.g.j.a.r.s.i.SecteurGeographiqueServiceImpl - BATCH SIZE : 1000
15:48:22.335 [restartedMain] INFO  o.h.e.i.StatisticalLoggingSessionEventListener - Session Metrics {
    15676227 nanoseconds spent acquiring 1 JDBC connections;
    0 nanoseconds spent releasing 0 JDBC connections;
    111370586 nanoseconds spent preparing 16090 JDBC statements;
    265089247563 nanoseconds spent executing 16073 JDBC statements;
    599946208 nanoseconds spent executing 17 JDBC batches;
    0 nanoseconds spent performing 0 L2C puts;
    0 nanoseconds spent performing 0 L2C hits;
    0 nanoseconds spent performing 0 L2C misses;
    866452023 nanoseconds spent executing 17 flushes (flushing a total of 16073 entities and 0 collections);
    0 nanoseconds spent executing 0 partial-flushes (flushing a total of 0 entities and 0 collections)
}

每次我都会得到 4 分 30 秒的执行时间。对于批量插入来说感觉非常巨大。 我错过/误解了什么？

Answer 1

在本地主机 (https://gareth.flowers/postgresql-portable/ v10.1.1) 上使用 postgresql 服务器尝试批量大小为 1000 后，执行运行时间不到 3 秒。所以看来代码或配置不应该归咎于这里。

不幸的是，我无法调查为什么在远程 postgresql(托管在 AWS 上)上花费了这么多时间，但我只能得出结论，这是一个网络或数据库问题。

截至今天，我无法访问 postgresql 远程日志，但如果您对在 postgresql 实例上查找内容有任何建议，我会洗耳恭听。

带有批处理(1000)和刷新+清理的日志:

16:20:52.360 [restartedMain] WARN  f.g.j.a.r.s.i.SecteurGeographiqueServiceImpl - BATCH SIZE : 1000
16:20:54.844 [restartedMain] INFO  o.h.e.i.StatisticalLoggingSessionEventListener - Session Metrics {
    523125 nanoseconds spent acquiring 1 JDBC connections;
    0 nanoseconds spent releasing 0 JDBC connections;
    44649191 nanoseconds spent preparing 16090 JDBC statements;
    1311557995 nanoseconds spent executing 16073 JDBC statements;
    204225325 nanoseconds spent executing 17 JDBC batches;
    0 nanoseconds spent performing 0 L2C puts;
    0 nanoseconds spent performing 0 L2C hits;
    0 nanoseconds spent performing 0 L2C misses;
    381230968 nanoseconds spent executing 17 flushes (flushing a total of 16073 entities and 0 collections);
    0 nanoseconds spent executing 0 partial-flushes (flushing a total of 0 entities and 0 collections)
}

不进行批处理、刷新或清理的日志:

16:57:34.426 [restartedMain] INFO  o.h.e.i.StatisticalLoggingSessionEventListener - Session Metrics {
    725069 nanoseconds spent acquiring 1 JDBC connections;
    0 nanoseconds spent releasing 0 JDBC connections;
    55763008 nanoseconds spent preparing 32146 JDBC statements;
    2816525053 nanoseconds spent executing 32146 JDBC statements;
    0 nanoseconds spent executing 0 JDBC batches;
    0 nanoseconds spent performing 0 L2C puts;
    0 nanoseconds spent performing 0 L2C hits;
    0 nanoseconds spent performing 0 L2C misses;
    1796451447 nanoseconds spent executing 1 flushes (flushing a total of 16073 entities and 0 collections);
    0 nanoseconds spent executing 0 partial-flushes (flushing a total of 0 entities and 0 collections)
}

此比较显示 JDBC 语句的整体执行时间增加了 46%。