Re: Adding the extension name to EData / log_line_prefix

Hi,

On 2024-05-13 19:25:11 -0300, Fabrízio de Royes Mello wrote:
> On Mon, May 13, 2024 at 5:51 PM Andres Freund <andres(at)anarazel(dot)de> wrote:
> > It's not entirely trivial to provide errfinish() with a parameter
> indicating
> > the extension, but it's doable:
> >
> > 1) Have PG_MODULE_MAGIC also define a new variable for the extension name,
> > empty at that point
> >
> > 2) In internal_load_library(), look up that new variable, and fill it
> with a,
> > mangled, libname.
> >
> > 4) in elog.h, define a new macro depending on BUILDING_DLL (if it is set,
> > we're in the server, otherwise an extension). In the backend itself,
> define
> > it to NULL, otherwise to the variable created by PG_MODULE_MAGIC.
> >
> > 5) In elog/ereport/errsave/... pass this new variable to
> > errfinish/errsave_finish.
> >
>
> Then every extension should define their own Pg_extension_filename, right?

It'd be automatically set by postgres when loading libraries.

> > I've attached a *very rough* prototype of this idea. My goal at this
> stage was
> > just to show that it's possible, not for the code to be in a reviewable
> state.
> >
> >
> > Here's e.g. what this produces with log_line_prefix='%m [%E] '
> >
> > 2024-05-13 13:50:17.518 PDT [postgres] LOG: database system is ready to
> accept connections
> > 2024-05-13 13:50:19.138 PDT [cube] ERROR: invalid input syntax for cube
> at character 13
> > 2024-05-13 13:50:19.138 PDT [cube] DETAIL: syntax error at or near "f"
> > 2024-05-13 13:50:19.138 PDT [cube] STATEMENT: SELECT cube('foo');
> >
> > 2024-05-13 13:43:07.484 PDT [postgres] LOG: database system is ready to
> accept connections
> > 2024-05-13 13:43:11.699 PDT [hstore] ERROR: syntax error in hstore:
> unexpected end of string at character 15
> > 2024-05-13 13:43:11.699 PDT [hstore] STATEMENT: SELECT hstore('foo');
> >
> >
>
> Was not able to build your patch by simply:

Oh, turns out it only builds with meson right now. I forgot that, with
autoconf, for some unknown reason, we only set BUILDING_DLL on some OSs.

I attached a crude patch changing that.

> > It's worth pointing out that this, quite fundamentally, can only work
> when the
> > log message is triggered directly by the extension. If the extension code
> > calls some postgres function and that function then errors out, it'll be
> seens
> > as being part of postgres.
> >
> > But I think that's ok - they're going to be properly errcode-ified etc.
> >
>
> Hmmm, depending on the extension it can extensively call/use postgres code
> so would be nice if we can differentiate if the code is called from
> Postgres itself or from an extension.

I think that's not realistically possible. It's also very fuzzy what that'd
mean. If there's a planner hook and then the query executes normally, what do
you report for an execution time error? And even the simpler case - should use
of pg_stat_statements cause everything within to be logged as a
pg_stat_statement message?

I think the best we can do is to actually say where the error is directly
triggered from.

Greetings,

Andres Freund