Subject: The same prepared query yield "-1" the first six times and then "-1.0"

From: Edoardo Panfili <[email-masked]>
Date: Mon, 21 Aug 2023 19:37:25 +0200

Hy, I posted this topic in pgsql-general and they say that maybe it is
better to ask in psql-jdbc so...

I am using
postgresql version: 15.3 (Debian 15.3-0+deb12u1)
org.postgresql.postgresql JDBC driver version: 42.6.0
via Java 17.0.7

I discovered an unattended (for me) situation: when I execute
10 times the same prepared query the result is not always the same.

I wrote a little test case to show this.

this is the db that I am using:
CREATE TABLE number(
name character varying(30) NOT NULL,
dim1 real DEFAULT '-1' NOT NULL
);
insert into number (name) VALUES('first');

and the test program:
static final String DB_URL = "jdbc:postgresql://192.168.64.7:5432/testdb";
static final String USER = "user";
static final String PASS = "password";
public static void main(String[] args) throws Exception {
  Connection conn = DriverManager.getConnection(DB_URL, USER, PASS);
  for(int i=0; i<10; i++) {
    try( PreparedStatement istruzioneCelle = conn.prepareStatement(
      "SELECT dim1 FROM number WHERE name='first'") ) {
      ResultSet rs = istruzioneCelle.executeQuery();
      rs.next();
      System.out.print("p: "+rs.getString("dim1")+"\n”);
    } catch (SQLException e) {
      e.printStackTrace();
    }
  }
  conn.close();
}

The attended result was a sequence of ten equal values but this is the
actual result:

p: -1
p: -1
p: -1
p: -1
p: -1
p: -1.0
p: -1.0
p: -1.0
p: -1.0
p: -1.0

Semantically the same but not the representation.

All works fine if I open and close the connection after every single query
but in production I am using pooled connections.
This is what I can read in postgresql logs (it seems that after 4 queries
the statement becomes named and the result changes after the second call to
the named query):

2023-08-21 11:51:50.633 CEST [1511] user@testdb LOG: execute
<unnamed>: SET extra_float_digits = 3
2023-08-21 11:51:50.634 CEST [1511] user@testdb LOG: execute
<unnamed>: SET application_name = 'PostgreSQL JDBC Driver'
2023-08-21 11:51:50.644 CEST [1511] user@testdb LOG: execute
<unnamed>: SELECT dim1 FROM number WHERE name='first'
2023-08-21 11:51:50.648 CEST [1511] user@testdb LOG: execute
<unnamed>: SELECT dim1 FROM number WHERE name='first'
2023-08-21 11:51:50.649 CEST [1511] user@testdb LOG: execute
<unnamed>: SELECT dim1 FROM number WHERE name='first'
2023-08-21 11:51:50.650 CEST [1511] user@testdb LOG: execute
<unnamed>: SELECT dim1 FROM number WHERE name='first'
2023-08-21 11:51:50.651 CEST [1511] user@testdb LOG: execute S_1:
SELECT dim1 FROM number WHERE name='first'
2023-08-21 11:51:50.651 CEST [1511] user@testdb LOG: execute S_1:
SELECT dim1 FROM number WHERE name='first'
2023-08-21 11:51:50.653 CEST [1511] user@testdb LOG: execute S_1:
SELECT dim1 FROM number WHERE name='first'
2023-08-21 11:51:50.653 CEST [1511] user@testdb LOG: execute S_1:
SELECT dim1 FROM number WHERE name='first'
2023-08-21 11:51:50.654 CEST [1511] user@testdb LOG: execute S_1:
SELECT dim1 FROM number WHERE name='first'
2023-08-21 11:51:50.656 CEST [1511] user@testdb LOG: execute S_1:
SELECT dim1 FROM number WHERE name=‘first'

Can I do something to avoid this problem?

thank you
Edoardo

---

From: Dave Cramer <[email-masked]>
Date: Mon, 21 Aug 2023 14:40:18 -0400

Hi Edoardo,

Thanks for the question.

So here is what is happening . As you can see after 5 times this query
starts using a named statement (S_1). Additionally when this occurs we
switch to binary data instead of text. That said, I don't think the results
should change.
Thanks for the repro. I will have a look.
Dave Cramer
www.postgres.rocks