Friday, February 9, 2018

JDBC Auto Commit and Log File Sync

By default when a connection is checked out of a JDBC connection pool (either Oracle Data Source or UCP), it has auto commit set to true. This means for DMLs, after each statement execution a commit happens implicitly. Effect of this is high log file sync (foreground) and log file parallel write (background waits) on the database.
The Java test case at the end of the post count the log file sync waits and user commits for inserting 10,000 rows into a single column table (create table x (a number)). The table below shows summary for running test with auto commit on and off. The database used was a standard edition 11.2.0.4.
MeasurementAuto Commit OnAuto Commit Off
Log File Sync Waits100001
User commits100001
Elapsed Time (sec)5023
Ideally, JDBC batching should be used when multiples rows are inserted like this (which requires setting auto commit to false anyway). However if this not possible then changing the auto commit property on the connection is the next best thing. Below output is from APConsole which gives a comparison of the wait times associated with having auto commit on and off. Log file sync wait is implicitly shown on the wait class graph as it's the only wait event in commit wait class.




Below java code could be used for testing for other DML events.
import java.sql.Connection;
import java.sql.PreparedStatement;
import java.sql.ResultSet;
import java.sql.SQLException;
import java.util.HashMap;
import oracle.ucp.jdbc.PoolDataSource;
import oracle.ucp.jdbc.PoolDataSourceFactory;

public class CMTest {

    private final HashMap valueMap = new HashMap<>();
    private final PoolDataSource ds;

    public CMTest() throws SQLException {

        ds = PoolDataSourceFactory.getPoolDataSource();
        ds.setConnectionFactoryClassName("oracle.jdbc.pool.OracleDataSource");
        ds.setUser("asanga");
        ds.setPassword("xxx");
        ds.setURL("jdbc:oracle:thin:@192.168.0.66:1521:std11g4");

    }

    public Connection getConnection() throws SQLException {

        return ds.getConnection();
    }

    public static void main(String[] args) throws SQLException {

        CMTest test = new CMTest();
        Connection con = test.getConnection();
        con.setAutoCommit(false); // comment to make auto auto commit true

        test.printStat(con, 1);
        test.runTest(con);
        test.printStat(con, 2);
    }

    public void printStat(Connection con, int i) throws SQLException {

        String SQL = "select st.name,s.value from v$statname st, v$sesstat s where st.STATISTIC#=s.STATISTIC# and s.sid=SYS_CONTEXT ('USERENV', 'SID') and st.name='user commits' "
                + "union "
                + "select e.event,TOTAL_WAITS from v$session_event e where e.event='log file sync' and e.sid=SYS_CONTEXT ('USERENV', 'SID')";
//                + "union "
//                + "select e.event,TIME_WAITED_MICRO from v$session_event e where e.event='log file sync' and e.sid=SYS_CONTEXT ('USERENV', 'SID')";

        PreparedStatement pr = con.prepareStatement(SQL);
        ResultSet rs = pr.executeQuery();
        while (rs.next()) {
            if (i == 1) {

                valueMap.put(rs.getString(1), rs.getInt(2));

            } else {
                Integer x = valueMap.get(rs.getString(1));
                x = (x == null) ? 0 : x;

                System.out.println(rs.getString(1) + " " + (rs.getInt(2) - x));

            }
        }
        rs.close();
        pr.close();

    }

    public void runTest(Connection con) throws SQLException {

        String sql = "insert into x values (?)";
//        String sql = "delete from x where a = ?";

        PreparedStatement pr = con.prepareStatement(sql);
        for (int i = 0; i < 10000; i++) {

            pr.setInt(1, i);
            pr.execute();
        }
        con.commit();
        pr.close();
    }
}
Related Posts
java.sql.SQLException: Could not commit with auto-commit set on When Using 12c JDBC Driver