Обсуждение: pltcl crashes due to a syntax error

Hello hackers,

When executing the following query on master branch:

CREATE EXTENSION pltcl;
CREATE or replace PROCEDURE test_proc5(INOUT a text)
         LANGUAGE pltcl
         AS $$
         set aa [concat $1 "+" $1]
         return [list $aa $aa])
         $$;

CALL test_proc5('abc');
CREATE EXTENSION
CREATE PROCEDURE
server closed the connection unexpectedly
         This probably means the server terminated abnormally
         before or while processing the request.
The connection to the server was lost. Attempting reset: Failed.

The connection to the server was lost. Attempting reset: Failed.


Core was generated by `postgres: postgres postgres [loca'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  __strlen_sse2 () at ../sysdeps/x86_64/multiarch/strlen-sse2.S:142
142     ../sysdeps/x86_64/multiarch/strlen-sse2.S: No such file or 
directory.
(gdb) bt
#0  __strlen_sse2 () at ../sysdeps/x86_64/multiarch/strlen-sse2.S:142
#1  0x00007f5f1353ba6a in utf_u2e (src=0x0) at pltcl.c:77
#2  0x00007f5f1353c9f7 in throw_tcl_error (interp=0x55ec24bdaf70, 
proname=0x55ec24b6b140 "test_proc5") at pltcl.c:1373
#3  0x00007f5f1353ed64 in pltcl_func_handler 
(fcinfo=fcinfo@entry=0x7ffdbfb407a0, 
call_state=call_state@entry=0x7ffdbfb405d0, 
pltrusted=pltrusted@entry=true) at pltcl.c:1029
#4  0x00007f5f1353ee8d in pltcl_handler (fcinfo=0x7ffdbfb407a0, 
pltrusted=pltrusted@entry=true) at pltcl.c:765
#5  0x00007f5f1353f1ef in pltcl_call_handler (fcinfo=<optimized out>) at 
pltcl.c:698
#6  0x000055ec239ec64a in ExecuteCallStmt 
(stmt=stmt@entry=0x55ec24a9a940, params=params@entry=0x0, 
atomic=atomic@entry=false, dest=dest@entry=0x55ec24a6ea18) at 
functioncmds.c:2285
#7  0x000055ec23c103a7 in standard_ProcessUtility (pstmt=0x55ec24a9a9d8, 
queryString=0x55ec24a99e68 "CALL test_proc5('abc');", 
readOnlyTree=<optimized out>, context=PROCESS_UTILITY_TOPLEVEL, 
params=0x0, queryEnv=0x0, dest=0x55ec24a6ea18,
     qc=0x7ffdbfb40f40) at utility.c:851
#8  0x000055ec23c1081b in ProcessUtility 
(pstmt=pstmt@entry=0x55ec24a9a9d8, queryString=<optimized out>, 
readOnlyTree=<optimized out>, 
context=context@entry=PROCESS_UTILITY_TOPLEVEL, params=<optimized out>, 
queryEnv=<optimized out>,
     dest=0x55ec24a6ea18, qc=0x7ffdbfb40f40) at utility.c:523
#9  0x000055ec23c0e04e in PortalRunUtility 
(portal=portal@entry=0x55ec24b18108, pstmt=0x55ec24a9a9d8, 
isTopLevel=isTopLevel@entry=true, 
setHoldSnapshot=setHoldSnapshot@entry=true, 
dest=dest@entry=0x55ec24a6ea18, qc=qc@entry=0x7ffdbfb40f40)
     at pquery.c:1158
#10 0x000055ec23c0e3b7 in FillPortalStore 
(portal=portal@entry=0x55ec24b18108, isTopLevel=isTopLevel@entry=true) 
at pquery.c:1031
#11 0x000055ec23c0e6ee in PortalRun (portal=portal@entry=0x55ec24b18108, 
count=count@entry=9223372036854775807, isTopLevel=isTopLevel@entry=true, 
run_once=run_once@entry=true, dest=dest@entry=0x55ec24a9aec8, 
altdest=altdest@entry=0x55ec24a9aec8,
     qc=0x7ffdbfb41130) at pquery.c:763
#12 0x000055ec23c0acca in exec_simple_query 
(query_string=query_string@entry=0x55ec24a99e68 "CALL 
test_proc5('abc');") at postgres.c:1274
#13 0x000055ec23c0caad in PostgresMain (dbname=<optimized out>, 
username=<optimized out>) at postgres.c:4680
#14 0x000055ec23c0687a in BackendMain (startup_data=<optimized out>, 
startup_data_len=<optimized out>) at backend_startup.c:105
#15 0x000055ec23b766bf in postmaster_child_launch 
(child_type=child_type@entry=B_BACKEND, 
startup_data=startup_data@entry=0x7ffdbfb41354 "", 
startup_data_len=startup_data_len@entry=4, 
client_sock=client_sock@entry=0x7ffdbfb41390)
     at launch_backend.c:265
#16 0x000055ec23b7ab36 in BackendStartup 
(client_sock=client_sock@entry=0x7ffdbfb41390) at postmaster.c:3593
#17 0x000055ec23b7adb0 in ServerLoop () at postmaster.c:1674
#18 0x000055ec23b7c20c in PostmasterMain (argc=argc@entry=3, 
argv=argv@entry=0x55ec24a54030) at postmaster.c:1372
#19 0x000055ec23aacf9f in main (argc=3, argv=0x55ec24a54030) at main.c:197

"a.kozhemyakin" <a.kozhemyakin@postgrespro.ru> writes:
> When executing the following query on master branch:

> CREATE EXTENSION pltcl;
> CREATE or replace PROCEDURE test_proc5(INOUT a text)
>          LANGUAGE pltcl
>          AS $$
>          set aa [concat $1 "+" $1]
>          return [list $aa $aa])
>          $$;

> CALL test_proc5('abc');
> CREATE EXTENSION
> CREATE PROCEDURE
> server closed the connection unexpectedly

Replicated here.  I'll look into it later if nobody beats me
to it.  Thanks for the report!

            regards, tom lane

On 2024-06-02 14:32 +0200, Pierre Forstmann wrote:
> I understand that Tcl_GetVar should not be used any more and should be
> replaced by Tcl_GetStringResult
> (but I know nothing about Tcl internals)
> 
> Following patch :
> diff postgres/src/pl/tcl/pltcl.c.orig postgres/src/pl/tcl/pltcl.c
> 1373c1373,1376
> <       econtext = utf_u2e(Tcl_GetVar(interp, "errorInfo",
> TCL_GLOBAL_ONLY));
> ---
> >       /*
> >        * econtext = utf_u2e(Tcl_GetVar(interp, "errorInfo",
> TCL_GLOBAL_ONLY));
> >        */
> >       econtext = utf_u2e(Tcl_GetStringResult(interp));
> 
> gives:
> 
> pierre=# CREATE OR REPLACE PROCEDURE test_proc(INOUT a text)
>  AS $$
>  set aa [concat $1 "+" $1]
>  return [list $aa $aa])
>  $$
>  LANGUAGE pltcl;
> CREATE PROCEDURE
> pierre=# CALL test_proc('abc');
> 2024-06-02 14:22:45.223 CEST [61649] ERROR:  list element in braces
> followed by ")" instead of space
> 2024-06-02 14:22:45.223 CEST [61649] CONTEXT:  list element in braces
> followed by ")" instead of space
> in PL/Tcl function "test_proc"
> 2024-06-02 14:22:45.223 CEST [61649] STATEMENT:  CALL test_proc('abc');
> ERROR:  list element in braces followed by ")" instead of space
> CONTEXT:  list element in braces followed by ")" instead of space
> in PL/Tcl function "test_proc"

Tcl_GetStringResult is already used for emsg.  Setting econtext to same
string is rather pointless.  The problem is that Tcl_ListObjGetElements
does not set errorInfo if conversion fails.  From the manpage:

"If listPtr is not already a list value, Tcl_ListObjGetElements will
 attempt to convert it to one; if the conversion fails, it returns
 TCL_ERROR and leaves an error message in the interpreter's result value
 if interp is not NULL."

Tcl_GetVar returns null if errorInfo does not exist.  Omitting econtext
from errcontext in that case looks like the proper fix to me.

Or just do away with throw_tcl_error and call ereport directly.  Compare
that to pltcl_trigger_handler where the same case is handled like this:

    /************************************************************
     * Otherwise, the return value should be a column name/value list
     * specifying the modified tuple to return.
     ************************************************************/
    if (Tcl_ListObjGetElements(interp, Tcl_GetObjResult(interp),
                               &result_Objc, &result_Objv) != TCL_OK)
        ereport(ERROR,
                (errcode(ERRCODE_E_R_I_E_TRIGGER_PROTOCOL_VIOLATED),
                 errmsg("could not split return value from trigger: %s",
                        utf_u2e(Tcl_GetStringResult(interp)))));

-- 
Erik

Erik Wienhold <ewie@ewie.name> writes:
> Tcl_GetVar returns null if errorInfo does not exist.  Omitting econtext
> from errcontext in that case looks like the proper fix to me.

Yeah, that was the conclusion I came to last night while sitting in
the airport, but I didn't have time to prepare a cleaned-up patch.

The new bit of information that this bug report provides is that it's
possible to get a TCL_ERROR result without Tcl having set errorInfo.
That seems a tad odd, and it must happen only in weird corner cases,
else we'd have heard of this decades ago.  Not sure if it's worth
trying to characterize those cases further, however.

> Or just do away with throw_tcl_error and call ereport directly.

I'd say this adds to the importance of having throw_tcl_error,
because now it's even more complex than before, and there are
multiple call sites.

> Compare
> that to pltcl_trigger_handler where the same case is handled like this:

Hm, I wonder why that's not using throw_tcl_error.  I guess because
it wants to give its own primary message, but still ...

            regards, tom lane

On 2024-06-03 00:15 +0200, Tom Lane wrote:
> The new bit of information that this bug report provides is that it's
> possible to get a TCL_ERROR result without Tcl having set errorInfo.
> That seems a tad odd, and it must happen only in weird corner cases,
> else we'd have heard of this decades ago.  Not sure if it's worth
> trying to characterize those cases further, however.

ISTM that errorInfo is set automatically only during script evaluation.
The Tcl_AddErrorInfo manpage says:

"The -errorinfo option value is gradually built up as an error unwinds
 through the nested operations.  Each time an error code is returned to
 Tcl_Eval, or any of the routines that performs script evaluation, the
 procedure Tcl_AddErrorInfo is called to add additional text to the
 -errorinfo value describing the command that was being executed when
 the error occurred.  By the time the error has been passed all the way
 back to the application, it will contain a complete trace of the
 activity in progress when the error occurred."

Tcl 8.4 basically uses the same wording.

Except for the reported case, we only call throw_tcl_error in three
places, all after checking the return code from Tcl_EvalObjEx.  And this
one Tcl_ListObjGetElements instance is not called during script
evaluation.

> > Or just do away with throw_tcl_error and call ereport directly.
> 
> I'd say this adds to the importance of having throw_tcl_error,
> because now it's even more complex than before, and there are
> multiple call sites.

I agree to have some uniform error handling.  But from the current usage
it looks as if throw_tcl_error is tied to Tcl_EvalObjEx.

-- 
Erik

Erik Wienhold <ewie@ewie.name> writes:
> On 2024-06-03 00:15 +0200, Tom Lane wrote:
>> The new bit of information that this bug report provides is that it's
>> possible to get a TCL_ERROR result without Tcl having set errorInfo.
>> That seems a tad odd, and it must happen only in weird corner cases,
>> else we'd have heard of this decades ago.  Not sure if it's worth
>> trying to characterize those cases further, however.

> ISTM that errorInfo is set automatically only during script evaluation.

Yeah, I've just come to the same conclusion.  Changing throw_tcl_error
to ignore errorInfo if it's unset would be wrong, because that implies
that the function we called doesn't fill errorInfo.  I found by
testing that it's actually possible that errorInfo contains leftover
text from a previous error (that might not even have been in the same
function), resulting in completely confusing/misleading output.

So your thought that we should just not use throw_tcl_error here
was correct, and a minimal fix could look like the attached.

I thought about going further and creating a different function that
could be used in such cases, but we seem to have only the two
Tcl_ListObjGetElements() calls that could use it, so for now I think
it's not worth the trouble.

Also, compile_pltcl_function contains a Tcl_EvalEx() call that
presumably could use throw_tcl_error, except it wants to add "could
not create internal procedure" which would require some refactoring.
As far as I can tell that error case is not reproducibly reachable,
as it'd require OOM or some other problem inside Tcl, so (a) it's
probably not worth troubling over and (b) changing it is a bit scary
for lack of ability to test.  I'm inclined to leave that alone too.

The other thing I noticed while looking at this is that the error text
for the other Tcl_ListObjGetElements() call seems a bit confusingly
worded: "could not split return value from trigger: %s".  You could
easily read that as suggesting that the return value is somehow
attached to the trigger and has to be separated from it.  I'm
tempted to suggest rephrasing it to be parallel to the new error
I added: "could not parse trigger return value: %s".  But I didn't
do that below.

Thoughts?

            regards, tom lane

diff --git a/src/pl/tcl/expected/pltcl_call.out b/src/pl/tcl/expected/pltcl_call.out
index e4498375ec..9307236944 100644
--- a/src/pl/tcl/expected/pltcl_call.out
+++ b/src/pl/tcl/expected/pltcl_call.out
@@ -66,6 +66,14 @@ END
 $$;
 NOTICE:  a: 10
 NOTICE:  _a: 10, _b: 20
+-- syntax errors
+CREATE PROCEDURE test_proc10(INOUT a text)
+LANGUAGE pltcl
+AS $$
+return [list a {$a + $a}])
+$$;
+CALL test_proc10('abc');
+ERROR:  could not parse function return value: list element in braces followed by ")" instead of space
 DROP PROCEDURE test_proc1;
 DROP PROCEDURE test_proc2;
 DROP PROCEDURE test_proc3;
diff --git a/src/pl/tcl/pltcl.c b/src/pl/tcl/pltcl.c
index 18d14a2b98..104175aa8c 100644
--- a/src/pl/tcl/pltcl.c
+++ b/src/pl/tcl/pltcl.c
@@ -1026,7 +1026,10 @@ pltcl_func_handler(PG_FUNCTION_ARGS, pltcl_call_state *call_state,
         /* Convert function result to tuple */
         resultObj = Tcl_GetObjResult(interp);
         if (Tcl_ListObjGetElements(interp, resultObj, &resultObjc, &resultObjv) == TCL_ERROR)
-            throw_tcl_error(interp, prodesc->user_proname);
+            ereport(ERROR,
+                    (errcode(ERRCODE_EXTERNAL_ROUTINE_EXCEPTION),
+                     errmsg("could not parse function return value: %s",
+                            utf_u2e(Tcl_GetStringResult(interp)))));

         tup = pltcl_build_tuple_result(interp, resultObjv, resultObjc,
                                        call_state);
@@ -1355,6 +1358,10 @@ pltcl_event_trigger_handler(PG_FUNCTION_ARGS, pltcl_call_state *call_state,

 /**********************************************************************
  * throw_tcl_error    - ereport an error returned from the Tcl interpreter
+ *
+ * Caution: use this only to report errors returned by Tcl_EvalObjEx() or
+ * other variants of Tcl_Eval().  Other functions may not fill "errorInfo",
+ * so it could be unset or even contain details from some previous error.
  **********************************************************************/
 static void
 throw_tcl_error(Tcl_Interp *interp, const char *proname)
diff --git a/src/pl/tcl/sql/pltcl_call.sql b/src/pl/tcl/sql/pltcl_call.sql
index 37efbdefc2..eba5793f94 100644
--- a/src/pl/tcl/sql/pltcl_call.sql
+++ b/src/pl/tcl/sql/pltcl_call.sql
@@ -71,6 +71,17 @@ END
 $$;


+-- syntax errors
+
+CREATE PROCEDURE test_proc10(INOUT a text)
+LANGUAGE pltcl
+AS $$
+return [list a {$a + $a}])
+$$;
+
+CALL test_proc10('abc');
+
+
 DROP PROCEDURE test_proc1;
 DROP PROCEDURE test_proc2;
 DROP PROCEDURE test_proc3;

On 2024-06-03 18:57 +0200, Tom Lane wrote:
> Erik Wienhold <ewie@ewie.name> writes:
> > On 2024-06-03 00:15 +0200, Tom Lane wrote:
> >> The new bit of information that this bug report provides is that it's
> >> possible to get a TCL_ERROR result without Tcl having set errorInfo.
> >> That seems a tad odd, and it must happen only in weird corner cases,
> >> else we'd have heard of this decades ago.  Not sure if it's worth
> >> trying to characterize those cases further, however.
> 
> > ISTM that errorInfo is set automatically only during script evaluation.
> 
> Yeah, I've just come to the same conclusion.  Changing throw_tcl_error
> to ignore errorInfo if it's unset would be wrong, because that implies
> that the function we called doesn't fill errorInfo.  I found by
> testing that it's actually possible that errorInfo contains leftover
> text from a previous error (that might not even have been in the same
> function), resulting in completely confusing/misleading output.
> 
> So your thought that we should just not use throw_tcl_error here
> was correct, and a minimal fix could look like the attached.

LGTM.

> Also, compile_pltcl_function contains a Tcl_EvalEx() call that
> presumably could use throw_tcl_error, except it wants to add "could
> not create internal procedure" which would require some refactoring.
> As far as I can tell that error case is not reproducibly reachable,
> as it'd require OOM or some other problem inside Tcl, so (a) it's
> probably not worth troubling over and (b) changing it is a bit scary
> for lack of ability to test.  I'm inclined to leave that alone too.

Agree.

> The other thing I noticed while looking at this is that the error text
> for the other Tcl_ListObjGetElements() call seems a bit confusingly
> worded: "could not split return value from trigger: %s".  You could
> easily read that as suggesting that the return value is somehow
> attached to the trigger and has to be separated from it.  I'm
> tempted to suggest rephrasing it to be parallel to the new error
> I added: "could not parse trigger return value: %s".  But I didn't
> do that below.

Yeah, I'd fix that trigger error text as well to bring both in line.

-- 
Erik

Erik Wienhold <ewie@ewie.name> writes:
> On 2024-06-03 18:57 +0200, Tom Lane wrote:
>> So your thought that we should just not use throw_tcl_error here
>> was correct, and a minimal fix could look like the attached.

> LGTM.

Pushed, thanks.

            regards, tom lane