On Mon, May 13, 2024 at 5:51 PM Andres Freund <and...@anarazel.de> wrote: > > Hi, > > It can be very useful to look at the log messages emitted by a larger number > of postgres instances to see if anything unusual is happening. E.g. checking > whether there are an increased number of internal, IO, corruption errors (and > LOGs too, because we emit plenty bad things as LOG) . One difficulty is that > extensions tend to not categorize their errors. But unfortunately errors in > extensions are hard to distinguish from errors emitted by postgres. > > A related issue is that it'd be useful to be able to group log messages by > extension, to e.g. see which extensions are emitting disproportionally many > log messages. > > Therefore I'd like to collect the extension name in elog/ereport and add a > matching log_line_prefix escape code. >
I liked the idea ... It is very helpful for troubleshooting problems in production. > 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? > 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: ./configure --prefix=/tmp/pg ... make -j ... /usr/bin/ld: ../../src/port/libpgport_srv.a(path_srv.o): warning: relocation against `Pg_extension_filename' in read-only section `.text' /usr/bin/ld: access/brin/brin.o: in function `brininsert': /data/src/pg/main/src/backend/access/brin/brin.c:403: undefined reference to `Pg_extension_filename' /usr/bin/ld: access/brin/brin.o: in function `brinbuild': /data/src/pg/main/src/backend/access/brin/brin.c:1107: undefined reference to `Pg_extension_filename' /usr/bin/ld: access/brin/brin.o: in function `brin_summarize_range': /data/src/pg/main/src/backend/access/brin/brin.c:1383: undefined reference to `Pg_extension_filename' /usr/bin/ld: /data/src/pg/main/src/backend/access/brin/brin.c:1389: undefined reference to `Pg_extension_filename' /usr/bin/ld: /data/src/pg/main/src/backend/access/brin/brin.c:1434: undefined reference to `Pg_extension_filename' /usr/bin/ld: access/brin/brin.o:/data/src/pg/main/src/backend/access/brin/brin.c:1450: more undefined references to `Pg_extension_filename' follow /usr/bin/ld: warning: creating DT_TEXTREL in a PIE collect2: error: ld returned 1 exit status make[2]: *** [Makefile:67: postgres] Error 1 make[2]: Leaving directory '/data/src/pg/main/src/backend' make[1]: *** [Makefile:42: all-backend-recurse] Error 2 make[1]: Leaving directory '/data/src/pg/main/src' make: *** [GNUmakefile:11: all-src-recurse] Error 2 > 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. Regards, -- Fabrízio de Royes Mello