Re: Problems with extended-Query logging code - Mailing list pgsql-hackers

Tom Lane wrote:
> I happened to notice that the recently added code to log Bind-message
> parameters was printing garbage into my log.  On investigation it turned
> out to be trying to print an already-pfree'd string.  That's fixable,

Uh, can you show me where?

> but having looked at the code closely, I see a bunch of other stuff I'm
> not happy about either:
> * It's overly verbose: printing the same parameters twice seems
> excessive.

You mean printing the bind parameters on execute?  I thought we wanted
lines to be self-contained, and they can suppress the hints.

> * It's inefficient: it's spending effort on formatting and copying
> parameter information around, whether or not there's any chance of
> that information ever being wanted.

The problem there was there was no way to know what the GUC setting was
going to be by the time you did the execute, so I always stored it.  It
is possible that is excessive.

> * It doesn't log the values of parameters sent in binary mode, which
> is something that at least JDBC needs.

Right.

> Another issue, which isn't the fault of the recent patches but has been
> there right along, is that execution of Parse or Bind could take awhile
> (due to planning of a complex query) but there's no log_duration or
> log_min_duration_statement coverage for these message types.

Yea, I figured that the odds that a bind or execute would take greater
than a certain duration was very unlikely, and the overhead of computing
the timing is might be pretty large compared to the actual prepare/bind.

> Here are some thoughts about fixing it:
> 
> * For extended-Query mode I propose that we treat log_duration and
> log_min_duration_statement as being effectively per-message not
> per-statement.  That is, we'd log a Parse or Bind operation if it
> individually exceeded the duration threshold, and not otherwise.

If you think the overhead it worth it, go ahead.

> * I'm inclined to think that Parse and Bind shouldn't be logged at all,
> or maybe only at DEBUG2 or higher, unless logged by duration logging.
> If we've got support for logging the statement text and the parameter
> values at Execute time, isn't logging the preliminary steps just
> bloating the log?

Good point.  I had not thought of that.

> * I think that the best way to log bind-parameter values is to run the
> datatype output functions on the saved parameter values.  This works
> whether they were sent in text or binary mode, and avoids any extra
> overhead at Bind time that might not be repaid.

Yes, I didn't get into something that complicated, but it would be a
more complete solution.

--  Bruce Momjian   bruce@momjian.us EnterpriseDB    http://www.enterprisedb.com
 + If your life is a hard drive, Christ can be your backup. +