MySQL Bugs: #89948: Batched statements are not committed for useLocalTransactionState=true

Bug #89948	Batched statements are not committed for useLocalTransactionState=true
Submitted:	7 Mar 2018 19:16	Modified:	31 Jul 2018 22:02
Reporter:	Jonas Boethius	Email Updates:
Status:	Closed	Impact on me:	None
Category:	Connector / J	Severity:	S1 (Critical)
Version:	5.1.45	OS:	Any
Assigned to:	Filipe Silva	CPU Architecture:	Any
Tags:	REWRITEBATCHEDSTATEMENTS, useLocalTransactionState

Description:
For performance tuning of the MySQL JDBC driver many sources recommend setting useLocalTransactionState=true (to avoid redundant commits when no transaction was started) and rewriteBatchedStatements=true (to reduce latency for multiple statements). Unfortunately it seems that this combination will leave the transaction uncommitted for many (most?) UPDATE and DELETE batched statements.

After troubleshooting unexpected behavior in our application, I was able to reproduce the problem directly using the MySQL driver. 

The problem seems to apply for both usage of batched statements as well as for batched prepared statements. 

I could reproduce the problem for DELETE and UPDATE batched statements. It seems to be no problem with INSERT statements.

Sampling some older driver versions indicates this is problem applies for multiple versions of the driver.

How to repeat:
This code reproduces the problem:

    public void checkBatchCommitted(String theUrl, String theUser, String thePassword) throws SQLException {
        Connection aTestCon = null;
        Connection aVerifyCon = null;
        try {
            Class.forName("com.mysql.jdbc.Driver");

            // Broken config
            String aJdbcUrl = theUrl + "?rewriteBatchedStatements=true&useLocalTransactionState=true";
            // Working config can be used as reference. Works with either rewrite or local tx enabled, not both
            // String aJdbcUrl = theUrl + "?rewriteBatchedStatements=false&useLocalTransactionState=true";

            // Needs to be high enough to force the driver to enable/disable multiQueries
            int aBatchSize = 10;
            // Working size
            // int aBatchSize = 2; // This value is small enough not to trigger usage of multi-queries

            aTestCon = DriverManager.getConnection(aJdbcUrl, theUser, thePassword);
            // We need an independent connection for a dedicated transaction to verify the uncommitted state of the first connection
            aVerifyCon = DriverManager.getConnection(aJdbcUrl, theUser, thePassword);

            try (Statement aStatement = aTestCon.createStatement()) {
                aStatement.executeUpdate("CREATE TABLE IF NOT EXISTS TestTable (id int(11) NOT NULL,PRIMARY KEY (id)) ENGINE=InnoDB DEFAULT CHARSET=utf8");
                aStatement.executeUpdate("TRUNCATE TABLE TestTable");
            }

            aTestCon.setAutoCommit(false);

            // Batch insert statements works fine (UPDATE/DELETE does not)
            try (PreparedStatement aStatement = aTestCon.prepareStatement("INSERT INTO TestTable (id) VALUES (?)")) {
                for (int i = 0; i < aBatchSize; i++) {
                    aStatement.setInt(1, i);
                    aStatement.addBatch();
                }
                aStatement.executeBatch();
            }
            aTestCon.commit();

            // Let's verify with independent transaction
            assertRowCount(aVerifyCon, aBatchSize);

            // Now delete (same problem regardless if statement or prepared statements used)
            // Same problem can be observed also with UPDATE statements but INSERT statements seems to work
            try (PreparedStatement aStatement = aTestCon.prepareStatement("DELETE FROM TestTable WHERE ID = ?")) {
                for (int i = 0; i < aBatchSize; i++) {
                    aStatement.setInt(1, i);
                    aStatement.addBatch();
                }
                aStatement.executeBatch();
            }
            // Here the delete batch should be committed but is not
            aTestCon.commit();

            // If we check row count with the same connection, it looks ok but this is due to the still pending transaction
            assertRowCount(aTestCon, 0);

            // When verifying in on a separate connection, we still see the rows that are supposed to be deleted
            assertRowCount(aVerifyCon, 0);

        } catch (Exception e) {
            e.printStackTrace();
        } finally {
            aTestCon.close();
            aVerifyCon.close();
        }

    }

    private void assertRowCount(Connection theConnection, int theExpected) throws SQLException {
        try (Statement aStatement = theConnection.createStatement()) {
            ResultSet aResultSet = aStatement.executeQuery("SELECT COUNT(*) FROM TestTable");
            aResultSet.next();
            int aRowCount = aResultSet.getInt(1);
            System.out.println("Row count was: " + aRowCount + ", we expect: " + theExpected);
            // We would expect 0 but we still see the added rows
            assert aRowCount == theExpected;
            aResultSet.close();
        }
    }

Hello Jonas Boe,

Thank you for the bug report and testcase.
Verified this behavior on MySQL Connector / J 5.1.45.

Thanks,
Chiranjeevi.

run:
Row count was: 10, we expect: 10
Row count was: 10, we expect: 0
BUILD SUCCESSFUL (total time: 0 seconds)

Have you tried using autogenerateTestcaseScript=true as a JDBC URL parameter to see that the expected COMMIT doesn't actually happen? This could also be the server misrepresenting the current transaction state (which has happened multiple times before). It could also be an interaction at the server for REPEATABLE READ and a connection that is in auto-commit, and one that is not (that is, if the COMMIT actually happens).

useLocalTransactionState really should get deprecated in favor of useLocalSessionState, which doesn't trust the server's flags it sends back for transactions in progress (because they're sometimes subtly wrong), but instead will always commit or rollback, but *won't* go back to the server to see what the isolation level or auto-commit states are (which are usually more 'no-op' due to how connection pools and frameworks call those methods too often).

Hi Mark, 
If the question was directed to me I have not used autogenerateTestcaseScript specifically. I have though been doing debugging and also using connectionLifecycleInterceptors and logger hooks. It is clear to me that the commit is never written to the server. It seems that it is the method calls to enableMultiQueries and disableMultiQueries in MysqlIO class that messes up the local value of MysqlIO.serverStatus. My server has autocommit=ON as default value. The same problem has been reproduced independently of transaction isolation (at least for repeatable read and read committed which I've tested). 
Personally I think the intention of useLocalTransactionState=true makes a lot of sense in many cases.

Hi Jonas,

You are quite right. This is a bug in the internal multi-queries enabling methods.

Until this is not fixed, as a workaround, you can turn on multi-queries manually with the connection option "allowMultiQueries=true". This avoids the wrong behavior and actually performs better since it skips a couple of round-trips to the server just to turn the multi-queries on and off on some query executions.

Hi Filipe,
I have applied the config you recommended and it works as it should now.
Thanks /Jonas

Posted by developer:
 
Added the following entry to the Connector/J 5.147 changelog:

"Setting rewriteBatchedStatements=true and useLocalTransactionState=true caused transactions to be uncommitted for batched UPDATE and DELETE statements. It was due to the intermediate queries for enabling multiquery support on the server resetting the local transaction state as a side effect. With this fix, the local transaction state is preserved when the intermediate queries are executed."

Posted by developer:
 
Added chnagelog entry also for Connector/J 8.0.13.