2023年7月12日 21:08:12go评论67阅读模式

英文:

Hibernate batch breaks versioning for optimistic_force_increment

问题

TL;DR: 使用 Hibernate 6.2.0.Final，启用批处理、对实体启用版本控制、在事务中使用乐观锁（OPTIMISTIC_FORCE_INCREMENT）对已版本控制的实体使用，但在事务中对该实体或其他实体不做其他更改时，版本实际上未递增。Hibernate 在提交之前会创建必要的更新语句并将其添加到批处理中，但实际上不会将其发送到数据库，而是在提交之后仍然保留在批处理中，Hibernate 会在 INFO 日志消息中发出警告。

示例代码中提到了一个名为 "Calendar" 的实体，它使用一个简单的整数 "version" 进行版本控制。当更改实体的属性时，版本会自动更新，这是预期的行为。当使用锁定类型 "OPTIMISTIC_FORCE_INCREMENT" 检索实体时，即使未更改实体，也希望实体获得递增的版本。然而，当启用批处理后，出现了奇怪的行为，尽管日志显示它仍然尝试递增版本，但实际上版本未递增。

通过调试会话，得出以下初步结论：

在提交事务之前（JdbcResourceLocalTransactionCoordinatorImpl.commit），会调用一个 beforeCompletionCallback。
此 beforeCompletionCallback 将检查需要在 BeforeTransactionCompletionProcessQueue 类的 beforeTransactionCompletion 方法中完成的任务。它将正确地检测到需要进行版本递增，并调用 EntityIncrementVersionProcess 类的 doBeforeTransactionCompletion 方法。
doBeforeTransactionCompletion 方法调用 MutationExecutor。如果批处理明确设置为 1，则返回的执行器是 MutationExecutorSingleNonBatched 类型。但是，如果批处理设置为 > 1，则返回的执行器类型是 MutationExecutorSingleBatched。
在执行执行器的 execute 方法后，在 MutationExecutorSingleNonBatched 的情况下，似乎实际执行了语句。但在 MutationExecutorSingleBatched 的情况下，它仅将语句添加到批处理中，但在实际提交之前不会执行。

测试方法中包含了一个用于验证此行为的测试示例。

是否有其他人在将版本控制与 Hibernate 中的批处理结合使用时遇到了这种奇怪的行为？如何在不完全禁用批处理的情况下解决此问题？

英文:

TL;DR: I'm using hibernate 6.2.0.Final. When I ...

Enable batching
Use versioning for an entity
In a transaction, use an optimistic_force_increment lock on that versioned entity
Make no other changes to that or any other entities during the transaction

... then the version of the versioned entity is not actually incremented. The necessary update statement is created and added to a batch just before committing, but it is not actually sent to the DB and remains in the batch after committing, which Hibernate then warns about in an INFO log message.

Example:

I have an entity Calendar which is versioned with a simple Integer version:

@Entity
@Table(name = &quot;calendar&quot;)
public class Calendar implements Serializable {

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

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

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


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

When I change one of the attributes, the version gets automatically updated, as I would expect.

When I fetch the entity with a lock type OPTIMISTIC_FORCE_INCREMENT, I also expect the entity to get an incremented version, even if I didn't change the entity:

@Repository
public interface CalendarRepository extends JpaRepository&lt;Calendar, UUID&gt; {

    @Lock(LockModeType.OPTIMISTIC_FORCE_INCREMENT)
    @Query(&quot;SELECT c FROM Calendar c &quot; +
            &quot;WHERE c.systemCode = :systemCode &quot; +
            &quot;  AND c.name = :name&quot;)
    Optional&lt;Calendar&gt; findBySystemCodeAndNameWithOptimisticForceIncrement(
            @Param(&quot;systemCode&quot;) String systemCode,
            @Param(&quot;name&quot;) String name);
}

And indeed, that is exactly what happens.

But, if I now turn on batching...

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

Then something weird happens. While logging indicates that it is still attempting to increment the version, the increment doesn't actually happen. (I may have a bit too much trace logging on, but when you're digging...)
You'll notice that AFTER the committing messsage, a new batch is still being created to do the update for the calendar entity. However, the batch is not actually executed, as shown by the informational warning 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=&#39;cf2027c2-1212-4d14-88d4-00c6de0500d8&#39;::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=&#39;cf2027c2-1212-4d14-88d4-00c6de0500d8&#39;::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

By stepping through debugger sessions, I've reached the tentative conclusion that

On committing (JdbcResourceLocalTransactionCoordinatorImpl.commit), before the actual commit, a beforeCompletionCallback is called.
This beforeCompletionCallback will go over things that need to be done in the beforeTransactionCompletion method of the BeforeTransactionCompletionProcessQueue class. It will correctly see that the version increment needs to be done and call doBeforeTransactionCompletion of the EntityIncrementVersionProcess class.
This doBeforeTransactionCompletion method calls for a MutationExecutor. If batching is explicitly set to 1, the returned executor is of the type MutationExecutorSingleNonBatched. But if batching is set to > 1, the returned executor is of the type MutationExecutorSingleBatched instead.
When afterwards the execute method of the executor is called, in the case of the MutationExecutorSingleNonBatched, it seems to actually execute the statement. However in the case of the MutationExecutorSingleBatched, it only adds the statement to the batch, but it doesn't get executed before the actual commit is sent.

Testing method:

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

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

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


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

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

Did anyone else run into this strange behaviour when combining versioning with batching in Hibernate? What would be a way to resolve this without resorting to disabling batching as a whole?

答案1

得分: 2

我已经能够复现你所看到的情况。我在尝试弄清楚是什么导致了我的Spring Boot 3.1.1项目中出现这条消息时，找到了这个问题。

HHH100503: 在批处理释放时，它仍然包含JDBC语句

我的项目使用了悲观的强制增量，并且我注意到有些行，但不是所有行，缺少了它们的@Version列更新。

从我正在处理的测试案例中，@Version列本身似乎没有明显的问题。它在5.6.17和6.1.7中有效，但在6.2.0及以上版本中失败。

我已将这个问题链接到Hibernate ORM问题 https://hibernate.atlassian.net/browse/HHH-16939，一旦完成，它将包括上述测试案例的PR。

英文:

I have been able to reproduce what you are seeing. I found this question while trying to figure out what was causing this message in my Spring Boot 3.1.1 project.

HHH100503: On release of batch it still contained JDBC statements

My project uses pessimistic force increment and I was noticing that some but not all of the rows, were missing their @Version column updates.

From the test case I am working on, there is nothing obviously wrong with the @Version column itself. It works in 5.6.17 and 6.1.7 but 6.2.0 and above fails.

I have linked this question to Hibernate ORM issue https://hibernate.atlassian.net/browse/HHH-16939, which will include the above test case PR once it is finished.

通过集体智慧和协作来改善编程学习和解决问题的方式。致力于成为全球开发者共同参与的知识库，让每个人都能够通过互相帮助和分享经验来进步。

Hibernate批处理破坏了乐观锁中的版本控制。

问题

答案1

如何在Spring的@RequestBody中查找JSON字段是否包含数据？

使用Jpa规范仅过滤输入参数的方法是什么？

与外键约束有困难。

Hibernate错误：java.lang.ClassNotFoundException：无法加载请求的类

What's the correct way to type hint an empty list as a literal in python?

如何在Highcharts Gantt中更改本地化的星期名称

如何在同一个流中使用多个过滤器和映射函数？

如何使用Map/Set来将代码优化到O(n)？

.NET MAUI Android在GitHub Actions上构建失败，错误代码为1。

如何在Playwright视觉比较中屏蔽多个定位器？

在C++中，可以使用可变模板参数来检索类型的内部类型。

selenium.common.exceptions.StaleElementReferenceException: Message: stale element reference: stale element not found

Creating and opening a URL to log in to Website via Basic Auth with Robot Framework/Selenium (Python)

AG Grid 在上下文菜单中以大文本形式打开

发表评论