Re: [sqlsmith] PANIC: failed to add BRIN tuple

I wrote:

> Re-fuzzing now with your patch applied.

This so far yielded three BRIN core dumps on different machines with the
same backtraces. Crash recovery fails in these cases.

I've put the data directory here (before recovery):

http://ansel.ydns.eu/~andreas/brincrash2-spidew.tar.xz (9.1M)

Corresponding backtraces of the backend and startup core files below.

regards,
Andreas

Core was generated by `postgres: smith brintest [local] UPDATE '.
Program terminated with signal SIGABRT, Aborted.
#0 0x00007f5a49a9c067 in __GI_raise (sig=sig(at)entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
56 ../nptl/sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt
#0 0x00007f5a49a9c067 in __GI_raise (sig=sig(at)entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#1 0x00007f5a49a9d448 in __GI_abort () at abort.c:89
#2 0x00000000007ec979 in errfinish (dummy=dummy(at)entry=0) at elog.c:557
#3 0x00000000007f012c in elog_finish (elevel=elevel(at)entry=20, fmt=fmt(at)entry=0x989cf0 "incorrect index offsets supplied") at elog.c:1378
#4 0x00000000006eda2f in PageIndexDeleteNoCompact (page=page(at)entry=0x7f5a48c6f200 "Y", itemnos=itemnos(at)entry=0x7ffe6d0d0abc, nitems=nitems(at)entry=1) at bufpage.c:1011
#5 0x0000000000470119 in brin_doupdate (idxrel=0x1c5a530, pagesPerRange=1, revmap=0x91a7d90, heapBlk=2166, oldbuf=3782, oldoff=2, origtup=0x719db80, origsz=3656, newtup=0x754e188, newsz=3656, samepage=1 '\001') at brin_pageops.c:181
#6 0x000000000046e5db in brininsert (idxRel=0x1c5a530, values=0x6591, nulls=0x6 <error: Cannot access memory at address 0x6>, heaptid=0xffffffffffffffff, heapRel=0x7f5a4a72f700, checkUnique=UNIQUE_CHECK_NO) at brin.c:244
#7 0x00000000005d888f in ExecInsertIndexTuples (slot=0x91a4870, tupleid=0x91a7df4, estate=0x91b9b38, noDupErr=0 '\000', specConflict=0x0, arbiterIndexes=0x0) at execIndexing.c:383
#8 0x00000000005f74e5 in ExecUpdate (tupleid=0x7ffe6d0d0ed0, oldtuple=0x6591, slot=0x91a4870, planSlot=0xffffffffffffffff, epqstate=0x7f5a4a72f700, estate=0x91b9b38, canSetTag=1 '\001') at nodeModifyTable.c:1015
#9 0x00000000005f7b7c in ExecModifyTable (node=0x71861c0) at nodeModifyTable.c:1501
#10 0x00000000005dd5e8 in ExecProcNode (node=node(at)entry=0x71861c0) at execProcnode.c:396
#11 0x00000000005d963f in ExecutePlan (dest=0x17bb870, direction=<optimized out>, numberTuples=0, sendTuples=<optimized out>, operation=CMD_UPDATE, use_parallel_mode=<optimized out>, planstate=0x71861c0, estate=0x91b9b38) at execMain.c:1567
#12 standard_ExecutorRun (queryDesc=0x17bb908, direction=<optimized out>, count=0) at execMain.c:338
#13 0x00000000006f74d9 in ProcessQuery (plan=<optimized out>, sourceText=0x1670e18 "update public.brintest set \n charcol = null, \n namecol = pg_catalog.name(cast(null as character varying)\n ), \n int8col = null, \n int2col = public.brintest.int2col, \n textcol = null, \n float4col = null, \n float8col = cast(coalesce(null,\n\n public.brintest.float8col) as double precision), \n inetcol = public.brintest.inetcol, \n cidrcol = public.brintest.cidrcol, \n bpcharcol = null, \n datecol = (select datecol from public.brintest limit 1 offset 25)\n, \n timecol = (select timecol from public.brintest limit 1 offset 42)\n, \n timetzcol = (select timetzcol from public.brintest limit 1 offset 3)\n, \n numericcol = (select numericcol from public.brintest limit 1 offset 32)\n, \n uuidcol = public.brintest.uuidcol\nreturning \n public.brintest.datecol as c0;", params=0x0, dest=0x17bb870, completionTag=0x7ffe6d0d10a0 "") at pquery.c:185
#14 0x00000000006f776f in PortalRunMulti (portal=portal(at)entry=0x1611b68, isTopLevel=isTopLevel(at)entry=1 '\001', dest=dest(at)entry=0x17bb870, altdest=0xc96680 <donothingDR>, completionTag=completionTag(at)entry=0x7ffe6d0d10a0 "") at pquery.c:1267
#15 0x00000000006f7a1c in FillPortalStore (portal=portal(at)entry=0x1611b68, isTopLevel=isTopLevel(at)entry=1 '\001') at pquery.c:1044
#16 0x00000000006f846d in PortalRun (portal=0x1611b68, count=9223372036854775807, isTopLevel=<optimized out>, dest=0x756c870, altdest=0x756c870, completionTag=0x7ffe6d0d1450 "") at pquery.c:782
#17 0x00000000006f5c73 in exec_simple_query (query_string=<optimized out>) at postgres.c:1094
#18 PostgresMain (argc=23141224, argv=0x2cab518, dbname=0x15f3578 "brintest", username=0x2cab570 "\030\265\312\002") at postgres.c:4059
#19 0x000000000046c8d2 in BackendRun (port=0x1618880) at postmaster.c:4258
#20 BackendStartup (port=0x1618880) at postmaster.c:3932
#21 ServerLoop () at postmaster.c:1690
#22 0x00000000006907fe in PostmasterMain (argc=argc(at)entry=4, argv=argv(at)entry=0x15f2560) at postmaster.c:1298
#23 0x000000000046d82d in main (argc=4, argv=0x15f2560) at main.c:228
(gdb) frame 4
#4 0x00000000006eda2f in PageIndexDeleteNoCompact (page=page(at)entry=0x7f5a48c6f200 "Y", itemnos=itemnos(at)entry=0x7ffe6d0d0abc, nitems=nitems(at)entry=1) at bufpage.c:1011
1011 elog(ERROR, "incorrect index offsets supplied");
(gdb) list
1006 }
1007 }
1008
1009 /* this will catch invalid or out-of-order itemnos[] */
1010 if (nextitm != nitems)
1011 elog(ERROR, "incorrect index offsets supplied");
1012
1013 if (empty)
1014 {
1015 /* Page is completely empty, so just reset it quickly */
(gdb) up
#5 0x0000000000470119 in brin_doupdate (idxrel=0x1c5a530, pagesPerRange=1, revmap=0x91a7d90, heapBlk=2166, oldbuf=3782, oldoff=2, origtup=0x719db80, origsz=3656, newtup=0x754e188, newsz=3656, samepage=1 '\001') at brin_pageops.c:181
(gdb) list
176 brin_initialize_empty_new_buffer(idxrel, newbuf);
177 UnlockReleaseBuffer(newbuf);
178 }
179
180 START_CRIT_SECTION();
181 PageIndexDeleteNoCompact(oldpage, &oldoff, 1);
182 if (PageAddItemFlags(oldpage, (Item) newtup, newsz, oldoff,
183 PAI_OVERWRITE | PAI_ALLOW_LARGE_OFFSET) ==
184 InvalidOffsetNumber)
185 elog(ERROR, "failed to add BRIN tuple");

2016-05-25 13:54:55.955 CEST [14614] LOG: redo starts at 59/DB000050
2016-05-25 13:54:56.014 CEST [14614] PANIC: brin_xlog_samepage_update: failed to add tuple
2016-05-25 13:54:56.014 CEST [14614] CONTEXT: xlog redo at 59/EC09EBD0 for BRIN/SAMEPAGE_UPDATE: offnum 2
$ gdb postgres data/postgres(dot)14614(at)(dot)core
Core was generated by `postgres: startup process recovering 000000010000005'.
Program terminated with signal SIGABRT, Aborted.
(gdb) bt
bt
#0 0x00007f234df5d507 in __GI_raise (sig=sig(at)entry=6)
at ../sysdeps/unix/sysv/linux/raise.c:55
#1 0x00007f234df5e8da in __GI_abort () at abort.c:89
#2 0x00000000007ed289 in errfinish (dummy=dummy(at)entry=0) at elog.c:557
#3 0x00000000007f0a5c in elog_finish (elevel=elevel(at)entry=22,
fmt=fmt(at)entry=0x82ec08 "brin_xlog_samepage_update: failed to add tuple")
at elog.c:1378
#4 0x0000000000473be5 in brin_xlog_samepage_update (record=<optimized out>)
at brin_xlog.c:198
#5 brin_redo (record=<optimized out>) at brin_xlog.c:279
#6 0x00000000004fbeaa in StartupXLOG () at xlog.c:6871
#7 0x0000000000691d91 in StartupProcessMain () at startup.c:216
#8 0x0000000000509f57 in AuxiliaryProcessMain (argc=argc(at)entry=2,
argv=argv(at)entry=0x7ffe245352b0) at bootstrap.c:419
#9 0x000000000068eeea in StartChildProcess (type=StartupProcess)
at postmaster.c:5227
#10 0x00000000006917a5 in PostmasterMain (argc=argc(at)entry=3,
argv=argv(at)entry=0x2c9c540) at postmaster.c:1290
#11 0x000000000046db36 in main (argc=3, argv=0x2c9c540) at main.c:228
(gdb) frame 4
#4 0x0000000000473be5 in brin_xlog_samepage_update (record=<optimized out>)
at brin_xlog.c:198
(gdb) list
list
193 elog(PANIC, "brin_xlog_samepage_update: invalid max offset number");
194
195 PageIndexDeleteNoCompact(page, &offnum, 1);
196 offnum = PageAddItem(page, (Item) brintuple, tuplen, offnum, true, false);
197 if (offnum == InvalidOffsetNumber)
198 elog(PANIC, "brin_xlog_samepage_update: failed to add tuple");
199
200 PageSetLSN(page, lsn);
201 MarkBufferDirty(buffer);
202 }