Thread: log_statement and PREPARE
The docs (8.1) say the following about log_statement: -- snip -- ... mod logs all ddl statements, plus INSERT, UPDATE, DELETE, TRUNCATE, and COPY FROM. PREPARE and EXPLAIN ANALYZE statements are also logged if their contained command is of an appropriate type. -- snip -- Can someone please expain the meaning of, "if their contained command is of an appropriate type"? I take it to mean that the prepared statement will be logged if the it contains an INSERT (if 'mod' was chosen, of course). I ask because i've set log_statement to 'mod' but am not seeing any of my prepared statements in the log. INSERT, UPDATE, and friends i do see. FWIW, the app is PHP using MDB2. But checking its source doesn't give me any reason to believe the issue lies there. Shouldn't i see these PREPAREs? brian
brian <brian@zijn-digital.com> writes:
> The docs (8.1) say the following about log_statement:
> -- snip --
> ... mod logs all ddl statements, plus INSERT, UPDATE, DELETE, TRUNCATE,
> and COPY FROM. PREPARE and EXPLAIN ANALYZE statements are also logged if
> their contained command is of an appropriate type.
> -- snip --
> Can someone please expain the meaning of, "if their contained command is
> of an appropriate type"? I take it to mean that the prepared statement
> will be logged if the it contains an INSERT (if 'mod' was chosen, of
> course).
I think you mis-parsed it. The sentence about PREPARE et al is an
independent sentence applying to all the possible values of
log_statement. That is, these commands will be logged if the contained
command is one that would have been logged, at the current log level.
> I ask because i've set log_statement to 'mod' but am not seeing any of
> my prepared statements in the log. INSERT, UPDATE, and friends i do see.
Ah. Probably you are confusing PREPARE-the-SQL-command, which is what
this is speaking of, with the protocol-level prepared-statement
functionality. 8.1 is pretty bad about logging extended-query-protocol
operations. If you can update to 8.2 you'll be happier.
regards, tom lane
Tom Lane wrote: > brian <brian@zijn-digital.com> writes: > >> The docs (8.1) say the following about log_statement: -- snip -- >> ... mod logs all ddl statements, plus INSERT, UPDATE, DELETE, >> TRUNCATE, and COPY FROM. PREPARE and EXPLAIN ANALYZE statements are >> also logged if their contained command is of an appropriate type. >> -- snip -- > >> Can someone please expain the meaning of, "if their contained >> command is of an appropriate type"? I take it to mean that the >> prepared statement will be logged if the it contains an INSERT (if >> 'mod' was chosen, of course). > > I think you mis-parsed it. The sentence about PREPARE et al is an > independent sentence applying to all the possible values of > log_statement. That is, these commands will be logged if the > contained command is one that would have been logged, at the current > log level. > But that should mean that my prepared statement that contains an INSERT should be logged, yes? (8.1 issues notwithstanding) >> I ask because i've set log_statement to 'mod' but am not seeing any >> of my prepared statements in the log. INSERT, UPDATE, and friends i >> do see. > > Ah. Probably you are confusing PREPARE-the-SQL-command, which is > what this is speaking of, with the protocol-level prepared-statement > functionality. I'd thought i wasn't confusing the two. For instance, the MDB2 source reveals the following in prepare(): $query = 'PREPARE '.$statement_name.$types_string.' AS '.$query; $statement =& $this->_doQuery($query, true, $connection); So, i do seem to be dealing, in the end, with PREPARE-the-SQL-command here. > 8.1 is pretty bad about logging extended-query-protocol > operations. If you can update to 8.2 you'll be happier. I have been trying to find the time to move up to 8.2 lately. Perhaps this evening is as good a time as any to do that on the dev box. Thanks for your time. brian
brian <brian@zijn-digital.com> writes:
> But that should mean that my prepared statement that contains an INSERT
> should be logged, yes? (8.1 issues notwithstanding)
> I ask because i've set log_statement to 'mod' but am not seeing any
> of my prepared statements in the log. INSERT, UPDATE, and friends i
> do see.
Hm, works for me:
regression=# create temp table fooey(f1 int);
CREATE TABLE
regression=# prepare foo(int) as insert into fooey values($1);
PREPARE
regression=# execute foo(42);
INSERT 0 1
regression=# show log_statement;
log_statement
---------------
mod
(1 row)
in log:
LOG: statement: create temp table fooey(f1 int);
LOG: statement: prepare foo(int) as insert into fooey values($1);
The same sequence in 8.2 logs:
LOG: statement: create temp table fooey(f1 int);
LOG: statement: prepare foo(int) as insert into fooey values($1);
LOG: statement: execute foo(42);
DETAIL: prepare: prepare foo(int) as insert into fooey values($1);
If what you were looking for was that the *execute* gets logged
dependent on what the prepared statement was, then you need 8.2.
All that stuff got rewritten pretty heavily for 8.2 ...
regards, tom lane
Tom Lane wrote: > brian <brian@zijn-digital.com> writes: > >>But that should mean that my prepared statement that contains an INSERT >>should be logged, yes? (8.1 issues notwithstanding) >>I ask because i've set log_statement to 'mod' but am not seeing any >>of my prepared statements in the log. INSERT, UPDATE, and friends i >>do see. > > > Hm, works for me: > > regression=# create temp table fooey(f1 int); > CREATE TABLE > regression=# prepare foo(int) as insert into fooey values($1); > PREPARE > regression=# execute foo(42); > INSERT 0 1 > regression=# show log_statement; > log_statement > --------------- > mod > (1 row) > > in log: > > LOG: statement: create temp table fooey(f1 int); > LOG: statement: prepare foo(int) as insert into fooey values($1); > > The same sequence in 8.2 logs: > > LOG: statement: create temp table fooey(f1 int); > LOG: statement: prepare foo(int) as insert into fooey values($1); > LOG: statement: execute foo(42); > DETAIL: prepare: prepare foo(int) as insert into fooey values($1); OK, maybe i *am* confused about PREPARE. The PEAR MDB2 source is doing: $query = 'PREPARE '.$statement_name.$types_string.' AS '.$query; which becomes something like: PREPARE mdb2_statement_pgsqla0e8d35156e904f9581ac790eb917b98 AS ... So i think i see your point. The "mdb2_statement_pgsql ... " string identifier is what is then passed along with my data to Pg when executed. So, quite different than "EXECUTE foo(42)". And this sort of thing is not logged? Even in 8.2? On the chance that there really is something amiss, i'll continue ... I know that the change to postgresql.conf has been recognised because i've been seeing the regular queries logged since changing log_statement. The only hint of a prepared statement being logged is when there's an error. eg: <2007-09-05 17:35:22 EDT>ERROR: duplicate key violates unique constraint "auth_member_id_key" <2007-09-05 17:35:22 EDT>STATEMENT: EXECUTE mdb2_statement_pgsqla0e8d35156e904f9581ac790eb917b98 (A_HASH_HERE, 5271) Otherwise, nothing but INSERT, UPDATE, etc. I'm using 8.1.4, btw. I'll take this over to the PEAR list. > If what you were looking for was that the *execute* gets logged > dependent on what the prepared statement was, then you need 8.2. > All that stuff got rewritten pretty heavily for 8.2 ... Yeah, i'll upgrade and check that out. Thanks again. brian
brian <brian@zijn-digital.com> writes:
> The only hint of a prepared statement being logged is when there's an
> error. eg:
> <2007-09-05 17:35:22 EDT>ERROR: duplicate key violates unique
> constraint "auth_member_id_key"
> <2007-09-05 17:35:22 EDT>STATEMENT: EXECUTE
> mdb2_statement_pgsqla0e8d35156e904f9581ac790eb917b98 (A_HASH_HERE, 5271)
That looks like an EXECUTE to me. If you want EXECUTEs to be logged
conditionally based on what they are executing, you need 8.2.
regards, tom lane
Tom Lane wrote: > brian <brian@zijn-digital.com> writes: > >>The only hint of a prepared statement being logged is when there's an >>error. eg: > > >><2007-09-05 17:35:22 EDT>ERROR: duplicate key violates unique >>constraint "auth_member_id_key" >><2007-09-05 17:35:22 EDT>STATEMENT: EXECUTE >>mdb2_statement_pgsqla0e8d35156e904f9581ac790eb917b98 (A_HASH_HERE, 5271) > > > That looks like an EXECUTE to me. If you want EXECUTEs to be logged > conditionally based on what they are executing, you need 8.2. > That was understood. What i meant is that the only time i see anything *related to* the prepared statement i think should be there is when the EXECUTE fails for some reason because the context of the error is logged. That particular EXECUTE was preceeded by a PREPARE that was not logged. It was my understanding that the PREPARE would be logged. In any case, i'll upgrade soonest. I keep reading here about all the 8.2 goodness. brian
brian <brian@zijn-digital.com> writes:
> That was understood. What i meant is that the only time i see anything
> *related to* the prepared statement i think should be there is when the
> EXECUTE fails for some reason because the context of the error is
> logged. That particular EXECUTE was preceeded by a PREPARE that was not
> logged. It was my understanding that the PREPARE would be logged.
[ squint... ] It got logged when I tried it. But I was testing 8.1
branch tip (or close to it -- post-8.1.9 for sure). I think you said
you were on 8.1.2? There could well have been some related bug fixes
in that branch, but I'm too lazy to check the release notes right now.
> In any case, i'll upgrade soonest. I keep reading here about all the 8.2
> goodness.
If you can update to 8.2 without too much pain, I'd sure recommend that.
But if you run into compatibility problems, it seems that 8.1.9 might
perhaps help too.
regards, tom lane
Tom Lane wrote: > brian <brian@zijn-digital.com> writes: > >>That was understood. What i meant is that the only time i see anything >>*related to* the prepared statement i think should be there is when the >>EXECUTE fails for some reason because the context of the error is >>logged. That particular EXECUTE was preceeded by a PREPARE that was not >>logged. It was my understanding that the PREPARE would be logged. > > > [ squint... ] It got logged when I tried it. But I was testing 8.1 > branch tip (or close to it -- post-8.1.9 for sure). I think you said > you were on 8.1.2? There could well have been some related bug fixes > in that branch, but I'm too lazy to check the release notes right now. > > >>In any case, i'll upgrade soonest. I keep reading here about all the 8.2 >>goodness. > > > If you can update to 8.2 without too much pain, I'd sure recommend that. > But if you run into compatibility problems, it seems that 8.1.9 might > perhaps help too. > I'm with 8.1.4 now. No big deal, though; this was all because i was trying to debug something and wanted to see the PREPARE come in for a bit. But i've already resolved the initial bug in my app. I was just wondering if i was reading the docs correctly. I'll upgrade. b