quick-perf / quickperf

QuickPerf is a testing library for Java to quickly evaluate and improve some performance-related properties
https://github.com/quick-perf/doc/wiki/QuickPerf
Apache License 2.0
469 stars 67 forks source link

Wrong report about lack of JDBC batching for update query? #132

Closed gmarziou closed 3 years ago

gmarziou commented 3 years ago

Describe the bug

I have a test of a query that updates a column in multiple rows using a where clause and spring.jpa.properties.hibernate.jdbc.batch_size=25 and I get a "JDBC batching is disabled." error.

Expected behavior

No error because it's a single query highly optimized.

Actual behavior

"JDBC batching is disabled." error.

To Reproduce

I added a test in ExpectJdbcBatchingWithoutBatchSizeTest

    @RunWith(QuickPerfJUnitRunner.class)
    public static class AClassHavingAMethodAnnotatedWithExpectJdbcBatchingAndExecutingOneUpdateBatched extends SqlTestBase {

        @Override
        protected Properties getHibernateProperties() {
            String hibernateDialect = MemoryDatabaseHibernateDialect.INSTANCE.getHibernateDialect();
            return   anHibernateConfig()
                    .withBatchSize(30)
                    .build(hibernateDialect);
        }

        @Test
        @ExpectJdbcBatching()
        @DisplaySqlOfTestMethodBody
        public void execute_one_update_in_batch_mode() {

            executeInATransaction(entityManager -> {
                String updateQueryAsString = "UPDATE Book SET title='Newer book'";
                Query query = entityManager.createNativeQuery(updateQueryAsString);
                query.executeUpdate();
            });

        }

    }

    @Test public void
    should_pass_with_one_update_and_batch_mode() {

        Class<?> testClass = AClassHavingAMethodAnnotatedWithExpectJdbcBatchingAndExecutingOneUpdateBatched.class;

        PrintableResult testResult = testResult(testClass);

        assertThat(testResult.failureCount()).isZero();

    }

The output shows that BatchSize is 0 for the update but for me it should not trigger an error, maybe there should be a filter on Batch:False?

Time:1, Success:True, Type:Prepared, Batch:False, QuerySize:1, BatchSize:0, Query:["
    UPDATE
        Book 
    SET
        title='Newer book'"], Params:[()]

Use @DisplaySql to also see queries before and after test execution.

java.lang.AssertionError: a performance property is not respected

[PERF] JDBC batching is disabled.

    You should check that hibernate.jdbc.batch_size Hibernate property has a positive value.
    A batch size value between 5 and 30 is generally recommended.

Versions

Additional context (Add any other context about the problem here.)

jeanbisutti commented 3 years ago

Thank you for trying to reproduce a potential bug.

In your test case, one UPDATE query is executed without batching as shown in the error report: Batch:False

The test uses ExpectJdbcBacting annotation. So the test is failing because JDBC batching is not used.

The following test doesn't use a native query, and it does not fail with a single update:

        @Test
        @ExpectJdbcBatching()
        @DisplaySqlOfTestMethodBody
        public void execute_insert_one_query_in_batch_mode() {

            executeInATransaction(entityManager -> {
                Book newBook = new Book();
                newBook.setTitle("new book");
                entityManager.persist(newBook);
            });

        }

JDBC batching is enabled here (Batch:True):

Time:0, Success:True, Type:Prepared, Batch:True, QuerySize:1, BatchSize:1, Query:["
    insert 
    into
        Book
        (isbn, title, id) 
    values
        (?, ?, ?)"], Params:[(NULL(VARCHAR),new book,1)]

Perhaps ExpectJdcBatching annotation should evolve: the test could fail if some queries could be batched, but they are not.

gmarziou commented 3 years ago

Maybe I over simplified in this test, my real query is below although it does not change fundamentally:

    @Modifying
    @Query("UPDATE Tap t SET t.etat = 'ANNULE' WHERE t.id IN (:tapIds) AND t.etat NOT IN ('ANNULE', 'SUPPRIME')")
    int annuler(@Param("tapIds") List<UUID> tapIds);

Also, in my test I have some functional assertions, so it means that in a real test you have several queries before and after the one that you test for perfs. To me, this is a limitation of using an annotation on test methods, ideally I'd prefer to have quickperf assertions I can insert within the method body but maybe this overlaps too much with datasource-assert

jeanbisutti commented 3 years ago

Also, in my test I have some functional assertions, so it means that in a real test you have several queries before and after the one that you test for perfs. To me, this is a limitation of using an annotation on test methods,

I am not sure to understand. Just for clarification: apart from DiplaySql annotation, the SQL annotations analyze the SQL generated from the test method body, not the SQL generated before and after the test method body.

jeanbisutti commented 3 years ago

Maybe I over simplified in this test, my real query is below although it does not change fundamentally:

If you have time, I would be interested in a test case.

gmarziou commented 3 years ago

I am not sure to understand. Just for clarification: apart from DiplaySql annotation, the SQL annotations analyze the SQL generated from the test method body, not the SQL generated before and after the test method body.

In fact when I had this issue, I put a breakpoint in SqlStatementBatchVerifier.verifyThatInsertUpdateDeleteExecutionAreBatched() and the measuredBatchSizesAsArray variable contained 3 entries: [25, 20, 0] the last one was the one matching the update query and the 2 others that were batched were the inserts to setup my test data.

So maybe I'm wrong but I imagine that it could have been the reverse: my data insertions could be not batched (and it could be OK) while my update query under test could be batched but still I would get an error.

gmarziou commented 3 years ago

If you have time, I would be interested in a test case.

I'll do my best.

jeanbisutti commented 3 years ago

In fact when I had this issue, I put a breakpoint in SqlStatementBatchVerifier.verifyThatInsertUpdateDeleteExecutionAreBatched() and the measuredBatchSizesAsArray variable contained 3 entries: [25, 20, 0]

It means that the code generates several JDBC executions with 25, 20, or 0 batch size. 0 batch size => at least one JDBC execution does not use the batch mode

jeanbisutti commented 3 years ago

@gmarziou I see what happens.

The following code executes one UPDATE without JDBC batching:

    @Modifying
    @Query("UPDATE Tap t SET t.etat = 'ANNULE' WHERE t.id IN (:tapIds) AND t.etat NOT IN ('ANNULE', 'SUPPRIME')")
    int annuler(@Param("tapIds") List<UUID> tapIds);

I created the #144 issue to add a lenient element to ExpectJdbcBathing annotation. With a false value, the test will not fail with the code above.