cursor use vs pg_stat_statements

Started by Andrew Dunstanabout 4 years ago4 messages
#1Andrew Dunstan
andrew@dunslane.net

The problem I'm writing about (h/t Simon Riggs for finding it) is
illustrated by the following snippet of java:

public static void runtest(Connection conn) throws Exception {
Statement stmt = conn.createStatement();
stmt.setFetchSize(10);
ResultSet rs = stmt.executeQuery("select oid, relfileid, relname from pg_class");
int count = 100;
while (rs.next() && count-- > 0) {
System.out.print(".");
}
rs.close();
stmt.commit();
stmt.close();
System.out.println("");
}

When called, this prints out a line with 100 dots showing 100 lines were
fetched, but pg_stat_statements shows this:

query | select oid, relfilenode, relname from pg_class
calls | 1
rows  | 10

suggesting only 10 rows were returned. It appears that only the first
"EXECUTE 10" command against the portal is counted. At the very least
this is a POLA violation, and it seems to be a bug. Maybe it's
documented somewhere but if so it's not obvious to me.

cheers

andrew

--
Andrew Dunstan
EDB: https://www.enterprisedb.com

#2Laurenz Albe
laurenz.albe@cybertec.at
In reply to: Andrew Dunstan (#1)
Re: cursor use vs pg_stat_statements

On Tue, 2021-10-19 at 15:24 -0400, Andrew Dunstan wrote:

The problem I'm writing about (h/t Simon Riggs for finding it) is
illustrated by the following snippet of java:

      public static void runtest(Connection conn) throws Exception {
        Statement stmt = conn.createStatement();
        stmt.setFetchSize(10);
        ResultSet rs = stmt.executeQuery("select oid, relfileid, relname from pg_class");
        int count = 100;
        while (rs.next() && count-- > 0) {
          System.out.print(".");
        }
        rs.close();
        stmt.commit();
        stmt.close();
        System.out.println("");
      }

When called, this prints out a line with 100 dots showing 100 lines were
fetched, but pg_stat_statements shows this:

    query | select oid, relfilenode, relname from pg_class
    calls | 1
    rows  | 10

suggesting only 10 rows were returned. It appears that only the first
"EXECUTE 10" command against the portal is counted. At the very least
this is a POLA violation, and it seems to be a bug. Maybe it's
documented somewhere but if so it's not obvious to me.

I can't reproduce this on 14.1, after fixing the errors in your code:

test=# SELECT query, calls, rows FROM pg_stat_statements WHERE queryid = '3485361931104084405' \gx
─[ RECORD 1 ]─────────────────────────────────────────
query │ select oid, relfilenode, relname from pg_class
calls │ 1
rows │ 424

The code I used was:

public class x {
public static void main(String[] args) throws ClassNotFoundException, java.sql.SQLException {
Class.forName("org.postgresql.Driver");

java.sql.Connection conn = java.sql.DriverManager.getConnection("jdbc:postgresql:test?user=laurenz");

java.sql.Statement stmt = conn.createStatement();
stmt.setFetchSize(10);
java.sql.ResultSet rs = stmt.executeQuery("select oid, relfilenode, relname from pg_class");
int count = 100;
while (rs.next() && count-- > 0) {
System.out.print(".");
}
rs.close();
stmt.close();
System.out.println("");
conn.close();
}
}

Yours,
Laurenz Albe

#3Andrew Dunstan
andrew@dunslane.net
In reply to: Laurenz Albe (#2)
1 attachment(s)
Re: cursor use vs pg_stat_statements

On 10/20/21 9:02 AM, Laurenz Albe wrote:

On Tue, 2021-10-19 at 15:24 -0400, Andrew Dunstan wrote:

The problem I'm writing about (h/t Simon Riggs for finding it) is
illustrated by the following snippet of java:

      public static void runtest(Connection conn) throws Exception {
        Statement stmt = conn.createStatement();
        stmt.setFetchSize(10);
        ResultSet rs = stmt.executeQuery("select oid, relfileid, relname from pg_class");
        int count = 100;
        while (rs.next() && count-- > 0) {
          System.out.print(".");
        }
        rs.close();
        stmt.commit();
        stmt.close();
        System.out.println("");
      }

When called, this prints out a line with 100 dots showing 100 lines were
fetched, but pg_stat_statements shows this:

    query | select oid, relfilenode, relname from pg_class
    calls | 1
    rows  | 10

suggesting only 10 rows were returned. It appears that only the first
"EXECUTE 10" command against the portal is counted. At the very least
this is a POLA violation, and it seems to be a bug. Maybe it's
documented somewhere but if so it's not obvious to me.

I can't reproduce this on 14.1, after fixing the errors in your code:

Try again with autocommit turned off. Sorry, I omitted that crucial
detail. Exact test code attached (name/password removed)

cheers

andrew

--
Andrew Dunstan
EDB: https://www.enterprisedb.com

Attachments:

Testme.javatext/x-java; charset=UTF-8; name=Testme.javaDownload
#4Michael Paquier
michael@paquier.xyz
In reply to: Andrew Dunstan (#3)
Re: cursor use vs pg_stat_statements

On Wed, Oct 20, 2021 at 09:53:38AM -0400, Andrew Dunstan wrote:

Try again with autocommit turned off. Sorry, I omitted that crucial
detail. Exact test code attached (name/password removed)

For the same of the archives, this should be OK now under 1d477a9.
See also this thread:
/messages/by-id/EBE6C507-9EB6-4142-9E4D-38B1673363A7@amazon.com
--
Michael