Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[BUG] Performance issue with setNull(Types.DECIMAL) on a decimal column #1106

Closed
sns-seb opened this issue Jul 9, 2019 · 5 comments
Closed
Assignees

Comments

@sns-seb
Copy link

sns-seb commented Jul 9, 2019

Driver version

7.2.2.jre8, 7.2.2.jre11, 7.3.1-preview.jre11

SQL Server version

SQL Server 2014 Standard Edition 12.00.5571.0.v1 on Amazon RDS (db.m5.xlarge)
SQL Server 2014 Enterprise Edition 12.00.5571.0.v1 on Amazon RDS (db.m5.4xlarge)

Client Operating System

Amazon Linux 2 AMI 2.0.20190313 x86_64 HVM gp2 (t3.medium)

JAVA/JVM version

openjdk version "11.0.3" 2019-04-16
OpenJDK Runtime Environment AdoptOpenJDK (build 11.0.3+7)
OpenJDK 64-Bit Server VM AdoptOpenJDK (build 11.0.3+7, mixed mode)

Table schema

See reproducer

Problem description

Usage of java.sql.PreparedStatement.setNull(int parameterIndex, int sqlType) with java.sql.Types.DECIMAL instead of java.sql.Types.DOUBLE to set a null value on a column of SQL type decimal leads to poor JDBC batch insert performance and constant drop of throughput over time.

We observed that performing massive inserts always setting the decimal column to null, the performance was nominal.
The performance impact would only kick in if column was sometime populated with null, sometime with a double using java.sql.PreparedStatement.setDouble(int parameterIndex, double x).

Some figures, collected in the environment described above, measured from the Java side (see reproducer) attempting to insert 3 millions rows in batches of 250 rows:

  • Usage of setNull(Types.DOUBLE) alone
    Stable at 83k / seconds
  • Usage of setNull(Types.DOUBLE) mixed with calls to setDouble()
    Stable at 83k / seconds
  • Usage of setNull(Types.DECIMAL) alone
    Stable at 83k / seconds
  • Usage of setNull(Types.DECIMAL) mixed with calls to setDouble()
    unstable (variations from one batch to the next) with at most 17k/s at the beginning of the run, rapidly dropping towards 10k/s and below

JDBC trace logs

Changing log level is not an option because they would affect performance

Reproduction code

import java.sql.Connection;
import java.sql.DatabaseMetaData;
import java.sql.DriverManager;
import java.sql.PreparedStatement;
import java.sql.SQLException;
import java.sql.Statement;
import java.sql.Types;
import java.time.Duration;
import java.time.Instant;
import java.util.Random;
import java.util.function.Consumer;

public class Main {
  public static void main(String[] args) {
    // example program arguments : jdbc:sqlserver://host:1433;databaseName=foo;user=bar;password=donut 10000 500
    for (String arg : args) {
      System.out.println(arg);
    }

    String jdbc_url = args[0];
    Long targetSize = Long.valueOf(args[1]);
    Long batchSize = Long.valueOf(args[2]);

    getDbConnection(jdbc_url, connection -> {
      try {
        execute(connection, targetSize, batchSize);
      } catch (SQLException e) {
        e.printStackTrace();
      }
    });
  }

  private static void getDbConnection(String jdbc_url, Consumer<Connection> connectionConsumer) {
    try {
      Class.forName("com.microsoft.sqlserver.jdbc.SQLServerDriver");
    } catch (ClassNotFoundException e) {
      e.printStackTrace();
    }
    try (Connection conn = DriverManager.getConnection(jdbc_url)) {
      if (conn != null) {
        conn.setAutoCommit(false);
        DatabaseMetaData metaObj = conn.getMetaData();
        System.out.println("Driver Name?= " + metaObj.getDriverName() + ", Driver Version?= " + metaObj.getDriverVersion() + ", Product Name?= " + metaObj.getDatabaseProductName()
            + ", Product Version?= " + metaObj.getDatabaseProductVersion());
      }
      connectionConsumer.accept(conn);
    } catch (Exception sqlException) {
      sqlException.printStackTrace();
    }
  }

  private static void execute(Connection conn, Long targetSize, Long batchSize) throws SQLException {
    try (Statement stmt = conn.createStatement()) {
      stmt.execute("IF OBJECT_ID('test', 'U') IS NOT NULL drop TABLE test;");
    }

    String create = "CREATE TABLE test (value decimal(38,20) NULL)";
    try (Statement stmt = conn.createStatement()) {
      stmt.execute(create);
    }

    Random rand = new Random();

    String insert = "INSERT INTO test (value) VALUES(?)";
    try (PreparedStatement preparedStatement = conn.prepareStatement(insert)) {

      Instant start = Instant.now();
      Instant batchStart = Instant.now();
      for (int i = 1; i <= targetSize; i++) {
        // *** uncomment a single line of the 4 methods call below to each of the 4 cases
//        onlySetNullDecimal(preparedStatement);
        mixWithSetNullDecimal(preparedStatement, rand);
//        onlySetNullDouble(preparedStatement);
//        mixWithSetNullDouble(preparedStatement, rand);

        preparedStatement.addBatch();

        if (i % batchSize == 0) {
          preparedStatement.executeBatch();
          conn.commit();
          long duration = Duration.between(batchStart, Instant.now()).toMillis();
          System.out.println("rate " + (int) (batchSize / (duration / 1000d)) + " insert/s. progress " + i + "/" + targetSize);
          batchStart = Instant.now();
        }

      }
      long duration = Duration.between(start, Instant.now()).toMillis();
      System.out.println("total duration " + duration + "ms");
      System.out.println("final rate " + (int) (targetSize / (duration / 1000d)) + " insert/s");
    }
  }

  private static void onlySetNullDecimal(PreparedStatement preparedStatement) throws SQLException {
    preparedStatement.setNull(1, Types.DECIMAL);
  }

  private static void mixWithSetNullDecimal(PreparedStatement preparedStatement, Random random) throws SQLException {
    if (random.nextBoolean()) {
      preparedStatement.setNull(1, Types.DECIMAL);
    } else {
      preparedStatement.setDouble(1, (double) Math.abs(random.nextInt()));
    }
  }

  private static void onlySetNullDouble(PreparedStatement preparedStatement) throws SQLException {
    preparedStatement.setNull(1, Types.DOUBLE);
  }

  private static void mixWithSetNullDouble(PreparedStatement preparedStatement, Random random) throws SQLException {
    if (random.nextBoolean()) {
      preparedStatement.setNull(1, Types.DOUBLE);
    } else {
      preparedStatement.setDouble(1, (double) Math.abs(random.nextInt()));
    }
  }

}
@sns-seb sns-seb added the Bug A bug in the driver. A high priority item that one can expect to be addressed quickly. label Jul 9, 2019
@sns-seb sns-seb changed the title [BUG] Performance issue - [BUG] Performance issue with setNull(Types.DECIMAL) on a decimal column Jul 9, 2019
@rene-ye
Copy link
Member

rene-ye commented Jul 9, 2019

Hi @sns-seb, thanks for letting us know. The team will look into this. What SQL Server version was used here? 12.0.x can refer to SQL Azure or 2014.

@sns-seb
Copy link
Author

sns-seb commented Jul 9, 2019

Hi @rene-ye, it was SQL Server 2014. I'll update the description

@rene-ye
Copy link
Member

rene-ye commented Jul 15, 2019

Hi @sns-seb, the performance "degradation" in this issue has to do with how the driver caches prepared statements. The image below is an example of the driver calls to the server when calling executeBatch() repeatedly with the same datatypes:
image

As you can see, the driver calls sp_prepexec on the second batch, and proceeds to execute the rest of the batch with sp_execute. This is a performance improvement discussed in #166. When datatypes are switched (as in the case above where the test is interchanging between Decimal and Double), the driver will constantly re-prepare statements:
image

We can enable statement pooling to resolve this issue. Adding disableStatementPooling=false;statementPoolingCacheSize=5; to the connection string greatly improves the performance and brings the test case's run time down to the expected run times of the other cases (notice the sp_execute 2...):
image

If you have any more questions regarding this behavior please feel free to ask.

TL;DR: Issue isn't caused by setNull() with Double/Decimal. The driver by default attempts some prepared statement caching, and constantly changing datatypes breaks this simple attempt.

@rene-ye rene-ye self-assigned this Jul 15, 2019
@rene-ye rene-ye added Waiting for Response Waiting for a reply from the original poster, or affiliated party and removed Bug A bug in the driver. A high priority item that one can expect to be addressed quickly. labels Jul 15, 2019
@sns-seb
Copy link
Author

sns-seb commented Jul 18, 2019

thanks for the detailed and clear explanation @rene-ye

I guess this issue can be closed, then?

I'm wondering whether a warning (or even an error) would make sense in this case, though.
I can't imagine a case where changing the datatype constantly for a given parameter of a given PreparedStatement would be valid and made on purpose.

@rene-ye rene-ye removed the Waiting for Response Waiting for a reply from the original poster, or affiliated party label Jul 18, 2019
@rene-ye rene-ye closed this as completed Jul 18, 2019
@rene-ye
Copy link
Member

rene-ye commented Jul 18, 2019

I'd assume there would be cases where frameworks are changing underlying datatypes unbeknownst to the user. Regardless, I see your point, we'll think about adding a warning or some kind of logging.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants