Re: log bind parameter values on error - Mailing list pgsql-hackers

On 2019-Dec-05, Tom Lane wrote:

> Possibly a workable compromise is to emit the info as an error
> context line, appending it to whatever context exists today.
> The result might look like, say,
>
> ERROR:  whatever
> CONTEXT: SQL function "foo"
> extended query with parameters x, y, ...

This is easy to accomodate -- just change the errdetail() to errcontext.
That makes the params be reported different than in the non-error case
(for duration).

> For extra credit maybe we could include the query's statement or
> portal name?
>
>       errcontext("extended query \"%s\" with parameters %s", ...);

Sure.  Done in the attached.

> An independent point: it seems like just wishful thinking to imagine that
> src/test/examples/ can serve as a regression test for this.  Nor is the
> proposed program very useful as an example.  I'd drop that and find a
> way to have an actual, routinely-exercised-by-check-world regression
> test.  If memory serves, pgbench can be cajoled into executing stuff
> in extended query mode --- maybe we could create a test case using
> that?

I tried

pgbench -c1 -t1 -n -M prepared -f errparameters.bnch
with this file

  select '{ invalid ' as value \gset
  select column1::jsonb from (values (:value)) as q;

and got these lines:

2019-12-06 13:49:36.388 -03 [31028] ERROR:  invalid input syntax for type json
2019-12-06 13:49:36.388 -03 [31028] DETAIL:  Token "invalid" is invalid.
2019-12-06 13:49:36.388 -03 [31028] CONTEXT:  JSON data, line 1: { invalid...
        extended query with parameters: $1 = '{ invalid '
2019-12-06 13:49:36.388 -03 [31028] STATEMENT:  select column1::jsonb from (values ($1)) as q;

With this file,
  select '1' as one \gset
  SELECT 1 / (random() / 2)::int, :one::int, :two::int;

using the same pgbench invocation as above, I get this in the log:

2019-12-06 14:50:59.181 -03 [6187] ERROR:  division by zero
2019-12-06 14:50:59.181 -03 [6187] CONTEXT:  extended query with parameters: $1 = '1', $2 = NULL
2019-12-06 14:50:59.181 -03 [6187] STATEMENT:  SELECT 1 / (random() / 2)::int, $1::int, $2::int;

(While testing this I noticed that failing to strdup the text repr of
the datum when it's given as a text-format parameter results in bogus
output.  So I added a pstrdup there.)

(It seems a bit weird that if I assign NULL to :two pgbench stores the
empty string, instead of the NULL that I get as in the above which is
what happens when the variable is not defined at all.  That's probably a
bug in \gset ...)

--
Álvaro Herrera                https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services