Re: BUG #17284: Assert failed in SerialAdd() when the summarize_serial mode is engaged

Hello hackers,
13.11.2021 15:00, PG Bug reporting form wrote:
> When running concurrent installchecks (x100) for src/test/isolation, I've
> observed the following server crash:
> Core was generated by `postgres: postgres regress30 127.0.0.1(55840) SEL'.
> Program terminated with signal SIGABRT, Aborted.
> #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
> 50      ../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:50
> #1  0x00007fd1b69d5535 in __GI_abort () at abort.c:79
> #2  0x000055d441cc3a02 in ExceptionalCondition (
>     conditionName=conditionName@entry=0x55d441e34cd2
> "TransactionIdIsValid(tailXid)", 
>     errorType=errorType@entry=0x55d441d1c01d "FailedAssertion",
> fileName=fileName@entry=0x55d441e34bc9 "predicate.c", 
>     lineNumber=lineNumber@entry=928) at assert.c:67
> #3  0x000055d441b8e0aa in SerialAdd
> (minConflictCommitSeqNo=18446744073709551615, xid=95552353) at
> predicate.c:928

The issue is reproduced (on REL_14_STABLE) with the following command
sequence (can be replayed with pgreplay):

2021-12-29 18:00:15.000 MSK|postgres|regression|61cc77ff.18af00|LOG: 
statement:
     create table D1 (id int not null);
     create table D2 (id int not null);
     insert into D1 values (1);
     insert into D2 values (1);
2021-12-29 18:00:15.100 MSK|postgres|regression|61cc77ff.18af00|LOG: 
disconnection: session time: 0:00:01.129 user=postgres
database=regression host=127.0.0.1 port=46730
2021-12-29 18:00:15.200 MSK|postgres|regression|61cc77ff.18af01|LOG: 
statement: begin isolation level serializable;
2021-12-29 18:00:15.300 MSK|postgres|regression|61cc77ff.18af02|LOG: 
statement: begin isolation level serializable;
2021-12-29 18:00:15.400 MSK|postgres|regression|61cc77ff.18af02|LOG: 
statement: update D2 set id = id + 1;
2021-12-29 18:00:15.500 MSK|postgres|regression|61cc77ff.18af02|LOG: 
statement: commit;
2021-12-29 18:00:15.600 MSK|postgres|regression|61cc77ff.18af03|LOG: 
statement: begin isolation level serializable;
2021-12-29 18:00:15.700 MSK|postgres|regression|61cc77ff.18af01|LOG: 
statement: update D1 set id = id + 1;
2021-12-29 18:00:15.800 MSK|postgres|regression|61cc77ff.18af03|LOG: 
statement: select id from D1;
2021-12-29 18:00:15.800 MSK|postgres|regression|61cc77ff.18af01|LOG: 
disconnection: session time: 0:00:01.000 user=postgres
database=regression host=127.0.0.1 port=46731
2021-12-29 18:00:15.900 MSK|postgres|regression|61cc77ff.18af02|LOG: 
statement: select pg_sleep(1);

To ease a reproduction, the following delays can be added to predicate.c:
@@ -1502,6 +1507,7 @@ SummarizeOldestCommittedSxact(void)
 {
        SERIALIZABLEXACT *sxact;
 
+       pg_usleep(1000000);
        LWLockAcquire(SerializableFinishedListLock, LW_EXCLUSIVE);
 
        /*

@@ -3745,6 +3760,7 @@ ClearOldPredicateLocks(void)
        SERIALIZABLEXACT *finishedSxact;
        PREDICATELOCK *predlock;
 
+       pg_usleep(2000000);
        /*
         * Loop through finished transactions. They are in commit order,
so we can
         * stop as soon as we find one that's still interesting.

With these delays and CPPFLAGS="-DTEST_SUMMARIZE_SERIAL" the assertion
failure can be observed just on `make check`.
As I can see, on disconnect of session 18af01 the
ReleasePredicateLocks() function calls SetNewSxactGlobalXmin() where
SerialSetActiveSerXmin(called with PredXact->SxactGlobalXmin ==
InvalidTransactionId) sets serialControl->tailXid to InvalidTransactionId.
Then session 18af03 calls SummarizeOldestCommittedSxact(), that in case
!SHMQueueEmpty(FinishedSerializableTransactions) calls SerialAdd() where
the check TransactionIdIsValid(serialControl->tailXid) fails.
But if ReleasePredicateLocks() in session 18af01 happens to reach
ReleasePredicateLocks(), the FinishedSerializableTransactions queue gets
empty, and it would prevent calling SerialAdd() in session 18af03.
So there is a small window (that probably can be widened by
LWLockAcquire()) between
            SetNewSxactGlobalXmin();
            needToClear = true;
and
    if (needToClear)
        ClearOldPredicateLocks();
where a concurrent transaction can fail in SummarizeOldestCommittedSxact().

Best regards,
Alexander