Re: [sqlsmith] Short reads in hash indexes

Andreas Seltenreich writes:

> Amit Kapila writes:
>
>> On Sat, Dec 3, 2016 at 3:44 PM, Andreas Seltenreich <seltenreich(at)gmx(dot)de> wrote:
>>> Amit Kapila writes:
>>>
>>>> [2. text/x-diff; fix_hash_bucketsplit_sqlsmith_v1.patch]
>>> Ok, I'll do testing with the patch applied.
>
> Good news: the assertion hasn't fired since the patch is in.

Meh, it fired again today after being silent for 100e6 queries :-/
I guess I need to add some confidence qualification on such statements.
Maybe sigmas as they do at CERN…

> smith=# select * from state_report where sqlstate = 'XX001';
> -[ RECORD 1 ]------------------------------------------------------------------------------
> count | 10
> sqlstate | XX001
> sample | ERROR: could not read block 1173 in file "base/16384/17256": read only 0 of 8192 bytes
> hosts | {airbisquit,frell,gorgo,marbit,pillcrow,quakken}
>
>> Hmm, I am not sure if this is related to previous problem, but it
>> could be. Is it possible to get the operation and or callstack for
>> above failure?
>
> Ok, will turn the elog into an assertion to get at the backtraces.

Doing so on top of 4212cb7, I caught the backtrace below. Query was:

--8<---------------cut here---------------start------------->8---
set max_parallel_workers_per_gather = 0;
select count(1) from
public.hash_name_heap as ref_2
join public.rtest_emplog as sample_1
on (ref_2.random = sample_1.who);
--8<---------------cut here---------------end--------------->8---

I've put the data directory where it can be reproduced here:

http://ansel.ydns.eu/~andreas/hash_index_short_read.tar.xz (12MB)

regards,
Andreas

TRAP: FailedAssertion("!(!"short read of block")", File: "md.c", Line: 782)
#2 0x00000000007f7f11 in ExceptionalCondition (conditionName=conditionName(at)entry=0x9a1ae9 "!(!\"short read of block\")", errorType=errorType(at)entry=0x83db3d "FailedAssertion", fileName=fileName(at)entry=0x946a9a "md.c", lineNumber=lineNumber(at)entry=782) at assert.c:54
#3 0x00000000006fb305 in mdread (reln=<optimized out>, forknum=<optimized out>, blocknum=4702, buffer=0x7fe97e7e1280 "\"") at md.c:782
#4 0x00000000006d0ffa in ReadBuffer_common (smgr=0x2af7408, relpersistence=<optimized out>, forkNum=forkNum(at)entry=MAIN_FORKNUM, blockNum=blockNum(at)entry=4702, mode=RBM_NORMAL, strategy=<optimized out>, hit=0x7ffde9df11cf "") at bufmgr.c:890
#5 0x00000000006d1a20 in ReadBufferExtended (reln=0x2fd10d8, forkNum=forkNum(at)entry=MAIN_FORKNUM, blockNum=4702, mode=mode(at)entry=RBM_NORMAL, strategy=strategy(at)entry=0x0) at bufmgr.c:664
#6 0x00000000006d1b74 in ReadBuffer (blockNum=<optimized out>, reln=<optimized out>) at bufmgr.c:596
#7 ReleaseAndReadBuffer (buffer=buffer(at)entry=87109984, relation=<optimized out>, blockNum=<optimized out>) at bufmgr.c:1540
#8 0x00000000004c047b in index_fetch_heap (scan=scan(at)entry=0x5313160) at indexam.c:469
#9 0x00000000004c05ee in index_getnext (scan=scan(at)entry=0x5313160, direction=direction(at)entry=ForwardScanDirection) at indexam.c:565
#10 0x00000000005f9b71 in IndexNext (node=node(at)entry=0x5311c48) at nodeIndexscan.c:105
#11 0x00000000005ec492 in ExecScanFetch (recheckMtd=0x5f9af0 <IndexRecheck>, accessMtd=0x5f9b30 <IndexNext>, node=0x5311c48) at execScan.c:95
#12 ExecScan (node=0x5311c48, accessMtd=0x5f9b30 <IndexNext>, recheckMtd=0x5f9af0 <IndexRecheck>) at execScan.c:145
#13 0x00000000005e4da8 in ExecProcNode (node=node(at)entry=0x5311c48) at execProcnode.c:427
#14 0x00000000006014f9 in ExecNestLoop (node=node(at)entry=0x53110a8) at nodeNestloop.c:174
#15 0x00000000005e4cf8 in ExecProcNode (node=node(at)entry=0x53110a8) at execProcnode.c:476
#16 0x0000000000601436 in ExecNestLoop (node=node(at)entry=0x5310e00) at nodeNestloop.c:123
#17 0x00000000005e4cf8 in ExecProcNode (node=node(at)entry=0x5310e00) at execProcnode.c:476
#18 0x0000000000601436 in ExecNestLoop (node=node(at)entry=0x530f698) at nodeNestloop.c:123
#19 0x00000000005e4cf8 in ExecProcNode (node=node(at)entry=0x530f698) at execProcnode.c:476
#20 0x00000000005e0e9e in ExecutePlan (dest=0x603a4a8, direction=<optimized out>, numberTuples=0, sendTuples=<optimized out>, operation=CMD_SELECT, use_parallel_mode=<optimized out>, planstate=0x530f698, estate=0x46bc008) at execMain.c:1568
#21 standard_ExecutorRun (queryDesc=0x3475168, direction=<optimized out>, count=0) at execMain.c:338
#22 0x00000000007029f8 in PortalRunSelect (portal=portal(at)entry=0x2561e18, forward=forward(at)entry=1 '\001', count=0, count(at)entry=9223372036854775807, dest=dest(at)entry=0x603a4a8) at pquery.c:946
#23 0x0000000000703f3e in PortalRun (portal=portal(at)entry=0x2561e18, count=count(at)entry=9223372036854775807, isTopLevel=isTopLevel(at)entry=1 '\001', dest=dest(at)entry=0x603a4a8, altdest=altdest(at)entry=0x603a4a8, completionTag=completionTag(at)entry=0x7ffde9df18b0 "") at pquery.c:787
#24 0x0000000000700d5b in exec_simple_query (query_string=0x4685258 ) at postgres.c:1094
#25 PostgresMain (argc=<optimized out>, argv=argv(at)entry=0x256f5a8, dbname=0x256f580 "regression", username=<optimized out>) at postgres.c:4069
#26 0x000000000046daf2 in BackendRun (port=0x25645a0) at postmaster.c:4274
#27 BackendStartup (port=0x25645a0) at postmaster.c:3946
#28 ServerLoop () at postmaster.c:1704
#29 0x0000000000699d28 in PostmasterMain (argc=argc(at)entry=4, argv=argv(at)entry=0x25425c0) at postmaster.c:1312
#30 0x000000000046ec96 in main (argc=4, argv=0x25425c0) at main.c:228