Обсуждение: Assertion failure in HEAD and 13 after calling COMMIT in a stored proc

Поиск
Список
Период
Сортировка

Assertion failure in HEAD and 13 after calling COMMIT in a stored proc

От
Jim Nasby
Дата:

The following generates an assertion failure. Quick testing with start and stop as well as the core dump shows it’s failing on the execution of `schema_name := schema_name(i)` immediately after COMMIT, because there’s no active snapshot. On a build without asserts I get a failure in GetActiveSnapshot() (second stack trace). This works fine on 12_STABLE, but fails on 13_STABLE and HEAD.


CREATE OR REPLACE FUNCTION public.schema_name(i integer)
 RETURNS text
 LANGUAGE sql
 IMMUTABLE
AS $function$
SELECT 'test_' || trim(to_char(i, '000000'))
$function$;

CREATE OR REPLACE PROCEDURE public.build_schema(start integer, stop integer, commit_interval integer DEFAULT 10, do_insert boolean DEFAULT true)
 LANGUAGE plpgsql
AS $procedure$
DECLARE
    schema_name text;
BEGIN
FOR i IN start .. stop LOOP
    schema_name := schema_name(i);
    IF i % commit_interval = 0 THEN
        --RAISE NOTICE 'COMMIT CREATE step %', i;
        COMMIT;
    END IF;
END LOOP;
END$procedure$;


CALL build_schema(1,11);


<assert failure>

Core file '/cores/core.1912' (x86_64) was loaded.

(lldb) bt
* thread #1, stop reason = signal SIGSTOP
  * frame #0: 0x00007fff6c3ae33a libsystem_kernel.dylib`__pthread_kill + 10
    frame #1: 0x00007fff6c46ae60 libsystem_pthread.dylib`pthread_kill + 430
    frame #2: 0x00007fff6c335808 libsystem_c.dylib`abort + 120
    frame #3: 0x000000010af1af6d postgres`ExceptionalCondition(conditionName="ActiveSnapshotSet()", errorType="FailedAssertion", fileName="postgres.c", lineNumber=867) at assert.c:67:2
    frame #4: 0x000000010ad3aeb3 postgres`pg_plan_query(querytree=0x00007ff663023848, query_string="\nSELECT 'test_' || trim(to_char(i, '000000'))\n", cursorOptions=256, boundParams=0x0000000000000000) at postgres.c:867:2
    frame #5: 0x000000010aad9059 postgres`init_execution_state(queryTree_list=0x00007ff663024208, fcache=0x00007ff663022720, lazyEvalOK=true) at functions.c:513:12
    frame #6: 0x000000010aad6dec postgres`init_sql_fcache(fcinfo=0x00007ff663035918, collation=0, lazyEvalOK=true) at functions.c:787:23
    frame #7: 0x000000010aad5ffa postgres`fmgr_sql(fcinfo=0x00007ff663035918) at functions.c:1070:3
    frame #8: 0x000000010aaaf660 postgres`ExecInterpExpr(state=0x00007ff663035828, econtext=0x00007ff663035738, isnull=0x00007ffee5459bbf) at execExprInterp.c:680:8
    frame #9: 0x000000010aaae9b7 postgres`ExecInterpExprStillValid(state=0x00007ff663035828, econtext=0x00007ff663035738, isNull=0x00007ffee5459bbf) at execExprInterp.c:1807:9
    frame #10: 0x00000001163e5b5a plpgsql.so`ExecEvalExpr(state=0x00007ff663035828, econtext=0x00007ff663035738, isNull=0x00007ffee5459bbf) at executor.h:303:9
    frame #11: 0x00000001163e4fe0 plpgsql.so`exec_eval_simple_expr(estate=0x00007ffee545a080, expr=0x00007ff662032db0, result=0x00007ffee5459b68, isNull=0x00007ffee5459bbf, rettype=0x00007ffee5459bb8, rettypmod=0x00007ffee5459bb4) at pl_exec.c:6328:12
    frame #12: 0x00000001163e4887 plpgsql.so`exec_eval_expr(estate=0x00007ffee545a080, expr=0x00007ff662032db0, isNull=0x00007ffee5459bbf, rettype=0x00007ffee5459bb8, rettypmod=0x00007ffee5459bb4) at pl_exec.c:5833:6
    frame #13: 0x00000001163e30c2 plpgsql.so`exec_assign_expr(estate=0x00007ffee545a080, target=0x00007ff66300e4d0, expr=0x00007ff662032db0) at pl_exec.c:4973:10
    frame #14: 0x00000001163dc407 plpgsql.so`exec_stmt_assign(estate=0x00007ffee545a080, stmt=0x00007ff662032e80) at pl_exec.c:2112:2
    frame #15: 0x00000001163d9de2 plpgsql.so`exec_stmt(estate=0x00007ffee545a080, stmt=0x00007ff662032e80) at pl_exec.c:1980:9
    frame #16: 0x00000001163e3387 plpgsql.so`exec_stmts(estate=0x00007ffee545a080, stmts=0x00007ff662032eb8) at pl_exec.c:1943:14
    frame #17: 0x00000001163ddd7c plpgsql.so`exec_stmt_fori(estate=0x00007ffee545a080, stmt=0x00007ff662032ca8) at pl_exec.c:2783:8
    frame #18: 0x00000001163d9ea2 plpgsql.so`exec_stmt(estate=0x00007ffee545a080, stmt=0x00007ff662032ca8) at pl_exec.c:2012:9
    frame #19: 0x00000001163e3387 plpgsql.so`exec_stmts(estate=0x00007ffee545a080, stmts=0x00007ff6620328d0) at pl_exec.c:1943:14
    frame #20: 0x00000001163dc20d plpgsql.so`exec_stmt_block(estate=0x00007ffee545a080, block=0x00007ff6620231c8) at pl_exec.c:1884:8
    frame #21: 0x00000001163d9dca plpgsql.so`exec_stmt(estate=0x00007ffee545a080, stmt=0x00007ff6620231c8) at pl_exec.c:1976:9
    frame #22: 0x00000001163d8393 plpgsql.so`plpgsql_exec_function(func=0x00007ff666055738, fcinfo=0x00007ffee545a478, simple_eval_estate=0x0000000000000000, simple_eval_resowner=0x0000000000000000, atomic=false) at pl_exec.c:610:7
    frame #23: 0x00000001163f6c4a plpgsql.so`plpgsql_call_handler(fcinfo=0x00007ffee545a478) at pl_handler.c:265:13
    frame #24: 0x000000010aa22232 postgres`ExecuteCallStmt(stmt=0x00007ff662010320, params=0x0000000000000000, atomic=false, dest=0x00007ff662010ba0) at functioncmds.c:2232:11
    frame #25: 0x000000010ad454af postgres`standard_ProcessUtility(pstmt=0x00007ff6620103e8, queryString="call build_schema (1,11);", context=PROCESS_UTILITY_TOPLEVEL, params=0x0000000000000000, queryEnv=0x0000000000000000, dest=0x00007ff662010ba0, qc=0x00007ffee545b070) at utility.c:817:4
    frame #26: 0x000000010ad44c82 postgres`ProcessUtility(pstmt=0x00007ff6620103e8, queryString="call build_schema (1,11);", context=PROCESS_UTILITY_TOPLEVEL, params=0x0000000000000000, queryEnv=0x0000000000000000, dest=0x00007ff662010ba0, qc=0x00007ffee545b070) at utility.c:524:3
    frame #27: 0x000000010ad4443e postgres`PortalRunUtility(portal=0x00007ff66282f320, pstmt=0x00007ff6620103e8, isTopLevel=true, setHoldSnapshot=false, dest=0x00007ff662010ba0, qc=0x00007ffee545b070) at pquery.c:1145:2
    frame #28: 0x000000010ad4359d postgres`PortalRunMulti(portal=0x00007ff66282f320, isTopLevel=true, setHoldSnapshot=false, dest=0x00007ff662010ba0, altdest=0x00007ff662010ba0, qc=0x00007ffee545b070) at pquery.c:1301:5
    frame #29: 0x000000010ad42b2e postgres`PortalRun(portal=0x00007ff66282f320, count=9223372036854775807, isTopLevel=true, run_once=true, dest=0x00007ff662010ba0, altdest=0x00007ff662010ba0, qc=0x00007ffee545b070) at pquery.c:786:5
    frame #30: 0x000000010ad3e0c5 postgres`exec_simple_query(query_string="call build_schema (1,11);") at postgres.c:1239:10
    frame #31: 0x000000010ad3d26d postgres`PostgresMain(argc=1, argv=0x00007ff66280f670, dbname="nasbyj", username="nasbyj") at postgres.c:4339:7
    frame #32: 0x000000010ac6752a postgres`BackendRun(port=0x00007ff664404080) at postmaster.c:4526:2
    frame #33: 0x000000010ac66979 postgres`BackendStartup(port=0x00007ff664404080) at postmaster.c:4210:3
    frame #34: 0x000000010ac658fd postgres`ServerLoop at postmaster.c:1739:7
    frame #35: 0x000000010ac633e4 postgres`PostmasterMain(argc=1, argv=0x00007ff661c06cc0) at postmaster.c:1412:11
    frame #36: 0x000000010ab45679 postgres`main(argc=1, argv=0x00007ff661c06cc0) at main.c:210:3
    frame #37: 0x00007fff6c266cc9 libdyld.dylib`start + 1
    frame #38: 0x00007fff6c266cc9 libdyld.dylib`start + 1
(lldb) fr 4
invalid command 'frame 4'.
(lldb) fr s 4
frame #4: 0x000000010ad3aeb3 postgres`pg_plan_query(querytree=0x00007ff663023848, query_string="\nSELECT 'test_' || trim(to_char(i, '000000'))\n", cursorOptions=256, boundParams=0x0000000000000000) at postgres.c:867:2
   864             return NULL;
   865
   866         /* Planner must have a snapshot in case it calls user-defined functions. */
-> 867         Assert(ActiveSnapshotSet());
   868
   869         TRACE_POSTGRESQL_QUERY_PLAN_START();
   870
(lldb)


... non-assert build ...


(lldb) bt
postgres was compiled with optimization - stepping may behave oddly; variables may not be available.
* thread #1, stop reason = signal SIGSTOP
  * frame #0: 0x0000000101d207db postgres`GetActiveSnapshot at snapmgr.c:845:25 [opt]
    frame #1: 0x0000000101a83f25 postgres`fmgr_sql [inlined] postquel_start(es=0x00007fd19789c5a8, fcache=<unavailable>) at functions.c:832:9 [opt]
    frame #2: 0x0000000101a83ec6 postgres`fmgr_sql(fcinfo=<unavailable>) at functions.c:1161 [opt]
    frame #3: 0x0000000101a6fae1 postgres`ExecInterpExpr(state=<unavailable>, econtext=<unavailable>, isnull=0x00007ffeee304a57) at execExprInterp.c:680:8 [opt]
    frame #4: 0x00000001028ddc10 plpgsql.so`exec_eval_expr [inlined] ExecEvalExpr(state=<unavailable>, econtext=0x00007fd19a818128, isNull=0x00007ffeee304a57) at executor.h:303:9 [opt]
    frame #5: 0x00000001028ddc06 plpgsql.so`exec_eval_expr [inlined] exec_eval_simple_expr(estate=0x00007ffeee304f18, expr=0x00007fd1980268c0, isNull=<unavailable>, rettype=<unavailable>, rettypmod=0x00007fd19a80fe00) at pl_exec.c:6328 [opt]
    frame #6: 0x00000001028ddb2a plpgsql.so`exec_eval_expr(estate=0x00007ffeee304f18, expr=0x00007fd1980268c0, isNull=<unavailable>, rettype=<unavailable>, rettypmod=0x00007fd19a80fe00) at pl_exec.c:5833 [opt]
    frame #7: 0x00000001028dd258 plpgsql.so`exec_assign_expr(estate=0x00007ffeee304f18, target=0x00007fd19a810120, expr=0x00007fd1980268c0) at pl_exec.c:4973:10 [opt]
    frame #8: 0x00000001028d86a2 plpgsql.so`exec_stmt [inlined] exec_stmt_assign(estate=0x00007ffeee304f18, stmt=0x00007fd198026980) at pl_exec.c:2112:2 [opt]
    frame #9: 0x00000001028d868a plpgsql.so`exec_stmt(estate=0x00007ffeee304f18, stmt=0x00007fd198026980) at pl_exec.c:1980 [opt]
    frame #10: 0x00000001028d9941 plpgsql.so`exec_stmt at pl_exec.c:1943:14 [opt]
    frame #11: 0x00000001028d9914 plpgsql.so`exec_stmt [inlined] exec_stmt_fori(estate=0x00007ffeee304f18, stmt=0x00007fd1980267d8) at pl_exec.c:2783 [opt]
    frame #12: 0x00000001028d98a9 plpgsql.so`exec_stmt(estate=<unavailable>, stmt=<unavailable>) at pl_exec.c:2012 [opt]
    frame #13: 0x00000001028dbf20 plpgsql.so`exec_stmt_block at pl_exec.c:1943:14 [opt]
    frame #14: 0x00000001028dbefb plpgsql.so`exec_stmt_block(estate=0x00007ffeee304f18, block=0x00007fd198026c20) at pl_exec.c:1884 [opt]
    frame #15: 0x00000001028d7ec3 plpgsql.so`exec_stmt(estate=0x00007ffeee304f18, stmt=0x00007fd198026c20) at pl_exec.c:1976:9 [opt]
    frame #16: 0x00000001028d6f45 plpgsql.so`plpgsql_exec_function(func=0x00007fd19785cc60, fcinfo=0x00007ffeee3051f0, simple_eval_estate=<unavailable>, simple_eval_resowner=<unavailable>, atomic=<unavailable>) at pl_exec.c:610:7 [opt]
    frame #17: 0x00000001028e9122 plpgsql.so`plpgsql_call_handler(fcinfo=0x00007ffeee3051f0) at pl_handler.c:265:13 [opt]
    frame #18: 0x0000000101a2b5e4 postgres`ExecuteCallStmt(stmt=0x00007fd1978102b0, params=0x00007fd19a80f4e8, atomic=<unavailable>, dest=0x00007fd1978108d0) at functioncmds.c:2232:11 [opt]
    frame #19: 0x0000000101bd31f5 postgres`standard_ProcessUtility(pstmt=0x00007fd197810360, queryString="CALL build_schema(1,11);", context=PROCESS_UTILITY_TOPLEVEL, params=0x0000000000000000, queryEnv=0x0000000000000000, dest=0x00007fd1978108d0, qc=0x00007ffeee305b80) at utility.c:817:4 [opt]
    frame #20: 0x0000000101bd2c58 postgres`ProcessUtility(pstmt=0x00007fd197810360, queryString=<unavailable>, context=<unavailable>, params=<unavailable>, queryEnv=<unavailable>, dest=<unavailable>, qc=0x00007ffeee305b80) at utility.c:524:3 [opt]
    frame #21: 0x0000000101bd29b1 postgres`PortalRunUtility(portal=0x00007fd197838118, pstmt=0x00007fd197810360, isTopLevel=<unavailable>, setHoldSnapshot=<unavailable>, dest=<unavailable>, qc=0x00007ffeee305b80) at pquery.c:1145:2 [opt]
    frame #22: 0x0000000101bd2028 postgres`PortalRunMulti(portal=0x00007fd197838118, isTopLevel=true, setHoldSnapshot=false, dest=0x00007fd1978108d0, altdest=0x00007fd1978108d0, qc=<unavailable>) at pquery.c:0 [opt]
    frame #23: 0x0000000101bd1afd postgres`PortalRun(portal=0x00007fd197838118, count=9223372036854775807, isTopLevel=true, run_once=<unavailable>, dest=0x00007fd1978108d0, altdest=0x00007fd1978108d0, qc=0x00007ffeee305b80) at pquery.c:786:5 [opt]
    frame #24: 0x0000000101bd0d5a postgres`exec_simple_query(query_string="CALL build_schema(1,11);") at postgres.c:1239:10 [opt]
    frame #25: 0x0000000101bce608 postgres`PostgresMain(argc=<unavailable>, argv=<unavailable>, dbname=<unavailable>, username=<unavailable>) at postgres.c:0 [opt]
    frame #26: 0x0000000101b57e11 postgres`BackendRun(port=<unavailable>) at postmaster.c:4526:2 [opt]
    frame #27: 0x0000000101b57590 postgres`ServerLoop [inlined] BackendStartup(port=<unavailable>) at postmaster.c:4210:3 [opt]
    frame #28: 0x0000000101b5756f postgres`ServerLoop at postmaster.c:1739 [opt]
    frame #29: 0x0000000101b5474a postgres`PostmasterMain(argc=<unavailable>, argv=0x00007fd197406cc0) at postmaster.c:1412:11 [opt]
    frame #30: 0x0000000101abf3ef postgres`main(argc=<unavailable>, argv=<unavailable>) at main.c:210:3 [opt]
    frame #31: 0x00007fff6c266cc9 libdyld.dylib`start + 1
    frame #32: 0x00007fff6c266cc9 libdyld.dylib`start + 1
(lldb)

@font-face {font-family:"Cambria Math"; panose-1:2 4 5 3 5 4 6 3 2 4; mso-font-charset:0; mso-generic-font-family:roman; mso-font-pitch:variable; mso-font-signature:-536870145 1107305727 0 0 415 0;}@font-face {font-family:Calibri; panose-1:2 15 5 2 2 2 4 3 2 4; mso-font-charset:0; mso-generic-font-family:swiss; mso-font-pitch:variable; mso-font-signature:-536859905 -1073732485 9 0 511 0;}p.MsoNormal, li.MsoNormal, div.MsoNormal {mso-style-unhide:no; mso-style-qformat:yes; mso-style-parent:""; margin:0in; mso-pagination:widow-orphan; font-size:12.0pt; font-family:"Calibri",sans-serif; mso-ascii-font-family:Calibri; mso-ascii-theme-font:minor-latin; mso-fareast-font-family:Calibri; mso-fareast-theme-font:minor-latin; mso-hansi-font-family:Calibri; mso-hansi-theme-font:minor-latin; mso-bidi-font-family:"Times New Roman"; mso-bidi-theme-font:minor-bidi;}span.EmailStyle15 {mso-style-type:personal; mso-style-noshow:yes; mso-style-unhide:no; mso-ansi-font-size:11.0pt; mso-bidi-font-size:11.0pt; font-family:"Calibri",sans-serif; mso-ascii-font-family:Calibri; mso-ascii-theme-font:minor-latin; mso-fareast-font-family:Calibri; mso-fareast-theme-font:minor-latin; mso-hansi-font-family:Calibri; mso-hansi-theme-font:minor-latin; mso-bidi-font-family:"Times New Roman"; mso-bidi-theme-font:minor-bidi; color:windowtext;}.MsoChpDefault {mso-style-type:export-only; mso-default-props:yes; font-size:12.0pt; mso-ansi-font-size:12.0pt; mso-bidi-font-size:12.0pt; font-family:"Calibri",sans-serif; mso-ascii-font-family:Calibri; mso-ascii-theme-font:minor-latin; mso-fareast-font-family:Calibri; mso-fareast-theme-font:minor-latin; mso-hansi-font-family:Calibri; mso-hansi-theme-font:minor-latin; mso-bidi-font-family:"Times New Roman"; mso-bidi-theme-font:minor-bidi;}div.WordSection1 {page:WordSection1;}

Re: Assertion failure in HEAD and 13 after calling COMMIT in a stored proc

От
Michael Paquier
Дата:
On Mon, Jun 21, 2021 at 04:19:27PM -0700, Jim Nasby wrote:
> The following generates an assertion failure. Quick testing with start and
> stop as well as the core dump shows it’s failing on the execution of
> `schema_name := schema_name(i)` immediately after COMMIT, because there’s no
> active snapshot. On a build without asserts I get a failure in
> GetActiveSnapshot() (second stack trace). This works fine on 12_STABLE, but
> fails on 13_STABLE and HEAD.

A bisect run points me to the following commit:
commit 73b06cf893c9d3bb38c11878a12cc29407e78b6c
Author: Tom Lane <tgl@sss.pgh.pa.us>
Date:   Fri Nov 22 15:02:18 2019 -0500

Avoid taking a new snapshot for an immutable simple expression in plpgsql.

Snapshots would be taken when using non-immutable functions.  I'd need
to study more this code to grab if we could improve the situation
after committing the transaction, but, Tom, shouldn't we enforce a
snapshot in the case where the expression has not been prepared for
execution in the new XACT, even for the immutable case?  It seems to
me that this refers to the case where expr_simple_lxid is still
invalid, no?
--
Michael

Вложения

Re: Assertion failure in HEAD and 13 after calling COMMIT in a stored proc

От
Ranier Vilela
Дата:
On Mon, Jun 21, 2021 at 04:19:27PM -0700, Jim Nasby wrote:
> The following generates an assertion failure. Quick testing with start and
> stop as well as the core dump shows it’s failing on the execution of
> `schema_name := schema_name(i)` immediately after COMMIT, because there’s no
> active snapshot. On a build without asserts I get a failure in
> GetActiveSnapshot() (second stack trace). This works fine on 12_STABLE, but
> fails on 13_STABLE and HEAD.

For me it's a typo.
need_snapshot = (expr->expr_simple_mutable || !estate->readonly_func);

HEAD with no assertion:

 CREATE OR REPLACE FUNCTION public.schema_name(i integer)
postgres-#   RETURNS text
postgres-#   LANGUAGE sql
postgres-#   IMMUTABLE
postgres-# AS $function$
postgres$# SELECT 'test_' || trim(to_char(i, '000000'))
postgres$# $function$;
CREATE FUNCTION
postgres=# CREATE OR REPLACE PROCEDURE public.build_schema(start integer, stop
postgres(# integer, commit_interval integer DEFAULT 10, do_insert boolean DEFAULT true)
postgres-#   LANGUAGE plpgsql
postgres-# AS $procedure$
postgres$# DECLARE
postgres$#      schema_name text;
postgres$# BEGIN
postgres$# FOR i IN start .. stop LOOP
postgres$#      schema_name := schema_name(i);
postgres$#      IF i % commit_interval = 0 THEN
postgres$#          --RAISE NOTICE 'COMMIT CREATE step %', i;
postgres$#          COMMIT;
postgres$#      END IF;
postgres$# END LOOP;
postgres$# END$procedure$;
CREATE PROCEDURE
postgres=# CALL build_schema(1,11);
CALL
postgres=# CALL build_schema(1,11);
CALL
postgres=# CALL build_schema(1,11);
CALL

The comments in the function are clear:
If expression is mutable OR is a non-read-only function, so need a snapshot.

Can you test please?

regards,
Ranier Vilela

Вложения

Re: Assertion failure in HEAD and 13 after calling COMMIT in a stored proc

От
Tom Lane
Дата:
Michael Paquier <michael@paquier.xyz> writes:
> On Mon, Jun 21, 2021 at 04:19:27PM -0700, Jim Nasby wrote:
>> The following generates an assertion failure.

> A bisect run points me to the following commit:
> commit 73b06cf893c9d3bb38c11878a12cc29407e78b6c
> Author: Tom Lane <tgl@sss.pgh.pa.us>
> Date:   Fri Nov 22 15:02:18 2019 -0500
> Avoid taking a new snapshot for an immutable simple expression in plpgsql.

Hmm.  I think the real issue here is that commit 84f5c2908 did
not cover the "simple expression" code path in plpgsql.  We
need to re-establish an outer snapshot when the next thing
that happens after COMMIT is a simple expression, too.

In this view, 73b06cf8 just removed code that was masking the
lack of a snapshot during the evaluation of the simple expr
itself.  However, we'd still have had a problem if the simple
expr returned a toast pointer that we had to dereference after
returning (and popping that snapshot).  So I'm thinking
back-patch to v11, as before.

            regards, tom lane



Re: Assertion failure in HEAD and 13 after calling COMMIT in a stored proc

От
Tom Lane
Дата:
I wrote:
> Hmm.  I think the real issue here is that commit 84f5c2908 did
> not cover the "simple expression" code path in plpgsql.  We
> need to re-establish an outer snapshot when the next thing
> that happens after COMMIT is a simple expression, too.

The attached seems to be enough to resolve Jim's example.  I'd like
to invent a test case that involves a detoast of the simple
expression's result, too, to show that transiently pushing a
snapshot for the duration of the expression is not the right fix.

            regards, tom lane

diff --git a/src/pl/plpgsql/src/pl_exec.c b/src/pl/plpgsql/src/pl_exec.c
index 0ce382e123..96bb77e0b1 100644
--- a/src/pl/plpgsql/src/pl_exec.c
+++ b/src/pl/plpgsql/src/pl_exec.c
@@ -38,6 +38,7 @@
 #include "plpgsql.h"
 #include "storage/proc.h"
 #include "tcop/cmdtag.h"
+#include "tcop/pquery.h"
 #include "tcop/tcopprot.h"
 #include "tcop/utility.h"
 #include "utils/array.h"
@@ -5958,6 +5959,15 @@ exec_eval_simple_expr(PLpgSQL_execstate *estate,
         expr->expr_simple_lxid == curlxid)
         return false;
 
+    /*
+     * Ensure that there's a portal-level snapshot, in case this simple
+     * expression is the first thing evaluated after a COMMIT or ROLLBACK.
+     * We'd have to do this anyway before executing the expression, so we
+     * might as well do it now to ensure that any possible replanning doesn't
+     * need to take a new snapshot.
+     */
+    EnsurePortalSnapshotExists();
+
     /*
      * Check to see if the cached plan has been invalidated.  If not, and this
      * is the first use in the current transaction, save a plan refcount in

Re: Assertion failure in HEAD and 13 after calling COMMIT in a stored proc

От
Tom Lane
Дата:
I wrote:
> The attached seems to be enough to resolve Jim's example.  I'd like
> to invent a test case that involves a detoast of the simple
> expression's result, too, to show that transiently pushing a
> snapshot for the duration of the expression is not the right fix.

Here we go.  This test case gives "cannot fetch toast data without an
active snapshot" in v11 and v12 branch tips.  Since those branches lack
the 73b06cf89 optimization, they push a snapshot while calling the
SQL-language function, thus it doesn't complain.  But what comes back
is toasted, and then we fail trying to detoast it.

            regards, tom lane

diff --git a/src/pl/plpgsql/src/expected/plpgsql_transaction.out b/src/pl/plpgsql/src/expected/plpgsql_transaction.out
index 918cc0913e..35845d1d6b 100644
--- a/src/pl/plpgsql/src/expected/plpgsql_transaction.out
+++ b/src/pl/plpgsql/src/expected/plpgsql_transaction.out
@@ -430,6 +430,24 @@ SELECT * FROM test1;
 ---+---
 (0 rows)

+-- detoast result of simple expression after commit
+CREATE TEMP TABLE test4(f1 text);
+ALTER TABLE test4 ALTER COLUMN f1 SET STORAGE EXTERNAL; -- disable compression
+INSERT INTO test4 SELECT repeat('xyzzy', 2000);
+-- immutable mark is a bit of a lie, but it serves to make call a simple expr
+-- that will return a still-toasted value
+CREATE FUNCTION data_source(i int) RETURNS TEXT LANGUAGE sql
+AS 'select f1 from test4' IMMUTABLE;
+DO $$
+declare x text;
+begin
+  for i in 1..3 loop
+    x := data_source(i);
+    commit;
+  end loop;
+  raise notice 'length(x) = %', length(x);
+end $$;
+NOTICE:  length(x) = 10000
 -- operations on composite types vs. internal transactions
 DO LANGUAGE plpgsql $$
 declare
diff --git a/src/pl/plpgsql/src/pl_exec.c b/src/pl/plpgsql/src/pl_exec.c
index 392456ae85..06bdd04774 100644
--- a/src/pl/plpgsql/src/pl_exec.c
+++ b/src/pl/plpgsql/src/pl_exec.c
@@ -35,6 +35,7 @@
 #include "parser/parse_type.h"
 #include "parser/scansup.h"
 #include "storage/proc.h"
+#include "tcop/pquery.h"
 #include "tcop/tcopprot.h"
 #include "tcop/utility.h"
 #include "utils/array.h"
@@ -6153,6 +6154,15 @@ exec_eval_simple_expr(PLpgSQL_execstate *estate,
     if (expr->expr_simple_in_use && expr->expr_simple_lxid == curlxid)
         return false;

+    /*
+     * Ensure that there's a portal-level snapshot, in case this simple
+     * expression is the first thing evaluated after a COMMIT or ROLLBACK.
+     * We'd have to do this anyway before executing the expression, so we
+     * might as well do it now to ensure that any possible replanning doesn't
+     * need to take a new snapshot.
+     */
+    EnsurePortalSnapshotExists();
+
     /*
      * Revalidate cached plan, so that we will notice if it became stale. (We
      * need to hold a refcount while using the plan, anyway.)  If replanning
diff --git a/src/pl/plpgsql/src/sql/plpgsql_transaction.sql b/src/pl/plpgsql/src/sql/plpgsql_transaction.sql
index cc26788b9a..8e4783c9a5 100644
--- a/src/pl/plpgsql/src/sql/plpgsql_transaction.sql
+++ b/src/pl/plpgsql/src/sql/plpgsql_transaction.sql
@@ -354,6 +354,27 @@ $$;
 SELECT * FROM test1;


+-- detoast result of simple expression after commit
+CREATE TEMP TABLE test4(f1 text);
+ALTER TABLE test4 ALTER COLUMN f1 SET STORAGE EXTERNAL; -- disable compression
+INSERT INTO test4 SELECT repeat('xyzzy', 2000);
+
+-- immutable mark is a bit of a lie, but it serves to make call a simple expr
+-- that will return a still-toasted value
+CREATE FUNCTION data_source(i int) RETURNS TEXT LANGUAGE sql
+AS 'select f1 from test4' IMMUTABLE;
+
+DO $$
+declare x text;
+begin
+  for i in 1..3 loop
+    x := data_source(i);
+    commit;
+  end loop;
+  raise notice 'length(x) = %', length(x);
+end $$;
+
+
 -- operations on composite types vs. internal transactions
 DO LANGUAGE plpgsql $$
 declare

Re: Assertion failure in HEAD and 13 after calling COMMIT in a stored proc

От
Tom Lane
Дата:
Justin Pryzby <pryzby@telsasoft.com> writes:
> This causes the server to crash during FETCH.

> ts=# begin; declare b cursor for VALUES(1); fetch 100 in b;
> BEGIN
> DECLARE CURSOR
> 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.

Hm, works for me:

regression=# begin; declare b cursor for VALUES(1); fetch 100 in b;
BEGIN
DECLARE CURSOR
 column1 
---------
       1
(1 row)

            regards, tom lane



Re: Assertion failure in HEAD and 13 after calling COMMIT in a stored proc

От
Greg Nancarrow
Дата:
On Tue, Jun 22, 2021 at 10:56 PM Ranier Vilela <ranier.vf@gmail.com> wrote:
>
> On Mon, Jun 21, 2021 at 04:19:27PM -0700, Jim Nasby wrote:
> > The following generates an assertion failure. Quick testing with start and
> > stop as well as the core dump shows it’s failing on the execution of
> > `schema_name := schema_name(i)` immediately after COMMIT, because there’s no
> > active snapshot. On a build without asserts I get a failure in
> > GetActiveSnapshot() (second stack trace). This works fine on 12_STABLE, but
> > fails on 13_STABLE and HEAD.
>
> For me it's a typo.
> need_snapshot = (expr->expr_simple_mutable || !estate->readonly_func);
>
...
>
> The comments in the function are clear:
> If expression is mutable OR is a non-read-only function, so need a snapshot.
>

I have to agree with you.
Looks like the "&&" should really be an "||". The explanation in the
code comment is pretty clear on this, as you say.

I was able to reproduce the problem using your example. It produced a
coredump, pointing to the failed "Assert(ActiveSnapshotSet());" in
pg_plan_query().
I also verified that your patch seemed to fix the problem.

However, I found that this issue is masked by the following recent commit:

commit d102aafb6259a6a412803d4b1d8c4f00aa17f67e
Author: Tom Lane <tgl@sss.pgh.pa.us>
Date:   Tue Jun 22 17:48:39 2021 -0400
    Restore the portal-level snapshot for simple expressions, too.

With this commit in place, there is an active snapshot in place
anyway, so for your example, that Assert no longer fires as it did
before.
However, I still think that your fix is valid and needed.

Regards,
Greg Nancarrow
Fujitsu Australia



Re: Assertion failure in HEAD and 13 after calling COMMIT in a stored proc

От
Ranier Vilela
Дата:
Em qua., 23 de jun. de 2021 às 03:04, Greg Nancarrow <gregn4422@gmail.com> escreveu:
On Tue, Jun 22, 2021 at 10:56 PM Ranier Vilela <ranier.vf@gmail.com> wrote:
>
> On Mon, Jun 21, 2021 at 04:19:27PM -0700, Jim Nasby wrote:
> > The following generates an assertion failure. Quick testing with start and
> > stop as well as the core dump shows it’s failing on the execution of
> > `schema_name := schema_name(i)` immediately after COMMIT, because there’s no
> > active snapshot. On a build without asserts I get a failure in
> > GetActiveSnapshot() (second stack trace). This works fine on 12_STABLE, but
> > fails on 13_STABLE and HEAD.
>
> For me it's a typo.
> need_snapshot = (expr->expr_simple_mutable || !estate->readonly_func);
>
...
>
> The comments in the function are clear:
> If expression is mutable OR is a non-read-only function, so need a snapshot.
>

I have to agree with you.
Looks like the "&&" should really be an "||". The explanation in the
code comment is pretty clear on this, as you say.

I was able to reproduce the problem using your example. It produced a
coredump, pointing to the failed "Assert(ActiveSnapshotSet());" in
pg_plan_query().
Yes before  d102aafb6, Jim Nasby example fires a coredump.

I also verified that your patch seemed to fix the problem.
Both fix the Jim example.


However, I found that this issue is masked by the following recent commit:

commit d102aafb6259a6a412803d4b1d8c4f00aa17f67e
Author: Tom Lane <tgl@sss.pgh.pa.us>
Date:   Tue Jun 22 17:48:39 2021 -0400
    Restore the portal-level snapshot for simple expressions, too.

With this commit in place, there is an active snapshot in place
anyway, so for your example, that Assert no longer fires as it did
before.
However, I still think that your fix is valid and needed.
I agreed.
Before 84f5c29, only the not-read-only function NOT push a new snapshot.
Now only mutable expression AND not-read-only function, pushes a new snapshot.
Under which conditions did Jim's example not fit?

With && is very restricted.
We have:
1. Mutable expression AND not-read-only function -> push a new snapshot
2. Mutable expression AND read-only-function -> not push a new snapshot
3. Not mutable expression AND not-read-only function -> not push a new snapshot
4. Not mutable expression AND read-only function -> not push a new snapshot

We agree that 2 and 3 should push a new snapshot.

If the user function is declared as not-read-only, even though read-only,
it's a failure to be fixed either by the user, or by the parser, not here.

regards,
Ranier Vilela

Re: Assertion failure in HEAD and 13 after calling COMMIT in a stored proc

От
Tom Lane
Дата:
Greg Nancarrow <gregn4422@gmail.com> writes:
> On Tue, Jun 22, 2021 at 10:56 PM Ranier Vilela <ranier.vf@gmail.com> wrote:
>> The comments in the function are clear:
>> If expression is mutable OR is a non-read-only function, so need a snapshot.

> I have to agree with you.
> Looks like the "&&" should really be an "||". The explanation in the
> code comment is pretty clear on this, as you say.

The code is correct as-is; the proposed change would result in taking
more snapshots than needed.  Perhaps the comment needs revision, since
you both misread it.  The comment is written in terms of "when can we
skip taking a snapshot", while the test in the code is written for
the inverse condition "when do we need a snapshot".

> I also verified that your patch seemed to fix the problem.

It accidentally masked it ... but only partially.

            regards, tom lane



Re: Assertion failure in HEAD and 13 after calling COMMIT in a stored proc

От
Greg Nancarrow
Дата:
On Wed, Jun 23, 2021 at 11:01 PM Tom Lane <tgl@sss.pgh.pa.us> wrote:
>
>
> The code is correct as-is; the proposed change would result in taking
> more snapshots than needed.  Perhaps the comment needs revision, since
> you both misread it.  The comment is written in terms of "when can we
> skip taking a snapshot", while the test in the code is written for
> the inverse condition "when do we need a snapshot".

Yes, you're right.
Even though I did realise that the comment was talking about the
inverse, the condition for needing a snapshot still seemed too narrow,
based on the comment, but checking the cases again, it is correct.

Perhaps that code could have been written as the following, to better
align with the comments:

    skip_snapshot = (!expr->expr_simple_mutable || estate->readonly_func);
    if (!skip_snapshot)
    {
        ...
    }

    ...

    if (!skip_snapshot)
        PopActiveSnapshot();


Regards,
Greg Nancarrow
Fujitsu Australia



Re: Assertion failure in HEAD and 13 after calling COMMIT in a stored proc

От
Tom Lane
Дата:
Greg Nancarrow <gregn4422@gmail.com> writes:
> On Wed, Jun 23, 2021 at 11:01 PM Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> The comment is written in terms of "when can we
>> skip taking a snapshot", while the test in the code is written for
>> the inverse condition "when do we need a snapshot".

> Perhaps that code could have been written as the following, to better
> align with the comments:
> [ invert the variable's meaning ]

Yeah, perhaps.  I remember feeling that the code was clearer this
way (because "if (!skip_snapshot)" seems a little backwards).
But it might be better to make the code fit the comment than to
try to invert the description in the comment.

            regards, tom lane



Re: Assertion failure in HEAD and 13 after calling COMMIT in a stored proc

От
Ranier Vilela
Дата:
Em qua., 23 de jun. de 2021 às 21:45, Greg Nancarrow <gregn4422@gmail.com> escreveu:
On Wed, Jun 23, 2021 at 11:01 PM Tom Lane <tgl@sss.pgh.pa.us> wrote:
>
>
> The code is correct as-is; the proposed change would result in taking
> more snapshots than needed.  Perhaps the comment needs revision, since
> you both misread it.  The comment is written in terms of "when can we
> skip taking a snapshot", while the test in the code is written for
> the inverse condition "when do we need a snapshot".

Yes, you're right.
Even though I did realise that the comment was talking about the
inverse, the condition for needing a snapshot still seemed too narrow,
based on the comment, but checking the cases again, it is correct.
I still don't agree. But we leave the code like that, to see how it behaves. 


Perhaps that code could have been written as the following, to better
align with the comments:

    skip_snapshot = (!expr->expr_simple_mutable || estate->readonly_func);
    if (!skip_snapshot)
    {
        ...
    }

    ...

    if (!skip_snapshot)
        PopActiveSnapshot();
-1. That way it's readability is much worse, more complicated and IMHO it generates worse asm.

regards,
Ranier Vilela

Re: Assertion failure in HEAD and 13 after calling COMMIT in a stored proc

От
Ranier Vilela
Дата:
Em qua., 23 de jun. de 2021 às 21:51, Tom Lane <tgl@sss.pgh.pa.us> escreveu:
Greg Nancarrow <gregn4422@gmail.com> writes:
> On Wed, Jun 23, 2021 at 11:01 PM Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> The comment is written in terms of "when can we
>> skip taking a snapshot", while the test in the code is written for
>> the inverse condition "when do we need a snapshot".

> Perhaps that code could have been written as the following, to better
> align with the comments:
> [ invert the variable's meaning ]

Yeah, perhaps.  I remember feeling that the code was clearer this
way (because "if (!skip_snapshot)" seems a little backwards).
But it might be better to make the code fit the comment than to
try to invert the description in the comment.
I'm not a native speaker, so I would be of little help with clearer and more elusive comments.
If you both agree that the current code is correct, please correct the comments.
The current code is much simpler and readable.

regards,
Ranier Vilela