Thread: BUG #18396: Assert in gistFindCorrectParent() fails on inserting large tuples into gist index

The following bug has been logged on the website:

Bug reference:      18396
Logged by:          Alexander Lakhin
Email address:      exclusion@gmail.com
PostgreSQL version: 16.2
Operating system:   Ubuntu 22.04
Description:       

The following script:
psql -c "CREATE EXTENSION btree_gist;"
numclients=50
for ((i=1;i<=100;i++)); do
  echo "iteration $i"
  for ((c=1;c<=$numclients;c++)); do
    echo "
CREATE TEMP TABLE t (a text);
CREATE INDEX idx ON t USING GIST (a);

INSERT INTO t SELECT '' FROM generate_series(1, 500) g;
INSERT INTO t SELECT
 (SELECT string_agg('text' || g, ' ') FROM generate_series(1, 600) g)
 FROM generate_series(1, 30);
" | psql >psql-$c.log &
  done
wait
grep 'TRAP:' server.log  && { res=0; break; }
done

triggers an assertion failure:
...
iteration 4
server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request.
connection to server was lost
TRAP: failed Assert("parent->lsn != PageGetLSN(parent->page) || is_build"),
File: "gist.c", Line: 1050, PID: 789065

with the stack trace:
#0  __pthread_kill_implementation (no_tid=0, signo=6,
threadid=140380599453504) at ./nptl/pthread_kill.c:44
#1  __pthread_kill_internal (signo=6, threadid=140380599453504) at
./nptl/pthread_kill.c:78
#2  __GI___pthread_kill (threadid=140380599453504, signo=signo@entry=6) at
./nptl/pthread_kill.c:89
#3  0x00007face7209476 in __GI_raise (sig=sig@entry=6) at
../sysdeps/posix/raise.c:26
#4  0x00007face71ef7f3 in __GI_abort () at ./stdlib/abort.c:79
#5  0x0000558b58981037 in ExceptionalCondition
(conditionName=conditionName@entry=0x558b589e6a80 "parent->lsn !=
PageGetLSN(parent->page) || is_build",
fileName=fileName@entry=0x558b58b44840 "gist.c",
lineNumber=lineNumber@entry=1050)
    at assert.c:66
#6  0x0000558b58452dc3 in gistFindCorrectParent (r=0x7facdb4a6760,
child=child@entry=0x558b5978ac68, is_build=<optimized out>) at gist.c:1050
#7  0x0000558b58455407 in gistfinishsplit (state=state@entry=0x7ffd28324ee0,
stack=stack@entry=0x558b5978ac68, giststate=giststate@entry=0x558b59712ad8,
splitinfo=<optimized out>, unlockbuf=unlockbuf@entry=true) at gist.c:1394
#8  0x0000558b58455122 in gistinserttuples
(state=state@entry=0x7ffd28324ee0, stack=0x558b5978ac68,
giststate=giststate@entry=0x558b59712ad8,
tuples=tuples@entry=0x7ffd28324c80, ntup=ntup@entry=2, oldoffnum=<optimized
out>,
    leftchild=-37, rightchild=-40, unlockbuf=true, unlockleftchild=false) at
gist.c:1324
#9  0x0000558b58455437 in gistfinishsplit (state=state@entry=0x7ffd28324ee0,
stack=stack@entry=0x558b59720148, giststate=giststate@entry=0x558b59712ad8,
splitinfo=<optimized out>, unlockbuf=unlockbuf@entry=false) at gist.c:1395
#10 0x0000558b58455122 in gistinserttuples
(state=state@entry=0x7ffd28324ee0, stack=0x558b59720148,
giststate=giststate@entry=0x558b59712ad8,
tuples=tuples@entry=0x558b59760c60, ntup=ntup@entry=1,
oldoffnum=oldoffnum@entry=0,
    leftchild=-33, rightchild=-34, unlockbuf=false, unlockleftchild=false)
at gist.c:1324
#11 0x0000558b584552ee in gistfinishsplit (state=state@entry=0x7ffd28324ee0,
stack=stack@entry=0x558b59738178, giststate=giststate@entry=0x558b59712ad8,
splitinfo=0x558b59760be8, unlockbuf=unlockbuf@entry=false) at gist.c:1370
#12 0x0000558b58455122 in gistinserttuples
(state=state@entry=0x7ffd28324ee0, stack=stack@entry=0x558b59738178,
giststate=giststate@entry=0x558b59712ad8,
tuples=tuples@entry=0x7ffd28324e78, ntup=ntup@entry=1,
    oldoffnum=oldoffnum@entry=0, leftchild=0, rightchild=0, unlockbuf=false,
unlockleftchild=false) at gist.c:1324
#13 0x0000558b5845584e in gistinserttuple (state=state@entry=0x7ffd28324ee0,
stack=stack@entry=0x558b59738178, giststate=giststate@entry=0x558b59712ad8,
tuple=<optimized out>, tuple@entry=0x558b5971b228,
oldoffnum=oldoffnum@entry=0)
    at gist.c:1250
#14 0x0000558b58455df0 in gistdoinsert (r=r@entry=0x7facdb4a6760,
itup=0x558b5971b228, freespace=freespace@entry=0,
giststate=giststate@entry=0x558b59712ad8,
heapRel=heapRel@entry=0x7facdb4a0e48, is_build=is_build@entry=false)
    at gist.c:886
#15 0x0000558b584568df in gistinsert (r=0x7facdb4a6760,
values=0x7ffd283250a0, isnull=0x7ffd28325080, ht_ctid=0x558b596f5428,
heapRel=0x7facdb4a0e48, checkUnique=<optimized out>, indexUnchanged=false,
indexInfo=0x558b596f6938)
    at gist.c:184
#16 0x0000558b5849b579 in index_insert
(indexRelation=indexRelation@entry=0x7facdb4a6760,
values=values@entry=0x7ffd283250a0, isnull=isnull@entry=0x7ffd28325080,
heap_t_ctid=heap_t_ctid@entry=0x558b596f5428,
    heapRelation=heapRelation@entry=0x7facdb4a0e48,
checkUnique=checkUnique@entry=UNIQUE_CHECK_NO, indexUnchanged=false,
indexInfo=0x558b596f6938) at indexam.c:235
#17 0x0000558b5864e668 in ExecInsertIndexTuples
(resultRelInfo=resultRelInfo@entry=0x558b596de518,
slot=slot@entry=0x558b596f53f8, estate=estate@entry=0x558b596ba2f8,
update=update@entry=false, noDupErr=noDupErr@entry=false,
    specConflict=specConflict@entry=0x0, arbiterIndexes=0x0,
onlySummarizing=false) at execIndexing.c:432
#18 0x0000558b5868422f in ExecInsert (context=context@entry=0x7ffd28325300,
resultRelInfo=resultRelInfo@entry=0x558b596de518, slot=0x558b596f53f8,
canSetTag=true, inserted_tuple=inserted_tuple@entry=0x0,
    insert_destrel=insert_destrel@entry=0x0) at nodeModifyTable.c:1139
...

Reproduced on REL_12_STABLE .. master, starting from the commit 28d3c2ddc,
which introduced this assert.

Hello Heikki and Tender Wang,

19.03.2024 17:26, Heikki Linnakangas wrote:
> On 19/03/2024 14:07, Tender Wang wrote:
>> Thanks for your report. I can reproduce this issue.
>> I try to delete the Assert, no coredump anymore.
>> I need some time to learn GiST to find the root cause.
>
> If you're interested to work on this, Tender, maybe you can figure that out?

>

Thank you for looking at this!

I'm also bothered by errors "no empty local buffer available" produced
(on master, but not on REL_12_STABLE) when inserting larger tuples:
INSERT INTO t SELECT '' FROM generate_series(1, 500) g;
INSERT INTO t SELECT
  (SELECT string_agg('text' || g, ' ') FROM generate_series(1, 700) g)
  FROM generate_series(1, 30);

Are those errors expected?

On 19/03/2024 14:07, Tender Wang wrote:
> Thanks for your report. I can reproduce this issue.
> I try to delete the Assert, no coredump anymore.
> I need some time to learn GiST to find the root cause.
At first glance, I think the assertion is too strict. In
gistFindCorrectParent(), if we walk right, we update the parent's block
number and reset its memorized downlinkoffnum to InvalidOffsetNumber. If
we later call gistFindCorrectParent() again with the same stack, because
the parent also needs to be split, we hit that assertion. But it's OK in
that case, we don't know the downlink because we had moved right.
Attached patch relaxes that.

But now I'm having some second thoughts. gistFindCorrectParent() looks
like this:

>       /*
>        * Scan the page to re-find the downlink. If the page was split, it might
>        * have moved to a different page, so follow the right links until we find
>        * it.
>        */
>       while (true)
>       {
>               OffsetNumber i;
>
>               maxoff = PageGetMaxOffsetNumber(parent->page);
>               for (i = FirstOffsetNumber; i <= maxoff; i = OffsetNumberNext(i))
>               {
>                       iid = PageGetItemId(parent->page, i);
>                       idxtuple = (IndexTuple) PageGetItem(parent->page, iid);
>                       if (ItemPointerGetBlockNumber(&(idxtuple->t_tid)) == child->blkno)
>                       {
>                               /* yes!!, found */
>                               child->downlinkoffnum = i;
>                               return;
>                       }
>               }
>
>               parent->blkno = GistPageGetOpaque(parent->page)->rightlink;
>               parent->downlinkoffnum = InvalidOffsetNumber;
>               UnlockReleaseBuffer(parent->buffer);
>               if (parent->blkno == InvalidBlockNumber)
>               {
>                       /*
>                        * End of chain and still didn't find parent. It's a very-very
>                        * rare situation when the root was split.
>                        */
>                       break;
>               }
>               parent->buffer = ReadBuffer(r, parent->blkno);
>               LockBuffer(parent->buffer, GIST_EXCLUSIVE);
>               gistcheckpage(r, parent->buffer);
>               parent->page = (Page) BufferGetPage(parent->buffer);
>       }

When we step right and update parent->blkno, shouldn't we also update
parent->lsn? Otherwise, we might fail to detect a concurrent page split
with the LSN-NSN interlock checks. Or maybe it's correct, and we should
indeed not update the memorized LSN. Or maybe it doesn't matter because
we retry from the parent anyway, thanks to the 'retry_from_parent' flag?
I'm not sure..

If you're interested to work on this, Tender, maybe you can figure that out?

--
Heikki Linnakangas
Neon (https://neon.tech)

On 19/03/2024 14:07, Tender Wang wrote:
> Thanks for your report. I can reproduce this issue.
> I try to delete the Assert, no coredump anymore.
> I need some time to learn GiST to find the root cause.
At first glance, I think the assertion is too strict. In
gistFindCorrectParent(), if we walk right, we update the parent's block
number and reset its memorized downlinkoffnum to InvalidOffsetNumber. If
we later call gistFindCorrectParent() again with the same stack, because
the parent also needs to be split, we hit that assertion. But it's OK in
that case, we don't know the downlink because we had moved right.
Attached patch relaxes that.

But now I'm having some second thoughts. gistFindCorrectParent() looks
like this:

>       /*
>        * Scan the page to re-find the downlink. If the page was split, it might
>        * have moved to a different page, so follow the right links until we find
>        * it.
>        */
>       while (true)
>       {
>               OffsetNumber i;
>
>               maxoff = PageGetMaxOffsetNumber(parent->page);
>               for (i = FirstOffsetNumber; i <= maxoff; i = OffsetNumberNext(i))
>               {
>                       iid = PageGetItemId(parent->page, i);
>                       idxtuple = (IndexTuple) PageGetItem(parent->page, iid);
>                       if (ItemPointerGetBlockNumber(&(idxtuple->t_tid)) == child->blkno)
>                       {
>                               /* yes!!, found */
>                               child->downlinkoffnum = i;
>                               return;
>                       }
>               }
>
>               parent->blkno = GistPageGetOpaque(parent->page)->rightlink;
>               parent->downlinkoffnum = InvalidOffsetNumber;
>               UnlockReleaseBuffer(parent->buffer);
>               if (parent->blkno == InvalidBlockNumber)
>               {
>                       /*
>                        * End of chain and still didn't find parent. It's a very-very
>                        * rare situation when the root was split.
>                        */
>                       break;
>               }
>               parent->buffer = ReadBuffer(r, parent->blkno);
>               LockBuffer(parent->buffer, GIST_EXCLUSIVE);
>               gistcheckpage(r, parent->buffer);
>               parent->page = (Page) BufferGetPage(parent->buffer);
>       }

When we step right and update parent->blkno, shouldn't we also update
parent->lsn? Otherwise, we might fail to detect a concurrent page split
with the LSN-NSN interlock checks. Or maybe it's correct, and we should
indeed not update the memorized LSN. Or maybe it doesn't matter because
we retry from the parent anyway, thanks to the 'retry_from_parent' flag?
I'm not sure..