[GENERAL] Inconsistent performance with LIKE and bind variable on long-lived connection - Mailing list pgsql-general
From | Steven Grimm |
---|---|
Subject | [GENERAL] Inconsistent performance with LIKE and bind variable on long-lived connection |
Date | |
Msg-id | CAOFXwWWhOYzhxAkQZzfZYPg2r-p_QvAaO31x7RpeBzJiEtEKpg@mail.gmail.com Whole thread Raw |
Responses |
Re: [GENERAL] Inconsistent performance with LIKE and bind variable onlong-lived connection
|
List | pgsql-general |
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.
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 = "jdbc:postgresql:test";
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);
}
}
}
---
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 = "jdbc:postgresql:test";
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);
}
}
}
pgsql-general by date: