Re: log bind parameter values on error

Hi,

On 2019-09-20 16:56:57 -0300, Alvaro Herrera wrote:
> > > +/*
> > > + * The top-level portal that the client is immediately working with:
> > > + * creating, binding, executing, or all at one using simple protocol
> > > + */
> > > +Portal current_top_portal = NULL;
> > > +
> >
> > This strikes me as decidedly not nice. For one this means that we'll not
> > be able to use this infrastructure for binds that are done serverside,
> > e.g. as part of plpgsql. I'm basically inclined to think that
> > integrating this at the postges.c level is the wrong thing.
> [...]
> > It seems to me that this would really need to be tracked inside the
> > portal infrastructure.
>
> I think that's how this was done at first, then Peter E drove him away
> from that into the current design.

I don't think it really was the way I am suggesting. There were a bunch
of helper functions managing current_top_portal, but it otherwise is
(and afaict was in all versions) still all postgres.c
controlled. Whereas I think it should be nearly exclusively be handled
by pquery.c, with the possible exception of an efficiency hack to reuse
client input string when they're in text format.

What I'm suggesting is that PortalStart() would build a string
representation out of the parameter list (using
ParamExternData.textValue if set, calling the output function
otherwise), and stash that in the portal.

At the start of all the already existing PG_TRY blocks in pquery.c we
push an element onto the error_context_stack that adds the errdetail
with the parameters to the error. Alternatively we could also add them
in in the PG_CATCH blocks, but that'd only work for elevel == ERROR
(i.e. neither FATAL nor non throwing log levels would be able to enrich
the error).

Thinking about this: I think the current approach doesn't actually
handle recursive errors correctly. Even if we fail to emit the error
message due to the parameter details requiring a lot of memory, we'd
again do so (and again fail) when handling that OOM error, because
current_top_portal afaict would still be set. At the very least this'd
need to integrate with the recursion_depth logic in elog.c.

> > > + appendStringInfoCharMacro(&param_str, '\'');
> > > + for (p = pstring; *p; p++)
> > > + {
> > > + if (*p == '\'') /* double single quotes */
> > > + appendStringInfoCharMacro(&param_str, *p);
> > > + appendStringInfoCharMacro(&param_str, *p);
> > > + }
> > > + appendStringInfoCharMacro(&param_str, '\'');
> >
> > I know this is old code, but: This is really inefficient. Will cause a
> > lot of unnecessary memory-reallocations for large text outputs, because
> > we don't immediately grow to at least close to the required size.
>
> Agreed, but we can't blame a patch because it moves around some old
> crufty code. If Alexey wants to include another patch to change this to
> a better formulation, I'm happy to push that before or after his main
> patch. And if he doesn't want to, that's fine with me too.

Well, this patch makes it potentially a considerably hotter path, so I
think there's some justification for pushing a bit. But I'd not require
it either.

As I said, I think we cannot generate this string at error time, because
it makes it much much more likely to exhaust the error context - a bad
thing.

> (Is doing a strlen first to enlarge the stringinfo an overall better
> approach?)

Yes, it'd be better.

> (I wonder if it would make sense to strchr each ' and memcpy the
> intervening bytes ... if only that didn't break the SI abstraction
> completely ...)

I'd probably just count the ' in one pass, enlarge the stringinfo to the
required size, and then put the string directly into he stringbuffer.
Possibly just putting the necessary code into stringinfo.c. We already
have multiple copies of this inefficient logic...

But even if not, I don't think writing data into the stringbuf directly
is that ugly, we do that in enough places that I'd argue that that's
basically part of how it's expected to be used.

In HEAD there's at least
- postgres.c:errdetail_params(),
- pl_exec.c:format_preparedparamsdata()
pl_exec.c:format_expr_params()
and
- dblink.c:escape_param_str()
- deparse.c:deparseStringLiteral()
- xlog.c:do_pg_start_backup() (after "Add the escape character"),
- tsearchcmds.c:serialize_deflist()
- ruleutils.c:simple_quote_literal()

are nearly the same.

Greetings,

Andres Freund