Re: log bind parameter values on error

From: Alvaro Herrera <alvherre(at)2ndquadrant(dot)com>
To: Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us>
Cc: Andres Freund <andres(at)anarazel(dot)de>, Alexey Bashtanov <bashtanov(at)imap(dot)cc>, Peter Eisentraut <peter(dot)eisentraut(at)2ndquadrant(dot)com>, PostgreSQL Hackers <pgsql-hackers(at)postgresql(dot)org>
Subject: Re: log bind parameter values on error
Date: 2019-12-06 17:57:19
Message-ID: 20191206175719.GA15456@alvherre.pgsql
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: 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

Attachment Content-Type Size
errcontext.patch text/x-diff 3.7 KB

In response to

Responses

Browse pgsql-hackers by date

  From Date Subject
Next Message Pavel Stehule 2019-12-06 18:13:05 Re: log bind parameter values on error
Previous Message Joe Nelson 2019-12-06 17:43:58 Re: Change atoi to strtol in same place