statement logging / extended query protocol issues

Поиск
Список
Период
Сортировка
От Oliver Jowett
Тема statement logging / extended query protocol issues
Дата
Msg-id 43151749.6050002@opencloud.com
обсуждение исходный текст
Ответы Re: statement logging / extended query protocol issues  (Bruce Momjian <pgman@candle.pha.pa.us>)
Список pgsql-hackers
8.1-beta1 produces some odd results with statement logging enabled when
the extended query protocol is used (e.g. when using the JDBC driver).
Repeatedly running a simple query with log_statement = 'all' produces this:

LOG:  statement: PREPARE  AS SELECT 'dummy statement'
LOG:  statement: <BIND>
LOG:  statement: EXECUTE   [PREPARE:  SELECT 'dummy statement']
[...]
LOG:  statement: PREPARE S_2 AS SELECT 'dummy statement'
LOG:  statement: <BIND>
LOG:  statement: EXECUTE   [PREPARE:  SELECT 'dummy statement']
LOG:  statement: <BIND>
LOG:  statement: EXECUTE   [PREPARE:  SELECT 'dummy statement']
LOG:  statement: <BIND>
[...]

Comments:
- The PREPARE lines are misleading as the query actually sent does not
include PREPARE at all.
- The driver never sends EXECUTE as a statement, but it is logged as one.
- "PREPARE  AS" is a confusing way of saying "the unnamed statement"
- The <BIND> lines are content-free.

Secondly, running a query that uses portals produces output like this:

LOG:  statement: PREPARE S_3 AS SELECT * from pg_proc
LOG:  statement: <BIND> C_4
LOG:  statement: EXECUTE C_4  [PREPARE:  SELECT * from pg_proc]
LOG:  statement: EXECUTE C_4  [PREPARE:  SELECT * from pg_proc]
LOG:  statement: EXECUTE C_4  [PREPARE:  SELECT * from pg_proc]
LOG:  statement: EXECUTE C_4  [PREPARE:  SELECT * from pg_proc]
LOG:  statement: EXECUTE C_4  [PREPARE:  SELECT * from pg_proc]
LOG:  statement: EXECUTE C_4  [PREPARE:  SELECT * from pg_proc]
LOG:  statement: EXECUTE C_4  [PREPARE:  SELECT * from pg_proc]

Comments:
- The <BIND> is still fairly content-free.
- The EXECUTEs are a bit misleading as the SELECT was actually only run
once (there are multiple Execute messages for the same portal). You
could infer that there is only one SELECT from the repeated portal name
and the lack of an intervening <BIND>, I suppose.

8.1 is admittedly better than 8.0 here (8.0 had no logging in this case
at all).. but it's not very user-friendly as it stands. I'm sure the
JDBC list is going to get lots of "why does statement logging give me
this weird output" questions :/

I've attached the Java code I used to produce this. It expects a single
argument, the JDBC URL to use, e.g.
'jdbc:postgresql://localhost:8101/test?user=oliver'

-O
import java.sql.*;
import java.util.*;

public class TestStatementLogging {
    public static void main(String[] args) throws Exception {
        Class.forName("org.postgresql.Driver");

        Connection conn = DriverManager.getConnection(args[0]);
        conn.setAutoCommit(false);

        PreparedStatement stmt = conn.prepareStatement("SELECT 'dummy statement'");
        for (int j = 0; j < 10; ++j)
            stmt.executeQuery();
        stmt.close();

        stmt = conn.prepareStatement("SELECT * from pg_proc");
        stmt.setFetchSize(1);
        ResultSet rs = stmt.executeQuery();
        while (rs.next())
            ;
        stmt.close();

        conn.createStatement().execute("I am a syntax error");
    }
}

В списке pgsql-hackers по дате отправления:

Предыдущее
От: Andrew Dunstan
Дата:
Сообщение: Re: Intermittent stats test failures on buildfarm
Следующее
От: Simon Riggs
Дата:
Сообщение: Re: Pre-allocated free space for row updating