From: | Oliver Jowett <oliver(at)opencloud(dot)com> |
---|---|
To: | pgsql-hackers <pgsql-hackers(at)postgresql(dot)org> |
Subject: | statement logging / extended query protocol issues |
Date: | 2005-08-31 02:34:49 |
Message-ID: | 43151749.6050002@opencloud.com |
Views: | Raw Message | Whole Thread | Download mbox | Resend email |
Thread: | |
Lists: | pgsql-hackers pgsql-patches |
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
Attachment | Content-Type | Size |
---|---|---|
TestStatementLogging.java | text/plain | 743 bytes |
From | Date | Subject | |
---|---|---|---|
Next Message | Simon Riggs | 2005-08-31 06:41:13 | Re: Pre-allocated free space for row updating |
Previous Message | Andrew Dunstan | 2005-08-31 00:35:44 | Re: Intermittent stats test failures on buildfarm |
From | Date | Subject | |
---|---|---|---|
Next Message | Marc G. Fournier | 2005-08-31 02:36:51 | Re: [BUGS] PSQL commands not backwards-compatible |
Previous Message | Bruce Momjian | 2005-08-31 02:20:07 | Re: [BUGS] PSQL commands not backwards-compatible |