From 0a141e4594dfd3fd35b3e2ba3ecc8f368caabaff Mon Sep 17 00:00:00 2001 From: Kristian Lejao <1741885+lejaokri@users.noreply.github.com> Date: Fri, 26 Jan 2024 14:37:24 -0800 Subject: [PATCH] Crash in SPExecuteSQL because of improper error handling (#2295) When logging statement, SPExecuteSQL and similar function expect that there could be an error hence they surround the ereport call in PG_TRY and PG_CATCH ignoring the error in PG_CATCH and moving one without properly resetting a few things such as MemoryContext and errordata_stack_depth. Task: BABEL-4716 Signed-off-by: Kristian Lejao --- .../babelfishpg_tds/src/backend/tds/tdsrpc.c | 163 +++++------------- test/JDBC/expected/TestTvp.out | 33 ++++ test/JDBC/input/datatypes/TestTvp.txt | 10 +- 3 files changed, 89 insertions(+), 117 deletions(-) diff --git a/contrib/babelfishpg_tds/src/backend/tds/tdsrpc.c b/contrib/babelfishpg_tds/src/backend/tds/tdsrpc.c index 33bdd33c35..4e30cb9927 100644 --- a/contrib/babelfishpg_tds/src/backend/tds/tdsrpc.c +++ b/contrib/babelfishpg_tds/src/backend/tds/tdsrpc.c @@ -151,6 +151,8 @@ static void SPPrepExec(TDSRequestSP req); static void SPCustomType(TDSRequestSP req); static void SPUnprepare(TDSRequestSP req); static void TDSLogStatementCursorHandler(TDSRequestSP req, char *stmt, int option); +static void LogStatementNoError(const char *header, const int handle, const char *msg, const uint16 nparams); + static InlineCodeBlockArgs *DeclareVariables(TDSRequestSP req, FunctionCallInfo *fcinfo, unsigned long options); List *tvp_lookup_list = NIL; bool lockForFaultInjection = false; @@ -580,35 +582,7 @@ SPExecuteSQL(TDSRequestSP req) /* command type - execute (0xe0) */ TdsSendDone(TDS_TOKEN_DONEPROC, TDS_DONE_FINAL, 0xe0, 0); - /* - * Log immediately if dictated by log_statement - */ - if (pltsql_plugin_handler_ptr->stmt_needs_logging || TDS_DEBUG_ENABLED(TDS_DEBUG2)) - { - - ErrorContextCallback *plerrcontext = error_context_stack; - - error_context_stack = plerrcontext->previous; - - /* In certain cases TVP can throw error for errdetail_params. */ - PG_TRY(); - { - ereport(LOG, - (errmsg("sp_executesql statement: %s", s.data), - errhidestmt(true), - errdetail_params(req->nTotalParams))); - } - PG_CATCH(); - { - ereport(LOG, - (errmsg("sp_executesql statement: %s", s.data), - errhidestmt(true))); - } - PG_END_TRY(); - - pltsql_plugin_handler_ptr->stmt_needs_logging = false; - error_context_stack = plerrcontext; - } + LogStatementNoError("sp_executesql:", -1, s.data, req->nTotalParams); /* * Print TDS log duration, if log_duration is set @@ -796,34 +770,7 @@ SPExecute(TDSRequestSP req) /* Command type - execute (0xe0). */ TdsSendDone(TDS_TOKEN_DONEPROC, TDS_DONE_FINAL, 0xe0, 0); - /* - * Log immediately if dictated by log_statement - */ - if (pltsql_plugin_handler_ptr->stmt_needs_logging || TDS_DEBUG_ENABLED(TDS_DEBUG2)) - { - ErrorContextCallback *plerrcontext = error_context_stack; - - error_context_stack = plerrcontext->previous; - - /* In certain cases TVP can throw error for errdetail_params. */ - PG_TRY(); - { - ereport(LOG, - (errmsg("sp_execute handle: %d", req->handle), - errhidestmt(true), - errdetail_params(req->nTotalParams))); - } - PG_CATCH(); - { - ereport(LOG, - (errmsg("sp_execute handle: %d", req->handle), - errhidestmt(true))); - } - PG_END_TRY(); - - pltsql_plugin_handler_ptr->stmt_needs_logging = false; - error_context_stack = plerrcontext; - } + LogStatementNoError("sp_execute", req->handle, "", req->nTotalParams); /* * Print TDS log duration, if log_duration is set @@ -938,36 +885,7 @@ SPPrepExec(TDSRequestSP req) /* command type - execute (0xe0) */ TdsSendDone(TDS_TOKEN_DONEPROC, TDS_DONE_FINAL, 0xe0, 0); - /* - * Log immediately if dictated by log_statement - */ - if (pltsql_plugin_handler_ptr->stmt_needs_logging || TDS_DEBUG_ENABLED(TDS_DEBUG2)) - { - ErrorContextCallback *plerrcontext = error_context_stack; - - error_context_stack = plerrcontext->previous; - - /* In certain cases TVP can throw error for errdetail_params. */ - PG_TRY(); - { - ereport(LOG, - (errmsg("sp_prepexec handle: %d, " - "statement: %s", req->handle, s.data), - errhidestmt(true), - errdetail_params(req->nTotalParams))); - } - PG_CATCH(); - { - ereport(LOG, - (errmsg("sp_prepexec handle: %d, " - "statement: %s", req->handle, s.data), - errhidestmt(true))); - } - PG_END_TRY(); - - pltsql_plugin_handler_ptr->stmt_needs_logging = false; - error_context_stack = plerrcontext; - } + LogStatementNoError("sp_prepexec", req->handle, s.data, req->nTotalParams); /* * Print TDS log duration, if log_duration is set @@ -1190,34 +1108,7 @@ SPCustomType(TDSRequestSP req) /* command type - execute (0xe0) */ TdsSendDone(TDS_TOKEN_DONEPROC, TDS_DONE_FINAL, 0xe0, 0); - /* - * Log immediately if dictated by log_statement - */ - if (pltsql_plugin_handler_ptr->stmt_needs_logging || TDS_DEBUG_ENABLED(TDS_DEBUG2)) - { - ErrorContextCallback *plerrcontext = error_context_stack; - - error_context_stack = plerrcontext->previous; - - /* In certain cases TVP can throw error for errdetail_params. */ - PG_TRY(); - { - ereport(LOG, - (errmsg("stored procedure: %s", req->name.data), - errhidestmt(true), - errdetail_params(req->nTotalParams))); - } - PG_CATCH(); - { - ereport(LOG, - (errmsg("stored procedure: %s", req->name.data), - errhidestmt(true))); - } - PG_END_TRY(); - - pltsql_plugin_handler_ptr->stmt_needs_logging = false; - error_context_stack = plerrcontext; - } + LogStatementNoError("stored procedure:", -1, req->name.data, req->nTotalParams); /* * Print TDS log duration, if log_duration is set @@ -4025,11 +3916,11 @@ TDSLogStatementCursorHandler(TDSRequestSP req, char *stmt, int option) if (pltsql_plugin_handler_ptr->stmt_needs_logging || TDS_DEBUG_ENABLED(TDS_DEBUG2)) { ErrorContextCallback *plerrcontext = error_context_stack; - error_context_stack = plerrcontext->previous; switch (option) { + case PRINT_CURSOR_HANDLE: ereport(LOG, (errmsg("sp_cursor handle: %d; statement: %s", @@ -4050,6 +3941,7 @@ TDSLogStatementCursorHandler(TDSRequestSP req, char *stmt, int option) req->cursorHandle, req->cursorPreparedHandle, stmt), errhidestmt(true), errdetail_params(req->nTotalParams))); + break; default: break; @@ -4062,3 +3954,42 @@ TDSLogStatementCursorHandler(TDSRequestSP req, char *stmt, int option) /* Print TDS log duration, if log_duration is set */ TDSLogDuration(stmt); } + +/* + * Log msg ignoring any error during ereport. + * This should only be called when it is safe to call FlushErrorState + * ie: ignoring any previous error that happened prior + * */ +static void LogStatementNoError(const char *header, const int handle, const char *msg, const uint16 nparams) +{ + MemoryContext curr = CurrentMemoryContext; + + ErrorContextCallback *plerrcontext = error_context_stack; + error_context_stack = plerrcontext->previous; + + if (pltsql_plugin_handler_ptr->stmt_needs_logging || TDS_DEBUG_ENABLED(TDS_DEBUG2)) + { + PG_TRY(); + { + ereport(LOG, + (errmsg("%s handle: %d " + "statement: %s", + header, handle, msg), + errhidestmt(true), + errdetail_params(nparams))); + } + PG_CATCH(); + { + MemoryContextSwitchTo(curr); + FlushErrorState(); + + ereport(LOG, + (errmsg("%s statement: %s", header, msg), + errhidestmt(true))); + } + PG_END_TRY(); + } + + pltsql_plugin_handler_ptr->stmt_needs_logging = false; + error_context_stack = plerrcontext; +} diff --git a/test/JDBC/expected/TestTvp.out b/test/JDBC/expected/TestTvp.out index 91df4b3de2..65f9395d94 100644 --- a/test/JDBC/expected/TestTvp.out +++ b/test/JDBC/expected/TestTvp.out @@ -1,12 +1,45 @@ create type tableType as table (a int, b smallint) create type table_variable_vu_type as table (a text not null, b int primary key, c int, d int) create proc table_variable_vu_proc1 (@x table_variable_vu_type readonly) as begin select tvp.b from @x tvp end + prepst#!#Select * from ? #!#tvp|-|tableType|-|utils/tvp-dotnet.csv|-|utils/tvp-dotnet.csv ~~START~~ int#!#smallint 1#!#1 ~~END~~ +prepst#!#Select * from ? #!#tvp|-|tableType|-|utils/tvp-dotnet.csv|-|utils/tvp-dotnet.csv +~~START~~ +int#!#smallint +1#!#1 +~~END~~ + +prepst#!#Select * from ? #!#tvp|-|tableType|-|utils/tvp-dotnet.csv|-|utils/tvp-dotnet.csv +~~START~~ +int#!#smallint +1#!#1 +~~END~~ + +prepst#!#Select * from ? #!#tvp|-|tableType|-|utils/tvp-dotnet.csv|-|utils/tvp-dotnet.csv +~~START~~ +int#!#smallint +1#!#1 +~~END~~ + +prepst#!#Select * from ? #!#tvp|-|tableType|-|utils/tvp-dotnet.csv|-|utils/tvp-dotnet.csv +~~START~~ +int#!#smallint +1#!#1 +~~END~~ + +prepst#!#Select * from ? #!#tvp|-|tableType|-|utils/tvp-dotnet.csv|-|utils/tvp-dotnet.csv +~~START~~ +int#!#smallint +1#!#1 +~~END~~ + + + declare @var1 table_variable_vu_type insert into @var1 values ('1', 2, 3, 4) exec sp_executesql N'EXEC table_variable_vu_proc1 @x = @p0', N'@p0 table_variable_vu_type readonly', @p0=@var1 ~~ROW COUNT: 1~~ diff --git a/test/JDBC/input/datatypes/TestTvp.txt b/test/JDBC/input/datatypes/TestTvp.txt index e978ef0501..929a217774 100644 --- a/test/JDBC/input/datatypes/TestTvp.txt +++ b/test/JDBC/input/datatypes/TestTvp.txt @@ -1,8 +1,16 @@ create type tableType as table (a int, b smallint) create type table_variable_vu_type as table (a text not null, b int primary key, c int, d int) create proc table_variable_vu_proc1 (@x table_variable_vu_type readonly) as begin select tvp.b from @x tvp end + prepst#!#Select * from @a #!#tvp|-|tableType|-|utils/tvp-dotnet.csv|-|utils/tvp-dotnet.csv +prepst#!#Select * from @a #!#tvp|-|tableType|-|utils/tvp-dotnet.csv|-|utils/tvp-dotnet.csv +prepst#!#Select * from @a #!#tvp|-|tableType|-|utils/tvp-dotnet.csv|-|utils/tvp-dotnet.csv +prepst#!#Select * from @a #!#tvp|-|tableType|-|utils/tvp-dotnet.csv|-|utils/tvp-dotnet.csv +prepst#!#Select * from @a #!#tvp|-|tableType|-|utils/tvp-dotnet.csv|-|utils/tvp-dotnet.csv +prepst#!#Select * from @a #!#tvp|-|tableType|-|utils/tvp-dotnet.csv|-|utils/tvp-dotnet.csv + + declare @var1 table_variable_vu_type insert into @var1 values ('1', 2, 3, 4) exec sp_executesql N'EXEC table_variable_vu_proc1 @x = @p0', N'@p0 table_variable_vu_type readonly', @p0=@var1 drop procedure table_variable_vu_proc1; drop type table_variable_vu_type; -drop type tableType; \ No newline at end of file +drop type tableType;