Inconsistent performance with LIKE and bind variable on long-lived connection

[Steven Grimm <sgrimm@xxxxxxxxxxxxxx>]

PostgreSQL 9.6.3 on OS X Sierra, JDBC driver version 42.1.1.

I noticed that one of my queries was slowing down after a few invocations. Narrowed it down to an issue with bind variables and LIKE conditions. Very consistently, on a given connection, the first 9 times a SELECT containing a LIKE whose value is a bind variable is executed, the query returns results quickly. But starting with the tenth execution, it slows down by a factor of 20 and stays slow until the connection is closed.

The slowdown doesn't happen with bind variables on equality conditions, and it doesn't happen if a constant is used in the LIKE condition rather than a bind variable.

The below Java code reproduces the problem 100% of the time on my system. It populates a test table with 10000 rows if the table doesn't already exist, then runs a simple two-condition SELECT with different combinations of bind variables and constants. Each query is run 20 times and its execution times in milliseconds are displayed.

On my system I get output like this:

Two bind variables      57  22   8   5   9   9  10  13   8 144 151 236 198 204 197 197 152 126 108 102
Equality bind variable   5   5   5   5   5   5   7   5   4   6   5   4   5   5   4   4   5   5   5   5
LIKE bind variable       5   5   5   5   9   5   5  12   6 111 106 107 108 121 110 101 107 108 113 108
No bind variables        5   5   4   5   5   5   4   4   5   5   4   5   5   4   6   5   4   5   7   4

In other words, when a bind variable is used in the LIKE condition, the query suddenly goes from taking 5-15 milliseconds to taking 100+ milliseconds. When the query is run in psql, it takes 5-10 milliseconds.

I'm not sure if this is a problem with the JDBC driver or the server, but it's certainly unexpected!

---

import java.sql.Connection;
import java.sql.DriverManager;
import java.sql.PreparedStatement;
import java.sql.ResultSet;
import java.sql.SQLException;

public class BindTest {
  static String url = ""

  private static void init() {
    try (Connection conn = DriverManager.getConnection(url)) {
      try (PreparedStatement stmt = conn.prepareStatement(
          "CREATE TABLE test (col1 TEXT, col2 TEXT, PRIMARY KEY (col1, col2))")) {
        stmt.execute();
      }

      try (PreparedStatement stmt = conn.prepareStatement("INSERT INTO test VALUES (?,?)")) {
        stmt.setString(1, "xyz");

        for (int i = 0; i<  10000; i++) {
          stmt.setInt(2, i);
          stmt.addBatch();
        }

        stmt.executeBatch();
      }

      try (PreparedStatement stmt = conn.prepareStatement("VACUUM ANALYZE")) {
        stmt.execute();
      }
    } catch (SQLException e) {
      // Table exists, so don't populate it
    }
  }

  private static void logTime(String name, PreparedStatement stmt) throws SQLException {
    StringBuilder out = new StringBuilder(String.format("%-22s", name));

    for (int i = 0; i<  20; i++) {
      long startTime = System.currentTimeMillis();
      ResultSet rs = stmt.executeQuery();
      while (rs.next()) {
        rs.getString(1);
      }
      long endTime = System.currentTimeMillis();
      rs.close();

      out.append(String.format(" %3d", endTime - startTime));
    }

    stmt.close();

    System.out.println(out);
  }

  public static void main(String[] args) throws Exception {
    init();

    try (Connection conn = DriverManager.getConnection(url)) {
      PreparedStatement stmt = conn.prepareStatement(
          "SELECT col2 FROM test WHERE col1 = ? AND col2 LIKE ? ORDER BY col2");
      stmt.setString(1, "xyz");
      stmt.setString(2, "%");
      logTime("Two bind variables", stmt);

      stmt = conn.prepareStatement(
          "SELECT col2 FROM test WHERE col1 = ? AND col2 LIKE '%' ORDER BY col2");
      stmt.setString(1, "xyz");
      logTime("Equality bind variable", stmt);

      stmt = conn.prepareStatement(
          "SELECT col2 FROM test WHERE col1 = 'xyz' AND col2 LIKE ? ORDER BY col2");
      stmt.setString(1, "%");
      logTime("LIKE bind variable", stmt);

      stmt = conn.prepareStatement(
          "SELECT col2 FROM test WHERE col1 = 'xyz' AND col2 LIKE '%' ORDER BY col2");
      logTime("No bind variables", stmt);
    }
  }
}