Thread: Log files cluttered with jdbc3/4 for pg8.2
I was nagging couple of months earlier about postgres not logging
function parameteres. Now we're planing on switching to pg8.2, so I'm
doing some tests to see how it all works.
I'm using postgres 8.2.4 with postgresql-8.2-505.jdbc3. I'm calling a
simple function from Java, here is the Java code:
CallableStatement cs = conn.prepareCall("{? = call f1(ROW(?,?))}");
cs.registerOutParameter(1, Types.INTEGER);
cs.setInt(2,2);
cs.setInt(3,3);
cs.execute();
Now, this is how the postgres log file looks like:
2007-06-20 11:26:11.870 CEST [3990] <> DEBUG: forked new backend,
pid=12137 socket=6
2007-06-20 11:26:11.935 CEST [12137] <test1> PARSE DEBUG: parse
<unnamed>: select * from f1($1,ROW($2,$3)) as result
2007-06-20 11:26:11.936 CEST [12137] <test1> PARSE LOG: duration: 0.928
ms parse <unnamed>: select * from f1($1,ROW($2,$3)) as result
2007-06-20 11:26:11.936 CEST [12137] <test1> PARSE DEBUG: bind
<unnamed> to <unnamed>
2007-06-20 11:26:11.936 CEST [12137] <test1> BIND LOG: duration: 0.171
ms bind <unnamed>: select * from f1($1,ROW($2,$3)) as result
2007-06-20 11:26:11.936 CEST [12137] <test1> BIND DETAIL: parameters:
$1 = '', $2 = '2', $3 = '3'
2007-06-20 11:26:11.936 CEST [12137] <test1> SELECT LOG: duration:
0.036 ms execute <unnamed>: select * from f1($1,ROW($2,$3)) as result
2007-06-20 11:26:11.936 CEST [12137] <test1> SELECT DETAIL: parameters:
$1 = '', $2 = '2', $3 = '3'
2007-06-20 11:26:12.057 CEST [12137] <test1> idle LOG: unexpected EOF
on client connection
2007-06-20 11:26:12.058 CEST [3990] <> DEBUG: server process (PID
12137) exited with exit code 0
I finaly see the actuall parametars the function was called with, but, I
have too much lines for a simple SELECT. Is there a way to turn off
PARSE/BIND log entries, so I can have just the SELECTs? I tried tweaking
postgresql.conf, everything I do produces no changes?
The same happens with JDBC driver for pg8.1. If I use JDBC driver for
pg7.4 then I have 'normal' log (presumeably because I don't have
prepared statements from within JDBC driver for 7.4).
And, if someone knows, why is it that I have SELECT LOG and SELECT
DETAIL entry?
Mario
Mario Splivalo <mario.splivalo@mobart.hr> writes:
> I finaly see the actuall parametars the function was called with, but, I
> have too much lines for a simple SELECT.
Well, if you set log_min_messages to DEBUG, as you evidently have,
you're going to get a pretty chatty log. You might want to rethink
your log_duration threshold as well.
regards, tom lane
On Wed, 2007-06-20 at 11:16 -0400, Tom Lane wrote:
> Mario Splivalo <mario.splivalo@mobart.hr> writes:
> > I finaly see the actuall parametars the function was called with, but, I
> > have too much lines for a simple SELECT.
>
> Well, if you set log_min_messages to DEBUG, as you evidently have,
> you're going to get a pretty chatty log. You might want to rethink
> your log_duration threshold as well.
Yes, I have log_min_messages to DEBUG, but if I set it to INFO, NOTICE,
WARNING or ERROR I still have PARSE LOG, BIND LOG/BIND DETAIL entries. I
haven't been able to found what exactley they are, and I'd realy like to
not have them in my log files.
I need to have log_duration at 0 so I log EVERY call from the jdbc to
the postgresql because that's excellent way of debuging the dataflow
from the middle-tier to the application.
I guess I'll be using pg7.4 JDBC driver for development, and use 8.2
JDBC in production (there I have log_duration set to around 600).
Could anyone point me on what exactly PARSE LOG and BIND LOG entries
are?
Mario
Mario Splivalo <mario.splivalo@mobart.hr> writes: > On Wed, 2007-06-20 at 11:16 -0400, Tom Lane wrote: >> Well, if you set log_min_messages to DEBUG, as you evidently have, >> you're going to get a pretty chatty log. You might want to rethink >> your log_duration threshold as well. > Yes, I have log_min_messages to DEBUG, but if I set it to INFO, NOTICE, > WARNING or ERROR I still have PARSE LOG, BIND LOG/BIND DETAIL entries. I > haven't been able to found what exactley they are, and I'd realy like to > not have them in my log files. They're real actions, they take a finite amount of time, and if you've got log_duration unconditionally enabled then they're going to be logged so that the system can report its CPU use. > I need to have log_duration at 0 so I log EVERY call from the jdbc to > the postgresql because that's excellent way of debuging the dataflow > from the middle-tier to the application. That is a job for log_statement not log_duration. > Could anyone point me on what exactly PARSE LOG and BIND LOG entries > are? http://www.postgresql.org/docs/8.2/static/protocol-flow.html#PROTOCOL-FLOW-EXT-QUERY regards, tom lane
"Mario Splivalo" <mario.splivalo@mobart.hr> writes: > Yes, I have log_min_messages to DEBUG, but if I set it to INFO, NOTICE, > WARNING or ERROR I still have PARSE LOG, BIND LOG/BIND DETAIL entries. I > haven't been able to found what exactley they are, and I'd realy like to > not have them in my log files. > > I need to have log_duration at 0 so I log EVERY call from the jdbc to > the postgresql because that's excellent way of debuging the dataflow > from the middle-tier to the application. > > I guess I'll be using pg7.4 JDBC driver for development, and use 8.2 > JDBC in production (there I have log_duration set to around 600). > > Could anyone point me on what exactly PARSE LOG and BIND LOG entries > are? Uhm, they are "every call from the jdbc to the postgresql". -- Gregory Stark EnterpriseDB http://www.enterprisedb.com
On Fri, 2007-06-22 at 10:00 -0400, Tom Lane wrote:
> > I need to have log_duration at 0 so I log EVERY call from the jdbc to
> > the postgresql because that's excellent way of debuging the dataflow
> > from the middle-tier to the application.
>
> That is a job for log_statement not log_duration.
Thnx, that makes sense now :) I guess I overlooked log_statement for
some reason in pg8.0.
Altough I'd like to see this:
SELECT LOG: execute <unnamed>: select * from ad_get('104', '2007-07-02
14:36:57.361+02', '109')
instead of
SELECT LOG: execute <unnamed>: select * from ad_get($1, $2, $3) as
result
SELECT DETAIL: parameters: $1 = '104', $2 = '2007-07-02 14:36:57.361
+02', $3 = '109'
Yes, I know, prepared statements, but still..
Mario