Re: log bind parameter values on error

Hi,

On 2019-11-05 12:07:50 +0000, Alexey Bashtanov wrote:
> > 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).
>
> I'm a bit worried about going this way, as it makes us log
> the query and its parameters too far apart in the code,
> and it's trickier to make sure we never log parameters without the query.

The way you do it you need to do it in numerous places, and I'm pretty
sure you're missing some already. E.g. this will not work to log
parameters for parametrized statements generated on the server side,
e.g. for foreign key queries. I don't think that's the right direction
to go. You can maybe argue that we don't need support for logging server
side generated parameters in the initial version, but the approach
should be compatible with adding that support.

> I think logging the parameters should not be part of error_context_stack,
> but rather a primary part of logging facility itself, like statement.
> That's because whether we want to log parameters depends
> on print_stmt in elog.c. With print_stmt being computed upon edata,
> I'm not sure how to work it out nicely.

I don't think those really are contradictions. You can continue to have
an errdetail_params(), and but call it from the error context callback
set up in the portal code.

That'd also get rid of the two different copies of the logic for
deciding whether to log bind parameters. Right now your approach
e.g. doesn't work for emit_log_hook. Nor is all that clear to me that
we'd never want to send this information to the client.

Even leaving that aside, I'm *STRONGLY* against entangling elog.c with
query execution details like ParamListInfo. We should work to make
elog.c know less about different parts of the system, not more.

> > 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.

> We handle it the same way as we do it for debug_query_string itself:
>
>         if (in_error_recursion_trouble())
>         {
>             error_context_stack = NULL;
>             debug_query_string = NULL;
>             current_top_portal = NULL;
>         }
>

Sorry, had missed that, it wasn't apparent in the diff. I personally
just always use a larger context size to make it easier to recognize...

Greetings,

Andres Freund