From eb0f55f02fc54e4777cf84b92838c4cb9c749855 Mon Sep 17 00:00:00 2001 From: Tom Lane Date: Sat, 28 Sep 2024 14:59:26 -0400 Subject: [PATCH v3 2/2] Improve reporting of errors in extension script files. Previously, CREATE/ALTER EXTENSION gave basically no useful context about errors reported while executing script files. I think the idea was that you could run the same commands manually to see the error, but that's often quite inconvenient. Let's improve that. In the case of a syntax error (or anything reported with an error cursor), just report the whole script file as the "internal query". This might be annoyingly long, but it seems more difficult than it's worth to try to shorten it to something relevant. There are interactions with libpq's reportErrorPosition logic to worry about, for example: it seems like a good idea that the line number that that code reports match up with the true line number within the script. Possibly someone will come back to this area later. Without an error cursor, if we have gotten past raw parsing (which we probably have), we can report just the current SQL statement as an item of error context. In any case also report the script file name as error context, since it might not be entirely obvious which of a series of update scripts failed. The error-context code path is already exercised by some test_extensions test cases, but add tests for the syntax-error path. Discussion: https://postgr.es/m/ZvV1ClhnbJLCz7Sm@msg.df7cb.de --- src/backend/commands/extension.c | 91 ++++++++++++++++++- src/test/modules/test_extensions/Makefile | 4 +- .../expected/test_extensions.out | 52 +++++++++++ src/test/modules/test_extensions/meson.build | 2 + .../test_extensions/sql/test_extensions.sql | 4 + .../test_ext7--2.0--2.1bad.sql | 11 +++ .../test_ext7--2.0--2.2bad.sql | 13 +++ src/tools/pgindent/typedefs.list | 1 + 8 files changed, 175 insertions(+), 3 deletions(-) create mode 100644 src/test/modules/test_extensions/test_ext7--2.0--2.1bad.sql create mode 100644 src/test/modules/test_extensions/test_ext7--2.0--2.2bad.sql diff --git a/src/backend/commands/extension.c b/src/backend/commands/extension.c index fab59ad5f6..ed5ab2c556 100644 --- a/src/backend/commands/extension.c +++ b/src/backend/commands/extension.c @@ -54,6 +54,7 @@ #include "funcapi.h" #include "mb/pg_wchar.h" #include "miscadmin.h" +#include "nodes/queryjumble.h" #include "storage/fd.h" #include "tcop/utility.h" #include "utils/acl.h" @@ -107,6 +108,17 @@ typedef struct ExtensionVersionInfo struct ExtensionVersionInfo *previous; /* current best predecessor */ } ExtensionVersionInfo; +/* + * Information for script_error_callback() + */ +typedef struct +{ + const char *sql; /* entire script file contents */ + const char *filename; /* script file pathname */ + ParseLoc stmt_location; /* current stmt start loc, or -1 if unknown */ + ParseLoc stmt_len; /* length in bytes; 0 means "rest of string" */ +} script_error_callback_arg; + /* Local functions */ static List *find_update_path(List *evi_list, ExtensionVersionInfo *evi_start, @@ -670,9 +682,63 @@ read_extension_script_file(const ExtensionControlFile *control, return dest_str; } +/* + * error context callback for failures in script-file execution + */ +static void +script_error_callback(void *arg) +{ + script_error_callback_arg *callback_arg = (script_error_callback_arg *) arg; + int syntaxerrposition; + const char *lastslash; + + /* + * If there is a syntax error position, convert to internal syntax error; + * otherwise report the current query as an item of context stack + */ + syntaxerrposition = geterrposition(); + if (syntaxerrposition > 0) + { + /* + * We must report the whole string because otherwise details such as + * psql's line number report would be wrong. + */ + errposition(0); + internalerrposition(syntaxerrposition); + internalerrquery(callback_arg->sql); + } + else if (callback_arg->stmt_location >= 0) + { + /* + * Since no syntax cursor will be shown, it's okay and helpful to trim + * the reported query string to just the current statement. + */ + const char *query = callback_arg->sql; + int location = callback_arg->stmt_location; + int len = callback_arg->stmt_len; + + query = CleanQuerytext(query, &location, &len); + errcontext("SQL statement \"%.*s\"", len, query); + } + + /* + * Trim the reported file name to remove the path. We know that + * get_extension_script_filename() inserted a '/', regardless of whether + * we're on Windows. + */ + lastslash = strrchr(callback_arg->filename, '/'); + if (lastslash) + lastslash++; + else + lastslash = callback_arg->filename; /* shouldn't happen, but cope */ + errcontext("extension script file \"%s\"", lastslash); +} + /* * Execute given SQL string. * + * The filename the string came from is also provided, for error reporting. + * * Note: it's tempting to just use SPI to execute the string, but that does * not work very well. The really serious problem is that SPI will parse, * analyze, and plan the whole string before executing any of it; of course @@ -682,12 +748,27 @@ read_extension_script_file(const ExtensionControlFile *control, * could be very long. */ static void -execute_sql_string(const char *sql) +execute_sql_string(const char *sql, const char *filename) { + script_error_callback_arg callback_arg; + ErrorContextCallback scripterrcontext; List *raw_parsetree_list; DestReceiver *dest; ListCell *lc1; + /* + * Setup error traceback support for ereport(). + */ + callback_arg.sql = sql; + callback_arg.filename = filename; + callback_arg.stmt_location = -1; + callback_arg.stmt_len = -1; + + scripterrcontext.callback = script_error_callback; + scripterrcontext.arg = (void *) &callback_arg; + scripterrcontext.previous = error_context_stack; + error_context_stack = &scripterrcontext; + /* * Parse the SQL string into a list of raw parse trees. */ @@ -709,6 +790,10 @@ execute_sql_string(const char *sql) List *stmt_list; ListCell *lc2; + /* Report location of this query for error context callback */ + callback_arg.stmt_location = parsetree->stmt_location; + callback_arg.stmt_len = parsetree->stmt_len; + /* * We do the work for each parsetree in a short-lived context, to * limit the memory used when there are many commands in the string. @@ -778,6 +863,8 @@ execute_sql_string(const char *sql) MemoryContextDelete(per_parsetree_context); } + error_context_stack = scripterrcontext.previous; + /* Be sure to advance the command counter after the last script command */ CommandCounterIncrement(); } @@ -1054,7 +1141,7 @@ execute_extension_script(Oid extensionOid, ExtensionControlFile *control, /* And now back to C string */ c_sql = text_to_cstring(DatumGetTextPP(t_sql)); - execute_sql_string(c_sql); + execute_sql_string(c_sql, filename); } PG_FINALLY(); { diff --git a/src/test/modules/test_extensions/Makefile b/src/test/modules/test_extensions/Makefile index 05272e6a40..1dbec14cba 100644 --- a/src/test/modules/test_extensions/Makefile +++ b/src/test/modules/test_extensions/Makefile @@ -13,7 +13,9 @@ EXTENSION = test_ext1 test_ext2 test_ext3 test_ext4 test_ext5 test_ext6 \ DATA = test_ext1--1.0.sql test_ext2--1.0.sql test_ext3--1.0.sql \ test_ext4--1.0.sql test_ext5--1.0.sql test_ext6--1.0.sql \ - test_ext7--1.0.sql test_ext7--1.0--2.0.sql test_ext8--1.0.sql \ + test_ext7--1.0.sql test_ext7--1.0--2.0.sql \ + test_ext7--2.0--2.1bad.sql test_ext7--2.0--2.2bad.sql \ + test_ext8--1.0.sql \ test_ext9--1.0.sql \ test_ext_cine--1.0.sql test_ext_cine--1.0--1.1.sql \ test_ext_cor--1.0.sql \ diff --git a/src/test/modules/test_extensions/expected/test_extensions.out b/src/test/modules/test_extensions/expected/test_extensions.out index f357cc21aa..dfe0596888 100644 --- a/src/test/modules/test_extensions/expected/test_extensions.out +++ b/src/test/modules/test_extensions/expected/test_extensions.out @@ -72,6 +72,32 @@ Objects in extension "test_ext7" type ext7_table2[] (4 rows) +-- test reporting of errors in extension scripts +alter extension test_ext7 update to '2.1bad'; +ERROR: syntax error at or near "FUNCTIN" +LINE 7: CREATE FUNCTIN my_erroneous_func(int) RETURNS int LANGUAGE S... + ^ +QUERY: /* src/test/modules/test_extensions/test_ext7--2.0--2.1bad.sql */ + +-- complain if script is sourced in psql, rather than via ALTER EXTENSION + + +-- test reporting of a simple syntax error in an extension script +CREATE FUNCTIN my_erroneous_func(int) RETURNS int LANGUAGE SQL +AS $$ SELECT $1 + 1 $$; + +CREATE FUNCTION my_other_func(int) RETURNS int LANGUAGE SQL +AS $$ SELECT $1 + 1 $$; + +CONTEXT: extension script file "test_ext7--2.0--2.1bad.sql" +alter extension test_ext7 update to '2.2bad'; +ERROR: syntax error at or near "," +LINE 1: SELECT $1 + , 1 + ^ +QUERY: SELECT $1 + , 1 +CONTEXT: SQL statement "CREATE FUNCTION my_erroneous_func(int) RETURNS int LANGUAGE SQL +AS $$ SELECT $1 + , 1 $$" +extension script file "test_ext7--2.0--2.2bad.sql" -- test handling of temp objects created by extensions create extension test_ext8; -- \dx+ would expose a variable pg_temp_nn schema name, so we can't use it here @@ -295,6 +321,9 @@ CREATE FUNCTION ext_cor_func() RETURNS text CREATE EXTENSION test_ext_cor; -- fail ERROR: function ext_cor_func() is not a member of extension "test_ext_cor" DETAIL: An extension is not allowed to replace an object that it does not own. +CONTEXT: SQL statement "CREATE OR REPLACE FUNCTION ext_cor_func() RETURNS text + AS $$ SELECT 'ext_cor_func: from extension'::text $$ LANGUAGE sql" +extension script file "test_ext_cor--1.0.sql" SELECT ext_cor_func(); ext_cor_func ------------------------ @@ -307,6 +336,9 @@ CREATE VIEW ext_cor_view AS CREATE EXTENSION test_ext_cor; -- fail ERROR: view ext_cor_view is not a member of extension "test_ext_cor" DETAIL: An extension is not allowed to replace an object that it does not own. +CONTEXT: SQL statement "CREATE OR REPLACE VIEW ext_cor_view AS + SELECT 'ext_cor_view: from extension'::text AS col" +extension script file "test_ext_cor--1.0.sql" SELECT ext_cor_func(); ERROR: function ext_cor_func() does not exist LINE 1: SELECT ext_cor_func(); @@ -323,6 +355,8 @@ CREATE TYPE test_ext_type; CREATE EXTENSION test_ext_cor; -- fail ERROR: type test_ext_type is not a member of extension "test_ext_cor" DETAIL: An extension is not allowed to replace an object that it does not own. +CONTEXT: SQL statement "CREATE TYPE test_ext_type AS ENUM('x', 'y')" +extension script file "test_ext_cor--1.0.sql" DROP TYPE test_ext_type; -- this makes a shell "point <<@@ polygon" operator too CREATE OPERATOR @@>> ( PROCEDURE = poly_contain_pt, @@ -331,6 +365,9 @@ CREATE OPERATOR @@>> ( PROCEDURE = poly_contain_pt, CREATE EXTENSION test_ext_cor; -- fail ERROR: operator <<@@(point,polygon) is not a member of extension "test_ext_cor" DETAIL: An extension is not allowed to replace an object that it does not own. +CONTEXT: SQL statement "CREATE OPERATOR <<@@ ( PROCEDURE = pt_contained_poly, + LEFTARG = point, RIGHTARG = polygon )" +extension script file "test_ext_cor--1.0.sql" DROP OPERATOR <<@@ (point, polygon); CREATE EXTENSION test_ext_cor; -- now it should work SELECT ext_cor_func(); @@ -379,37 +416,52 @@ CREATE COLLATION ext_cine_coll CREATE EXTENSION test_ext_cine; -- fail ERROR: collation ext_cine_coll is not a member of extension "test_ext_cine" DETAIL: An extension may only use CREATE ... IF NOT EXISTS to skip object creation if the conflicting object is one that it already owns. +CONTEXT: SQL statement "CREATE COLLATION IF NOT EXISTS ext_cine_coll + ( LC_COLLATE = "POSIX", LC_CTYPE = "POSIX" )" +extension script file "test_ext_cine--1.0.sql" DROP COLLATION ext_cine_coll; CREATE MATERIALIZED VIEW ext_cine_mv AS SELECT 11 AS f1; CREATE EXTENSION test_ext_cine; -- fail ERROR: materialized view ext_cine_mv is not a member of extension "test_ext_cine" DETAIL: An extension may only use CREATE ... IF NOT EXISTS to skip object creation if the conflicting object is one that it already owns. +CONTEXT: SQL statement "CREATE MATERIALIZED VIEW IF NOT EXISTS ext_cine_mv AS SELECT 42 AS f1" +extension script file "test_ext_cine--1.0.sql" DROP MATERIALIZED VIEW ext_cine_mv; CREATE FOREIGN DATA WRAPPER dummy; CREATE SERVER ext_cine_srv FOREIGN DATA WRAPPER dummy; CREATE EXTENSION test_ext_cine; -- fail ERROR: server ext_cine_srv is not a member of extension "test_ext_cine" DETAIL: An extension may only use CREATE ... IF NOT EXISTS to skip object creation if the conflicting object is one that it already owns. +CONTEXT: SQL statement "CREATE SERVER IF NOT EXISTS ext_cine_srv FOREIGN DATA WRAPPER ext_cine_fdw" +extension script file "test_ext_cine--1.0.sql" DROP SERVER ext_cine_srv; CREATE SCHEMA ext_cine_schema; CREATE EXTENSION test_ext_cine; -- fail ERROR: schema ext_cine_schema is not a member of extension "test_ext_cine" DETAIL: An extension may only use CREATE ... IF NOT EXISTS to skip object creation if the conflicting object is one that it already owns. +CONTEXT: SQL statement "CREATE SCHEMA IF NOT EXISTS ext_cine_schema" +extension script file "test_ext_cine--1.0.sql" DROP SCHEMA ext_cine_schema; CREATE SEQUENCE ext_cine_seq; CREATE EXTENSION test_ext_cine; -- fail ERROR: sequence ext_cine_seq is not a member of extension "test_ext_cine" DETAIL: An extension may only use CREATE ... IF NOT EXISTS to skip object creation if the conflicting object is one that it already owns. +CONTEXT: SQL statement "CREATE SEQUENCE IF NOT EXISTS ext_cine_seq" +extension script file "test_ext_cine--1.0.sql" DROP SEQUENCE ext_cine_seq; CREATE TABLE ext_cine_tab1 (x int); CREATE EXTENSION test_ext_cine; -- fail ERROR: table ext_cine_tab1 is not a member of extension "test_ext_cine" DETAIL: An extension may only use CREATE ... IF NOT EXISTS to skip object creation if the conflicting object is one that it already owns. +CONTEXT: SQL statement "CREATE TABLE IF NOT EXISTS ext_cine_tab1 (x int)" +extension script file "test_ext_cine--1.0.sql" DROP TABLE ext_cine_tab1; CREATE TABLE ext_cine_tab2 AS SELECT 42 AS y; CREATE EXTENSION test_ext_cine; -- fail ERROR: table ext_cine_tab2 is not a member of extension "test_ext_cine" DETAIL: An extension may only use CREATE ... IF NOT EXISTS to skip object creation if the conflicting object is one that it already owns. +CONTEXT: SQL statement "CREATE TABLE IF NOT EXISTS ext_cine_tab2 AS SELECT 42 AS y" +extension script file "test_ext_cine--1.0.sql" DROP TABLE ext_cine_tab2; CREATE EXTENSION test_ext_cine; \dx+ test_ext_cine diff --git a/src/test/modules/test_extensions/meson.build b/src/test/modules/test_extensions/meson.build index c5f3424da5..2b31cbf425 100644 --- a/src/test/modules/test_extensions/meson.build +++ b/src/test/modules/test_extensions/meson.build @@ -15,6 +15,8 @@ test_install_data += files( 'test_ext6.control', 'test_ext7--1.0--2.0.sql', 'test_ext7--1.0.sql', + 'test_ext7--2.0--2.1bad.sql', + 'test_ext7--2.0--2.2bad.sql', 'test_ext7.control', 'test_ext8--1.0.sql', 'test_ext8.control', diff --git a/src/test/modules/test_extensions/sql/test_extensions.sql b/src/test/modules/test_extensions/sql/test_extensions.sql index 642c82ff5d..b5878f6f80 100644 --- a/src/test/modules/test_extensions/sql/test_extensions.sql +++ b/src/test/modules/test_extensions/sql/test_extensions.sql @@ -28,6 +28,10 @@ create extension test_ext7; alter extension test_ext7 update to '2.0'; \dx+ test_ext7 +-- test reporting of errors in extension scripts +alter extension test_ext7 update to '2.1bad'; +alter extension test_ext7 update to '2.2bad'; + -- test handling of temp objects created by extensions create extension test_ext8; diff --git a/src/test/modules/test_extensions/test_ext7--2.0--2.1bad.sql b/src/test/modules/test_extensions/test_ext7--2.0--2.1bad.sql new file mode 100644 index 0000000000..910b1d4f38 --- /dev/null +++ b/src/test/modules/test_extensions/test_ext7--2.0--2.1bad.sql @@ -0,0 +1,11 @@ +/* src/test/modules/test_extensions/test_ext7--2.0--2.1bad.sql */ + +-- complain if script is sourced in psql, rather than via ALTER EXTENSION +\echo Use "ALTER EXTENSION test_ext7 UPDATE TO '2.1bad'" to load this file. \quit + +-- test reporting of a simple syntax error in an extension script +CREATE FUNCTIN my_erroneous_func(int) RETURNS int LANGUAGE SQL +AS $$ SELECT $1 + 1 $$; + +CREATE FUNCTION my_other_func(int) RETURNS int LANGUAGE SQL +AS $$ SELECT $1 + 1 $$; diff --git a/src/test/modules/test_extensions/test_ext7--2.0--2.2bad.sql b/src/test/modules/test_extensions/test_ext7--2.0--2.2bad.sql new file mode 100644 index 0000000000..19aa9bf264 --- /dev/null +++ b/src/test/modules/test_extensions/test_ext7--2.0--2.2bad.sql @@ -0,0 +1,13 @@ +/* src/test/modules/test_extensions/test_ext7--2.0--2.2bad.sql */ + +-- complain if script is sourced in psql, rather than via ALTER EXTENSION +\echo Use "ALTER EXTENSION test_ext7 UPDATE TO '2.2bad'" to load this file. \quit + +-- test reporting of a nested syntax error in an extension script +SET LOCAL check_function_bodies = on; + +CREATE FUNCTION my_erroneous_func(int) RETURNS int LANGUAGE SQL +AS $$ SELECT $1 + , 1 $$; + +CREATE FUNCTION my_other_func(int) RETURNS int LANGUAGE SQL +AS $$ SELECT $1 + 1 $$; diff --git a/src/tools/pgindent/typedefs.list b/src/tools/pgindent/typedefs.list index 5fabb127d7..964f51f429 100644 --- a/src/tools/pgindent/typedefs.list +++ b/src/tools/pgindent/typedefs.list @@ -3883,6 +3883,7 @@ saophash_hash save_buffer scram_state scram_state_enum +script_error_callback_arg security_class_t sem_t sepgsql_context_info_t -- 2.43.5