Обсуждение: BUG #13979: Strange pg_stat_statements results with PREPARE/EXECUTE
BUG #13979: Strange pg_stat_statements results with PREPARE/EXECUTE
От
kasahara.tatsuhito@gmail.com
Дата:
The following bug has been logged on the website:
Bug reference: 13979
Logged by: Kasahara Tatsuhito
Email address: kasahara.tatsuhito@gmail.com
PostgreSQL version: 9.5.1
Operating system: RHEL
Description:
Hi, I noticed that in some cases pg_stat_statements shows strange results.
(example)
=# CREATE TABLE tt(c1 int);
=# INSERT INTO tt SELECT generate_series(1,10);
=# SELECT pg_stat_statements_reset();
Then, performed simple SELECTs via java. (see the end of this mail)
After that, I got the following pg_stat_statements result, and ISTM it's
reasonable.
=# SELECT queryid, calls, query FROM pg_stat_statements WHERE query LIKE
'%tt%';
queryid | calls | query
-----------+-------+--------------------------------
575935600 | 10 | SELECT * FROM tt WHERE c1 = $1
Next, reset the pg_stat_statements and performed PREPARE and EXECUTE via
psql.
=# SELECT pg_stat_statements_reset();
=# PREPARE p1(int) AS SELECT * FROM tt WHERE c1 = $1;
=# EXECUTE p1(1);
=# SELECT queryid, calls, query FROM pg_stat_statements WHERE query LIKE
'%tt%';
queryid | calls | query
-----------+-------+----------------------------------------------------
575935600 | 1 | PREPARE p1(int) AS SELECT * FROM tt WHERE c1 = $1;
(1 row)
Then, performed same SELECTs via java.
After that, I got a bit strange pg_stat_statements result..
=# SELECT queryid, calls, query FROM pg_stat_statements WHERE query LIKE
'%tt%';
queryid | calls | query
-----------+-------+----------------------------------------------------
575935600 | 11 | PREPARE p1(int) AS SELECT * FROM tt WHERE c1 = $1;
(1 row)
I'm not sure it's expected behaviors, but seems a bug.
Best regards,
// Java Test code
import java.lang.*;
import java.sql.*;
class Test {
public static void main(String[] args) {
String driver = "org.postgresql.Driver";
String url =
"jdbc:postgresql://localhost/postgres?user=postgres&ApplicationName=my_jdbc_test";
try{
Connection con = DriverManager.getConnection(url);
con.setAutoCommit(false);
String sql1 = "SELECT * FROM tt WHERE c1 = ?";
PreparedStatement ps1 = con.prepareStatement(sql1);
for (int i=1; i<=10; i++) {
ps1.setInt(1,i);
ResultSet rs = ps1.executeQuery();
while(rs.next()){
System.out.println("results c1:" + rs.getInt(1));
}
}
con.commit();
ps1.close();
con.close();
}catch (Exception e){
e.printStackTrace();
}
}
}
Re: BUG #13979: Strange pg_stat_statements results with PREPARE/EXECUTE
От
"David G. Johnston"
Дата:
On Tuesday, February 23, 2016, <kasahara.tatsuhito@gmail.com> wrote:
> The following bug has been logged on the website:
>
> Bug reference: 13979
> Logged by: Kasahara Tatsuhito
> Email address: kasahara.tatsuhito@gmail.com <javascript:;>
> PostgreSQL version: 9.5.1
> Operating system: RHEL
> Description:
>
> Hi, I noticed that in some cases pg_stat_statements shows strange results.
> (example)
>
> =# CREATE TABLE tt(c1 int);
> =# INSERT INTO tt SELECT generate_series(1,10);
> =# SELECT pg_stat_statements_reset();
>
> Then, performed simple SELECTs via java. (see the end of this mail)
> After that, I got the following pg_stat_statements result, and ISTM it's
> reasonable.
>
> =# SELECT queryid, calls, query FROM pg_stat_statements WHERE query LIKE
> '%tt%';
> queryid | calls | query
> -----------+-------+--------------------------------
> 575935600 | 10 | SELECT * FROM tt WHERE c1 = $1
>
>
> Next, reset the pg_stat_statements and performed PREPARE and EXECUTE via
> psql.
>
> =# SELECT pg_stat_statements_reset();
> =# PREPARE p1(int) AS SELECT * FROM tt WHERE c1 = $1;
> =# EXECUTE p1(1);
> =# SELECT queryid, calls, query FROM pg_stat_statements WHERE query LIKE
> '%tt%';
> queryid | calls | query
> -----------+-------+----------------------------------------------------
> 575935600 | 1 | PREPARE p1(int) AS SELECT * FROM tt WHERE c1 = $1;
> (1 row)
>
> Then, performed same SELECTs via java.
> After that, I got a bit strange pg_stat_statements result..
>
> =# SELECT queryid, calls, query FROM pg_stat_statements WHERE query LIKE
> '%tt%';
> queryid | calls | query
> -----------+-------+----------------------------------------------------
> 575935600 | 11 | PREPARE p1(int) AS SELECT * FROM tt WHERE c1 = $1;
> (1 row)
>
>
> I'm not sure it's expected behaviors, but seems a bug.
>
> Best regards,
>
> // Java Test code
> import java.lang.*;
> import java.sql.*;
>
> class Test {
> public static void main(String[] args) {
> String driver = "org.postgresql.Driver";
> String url =
>
> "jdbc:postgresql://localhost/postgres?user=postgres&ApplicationName=my_jdbc_test";
> try{
> Connection con = DriverManager.getConnection(url);
> con.setAutoCommit(false);
> String sql1 = "SELECT * FROM tt WHERE c1 = ?";
> PreparedStatement ps1 = con.prepareStatement(sql1);
>
> for (int i=1; i<=10; i++) {
> ps1.setInt(1,i);
> ResultSet rs = ps1.executeQuery();
> while(rs.next()){
> System.out.println("results c1:" + rs.getInt(1));
> }
> }
>
> con.commit();
> ps1.close();
> con.close();
> }catch (Exception e){
> e.printStackTrace();
> }
> }
> }
>
>
You need to tell people what exactly you think is strange/what you would
expect to see.
David J.
2016-02-23 23:36 GMT+09:00 David G. Johnston <david.g.johnston@gmail.com>: > You need to tell people what exactly you think is strange/what you would > expect to see. Yeah. So I expected following result after performing second time "SELECT * FROM tt WHERE c1 = $1" in a previous e-mail. =# SELECT queryid, calls, query FROM pg_stat_statements WHERE query LIKE '%tt%'; queryid | calls | query -----------+-------+---------------------------------------------------- 575935600 | 1| PREPARE p1(int) AS SELECT * FROM tt WHERE c1 = $1; other-queryid | 10 | SELECT * FROM tt WHERE c1 = $1; (2 row) But actually SELECT was counted as PREPARE in pg_stat_statements. That's what I thought strange. It seems to me that "<query>" and "PREPARE <query>" always have same queryid. Therefore should I consider these queries as the same one ? -- Tatsuhito Kasahara kasahara.tatsuhito _at_ gmail.com
Re: BUG #13979: Strange pg_stat_statements results with PREPARE/EXECUTE
От
"David G. Johnston"
Дата:
On Tue, Feb 23, 2016 at 8:24 AM, Kasahara Tatsuhito < kasahara.tatsuhito@gmail.com> wrote: > 2016-02-23 23:36 GMT+09:00 David G. Johnston <david.g.johnston@gmail.com>= : > > You need to tell people what exactly you think is strange/what you woul= d > > expect to see. > Yeah. > > So I expected following result after performing second time "SELECT * > FROM tt WHERE c1 =3D $1" in a previous e-mail. > > =3D# SELECT queryid, calls, query FROM pg_stat_statements WHERE query LIK= E > '%tt%'; > queryid | calls | query > -----------+-------+---------------------------------------------------- > 575935600 | 1| PREPARE p1(int) AS SELECT * FROM tt WHERE c1 =3D $1; > other-queryid | 10 | SELECT * FROM tt WHERE c1 =3D $1; > (2 row) > > But actually SELECT was counted as PREPARE in pg_stat_statements. > That's what I thought strange. > > It seems to me that "<query>" and "PREPARE <query>" always have same > queryid. > Therefore should I consider these queries as the same one ? > > =E2=80=8BWhat do you think the following statement does? =E2=80=8B PreparedStatement ps1 =3D con.prepareStatement(sql1); =E2=80=8BDavid J. =E2=80=8B
Kasahara Tatsuhito <kasahara.tatsuhito@gmail.com> writes:
> So I expected following result after performing second time "SELECT *
> FROM tt WHERE c1 = $1" in a previous e-mail.
> =# SELECT queryid, calls, query FROM pg_stat_statements WHERE query LIKE
> '%tt%';
> queryid | calls | query
> -----------+-------+----------------------------------------------------
> 575935600 | 1| PREPARE p1(int) AS SELECT * FROM tt WHERE c1 = $1;
> other-queryid | 10 | SELECT * FROM tt WHERE c1 = $1;
> (2 row)
> But actually SELECT was counted as PREPARE in pg_stat_statements.
> That's what I thought strange.
What's in the query field is whatever source string the query was created
from. In the case of a prepared statement, we could potentially show
either the PREPARE or the EXECUTE, but the former was deemed much more
useful. There's no logic in there to invent a string that was never
actually submitted to the engine.
regards, tom lane
Hi, 2016-02-24 0:32 GMT+09:00 David G. Johnston <david.g.johnston@gmail.com>: > What do you think the following statement does? > > PreparedStatement ps1 = con.prepareStatement(sql1); I think above statement would performed "PREAPRE". But sometimes those were counted as PREPARE, or sometimes were counted as normal SELECT. So, I was little confused... But I see it's a restrictions of current postgres's design. Best regards, -- Tatsuhito Kasahara kasahara.tatsuhito _at_ gmail.com
Hi, 2016-02-24 0:38 GMT+09:00 Tom Lane <tgl@sss.pgh.pa.us>: > What's in the query field is whatever source string the query was created > from. In the case of a prepared statement, we could potentially show > either the PREPARE or the EXECUTE, but the former was deemed much more > useful. There's no logic in there to invent a string that was never > actually submitted to the engine. Thanks for your explanation. I got it. Anyway in the real cases, I think we would not encounter those case(like my samples) so much. -- Tatsuhito Kasahara kasahara.tatsuhito _at_ gmail.com