Обсуждение: BUG #16139: Assertion fails on INSERT into a postgres_fdw' table with two AFTER INSERT triggers

The following bug has been logged on the website:

Bug reference:      16139
Logged by:          Alexander Lakhin
Email address:      exclusion@gmail.com
PostgreSQL version: 12.1
Operating system:   Ubuntu 18.04
Description:

The following script:
CREATE EXTENSION postgres_fdw;
CREATE SERVER loopback FOREIGN DATA WRAPPER postgres_fdw OPTIONS (dbname
'postgres');
CREATE USER MAPPING FOR CURRENT_USER SERVER loopback;
CREATE TABLE loc2 (f1 int);
CREATE FOREIGN TABLE rem2 (f1 int) SERVER loopback OPTIONS(table_name
'loc2');
CREATE OR REPLACE FUNCTION trigger_data() RETURNS trigger
LANGUAGE plpgsql AS 'begin return NEW; end;';

CREATE TRIGGER trigger1 AFTER INSERT ON rem2 FOR EACH ROW EXECUTE PROCEDURE
trigger_data();
CREATE TRIGGER trigger2 AFTER INSERT ON rem2 FOR EACH ROW EXECUTE PROCEDURE
trigger_data();
INSERT INTO rem2 VALUES(1);

raises the assertion:
Core was generated by `postgres: law regression [local] INSERT
                        '.
Program terminated with signal SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
51      ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
#1  0x00007fd866e97801 in __GI_abort () at abort.c:79
#2  0x000055c2cfc2f022 in ExceptionalCondition (
    conditionName=conditionName@entry=0x55c2cfdaa228 "!(!(((slot)->tts_flags
& (1 << 1)) != 0))", 
    errorType=errorType@entry=0x55c2cfc86108 "FailedAssertion",
fileName=fileName@entry=0x55c2cfdc7e3b "execTuples.c", 
    lineNumber=lineNumber@entry=1620) at assert.c:54
#3  0x000055c2cf99380f in ExecFetchSlotHeapTuple
(slot=slot@entry=0x55c2d03b2bc8, materialize=materialize@entry=true, 
    shouldFree=shouldFree@entry=0x7ffd86cf260e) at execTuples.c:1620
#4  0x000055c2cf9609b7 in AfterTriggerExecute
(estate=estate@entry=0x55c2d039dd88, event=event@entry=0x55c2d03c0b7c, 
    relInfo=relInfo@entry=0x55c2d039e028,
trigdesc=trigdesc@entry=0x55c2d039e140, finfo=finfo@entry=0x55c2d039e300, 
    instr=instr@entry=0x0, per_tuple_context=0x55c2d03c2a50,
trig_tuple_slot1=0x55c2d03b2bc8, 
    trig_tuple_slot2=0x55c2d03b2c60) at trigger.c:4259
#5  0x000055c2cf960fa5 in afterTriggerInvokeEvents
(events=events@entry=0x55c2d034ebf8, firing_id=1, 
    estate=estate@entry=0x55c2d039dd88, delete_ok=delete_ok@entry=false) at
trigger.c:4540
#6  0x000055c2cf966876 in AfterTriggerEndQuery
(estate=estate@entry=0x55c2d039dd88) at trigger.c:4851
#7  0x000055c2cf986c53 in standard_ExecutorFinish (queryDesc=0x55c2d02edbc8)
at execMain.c:439
#8  0x000055c2cf986c74 in ExecutorFinish
(queryDesc=queryDesc@entry=0x55c2d02edbc8) at execMain.c:407
#9  0x000055c2cfb08771 in ProcessQuery (plan=plan@entry=0x55c2d03ac3d0, 
    sourceText=0x55c2d02ca3d8 "INSERT INTO rem2 VALUES(1);", params=0x0,
queryEnv=0x0, dest=dest@entry=0x55c2d03abe70, 
    completionTag=completionTag@entry=0x7ffd86cf29e0 "INSERT 0 1") at
pquery.c:203
#10 0x000055c2cfb088d2 in PortalRunMulti
(portal=portal@entry=0x55c2d0331498, isTopLevel=isTopLevel@entry=true, 
    setHoldSnapshot=setHoldSnapshot@entry=false,
dest=dest@entry=0x55c2d03abe70, altdest=altdest@entry=0x55c2d03abe70, 
    completionTag=completionTag@entry=0x7ffd86cf29e0 "INSERT 0 1") at
pquery.c:1283
#11 0x000055c2cfb0977d in PortalRun (portal=portal@entry=0x55c2d0331498,
count=count@entry=9223372036854775807, 
    isTopLevel=isTopLevel@entry=true, run_once=run_once@entry=true,
dest=dest@entry=0x55c2d03abe70, 
    altdest=altdest@entry=0x55c2d03abe70, completionTag=0x7ffd86cf29e0
"INSERT 0 1") at pquery.c:796
#12 0x000055c2cfb05a2d in exec_simple_query (
    query_string=query_string@entry=0x55c2d02ca3d8 "INSERT INTO rem2
VALUES(1);") at postgres.c:1215
#13 0x000055c2cfb079fd in PostgresMain (argc=<optimized out>,
argv=argv@entry=0x55c2d02f5598, dbname=<optimized out>, 
    username=<optimized out>) at postgres.c:4236
#14 0x000055c2cfa79e2d in BackendRun (port=port@entry=0x55c2d02eb9d0) at
postmaster.c:4437
#15 0x000055c2cfa7d0f3 in BackendStartup (port=port@entry=0x55c2d02eb9d0) at
postmaster.c:4128
#16 0x000055c2cfa7d40a in ServerLoop () at postmaster.c:1704
#17 0x000055c2cfa7e7fb in PostmasterMain (argc=3, argv=<optimized out>) at
postmaster.c:1377
#18 0x000055c2cf9d9d87 in main (argc=3, argv=0x55c2d02c4a30) at main.c:228

On Wed, Nov 27, 2019 at 4:21 PM PG Bug reporting form
<noreply@postgresql.org> wrote:
> The following script:
> CREATE EXTENSION postgres_fdw;
> CREATE SERVER loopback FOREIGN DATA WRAPPER postgres_fdw OPTIONS (dbname
> 'postgres');
> CREATE USER MAPPING FOR CURRENT_USER SERVER loopback;
> CREATE TABLE loc2 (f1 int);
> CREATE FOREIGN TABLE rem2 (f1 int) SERVER loopback OPTIONS(table_name
> 'loc2');
> CREATE OR REPLACE FUNCTION trigger_data() RETURNS trigger
> LANGUAGE plpgsql AS 'begin return NEW; end;';
>
> CREATE TRIGGER trigger1 AFTER INSERT ON rem2 FOR EACH ROW EXECUTE PROCEDURE
> trigger_data();
> CREATE TRIGGER trigger2 AFTER INSERT ON rem2 FOR EACH ROW EXECUTE PROCEDURE
> trigger_data();
> INSERT INTO rem2 VALUES(1);
>
> raises the assertion:

Reproduced.  Will look into this.

Best regards,
Etsuro Fujita

On Wed, Nov 27, 2019 at 5:20 PM Etsuro Fujita <etsuro.fujita@gmail.com> wrote:
> On Wed, Nov 27, 2019 at 4:21 PM PG Bug reporting form
> <noreply@postgresql.org> wrote:
> > The following script:
> > CREATE EXTENSION postgres_fdw;
> > CREATE SERVER loopback FOREIGN DATA WRAPPER postgres_fdw OPTIONS (dbname
> > 'postgres');
> > CREATE USER MAPPING FOR CURRENT_USER SERVER loopback;
> > CREATE TABLE loc2 (f1 int);
> > CREATE FOREIGN TABLE rem2 (f1 int) SERVER loopback OPTIONS(table_name
> > 'loc2');
> > CREATE OR REPLACE FUNCTION trigger_data() RETURNS trigger
> > LANGUAGE plpgsql AS 'begin return NEW; end;';
> >
> > CREATE TRIGGER trigger1 AFTER INSERT ON rem2 FOR EACH ROW EXECUTE PROCEDURE
> > trigger_data();
> > CREATE TRIGGER trigger2 AFTER INSERT ON rem2 FOR EACH ROW EXECUTE PROCEDURE
> > trigger_data();
> > INSERT INTO rem2 VALUES(1);
> >
> > raises the assertion:
>
> Reproduced.  Will look into this.

A bit of investigation showed that this is caused by commit
ff11e7f4b9ae017585c3ba146db7ba39c31f209a.  I haven't yet looked at the
commit in any detail, though.

Best regards,
Etsuro Fujita

On Wed, Nov 27, 2019 at 8:35 PM Etsuro Fujita <etsuro.fujita@gmail.com> wrote:
> A bit of investigation showed that this is caused by commit
> ff11e7f4b9ae017585c3ba146db7ba39c31f209a.  I haven't yet looked at the
> commit in any detail, though.

I spent some time studying the commit.  I think AfterTriggerExecute()
should make sure that:

 * foreign tables always use zero and save the tuple(s) to a
 * tuplestore.  AFTER_TRIGGER_FDW_FETCH directs AfterTriggerExecute() to
 * retrieve a fresh tuple or pair of tuples from that tuplestore, while
 * AFTER_TRIGGER_FDW_REUSE directs it to use the most-recently-retrieved
 * tuple(s).  This permits storing tuples once regardless of the number of
 * row-level triggers on a foreign table.

But the commit modified that function to clear the tg_trigslot and
tg_newslot slots' contents, which are reused when
AFTER_TRIGGER_FDW_REUSE, as shown below:

@@ -4374,12 +4373,17 @@ AfterTriggerExecute(AfterTriggerEvent event,
        heap_freetuple(rettuple);

    /*
-    * Release buffers
+    * Release resources
     */
-   if (buffer1 != InvalidBuffer)
-       ReleaseBuffer(buffer1);
-   if (buffer2 != InvalidBuffer)
-       ReleaseBuffer(buffer2);
+   if (should_free_trig)
+       heap_freetuple(LocTriggerData.tg_trigtuple);
+   if (should_free_new)
+       heap_freetuple(LocTriggerData.tg_newtuple);
+
+   if (LocTriggerData.tg_trigslot)
+       ExecClearTuple(LocTriggerData.tg_trigslot);
+   if (LocTriggerData.tg_newslot)
+       ExecClearTuple(LocTriggerData.tg_newslot);

Attached is a patch for fixing that.  Maybe I'm missing something, though.

Best regards,
Etsuro Fujita

On Thu, Nov 28, 2019 at 8:25 PM Etsuro Fujita <etsuro.fujita@gmail.com> wrote:
> On Wed, Nov 27, 2019 at 8:35 PM Etsuro Fujita <etsuro.fujita@gmail.com> wrote:
> > A bit of investigation showed that this is caused by commit
> > ff11e7f4b9ae017585c3ba146db7ba39c31f209a.  I haven't yet looked at the
> > commit in any detail, though.
>
> I spent some time studying the commit.

Another minor thing I noticed about the commit is this:

@@ -4281,31 +4266,38 @@ AfterTriggerExecute(AfterTriggerEvent event,
             * that is stored as a heap tuple, constructed in different memory
             * context, in the slot anyway.
             */
-           LocTriggerData.tg_trigtuple =
ExecFetchSlotHeapTuple(trig_tuple_slot1,
-                                                                   true, NULL);
-           LocTriggerData.tg_trigtuplebuf = InvalidBuffer;
+           LocTriggerData.tg_trigslot = trig_tuple_slot1;
+           LocTriggerData.tg_trigtuple =
+               ExecFetchSlotHeapTuple(trig_tuple_slot1, true,
&should_free_trig);

+           LocTriggerData.tg_newslot = trig_tuple_slot2;
            LocTriggerData.tg_newtuple =
                ((evtshared->ats_event & TRIGGER_EVENT_OPMASK) ==
                 TRIGGER_EVENT_UPDATE) ?
-               ExecFetchSlotHeapTuple(trig_tuple_slot2, true, NULL) : NULL;
-           LocTriggerData.tg_newtuplebuf = InvalidBuffer;
+               ExecFetchSlotHeapTuple(trig_tuple_slot2, true,
&should_free_new) : NULL;

            break;

LocTriggerData.tg_newslot is always set to trig_tuple_slot2, but I
think we should set it to trig_tuple_slot2 if UPDATE, NULL otherwise,
to ensure that it's a NULL pointer if INSERT/DELETE, which I think
trigger-function authors would assume.  So I updated the patch.
Attached is an updated version of the patch.

Other changes:

* The commit forgot to update the documentation on the trigger
interface, so I updated it (as such).
* I added a bit more regression test cases.

Best regards,
Etsuro Fujita

On Tue, Dec 3, 2019 at 8:53 PM Etsuro Fujita <etsuro.fujita@gmail.com> wrote:
> Attached is an updated version of the patch.

I noticed that the patch I proposed has an issue for some cases.  Let
me explain.  I assumed that the slots trig_tuple_slot1 and
trig_tuple_slot2 passed to AfterTriggerExecute() are NULL if the
target table is not a foreign table, from thiscomment for that
function:

 *  trig_tuple_slot1: scratch slot for tg_trigtuple (foreign tables only)
 *  trig_tuple_slot2: scratch slot for tg_newtuple (foreign tables only)

but actually that's not true.  Consider an example:

postgres=# create table t1 (a int, b int);
postgres=# create table t2 (a int, b int);
postgres=# create server loopback foreign data wrapper postgres_fdw
options (dbname 'postgres');
postgres=# create user MAPPING FOR CURRENT_USER server loopback ;
postgres=# create foreign table ft1 (a int, b int) server loopback
options (table_name 't1');
postgres=# insert into t1 values (1, 1);
postgres=# create trigger trig_row_after_foreign after insert or
update or delete on ft1 for each row execute procedure trigger_data
(23, 'skidoo');
postgres=# create trigger trig_row_after_regular after insert or
update or delete on t2 for each row execute procedure trigger_data
(23, 'skidoo');

postgres=# with moved_rows as (update ft1 set a = 2, b = 2 where a = 1
returning *) insert into t2 select * from moved_rows;
NOTICE:  trig_row_after_foreign(23, skidoo) AFTER ROW UPDATE ON ft1
NOTICE:  OLD: (1,1),NEW: (2,2)
NOTICE:  trig_row_after_regular(23, skidoo) AFTER ROW INSERT ON t2
NOTICE:  NEW: (2,2)
INSERT 0 1

For this query, when executing the trigger trig_row_after_regular
(trigger on a regular table!) by AfterTriggerExecute(), the caller of
that function passes to it non-NULL trig_tuple_slot1 and
trig_tuple_slot2 made for the previous trigger trig_row_after_foreign.
And this causes AfterTriggerExecute() to incorrectly skip clearing
tg_trigtuple and tg_newtuple at the final step, because I made this
change to that function:

*** 4355,4364 **** AfterTriggerExecute(EState *estate,
    if (should_free_new)
        heap_freetuple(LocTriggerData.tg_newtuple);

!   if (LocTriggerData.tg_trigslot)
!       ExecClearTuple(LocTriggerData.tg_trigslot);
!   if (LocTriggerData.tg_newslot)
!       ExecClearTuple(LocTriggerData.tg_newslot);

    /*
     * If doing EXPLAIN ANALYZE, stop charging time to this trigger, and count
--- 4360,4373 ----
    if (should_free_new)
        heap_freetuple(LocTriggerData.tg_newtuple);

!   /* don't clear slots' contents if foreign table */
!   if (trig_tuple_slot1 == NULL)
!   {
!       if (LocTriggerData.tg_trigslot)
!           ExecClearTuple(LocTriggerData.tg_trigslot);
!       if (LocTriggerData.tg_newslot)
!           ExecClearTuple(LocTriggerData.tg_newslot);
!   }

To fix, I propose to modify the caller (ie,
afterTriggerInvokeEvents()) so that it sets the passed-in slots
trig_tuple_slot1 and trig_tuple_slot2 to NULL if the target table is
not a foreign table.  Attached is an updated patch for that.  I also
added the commit message.  If no objections, I'll push the patch.

Best regards,
Etsuro Fujita

On Fri, Dec 6, 2019 at 5:27 PM Etsuro Fujita <etsuro.fujita@gmail.com> wrote:
> If no objections, I'll push the patch.

Pushed.  Thanks for the report, Alexander Lakhin!

Best regards,
Etsuro Fujita