Hi,
This discussion started at
https://postgr.es/m/20230627212423.p56zxuqeh5kya...@awork3.anarazel.de
but isn't really related to the bug.
On 2023-06-27 17:44:57 -0400, Tom Lane wrote:
> Andres Freund <and...@anarazel.de> writes:
> > That's not going to help you / the reporter, but to make issues like this
> > easier to debug in the future, I think we should
> > a) install an error context in load_libraries() printing the GUC name and
> > b) install an error context in internal_load_library() printing the name of
> > the shared library name
>
> +1. I'm not sure this specific issue justifies it, but it seems like that
> might make it easier to diagnose other shared-library-load-time issues
> as well.
Yea, this bug alone wouldn't have made me suggest it, but I've looked at
enough issues where I regretted not knowing what library caused and error
and/or what caused a library to be loaded that I think it's worth it.
I first added an error context to both the places mentioned above, but that
leads to annoyingly redundant messages. And I realized that it'd also be
useful to print a message when loading a library due to
load_external_function() - I've definitely wondered about errors triggered
below that in the past.
I ended up adding a reason enum and a detail const char* to
internal_load_library(). I don't like that approach a whole lot, but couldn't
really come up with something better.
Example errors that now have a context:
Error in _PG_init() of library called via shared_preload_libraries (error added
by me):
FATAL: not today
CONTEXT: in "_PG_init()" callback of library
"/tmp/meson-install/lib/x86_64-linux-gnu/postgresql/auto_explain.so"
library load for "shared_preload_libraries" parameter
or
FATAL: could not access file "dont_exist": No such file or directory
CONTEXT: library load for "shared_preload_libraries" parameter
Creating a C function referencing a library that needs to be loaded with
shared_preload_libraries:
=# CREATE FUNCTION frak()
RETURNS text IMMUTABLE STRICT
AS '/srv/dev/build/m/src/test/modules/test_slru/test_slru.so' LANGUAGE C;
ERROR: XX000: cannot load "test_slru" after startup
DETAIL: "test_slru" must be loaded with shared_preload_libraries.
CONTEXT: in "_PG_init()" callback of library
"/srv/dev/build/m/src/test/modules/test_slru/test_slru.so"
library load for C function "frak"
LOAD of a non-postgres library:
=# LOAD '/usr/lib/libarmadillo.so.11';
ERROR: XX000: incompatible library "/usr/lib/libarmadillo.so.11": missing
magic block
HINT: Extension libraries are required to use the PG_MODULE_MAGIC macro.
CONTEXT: library load for LOAD statement
Note that here the errcontext callback prints the reason for the library being
loaded, but not the library name. I made it so that the library name is only
printed during _PG_init(), otherwise it's always duplicating the primary error
message. Which looks messy - but perhaps it's more important to be
"predictable"?
I don't love "library load for ..." and played around with a few other
variants, but I didn't come up with anything particularly satisfying.
I was tempted to invent a separate "library load reason" for
fmgr_info_C_lang() and other uses of load_external_function(), but concluded
that that reaches diminishing-returns territory.
Is it worth adding tests for:
1) an error during shared_preload_libraries, local_preload_libraries,
session_preload_libraries
2) loading a non-postgres library and hitting "missing magic block"
3) local_preload_libraries not being allowed to load libraries outside of
plugins/?
4) session_preload_libraries being allowed to load libraries outside of
plugins/?
?
Greetings,
Andres Freund
>From 2d8c6f0c14c34c373f54834a703e4e7b0539665b Mon Sep 17 00:00:00 2001
From: Andres Freund <and...@anarazel.de>
Date: Tue, 27 Jun 2023 16:42:51 -0700
Subject: [PATCH v1] Add error context callback to internal_load_library()
Author:
Reviewed-by:
Discussion: https://postgr.es/20230627212423.p56zxuqeh5kya...@awork3.anarazel.de
Backpatch:
---
src/include/fmgr.h | 11 +++
src/backend/tcop/utility.c | 2 +-
src/backend/utils/fmgr/dfmgr.c | 91 +++++++++++++++++--
src/backend/utils/init/miscinit.c | 2 +-
contrib/test_decoding/expected/slot.out | 1 +
.../regress/expected/create_function_c.out | 1 +
src/tools/pgindent/typedefs.list | 2 +
7 files changed, 102 insertions(+), 8 deletions(-)
diff --git a/src/include/fmgr.h b/src/include/fmgr.h
index b120f5e7fef..10c3404cff2 100644
--- a/src/include/fmgr.h
+++ b/src/include/fmgr.h
@@ -741,10 +741,21 @@ extern bool CheckFunctionValidatorAccess(Oid validatorOid, Oid functionOid);
*/
extern PGDLLIMPORT char *Dynamic_library_path;
+typedef enum LoadLibraryReason
+{
+ LLR_UNSPECIFIED,
+ LLR_GUC,
+ LLR_LOAD,
+ LLR_C_FUNCTION,
+ LLR_RESTORE_LIBRARY_STATE,
+} LoadLibraryReason;
+
extern void *load_external_function(const char *filename, const char *funcname,
bool signalNotFound, void **filehandle);
extern void *lookup_external_function(void *filehandle, const char *funcname);
extern void load_file(const char *filename, bool restricted);
+extern void load_file_ext(const char *filename, bool restricted,
+ LoadLibraryReason reason, const char *detail);
extern void **find_rendezvous_variable(const char *varName);
extern Size EstimateLibraryStateSpace(void);
extern void SerializeLibraryState(Size maxsize, char *start_address);
diff --git a/src/backend/tcop/utility.c b/src/backend/tcop/utility.c
index 30b51bf4d30..dbf903f29e7 100644
--- a/src/backend/tcop/utility.c
+++ b/src/backend/tcop/utility.c
@@ -850,7 +850,7 @@ standard_ProcessUtility(PlannedStmt *pstmt,
closeAllVfds(); /* probably not necessary... */
/* Allowed names are restricted if you're not superuser */
- load_file(stmt->filename, !superuser());
+ load_file_ext(stmt->filename, !superuser(), LLR_LOAD, NULL);
}
break;
diff --git a/src/backend/utils/fmgr/dfmgr.c b/src/backend/utils/fmgr/dfmgr.c
index b85d52c913c..d9e23bb3b27 100644
--- a/src/backend/utils/fmgr/dfmgr.c
+++ b/src/backend/utils/fmgr/dfmgr.c
@@ -63,6 +63,15 @@ typedef struct df_files
char filename[FLEXIBLE_ARRAY_MEMBER]; /* Full pathname of file */
} DynamicFileList;
+/* State for load_library_error_callback() */
+typedef struct LoadLibraryErrorCallbackState
+{
+ const char *libname;
+ LoadLibraryReason reason;
+ const char *detail;
+ bool in_pg_init;
+} LoadLibraryErrorCallbackState;
+
static DynamicFileList *file_list = NULL;
static DynamicFileList *file_tail = NULL;
@@ -75,7 +84,9 @@ static DynamicFileList *file_tail = NULL;
char *Dynamic_library_path;
-static void *internal_load_library(const char *libname);
+static void *internal_load_library(const char *libname,
+ LoadLibraryReason reason,
+ const char *detail);
static void incompatible_module_error(const char *libname,
const Pg_magic_struct *module_magic_data) pg_attribute_noreturn();
static bool file_exists(const char *name);
@@ -83,6 +94,7 @@ static char *expand_dynamic_library_name(const char *name);
static void check_restricted_library_name(const char *name);
static char *substitute_libpath_macro(const char *name);
static char *find_in_dynamic_libpath(const char *basename);
+static void load_library_error_callback(void *arg);
/* Magic structure that module needs to match to be accepted */
static const Pg_magic_struct magic_data = PG_MODULE_MAGIC_DATA;
@@ -113,7 +125,7 @@ load_external_function(const char *filename, const char *funcname,
fullname = expand_dynamic_library_name(filename);
/* Load the shared library, unless we already did */
- lib_handle = internal_load_library(fullname);
+ lib_handle = internal_load_library(fullname, LLR_C_FUNCTION, funcname);
/* Return handle if caller wants it */
if (filehandle)
@@ -139,9 +151,13 @@ load_external_function(const char *filename, const char *funcname,
*
* When 'restricted' is true, only libraries in the presumed-secure
* directory $libdir/plugins may be referenced.
+ *
+ * 'reason' and 'detail' are used to set up an error context handler during
+ * library loading.
*/
void
-load_file(const char *filename, bool restricted)
+load_file_ext(const char *filename, bool restricted,
+ LoadLibraryReason reason, const char *detail)
{
char *fullname;
@@ -153,11 +169,20 @@ load_file(const char *filename, bool restricted)
fullname = expand_dynamic_library_name(filename);
/* Load the shared library */
- (void) internal_load_library(fullname);
+ (void) internal_load_library(fullname, reason, detail);
pfree(fullname);
}
+/*
+ * Backward compatible wrapper around load_file_ext()
+ */
+void
+load_file(const char *filename, bool restricted)
+{
+ load_file_ext(filename, restricted, LLR_UNSPECIFIED, NULL);
+}
+
/*
* Lookup a function whose library file is already loaded.
* Return NULL if not found.
@@ -181,13 +206,26 @@ lookup_external_function(void *filehandle, const char *funcname)
* perhaps other things that are definitely unsafe currently.
*/
static void *
-internal_load_library(const char *libname)
+internal_load_library(const char *libname,
+ LoadLibraryReason reason, const char *detail)
{
DynamicFileList *file_scanner;
PGModuleMagicFunction magic_func;
char *load_error;
struct stat stat_buf;
PG_init_t PG_init;
+ LoadLibraryErrorCallbackState errstate = {
+ .reason = reason,.detail = detail,
+ .libname = libname,
+ .in_pg_init = false,
+ };
+ ErrorContextCallback errcallback = {
+ .callback = load_library_error_callback,
+ .arg = (void *) &errstate,
+ .previous = error_context_stack,
+ };
+
+ error_context_stack = &errcallback;
/*
* Scan the list of loaded FILES to see if the file has been loaded.
@@ -286,7 +324,11 @@ internal_load_library(const char *libname)
*/
PG_init = (PG_init_t) dlsym(file_scanner->handle, "_PG_init");
if (PG_init)
+ {
+ errstate.in_pg_init = true;
(*PG_init) ();
+ errstate.in_pg_init = false;
+ }
/* OK to link it into list */
if (file_list == NULL)
@@ -296,6 +338,8 @@ internal_load_library(const char *libname)
file_tail = file_scanner;
}
+ error_context_stack = errcallback.previous;
+
return file_scanner->handle;
}
@@ -400,6 +444,41 @@ incompatible_module_error(const char *libname,
errdetail_internal("%s", details.data)));
}
+/*
+ * Error context callback for internal_load_library()
+ */
+static void
+load_library_error_callback(void *arg)
+{
+ LoadLibraryErrorCallbackState *state = (LoadLibraryErrorCallbackState *) arg;
+
+ /*
+ * The errors in internal_load_library() contain the filename, but that's
+ * not the case during _PG_init().
+ */
+ if (state->in_pg_init)
+ errcontext("in \"%s\" callback of library \"%s\"", "_PG_init()", state->libname);
+
+ switch (state->reason)
+ {
+ case LLR_UNSPECIFIED:
+ errcontext("library load for unspecified reason");
+ break;
+ case LLR_GUC:
+ errcontext("library load for \"%s\" parameter", state->detail);
+ break;
+ case LLR_LOAD:
+ errcontext("library load for LOAD statement");
+ break;
+ case LLR_C_FUNCTION:
+ errcontext("library load for C function \"%s\"", state->detail);
+ break;
+ case LLR_RESTORE_LIBRARY_STATE:
+ errcontext("restoring library state in parallel worker");
+ break;
+ }
+}
+
static bool
file_exists(const char *name)
{
@@ -694,7 +773,7 @@ RestoreLibraryState(char *start_address)
{
while (*start_address != '\0')
{
- internal_load_library(start_address);
+ internal_load_library(start_address, LLR_RESTORE_LIBRARY_STATE, NULL);
start_address += strlen(start_address) + 1;
}
}
diff --git a/src/backend/utils/init/miscinit.c b/src/backend/utils/init/miscinit.c
index a604432126c..3476f03c8be 100644
--- a/src/backend/utils/init/miscinit.c
+++ b/src/backend/utils/init/miscinit.c
@@ -1829,7 +1829,7 @@ load_libraries(const char *libraries, const char *gucname, bool restricted)
expanded = psprintf("$libdir/plugins/%s", filename);
filename = expanded;
}
- load_file(filename, restricted);
+ load_file_ext(filename, restricted, LLR_GUC, gucname);
ereport(DEBUG1,
(errmsg_internal("loaded library \"%s\"", filename)));
if (expanded)
diff --git a/contrib/test_decoding/expected/slot.out b/contrib/test_decoding/expected/slot.out
index 63a9940f73a..7d63140f43b 100644
--- a/contrib/test_decoding/expected/slot.out
+++ b/contrib/test_decoding/expected/slot.out
@@ -32,6 +32,7 @@ SELECT 'init' FROM pg_create_logical_replication_slot('regression_slot_t2', 'tes
SELECT pg_create_logical_replication_slot('foo', 'nonexistent');
ERROR: could not access file "nonexistent": No such file or directory
+CONTEXT: library load for C function "_PG_output_plugin_init"
-- here we want to start a new session and wait till old one is gone
select pg_backend_pid() as oldpid \gset
\c -
diff --git a/src/test/regress/expected/create_function_c.out b/src/test/regress/expected/create_function_c.out
index 2dba9d70349..0fc31c8ef89 100644
--- a/src/test/regress/expected/create_function_c.out
+++ b/src/test/regress/expected/create_function_c.out
@@ -18,6 +18,7 @@ LOAD :'regresslib';
CREATE FUNCTION test1 (int) RETURNS int LANGUAGE C
AS 'nosuchfile';
ERROR: could not access file "nosuchfile": No such file or directory
+CONTEXT: library load for C function "test1"
-- To produce stable regression test output, we have to filter the name
-- of the regresslib file out of the error message in this test.
\set VERBOSITY sqlstate
diff --git a/src/tools/pgindent/typedefs.list b/src/tools/pgindent/typedefs.list
index 260854747b4..3292a6c9f3a 100644
--- a/src/tools/pgindent/typedefs.list
+++ b/src/tools/pgindent/typedefs.list
@@ -1431,6 +1431,8 @@ ListenAction
ListenActionKind
ListenStmt
LoInfo
+LoadLibraryReason
+LoadLibraryErrorCallbackState
LoadStmt
LocalBufferLookupEnt
LocalPgBackendStatus
--
2.38.0
