jpa Hibernate批处理中断optimistic_force_increment的版本控制

fjaof16o  于 2023-08-06  发布在  其他
关注(0)|答案(1)|浏览(105)

TL;DR:我使用的是hibernate 6.2.0.Final。当我
1.启用批处理
1.对实体使用版本控制
1.在事务中,对该版本化实体使用optimistic_force_increment锁
1.在事务处理期间,不要对该实体或任何其他实体进行任何其他更改
...则版本化实体的版本实际上不递增。在提交之前创建必要的update语句并将其添加到批处理中,但它实际上并没有发送到DB,而是保留在批处理中 * 在 * 提交之后,Hibernate然后在INFO日志消息中警告。
范例:
我有一个实体Calendar,它的版本是一个简单的整数version

@Entity
@Table(name = "calendar")
public class Calendar implements Serializable {

    @Id
    @GeneratedValue
    @Column(name = "id")
    private UUID id;

    @NotNull
    @Size(min = 3, max = 3)
    @Column(name = "system_code", length = 3, nullable = false)
    private String systemCode;

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

    @Version
    @NotNull
    @Column(name = "version", nullable = false)
    private Integer version = 1;

字符串
当我更改其中一个属性时,版本会自动更新,正如我所期望的那样。
当我获取锁类型为OPTIMISTIC_FORCE_INCREMENT的实体时,即使我没有更改实体,我也希望实体获得递增的版本:

@Repository
public interface CalendarRepository extends JpaRepository<Calendar, UUID> {

    @Lock(LockModeType.OPTIMISTIC_FORCE_INCREMENT)
    @Query("SELECT c FROM Calendar c " +
            "WHERE c.systemCode = :systemCode " +
            "  AND c.name = :name")
    Optional<Calendar> findBySystemCodeAndNameWithOptimisticForceIncrement(
            @Param("systemCode") String systemCode,
            @Param("name") String name);
}


事实上,这正是所发生的。
但是,如果我现在打开批处理...

spring:
  jpa:
    properties:
      hibernate:      
        jdbc:
          batch_size: 20
        order_updates: true
        order_inserts: true


然后奇怪的事情发生了。虽然日志记录表明它仍在尝试增加版本,但实际上并没有增加版本。(我可能有太多的跟踪日志,但当你挖掘...)你会注意到,在committing消息之后,仍然会创建一个新的批处理来更新日历实体。但是,批处理实际上并未执行,如信息性警告HHH100503: On release of batch it still contained JDBC statements所示。

2023-07-12T14:29:34+02:00 [main] DEBUG o.h.e.t.internal.TransactionImpl - committing
2023-07-12T14:29:34+02:00 [main] TRACE o.h.r.t.b.j.i.JdbcResourceLocalTransactionCoordinatorImpl - ResourceLocalTransactionCoordinatorImpl#beforeCompletionCallback
2023-07-12T14:29:34+02:00 [main] TRACE o.h.e.jdbc.internal.JdbcCoordinatorImpl - Starting after statement execution processing [ON_CLOSE]
2023-07-12T14:29:34+02:00 [main] TRACE org.hibernate.orm.jdbc.batch - Created Batch (20) - `com.***.domain.Calendar#UPDATE`
2023-07-12T14:29:34+02:00 [main] TRACE org.hibernate.orm.jdbc.batch - Adding to JDBC batch (1) - `com.***.domain.Calendar#UPDATE`
2023-07-12T14:29:34+02:00 [main] TRACE o.h.r.j.i.ResourceRegistryStandardImpl - Registering statement [HikariProxyPreparedStatement@2037475545 wrapping update ibl_***.calendar set version=? where id=? and version=?]
2023-07-12T14:29:34+02:00 [main] TRACE o.h.r.j.i.ResourceRegistryStandardImpl - Registering result set [null]
2023-07-12T14:29:34+02:00 [main] DEBUG org.hibernate.SQL - update ibl_***.calendar set version=? where id=? and version=?
2023-07-12T14:29:34+02:00 [main] TRACE org.hibernate.orm.jdbc.bind - binding parameter [1] as [INTEGER] - [2]
2023-07-12T14:29:34+02:00 [main] TRACE org.hibernate.orm.jdbc.bind - binding parameter [2] as [UUID] - [cf2027c2-1212-4d14-88d4-00c6de0500d8]
2023-07-12T14:29:34+02:00 [main] TRACE org.hibernate.orm.jdbc.bind - binding parameter [3] as [INTEGER] - [1]
2023-07-12T14:29:34+02:00 [main] TRACE o.h.r.j.i.AbstractLogicalConnectionImplementor - LogicalConnection#beforeTransactionCompletion
2023-07-12T14:29:34+02:00 [main] TRACE o.h.r.t.i.SynchronizationRegistryStandardImpl - SynchronizationRegistryStandardImpl.notifySynchronizationsBeforeTransactionCompletion
2023-07-12T14:29:34+02:00 [main] TRACE o.h.r.j.i.AbstractLogicalConnectionImplementor - Preparing to commit transaction via JDBC Connection.commit()
2023-07-12T14:29:34+02:00 [main] TRACE o.h.r.j.i.AbstractLogicalConnectionImplementor - Transaction committed via JDBC Connection.commit()
2023-07-12T14:29:34+02:00 [main] TRACE o.h.r.j.i.AbstractLogicalConnectionImplementor - LogicalConnection#afterTransaction
2023-07-12T14:29:34+02:00 [main] TRACE o.h.r.j.i.ResourceRegistryStandardImpl - Releasing JDBC resources
2023-07-12T14:29:34+02:00 [main] INFO  org.hibernate.orm.jdbc.batch - HHH100503: On release of batch it still contained JDBC statements
2023-07-12T14:29:34+02:00 [main] TRACE o.h.r.j.i.ResourceRegistryStandardImpl - Releasing statement [HikariProxyPreparedStatement@2037475545 wrapping update ibl_***a.calendar set version=2 where id='cf2027c2-1212-4d14-88d4-00c6de0500d8'::uuid and version=1]
2023-07-12T14:29:34+02:00 [main] TRACE o.h.r.j.i.ResourceRegistryStandardImpl - Closing result set [null]
2023-07-12T14:29:34+02:00 [main] TRACE o.h.r.j.i.ResourceRegistryStandardImpl - Closing prepared statement [HikariProxyPreparedStatement@2037475545 wrapping update ibl_***.calendar set version=2 where id='cf2027c2-1212-4d14-88d4-00c6de0500d8'::uuid and version=1]
2023-07-12T14:29:34+02:00 [main] TRACE o.h.e.jdbc.internal.JdbcCoordinatorImpl - Starting after statement execution processing [ON_CLOSE]
2023-07-12T14:29:34+02:00 [main] TRACE o.h.r.t.b.j.i.JdbcResourceLocalTransactionCoordinatorImpl - ResourceLocalTransactionCoordinatorImpl#afterCompletionCallback(true)
2023-07-12T14:29:34+02:00 [main] TRACE o.h.r.t.i.SynchronizationRegistryStandardImpl - SynchronizationRegistryStandardImpl.notifySynchronizationsAfterTransactionCompletion(3)
2023-07-12T14:29:34+02:00 [main] TRACE o.h.e.jdbc.internal.JdbcCoordinatorImpl - Closing JDBC container [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl@1561e62e]
2023-07-12T14:29:34+02:00 [main] DEBUG o.h.e.jdbc.internal.JdbcCoordinatorImpl - HHH000420: Closing un-released batch
2023-07-12T14:29:34+02:00 [main] DEBUG org.hibernate.orm.jdbc.batch - PreparedStatementDetails did not contain PreparedStatement on #releaseStatements : update ibl_***.calendar set version=? where id=? and version=?
2023-07-12T14:29:34+02:00 [main] TRACE o.h.e.jdbc.internal.JdbcCoordinatorImpl - Starting after statement execution processing [ON_CLOSE]
2023-07-12T14:29:34+02:00 [main] TRACE o.h.r.j.i.ResourceRegistryStandardImpl - Releasing JDBC resources
2023-07-12T14:29:34+02:00 [main] DEBUG org.hibernate.orm.jdbc.batch - PreparedStatementDetails did not contain PreparedStatement on #releaseStatements : update ibl_***.calendar set version=? where id=? and version=?
2023-07-12T14:29:34+02:00 [main] TRACE o.h.e.jdbc.internal.JdbcCoordinatorImpl - Starting after statement execution processing [ON_CLOSE]
2023-07-12T14:29:34+02:00 [main] TRACE o.h.r.j.i.LogicalConnectionManagedImpl - Closing logical connection
2023-07-12T14:29:34+02:00 [main] TRACE o.h.r.j.i.ResourceRegistryStandardImpl - Releasing JDBC resources
2023-07-12T14:29:34+02:00 [main] DEBUG org.hibernate.orm.jdbc.batch - PreparedStatementDetails did not contain PreparedStatement on #releaseStatements : update ibl_***.calendar set version=? where id=? and version=?
2023-07-12T14:29:34+02:00 [main] TRACE o.h.e.jdbc.internal.JdbcCoordinatorImpl - Starting after statement execution processing [ON_CLOSE]
2023-07-12T14:29:34+02:00 [main] TRACE o.h.r.j.i.LogicalConnectionManagedImpl - Logical connection closed


通过单步调试器会话,我得出了一个初步结论
1.在提交(JdbcResourceLocalTransactionCoordinatorImpl.commit)时,在实际提交之前,调用beforeCompletionCallback
1.这个beforeCompletionCallback将完成需要在BeforeTransactionCompletionProcessQueue类的beforeTransactionCompletion方法中完成的事情。它将正确地看到版本增量需要完成,并调用EntityIncrementVersionProcess类的doBeforeTransactionCompletion
1.这个doBeforeTransactionCompletion方法调用一个MutationExecutor。如果batching显式设置为1,则返回的执行器类型为MutationExecutorSingleNonBatched。但是如果batching设置为> 1,则返回的executor类型为MutationExecutorSingleBatched
1.当后来调用executor的execute方法时,在MutationExecutorSingleNonBatched的情况下,它似乎实际上执行了该语句。然而在MutationExecutorSingleBatched的情况下,它只将语句添加到批处理中,但在实际提交发送之前不会执行。
检测方法:

@Test
    @Order(1)
    void findBySystemCodeAndNameWithOptimisticForceIncrement() {

        // Prepare the environment
        transactionTemplate.execute(new TransactionCallbackWithoutResult() {
            @Override
            protected void doInTransactionWithoutResult(TransactionStatus status) {
                calendarRepository.save(new Calendar()
                        .name("Calendar for AAA")
                        .systemCode("AAA"));
            }
        });

        // Call the tested method in a transaction
        transactionTemplate.execute(new TransactionCallbackWithoutResult() {
            @Override
            protected void doInTransactionWithoutResult(TransactionStatus status){
                calendarRepository
                        .findBySystemCodeAndNameWithOptimisticForceIncrement("AAA", "Calendar for AAA")
                        .orElseThrow()
            }
        });

        // Verify the result
        Calendar savedCalendar = transactionTemplate.execute(status -> calendarRepository
                .findBySystemCodeAndName("AAA", "Calendar for AAA")
                .orElseThrow()
        );

        assertThat(savedCalendar.getVersion()).isEqualTo(2);
    }


在Hibernate中将版本控制与批处理结合使用时,是否还有其他人遇到过这种奇怪的行为?有什么方法可以解决这个问题,而不必从整体上禁用批处理?

66bbxpm5

66bbxpm51#

我已经能够重现你所看到的。我在Sping Boot 3.1.1项目中试图找出导致此消息的原因时发现了这个问题。

HHH100503: On release of batch it still contained JDBC statements

字符串
我的项目使用悲观的强制增量,我注意到一些但不是所有的行都丢失了它们的@Version列更新。
从我正在处理的测试用例来看,@Version列本身没有明显的错误。它在5.6.17和6.1.7中工作,但6.2.0及更高版本失败。
我已经将这个问题链接到Hibernate ORM issue https://hibernate.atlassian.net/browse/HHH-16939,一旦完成,它将包括上面的测试用例PR。

相关问题