Thread: Extended protocol logging
These are logs from Beta 2. Did I miss a discussion where we removed the name of the portal during parse, and bind ? 5715%2006-11-01 01:02:26.631 PST%454862a0.1653%SELECT LOG: execute S_2: select t0.c_id, t0.c_contact, t0.c_credit_limit, t0.c_state, t0.c_zip, t0.c_phone, t0.c_credit, t0.c_since, t0.c_ytd_payment, t0.c_street1, t0.c_balance, t0.c_first, t0.c_last, t0.c_street2, t0.c_country, t0.c_city from c_customer t0 where t0.c_id = $1 for update 5715%2006-11-01 01:02:26.631 PST%454862a0.1653%SELECT DETAIL: parameters: $1 = '44381' 5719%2006-11-01 01:02:28.459 PST%454862a0.1657%SELECT LOG: duration: 4.365 ms 5719%2006-11-01 01:02:28.463 PST%454862a0.1657%PARSE LOG: duration: 0.672 ms 5719%2006-11-01 01:02:28.464 PST%454862a0.1657%BIND LOG: duration: 0.128 ms Dave
Dave Cramer <pg@fastcrypt.com> writes:
> These are logs from Beta 2.
With what logging settings? log_duration has rather different behavior
from what it used to do.
regards, tom lane
On Tue, 2006-10-31 at 23:51 -0500, Tom Lane wrote: > Dave Cramer <pg@fastcrypt.com> writes: > > These are logs from Beta 2. > > With what logging settings? log_duration has rather different behavior > from what it used to do. I think it would be useful to have the log results from a test program in the protocol section, so interface designers know what will get logged from various protocol sequences. That way JDBC people and others can interpret what their own interfaces should look like for 8.2 -- Simon Riggs EnterpriseDB http://www.enterprisedb.com
On 31-Oct-06, at 11:51 PM, Tom Lane wrote: > Dave Cramer <pg@fastcrypt.com> writes: >> These are logs from Beta 2. > > With what logging settings? log_duration has rather different > behavior > from what it used to do. to be honest I don't know, and looking at the logs I suspect that this is just logging duration, however it's still looking pretty ambiguous. ( I will get the settings, my client is on the other side of the world) what exactly does it mean ? The total operation was 4.365ms and the parse was .672 and bind was .128? Is it possible for different connections to be interleaved? I still think having the parse, bind,execute show the statement name makes sense if for no other reason than clarity. I would think writing a log parser would be fairly challenging without them. Dave > > regards, tom lane > > ---------------------------(end of > broadcast)--------------------------- > TIP 2: Don't 'kill -9' the postmaster >
On 1-Nov-06, at 6:18 AM, Simon Riggs wrote: > On Tue, 2006-10-31 at 23:51 -0500, Tom Lane wrote: >> Dave Cramer <pg@fastcrypt.com> writes: >>> These are logs from Beta 2. >> >> With what logging settings? log_duration has rather different >> behavior >> from what it used to do. > > I think it would be useful to have the log results from a test program > in the protocol section, so interface designers know what will get > logged from various protocol sequences. I think some sort of examples are in order, or more consistency. > > That way JDBC people and others can interpret what their own > interfaces > should look like for 8.2 from a JDBC point of view we don't look at the logs in the API. I am just debugging something > > -- > Simon Riggs > EnterpriseDB http://www.enterprisedb.com > > >
On Wed, 2006-11-01 at 10:06 -0500, Tom Lane wrote: > "Simon Riggs" <simon@2ndquadrant.com> writes: > > On Tue, 2006-10-31 at 23:51 -0500, Tom Lane wrote: > >> With what logging settings? log_duration has rather different behavior > >> from what it used to do. > > > I think it would be useful to have the log results from a test program > > in the protocol section, > > The contents of the postmaster log are surely not part of the FE protocol. > Clients can't even see the log without resorting to nonstandard hacks. OK, can we please put the example from -hackers into the docs, somewhere, with particular note of which protocol messages result in which logging output? -- Simon Riggs EnterpriseDB http://www.enterprisedb.com
"Simon Riggs" <simon@2ndquadrant.com> writes: > On Tue, 2006-10-31 at 23:51 -0500, Tom Lane wrote: >> With what logging settings? log_duration has rather different behavior >> from what it used to do. > I think it would be useful to have the log results from a test program > in the protocol section, The contents of the postmaster log are surely not part of the FE protocol. Clients can't even see the log without resorting to nonstandard hacks. What it sounds like to me is that Dave's client has got log_duration = ON when what he should have is log_min_duration_statement = 0. Those two settings used to be just about redundant but as of 8.2 they have got distinct functionality. See this thread: http://archives.postgresql.org/pgsql-hackers/2006-09/msg00681.php regards, tom lane