Adding the extension name to EData / log_line_prefix

Started by Andres Freundover 1 year ago15 messages

andres@anarazel.de

over 1 year ago

1 attachment(s)

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.

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.

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');

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.

Thoughts?

Greetings,

Andres Freund

Attachments:

v1-0001-WIP-Track-shared-library-in-which-elog-ereport-is.patchtext/x-diff; charset=us-asciiDownload

From 1c59c465f2d359e8c47cf91d1ea458ea3b64ec84 Mon Sep 17 00:00:00 2001
From: Andres Freund <andres@anarazel.de>
Date: Mon, 13 May 2024 13:47:41 -0700
Subject: [PATCH v1] WIP: Track shared library in which elog/ereport is called

---
 src/include/fmgr.h             |  1 +
 src/include/utils/elog.h       | 18 +++++++++++++-----
 src/backend/utils/error/elog.c | 33 ++++++++++++++++++++++++---------
 src/backend/utils/fmgr/dfmgr.c | 30 ++++++++++++++++++++++++++++++
 4 files changed, 68 insertions(+), 14 deletions(-)

diff --git a/src/include/fmgr.h b/src/include/fmgr.h
index ccb4070a251..3c7cfd7fee9 100644
--- a/src/include/fmgr.h
+++ b/src/include/fmgr.h
@@ -504,6 +504,7 @@ PG_MAGIC_FUNCTION_NAME(void) \
 	static const Pg_magic_struct Pg_magic_data = PG_MODULE_MAGIC_DATA; \
 	return &Pg_magic_data; \
 } \
+PGDLLEXPORT const char *Pg_extension_filename = NULL; \
 extern int no_such_variable
 
 
diff --git a/src/include/utils/elog.h b/src/include/utils/elog.h
index 054dd2bf62f..5e57f01823d 100644
--- a/src/include/utils/elog.h
+++ b/src/include/utils/elog.h
@@ -137,6 +137,13 @@ struct Node;
  * prevents gcc from making the unreachability deduction at optlevel -O0.
  *----------
  */
+#ifdef BUILDING_DLL
+#define ELOG_EXTNAME NULL
+#else
+extern PGDLLEXPORT const char *Pg_extension_filename;
+#define ELOG_EXTNAME Pg_extension_filename
+#endif
+
 #ifdef HAVE__BUILTIN_CONSTANT_P
 #define ereport_domain(elevel, domain, ...)	\
 	do { \
@@ -144,7 +151,7 @@ struct Node;
 		if (__builtin_constant_p(elevel) && (elevel) >= ERROR ? \
 			errstart_cold(elevel, domain) : \
 			errstart(elevel, domain)) \
-			__VA_ARGS__, errfinish(__FILE__, __LINE__, __func__); \
+			__VA_ARGS__, errfinish(__FILE__, __LINE__, __func__, ELOG_EXTNAME); \
 		if (__builtin_constant_p(elevel) && (elevel) >= ERROR) \
 			pg_unreachable(); \
 	} while(0)
@@ -154,7 +161,7 @@ struct Node;
 		const int elevel_ = (elevel); \
 		pg_prevent_errno_in_scope(); \
 		if (errstart(elevel_, domain)) \
-			__VA_ARGS__, errfinish(__FILE__, __LINE__, __func__); \
+			__VA_ARGS__, errfinish(__FILE__, __LINE__, __func__, ELOG_EXTNAME); \
 		if (elevel_ >= ERROR) \
 			pg_unreachable(); \
 	} while(0)
@@ -169,7 +176,7 @@ extern bool message_level_is_interesting(int elevel);
 
 extern bool errstart(int elevel, const char *domain);
 extern pg_attribute_cold bool errstart_cold(int elevel, const char *domain);
-extern void errfinish(const char *filename, int lineno, const char *funcname);
+extern void errfinish(const char *filename, int lineno, const char *funcname, const char *extfile);
 
 extern int	errcode(int sqlerrcode);
 
@@ -268,7 +275,7 @@ extern int	getinternalerrposition(void);
 		struct Node *context_ = (context); \
 		pg_prevent_errno_in_scope(); \
 		if (errsave_start(context_, domain)) \
-			__VA_ARGS__, errsave_finish(context_, __FILE__, __LINE__, __func__); \
+			__VA_ARGS__, errsave_finish(context_, __FILE__, __LINE__, __func__, ELOG_EXTNAME); \
 	} while(0)
 
 #define errsave(context, ...)	\
@@ -293,7 +300,7 @@ extern int	getinternalerrposition(void);
 extern bool errsave_start(struct Node *context, const char *domain);
 extern void errsave_finish(struct Node *context,
 						   const char *filename, int lineno,
-						   const char *funcname);
+						   const char *funcname, const char *extname);
 
 
 /* Support for constructing error strings separately from ereport() calls */
@@ -449,6 +456,7 @@ typedef struct ErrorData
 	const char *funcname;		/* __func__ of ereport() call */
 	const char *domain;			/* message domain */
 	const char *context_domain; /* message domain for context message */
+	const char *extname;		/* extension filename or NULL */
 	int			sqlerrcode;		/* encoded ERRSTATE */
 	char	   *message;		/* primary error message (translated) */
 	char	   *detail;			/* detail error message */
diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c
index d91a85cb2d7..1d34e89d7f5 100644
--- a/src/backend/utils/error/elog.c
+++ b/src/backend/utils/error/elog.c
@@ -180,7 +180,7 @@ static ErrorData *get_error_stack_entry(void);
 static void set_stack_entry_domain(ErrorData *edata, const char *domain);
 static void set_stack_entry_location(ErrorData *edata,
 									 const char *filename, int lineno,
-									 const char *funcname);
+									 const char *funcname, const char *extname);
 static bool matches_backtrace_functions(const char *funcname);
 static pg_noinline void set_backtrace(ErrorData *edata, int num_skip);
 static void set_errdata_field(MemoryContextData *cxt, char **ptr, const char *str);
@@ -474,7 +474,7 @@ errstart(int elevel, const char *domain)
  * return to the caller.  See elog.h for the error level definitions.
  */
 void
-errfinish(const char *filename, int lineno, const char *funcname)
+errfinish(const char *filename, int lineno, const char *funcname, const char *extname)
 {
 	ErrorData  *edata = &errordata[errordata_stack_depth];
 	int			elevel;
@@ -485,7 +485,7 @@ errfinish(const char *filename, int lineno, const char *funcname)
 	CHECK_STACK_DEPTH();
 
 	/* Save the last few bits of error state into the stack entry */
-	set_stack_entry_location(edata, filename, lineno, funcname);
+	set_stack_entry_location(edata, filename, lineno, funcname, extname);
 
 	elevel = edata->elevel;
 
@@ -683,7 +683,7 @@ errsave_start(struct Node *context, const char *domain)
  */
 void
 errsave_finish(struct Node *context, const char *filename, int lineno,
-			   const char *funcname)
+			   const char *funcname, const char *extname)
 {
 	ErrorSaveContext *escontext = (ErrorSaveContext *) context;
 	ErrorData  *edata = &errordata[errordata_stack_depth];
@@ -697,7 +697,7 @@ errsave_finish(struct Node *context, const char *filename, int lineno,
 	 */
 	if (edata->elevel >= ERROR)
 	{
-		errfinish(filename, lineno, funcname);
+		errfinish(filename, lineno, funcname, extname);
 		pg_unreachable();
 	}
 
@@ -708,7 +708,7 @@ errsave_finish(struct Node *context, const char *filename, int lineno,
 	recursion_depth++;
 
 	/* Save the last few bits of error state into the stack entry */
-	set_stack_entry_location(edata, filename, lineno, funcname);
+	set_stack_entry_location(edata, filename, lineno, funcname, extname);
 
 	/* Replace the LOG value that errsave_start inserted */
 	edata->elevel = ERROR;
@@ -798,7 +798,7 @@ set_stack_entry_domain(ErrorData *edata, const char *domain)
 static void
 set_stack_entry_location(ErrorData *edata,
 						 const char *filename, int lineno,
-						 const char *funcname)
+						 const char *funcname, const char *extname)
 {
 	if (filename)
 	{
@@ -817,6 +817,7 @@ set_stack_entry_location(ErrorData *edata,
 	edata->filename = filename;
 	edata->lineno = lineno;
 	edata->funcname = funcname;
+	edata->extname = extname;
 }
 
 /*
@@ -1903,7 +1904,7 @@ ThrowErrorData(ErrorData *edata)
 	recursion_depth--;
 
 	/* Process the error. */
-	errfinish(edata->filename, edata->lineno, edata->funcname);
+	errfinish(edata->filename, edata->lineno, edata->funcname, edata->extname);
 }
 
 /*
@@ -2000,7 +2001,7 @@ pg_re_throw(void)
 		 */
 		error_context_stack = NULL;
 
-		errfinish(edata->filename, edata->lineno, edata->funcname);
+		errfinish(edata->filename, edata->lineno, edata->funcname, edata->extname);
 	}
 
 	/* Doesn't return ... */
@@ -3110,6 +3111,20 @@ log_status_format(StringInfo buf, const char *format, ErrorData *edata)
 				else
 					appendStringInfoString(buf, unpack_sql_state(edata->sqlerrcode));
 				break;
+			case 'E':
+				{
+					const char *extname = edata->extname;
+
+					if (!extname)
+						extname = "postgres";
+
+					if (padding != 0)
+						appendStringInfo(buf, "%*s", padding,
+										 extname);
+					else
+						appendStringInfoString(buf, extname);
+					break;
+				}
 			case 'Q':
 				if (padding != 0)
 					appendStringInfo(buf, "%*lld", padding,
diff --git a/src/backend/utils/fmgr/dfmgr.c b/src/backend/utils/fmgr/dfmgr.c
index eafa0128ef0..873868b6a15 100644
--- a/src/backend/utils/fmgr/dfmgr.c
+++ b/src/backend/utils/fmgr/dfmgr.c
@@ -36,6 +36,7 @@
 #include "storage/fd.h"
 #include "storage/shmem.h"
 #include "utils/hsearch.h"
+#include "utils/memutils.h"
 
 
 /* signature for PostgreSQL-specific library init function */
@@ -268,6 +269,35 @@ internal_load_library(const char *libname)
 				/* issue suitable complaint */
 				incompatible_module_error(libname, &module_magic_data);
 			}
+
+			{
+				const char **extname;
+				char *libname_short;
+
+				extname = dlsym(file_scanner->handle,
+								"Pg_extension_filename");
+				if (!extname)
+					elog(ERROR, "couldn't find Pg_extension_filename");
+
+				/*
+				 * For loaded libraries, the filename, without file ending,
+				 * ought to be unique. Pg_extension_filename is intended for
+				 * logging, a full file path would be onerous.
+				 */
+				libname_short = last_dir_separator(libname) + 1;
+				libname_short = MemoryContextStrdup(TopMemoryContext,
+													last_dir_separator(libname) + 1);
+
+				for (int i = strlen(libname_short); i >= 0; i--)
+				{
+					if (libname_short[i] == '.')
+					{
+						libname_short[i] = '\0';
+						break;
+					}
+				}
+				*extname = MemoryContextStrdup(TopMemoryContext, libname_short);
+			}
 		}
 		else
 		{
-- 
2.44.0.279.g3bd955d269

Fabrízio de Royes Mello

fabriziomello@gmail.com

over 1 year ago

In reply to: Andres Freund (#1)

Re: Adding the extension name to EData / log_line_prefix

On Mon, May 13, 2024 at 5:51 PM Andres Freund <andres@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

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

Andres Freund

andres@anarazel.de

over 1 year ago

In reply to: Fabrízio de Royes Mello (#2)

2 attachment(s)

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

Attachments:

v2-0001-WIP-Track-shared-library-in-which-elog-ereport-is.patchtext/x-diff; charset=us-asciiDownload

From 1c59c465f2d359e8c47cf91d1ea458ea3b64ec84 Mon Sep 17 00:00:00 2001
From: Andres Freund <andres@anarazel.de>
Date: Mon, 13 May 2024 13:47:41 -0700
Subject: [PATCH v2 1/2] WIP: Track shared library in which elog/ereport is
 called

---
 src/include/fmgr.h             |  1 +
 src/include/utils/elog.h       | 18 +++++++++++++-----
 src/backend/utils/error/elog.c | 33 ++++++++++++++++++++++++---------
 src/backend/utils/fmgr/dfmgr.c | 30 ++++++++++++++++++++++++++++++
 4 files changed, 68 insertions(+), 14 deletions(-)

diff --git a/src/include/fmgr.h b/src/include/fmgr.h
index ccb4070a251..3c7cfd7fee9 100644
--- a/src/include/fmgr.h
+++ b/src/include/fmgr.h
@@ -504,6 +504,7 @@ PG_MAGIC_FUNCTION_NAME(void) \
 	static const Pg_magic_struct Pg_magic_data = PG_MODULE_MAGIC_DATA; \
 	return &Pg_magic_data; \
 } \
+PGDLLEXPORT const char *Pg_extension_filename = NULL; \
 extern int no_such_variable
 
 
diff --git a/src/include/utils/elog.h b/src/include/utils/elog.h
index 054dd2bf62f..5e57f01823d 100644
--- a/src/include/utils/elog.h
+++ b/src/include/utils/elog.h
@@ -137,6 +137,13 @@ struct Node;
  * prevents gcc from making the unreachability deduction at optlevel -O0.
  *----------
  */
+#ifdef BUILDING_DLL
+#define ELOG_EXTNAME NULL
+#else
+extern PGDLLEXPORT const char *Pg_extension_filename;
+#define ELOG_EXTNAME Pg_extension_filename
+#endif
+
 #ifdef HAVE__BUILTIN_CONSTANT_P
 #define ereport_domain(elevel, domain, ...)	\
 	do { \
@@ -144,7 +151,7 @@ struct Node;
 		if (__builtin_constant_p(elevel) && (elevel) >= ERROR ? \
 			errstart_cold(elevel, domain) : \
 			errstart(elevel, domain)) \
-			__VA_ARGS__, errfinish(__FILE__, __LINE__, __func__); \
+			__VA_ARGS__, errfinish(__FILE__, __LINE__, __func__, ELOG_EXTNAME); \
 		if (__builtin_constant_p(elevel) && (elevel) >= ERROR) \
 			pg_unreachable(); \
 	} while(0)
@@ -154,7 +161,7 @@ struct Node;
 		const int elevel_ = (elevel); \
 		pg_prevent_errno_in_scope(); \
 		if (errstart(elevel_, domain)) \
-			__VA_ARGS__, errfinish(__FILE__, __LINE__, __func__); \
+			__VA_ARGS__, errfinish(__FILE__, __LINE__, __func__, ELOG_EXTNAME); \
 		if (elevel_ >= ERROR) \
 			pg_unreachable(); \
 	} while(0)
@@ -169,7 +176,7 @@ extern bool message_level_is_interesting(int elevel);
 
 extern bool errstart(int elevel, const char *domain);
 extern pg_attribute_cold bool errstart_cold(int elevel, const char *domain);
-extern void errfinish(const char *filename, int lineno, const char *funcname);
+extern void errfinish(const char *filename, int lineno, const char *funcname, const char *extfile);
 
 extern int	errcode(int sqlerrcode);
 
@@ -268,7 +275,7 @@ extern int	getinternalerrposition(void);
 		struct Node *context_ = (context); \
 		pg_prevent_errno_in_scope(); \
 		if (errsave_start(context_, domain)) \
-			__VA_ARGS__, errsave_finish(context_, __FILE__, __LINE__, __func__); \
+			__VA_ARGS__, errsave_finish(context_, __FILE__, __LINE__, __func__, ELOG_EXTNAME); \
 	} while(0)
 
 #define errsave(context, ...)	\
@@ -293,7 +300,7 @@ extern int	getinternalerrposition(void);
 extern bool errsave_start(struct Node *context, const char *domain);
 extern void errsave_finish(struct Node *context,
 						   const char *filename, int lineno,
-						   const char *funcname);
+						   const char *funcname, const char *extname);
 
 
 /* Support for constructing error strings separately from ereport() calls */
@@ -449,6 +456,7 @@ typedef struct ErrorData
 	const char *funcname;		/* __func__ of ereport() call */
 	const char *domain;			/* message domain */
 	const char *context_domain; /* message domain for context message */
+	const char *extname;		/* extension filename or NULL */
 	int			sqlerrcode;		/* encoded ERRSTATE */
 	char	   *message;		/* primary error message (translated) */
 	char	   *detail;			/* detail error message */
diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c
index d91a85cb2d7..1d34e89d7f5 100644
--- a/src/backend/utils/error/elog.c
+++ b/src/backend/utils/error/elog.c
@@ -180,7 +180,7 @@ static ErrorData *get_error_stack_entry(void);
 static void set_stack_entry_domain(ErrorData *edata, const char *domain);
 static void set_stack_entry_location(ErrorData *edata,
 									 const char *filename, int lineno,
-									 const char *funcname);
+									 const char *funcname, const char *extname);
 static bool matches_backtrace_functions(const char *funcname);
 static pg_noinline void set_backtrace(ErrorData *edata, int num_skip);
 static void set_errdata_field(MemoryContextData *cxt, char **ptr, const char *str);
@@ -474,7 +474,7 @@ errstart(int elevel, const char *domain)
  * return to the caller.  See elog.h for the error level definitions.
  */
 void
-errfinish(const char *filename, int lineno, const char *funcname)
+errfinish(const char *filename, int lineno, const char *funcname, const char *extname)
 {
 	ErrorData  *edata = &errordata[errordata_stack_depth];
 	int			elevel;
@@ -485,7 +485,7 @@ errfinish(const char *filename, int lineno, const char *funcname)
 	CHECK_STACK_DEPTH();
 
 	/* Save the last few bits of error state into the stack entry */
-	set_stack_entry_location(edata, filename, lineno, funcname);
+	set_stack_entry_location(edata, filename, lineno, funcname, extname);
 
 	elevel = edata->elevel;
 
@@ -683,7 +683,7 @@ errsave_start(struct Node *context, const char *domain)
  */
 void
 errsave_finish(struct Node *context, const char *filename, int lineno,
-			   const char *funcname)
+			   const char *funcname, const char *extname)
 {
 	ErrorSaveContext *escontext = (ErrorSaveContext *) context;
 	ErrorData  *edata = &errordata[errordata_stack_depth];
@@ -697,7 +697,7 @@ errsave_finish(struct Node *context, const char *filename, int lineno,
 	 */
 	if (edata->elevel >= ERROR)
 	{
-		errfinish(filename, lineno, funcname);
+		errfinish(filename, lineno, funcname, extname);
 		pg_unreachable();
 	}
 
@@ -708,7 +708,7 @@ errsave_finish(struct Node *context, const char *filename, int lineno,
 	recursion_depth++;
 
 	/* Save the last few bits of error state into the stack entry */
-	set_stack_entry_location(edata, filename, lineno, funcname);
+	set_stack_entry_location(edata, filename, lineno, funcname, extname);
 
 	/* Replace the LOG value that errsave_start inserted */
 	edata->elevel = ERROR;
@@ -798,7 +798,7 @@ set_stack_entry_domain(ErrorData *edata, const char *domain)
 static void
 set_stack_entry_location(ErrorData *edata,
 						 const char *filename, int lineno,
-						 const char *funcname)
+						 const char *funcname, const char *extname)
 {
 	if (filename)
 	{
@@ -817,6 +817,7 @@ set_stack_entry_location(ErrorData *edata,
 	edata->filename = filename;
 	edata->lineno = lineno;
 	edata->funcname = funcname;
+	edata->extname = extname;
 }
 
 /*
@@ -1903,7 +1904,7 @@ ThrowErrorData(ErrorData *edata)
 	recursion_depth--;
 
 	/* Process the error. */
-	errfinish(edata->filename, edata->lineno, edata->funcname);
+	errfinish(edata->filename, edata->lineno, edata->funcname, edata->extname);
 }
 
 /*
@@ -2000,7 +2001,7 @@ pg_re_throw(void)
 		 */
 		error_context_stack = NULL;
 
-		errfinish(edata->filename, edata->lineno, edata->funcname);
+		errfinish(edata->filename, edata->lineno, edata->funcname, edata->extname);
 	}
 
 	/* Doesn't return ... */
@@ -3110,6 +3111,20 @@ log_status_format(StringInfo buf, const char *format, ErrorData *edata)
 				else
 					appendStringInfoString(buf, unpack_sql_state(edata->sqlerrcode));
 				break;
+			case 'E':
+				{
+					const char *extname = edata->extname;
+
+					if (!extname)
+						extname = "postgres";
+
+					if (padding != 0)
+						appendStringInfo(buf, "%*s", padding,
+										 extname);
+					else
+						appendStringInfoString(buf, extname);
+					break;
+				}
 			case 'Q':
 				if (padding != 0)
 					appendStringInfo(buf, "%*lld", padding,
diff --git a/src/backend/utils/fmgr/dfmgr.c b/src/backend/utils/fmgr/dfmgr.c
index eafa0128ef0..873868b6a15 100644
--- a/src/backend/utils/fmgr/dfmgr.c
+++ b/src/backend/utils/fmgr/dfmgr.c
@@ -36,6 +36,7 @@
 #include "storage/fd.h"
 #include "storage/shmem.h"
 #include "utils/hsearch.h"
+#include "utils/memutils.h"
 
 
 /* signature for PostgreSQL-specific library init function */
@@ -268,6 +269,35 @@ internal_load_library(const char *libname)
 				/* issue suitable complaint */
 				incompatible_module_error(libname, &module_magic_data);
 			}
+
+			{
+				const char **extname;
+				char *libname_short;
+
+				extname = dlsym(file_scanner->handle,
+								"Pg_extension_filename");
+				if (!extname)
+					elog(ERROR, "couldn't find Pg_extension_filename");
+
+				/*
+				 * For loaded libraries, the filename, without file ending,
+				 * ought to be unique. Pg_extension_filename is intended for
+				 * logging, a full file path would be onerous.
+				 */
+				libname_short = last_dir_separator(libname) + 1;
+				libname_short = MemoryContextStrdup(TopMemoryContext,
+													last_dir_separator(libname) + 1);
+
+				for (int i = strlen(libname_short); i >= 0; i--)
+				{
+					if (libname_short[i] == '.')
+					{
+						libname_short[i] = '\0';
+						break;
+					}
+				}
+				*extname = MemoryContextStrdup(TopMemoryContext, libname_short);
+			}
 		}
 		else
 		{
-- 
2.44.0.279.g3bd955d269

v2-0002-WIP-Set-BUILDING_DLL-universally.patchtext/x-diff; charset=us-asciiDownload

From 773e8b25bd4b2a71d256ecfea0366d3670302f31 Mon Sep 17 00:00:00 2001
From: Andres Freund <andres@anarazel.de>
Date: Mon, 13 May 2024 16:01:16 -0700
Subject: [PATCH v2 2/2] WIP: Set BUILDING_DLL universally

That's done with meson already.

We probably should rename it, it's quite misleading.
---
 src/makefiles/Makefile.cygwin | 28 ----------------------------
 src/makefiles/Makefile.win32  | 28 ----------------------------
 src/Makefile.global.in        | 28 ++++++++++++++++++++++++++++
 3 files changed, 28 insertions(+), 56 deletions(-)

diff --git a/src/makefiles/Makefile.cygwin b/src/makefiles/Makefile.cygwin
index 77593972638..68b98ef06b7 100644
--- a/src/makefiles/Makefile.cygwin
+++ b/src/makefiles/Makefile.cygwin
@@ -12,34 +12,6 @@ LIBS:=$(filter-out -lm -lc, $(LIBS))
 
 override CPPFLAGS += -DWIN32_STACK_RLIMIT=$(WIN32_STACK_RLIMIT)
 
-ifneq (,$(findstring backend,$(subdir)))
-ifeq (,$(findstring conversion_procs,$(subdir)))
-ifeq (,$(findstring libpqwalreceiver,$(subdir)))
-ifeq (,$(findstring replication/pgoutput,$(subdir)))
-ifeq (,$(findstring snowball,$(subdir)))
-override CPPFLAGS+= -DBUILDING_DLL
-endif
-endif
-endif
-endif
-endif
-
-ifneq (,$(findstring src/common,$(subdir)))
-override CPPFLAGS+= -DBUILDING_DLL
-endif
-
-ifneq (,$(findstring src/port,$(subdir)))
-override CPPFLAGS+= -DBUILDING_DLL
-endif
-
-ifneq (,$(findstring timezone,$(subdir)))
-override CPPFLAGS+= -DBUILDING_DLL
-endif
-
-ifneq (,$(findstring ecpg/ecpglib,$(subdir)))
-override CPPFLAGS+= -DBUILDING_DLL
-endif
-
 # required by Python headers
 ifneq (,$(findstring src/pl/plpython,$(subdir)))
 override CPPFLAGS+= -DUSE_DL_IMPORT
diff --git a/src/makefiles/Makefile.win32 b/src/makefiles/Makefile.win32
index dc1aafa115a..fe13aae1e3f 100644
--- a/src/makefiles/Makefile.win32
+++ b/src/makefiles/Makefile.win32
@@ -10,34 +10,6 @@ endif
 
 override CPPFLAGS += -DWIN32_STACK_RLIMIT=$(WIN32_STACK_RLIMIT)
 
-ifneq (,$(findstring backend,$(subdir)))
-ifeq (,$(findstring conversion_procs,$(subdir)))
-ifeq (,$(findstring libpqwalreceiver,$(subdir)))
-ifeq (,$(findstring replication/pgoutput,$(subdir)))
-ifeq (,$(findstring snowball,$(subdir)))
-override CPPFLAGS+= -DBUILDING_DLL
-endif
-endif
-endif
-endif
-endif
-
-ifneq (,$(findstring src/common,$(subdir)))
-override CPPFLAGS+= -DBUILDING_DLL
-endif
-
-ifneq (,$(findstring src/port,$(subdir)))
-override CPPFLAGS+= -DBUILDING_DLL
-endif
-
-ifneq (,$(findstring timezone,$(subdir)))
-override CPPFLAGS+= -DBUILDING_DLL
-endif
-
-ifneq (,$(findstring ecpg/ecpglib,$(subdir)))
-override CPPFLAGS+= -DBUILDING_DLL
-endif
-
 # required by Python headers
 ifneq (,$(findstring src/pl/plpython,$(subdir)))
 override CPPFLAGS+= -DUSE_DL_IMPORT
diff --git a/src/Makefile.global.in b/src/Makefile.global.in
index a00c909681e..3c35aa5ee68 100644
--- a/src/Makefile.global.in
+++ b/src/Makefile.global.in
@@ -1118,3 +1118,31 @@ rm -rf '$(DESTDIR)${bitcodedir}/$(1)/'
 rm -f '$(DESTDIR)${bitcodedir}/$(1).index.bc'
 
 endef
+
+ifneq (,$(findstring backend,$(subdir)))
+ifeq (,$(findstring conversion_procs,$(subdir)))
+ifeq (,$(findstring libpqwalreceiver,$(subdir)))
+ifeq (,$(findstring replication/pgoutput,$(subdir)))
+ifeq (,$(findstring snowball,$(subdir)))
+override CPPFLAGS+= -DBUILDING_DLL
+endif
+endif
+endif
+endif
+endif
+
+ifneq (,$(findstring src/common,$(subdir)))
+override CPPFLAGS+= -DBUILDING_DLL
+endif
+
+ifneq (,$(findstring src/port,$(subdir)))
+override CPPFLAGS+= -DBUILDING_DLL
+endif
+
+ifneq (,$(findstring timezone,$(subdir)))
+override CPPFLAGS+= -DBUILDING_DLL
+endif
+
+ifneq (,$(findstring ecpg/ecpglib,$(subdir)))
+override CPPFLAGS+= -DBUILDING_DLL
+endif
-- 
2.44.0.279.g3bd955d269

Tom Lane

tgl@sss.pgh.pa.us

over 1 year ago

In reply to: Andres Freund (#3)

Re: Adding the extension name to EData / log_line_prefix

Andres Freund <andres@anarazel.de> writes:

On 2024-05-13 19:25:11 -0300, Fabrízio de Royes Mello wrote:

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?

Not to mention that there could be more than one extension on the call
stack. I think tying this statically to the ereport call site is
fine.

The mechanism that Andres describes for sourcing the name seems a bit
overcomplex though. Why not just allow/require each extension to
specify its name as a constant string? We could force the matter by
redefining PG_MODULE_MAGIC as taking an argument:

PG_MODULE_MAGIC("hstore");

regards, tom lane

Andres Freund

andres@anarazel.de

over 1 year ago

In reply to: Tom Lane (#4)

Re: Adding the extension name to EData / log_line_prefix

Hi,

On 2024-05-13 19:11:53 -0400, Tom Lane wrote:

The mechanism that Andres describes for sourcing the name seems a bit
overcomplex though. Why not just allow/require each extension to
specify its name as a constant string? We could force the matter by
redefining PG_MODULE_MAGIC as taking an argument:
PG_MODULE_MAGIC("hstore");

Mostly because it seemed somewhat sad to require every extension to have
version-specific ifdefs around that, particularly because it's not hard for us
to infer.

I think there might be other use cases for the backend to provide "extension
scoped" information, FWIW. Even just providing the full path to the extension
library could be useful.

Greetings,

Andres Freund

Julien Rouhaud

rjuju123@gmail.com

over 1 year ago

In reply to: Tom Lane (#4)

Re: Adding the extension name to EData / log_line_prefix

On Mon, May 13, 2024 at 07:11:53PM GMT, Tom Lane wrote:

Andres Freund <andres@anarazel.de> writes:

On 2024-05-13 19:25:11 -0300, Fabrï¿½zio de Royes Mello wrote:

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?

Not to mention that there could be more than one extension on the call
stack. I think tying this statically to the ereport call site is
fine.

The mechanism that Andres describes for sourcing the name seems a bit
overcomplex though. Why not just allow/require each extension to
specify its name as a constant string? We could force the matter by
redefining PG_MODULE_MAGIC as taking an argument:

PG_MODULE_MAGIC("hstore");

FTR there was a proposal at [1]/messages/by-id/3207907.AWbSqkKDnR@aivenronan some time ago that could be used for that need
(and others), I thought it could be good to mention it just in case. That
would obviously only work if all extensions uses that framework.

[1]: /messages/by-id/3207907.AWbSqkKDnR@aivenronan

Peter Eisentraut

peter@eisentraut.org

over 1 year ago

In reply to: Tom Lane (#4)

Re: Adding the extension name to EData / log_line_prefix

On 14.05.24 01:11, Tom Lane wrote:

The mechanism that Andres describes for sourcing the name seems a bit
overcomplex though. Why not just allow/require each extension to
specify its name as a constant string? We could force the matter by
redefining PG_MODULE_MAGIC as taking an argument:

PG_MODULE_MAGIC("hstore");

We kind of already have something like this, for NLS. If you look for
pg_bindtextdomain(TEXTDOMAIN) and ereport_domain(), this information
already trickles into the vicinity of the error data. Maybe the same
thing could just be used for this, by wiring up the macros a bit
differently.

Tom Lane

tgl@sss.pgh.pa.us

over 1 year ago

In reply to: Peter Eisentraut (#7)

Re: Adding the extension name to EData / log_line_prefix

Peter Eisentraut <peter@eisentraut.org> writes:

On 14.05.24 01:11, Tom Lane wrote:

The mechanism that Andres describes for sourcing the name seems a bit
overcomplex though. Why not just allow/require each extension to
specify its name as a constant string? We could force the matter by
redefining PG_MODULE_MAGIC as taking an argument:
PG_MODULE_MAGIC("hstore");

We kind of already have something like this, for NLS. If you look for
pg_bindtextdomain(TEXTDOMAIN) and ereport_domain(), this information
already trickles into the vicinity of the error data. Maybe the same
thing could just be used for this, by wiring up the macros a bit
differently.

Hmm, cute idea, but it'd only help for extensions that are
NLS-enabled. Which I bet is a tiny fraction of the population.
So far as I can find, we don't even document how to set up
TEXTDOMAIN for an extension --- you have to cargo-cult the
macro definition from some in-core extension.

regards, tom lane

Chapman Flack

jcflack@acm.org

over 1 year ago

In reply to: Tom Lane (#8)

Re: Adding the extension name to EData / log_line_prefix

On 05/15/24 11:50, Tom Lane wrote:

Hmm, cute idea, but it'd only help for extensions that are
NLS-enabled. Which I bet is a tiny fraction of the population.
So far as I can find, we don't even document how to set up
TEXTDOMAIN for an extension --- you have to cargo-cult the

But I'd bet, within the fraction of the population that does use it,
it is already a short string that looks a whole lot like the name
of the extension. So maybe enhancing the documentation and making it
easy to set up would achieve much of the objective here.

Could PGXS be made to supply the extension name as TEXTDOMAIN when
building code that does not otherwise define it, and would that have
any ill effect on the otherwise not-NLS-enabled code? Would the worst-
case effect be a failed search for a nonexistent .mo file, followed by
output of the untranslated message as before?

At first glance, it appears elog will apply PG_TEXTDOMAIN("postgres")
in an extension that does not otherwise define TEXTDOMAIN. But I assume
the usual effect of that is already a failed lookup followed by output of
the untranslated message, except in the case of the out-of-core extension
using a message matching a PG_TEXTDOMAIN("postgres") translation.

If that case is considered unexpected, or actively discouraged, perhaps
defining TEXTDOMAIN in an otherwise not-NLS-enabled extension could be
relatively painless.

Regards,
-Chap

#10

Andres Freund

andres@anarazel.de

over 1 year ago

In reply to: Chapman Flack (#9)

Re: Adding the extension name to EData / log_line_prefix

Hi,

On 2024-05-15 12:54:45 -0400, Chapman Flack wrote:

On 05/15/24 11:50, Tom Lane wrote:

Hmm, cute idea, but it'd only help for extensions that are
NLS-enabled. Which I bet is a tiny fraction of the population.
So far as I can find, we don't even document how to set up
TEXTDOMAIN for an extension --- you have to cargo-cult the

But I'd bet, within the fraction of the population that does use it,
it is already a short string that looks a whole lot like the name
of the extension. So maybe enhancing the documentation and making it
easy to set up would achieve much of the objective here.

The likely outcome would IMO be that some extensions will have the data,
others not. Whereas inferring the information from our side will give you
something reliable.

But I also just don't think it's something that architecturally fits together
that well. If we either had TEXTDOMAIN reliably set across extensions or it'd
architecturally be pretty, I'd go for it, but imo it's neither.

Greetings,

Andres Freund

#11

Tom Lane

tgl@sss.pgh.pa.us

over 1 year ago

In reply to: Andres Freund (#10)

Re: Adding the extension name to EData / log_line_prefix

Andres Freund <andres@anarazel.de> writes:

On 2024-05-15 12:54:45 -0400, Chapman Flack wrote:

But I'd bet, within the fraction of the population that does use it,
it is already a short string that looks a whole lot like the name
of the extension. So maybe enhancing the documentation and making it
easy to set up would achieve much of the objective here.

The likely outcome would IMO be that some extensions will have the data,
others not. Whereas inferring the information from our side will give you
something reliable.
But I also just don't think it's something that architecturally fits together
that well. If we either had TEXTDOMAIN reliably set across extensions or it'd
architecturally be pretty, I'd go for it, but imo it's neither.

There is one advantage over my suggestion of changing PG_MODULE_MAGIC:
if we tell people to write

PG_MODULE_MAGIC;
#undef TEXTDOMAIN
#define TEXTDOMAIN PG_TEXTDOMAIN("hstore")

then that's 100% backwards compatible and they don't need any
version-testing ifdef's.

I still think that the kind of infrastructure Andres proposes
is way overkill compared to the value, plus it's almost certainly
going to have a bunch of platform-specific problems to solve.
So I think Peter's thought is worth pursuing.

regards, tom lane

#12

Chapman Flack

jcflack@acm.org

over 1 year ago

In reply to: Tom Lane (#11)

Re: Adding the extension name to EData / log_line_prefix

On 05/15/24 13:45, Tom Lane wrote:

if we tell people to write

PG_MODULE_MAGIC;
#undef TEXTDOMAIN
#define TEXTDOMAIN PG_TEXTDOMAIN("hstore")

then that's 100% backwards compatible and they don't need any
version-testing ifdef's.

OT for this thread, but related: supposing out-of-core extensions
participate increasingly in NLS, would they really want to use
the PG_TEXTDOMAIN macro?

That munges the supplied domain name with PG's major version and
.so version numbers.

Were such versioning wanted for an out-of-core extension's message
catalogs, wouldn't the extension's own versioning be better suited?

Regards,
-Chap

#13

Andres Freund

andres@anarazel.de

over 1 year ago

In reply to: Tom Lane (#11)

Re: Adding the extension name to EData / log_line_prefix

Hi,

On 2024-05-15 13:45:30 -0400, Tom Lane wrote:

There is one advantage over my suggestion of changing PG_MODULE_MAGIC:
if we tell people to write

PG_MODULE_MAGIC;
#undef TEXTDOMAIN
#define TEXTDOMAIN PG_TEXTDOMAIN("hstore")

then that's 100% backwards compatible and they don't need any
version-testing ifdef's.

I still think that the kind of infrastructure Andres proposes
is way overkill compared to the value, plus it's almost certainly
going to have a bunch of platform-specific problems to solve.

Maybe I missing something here. Even adding those two lines to the extensions
in core and contrib is going to end up being more lines than what I proposed?

What portability issues do you forsee? We already look up the same symbol in
all the shared libraries ("Pg_magic_func"), so we know that we can deal with
duplicate function names. Are you thinking that somehow we'd end up with
symbol interposition or something?

Greetings,

Andres Freund

#14

Tom Lane

tgl@sss.pgh.pa.us

over 1 year ago

In reply to: Andres Freund (#13)

Re: Adding the extension name to EData / log_line_prefix

Andres Freund <andres@anarazel.de> writes:

What portability issues do you forsee? We already look up the same symbol in
all the shared libraries ("Pg_magic_func"), so we know that we can deal with
duplicate function names. Are you thinking that somehow we'd end up with
symbol interposition or something?

No, it's the dependence on the physical library file name that's
bothering me. Maybe that won't be an issue, but I foresee requests
like "would you please case-fold it" or "the extension-trimming rule
isn't quite right", etc.

regards, tom lane

#15

Peter Eisentraut

peter@eisentraut.org

over 1 year ago

In reply to: Tom Lane (#8)

Re: Adding the extension name to EData / log_line_prefix

On 15.05.24 17:50, Tom Lane wrote:

We kind of already have something like this, for NLS. If you look for
pg_bindtextdomain(TEXTDOMAIN) and ereport_domain(), this information
already trickles into the vicinity of the error data. Maybe the same
thing could just be used for this, by wiring up the macros a bit
differently.

Hmm, cute idea, but it'd only help for extensions that are
NLS-enabled. Which I bet is a tiny fraction of the population.
So far as I can find, we don't even document how to set up
TEXTDOMAIN for an extension --- you have to cargo-cult the
macro definition from some in-core extension.

Yeah, the whole thing is a bit mysterious, and we don't need to use the
exact mechanism we have now.

But abstractly, we should only have to specify the, uh, domain of the
log messages once. Whether that is used for building a message catalog
or tagging the server log, those are just two different downstream uses
of the same piece of information.