Re: Write Ahead Logging for Hash Indexes

Hi All,

Below is the backtrace for the issue reported in my earlier mail [1].
From the callstack it looks like we are trying to release lock on a
meta page twice in _hash_expandtable().

(gdb) bt
#0 0x00000000007b01cf in LWLockRelease (lock=0x7f55f59d0570) at lwlock.c:1799
#1 0x000000000078990c in LockBuffer (buffer=2, mode=0) at bufmgr.c:3540
#2 0x00000000004a5d3c in _hash_chgbufaccess (rel=0x7f5605b608c0,
buf=2, from_access=1, to_access=-1) at hashpage.c:331
#3 0x00000000004a722d in _hash_expandtable (rel=0x7f5605b608c0,
metabuf=2) at hashpage.c:995
#4 0x00000000004a316a in _hash_doinsert (rel=0x7f5605b608c0,
itup=0x2ba5030) at hashinsert.c:313
#5 0x00000000004a0d85 in hashinsert (rel=0x7f5605b608c0,
values=0x7ffdf5409c70, isnull=0x7ffdf5409c50 "", ht_ctid=0x2c2e4f4,
heapRel=0x7f5605b58250,
checkUnique=UNIQUE_CHECK_NO) at hash.c:248
#6 0x00000000004c5a16 in index_insert (indexRelation=0x7f5605b608c0,
values=0x7ffdf5409c70, isnull=0x7ffdf5409c50 "",
heap_t_ctid=0x2c2e4f4,
heapRelation=0x7f5605b58250, checkUnique=UNIQUE_CHECK_NO) at indexam.c:204
#7 0x000000000063f2d5 in ExecInsertIndexTuples (slot=0x2b9a2c0,
tupleid=0x2c2e4f4, estate=0x2b99c00, noDupErr=0 '\000',
specConflict=0x0,
arbiterIndexes=0x0) at execIndexing.c:388
#8 0x000000000066a1fc in ExecInsert (mtstate=0x2b99e50,
slot=0x2b9a2c0, planSlot=0x2b9a2c0, arbiterIndexes=0x0,
onconflict=ONCONFLICT_NONE,
estate=0x2b99c00, canSetTag=1 '\001') at nodeModifyTable.c:481
#9 0x000000000066b841 in ExecModifyTable (node=0x2b99e50) at
nodeModifyTable.c:1496
#10 0x0000000000645e51 in ExecProcNode (node=0x2b99e50) at execProcnode.c:396
#11 0x00000000006424d9 in ExecutePlan (estate=0x2b99c00,
planstate=0x2b99e50, use_parallel_mode=0 '\000', operation=CMD_INSERT,
sendTuples=0 '\000',
numberTuples=0, direction=ForwardScanDirection, dest=0xd73c20
<donothingDR>) at execMain.c:1567
#12 0x000000000064087a in standard_ExecutorRun (queryDesc=0x2b89c70,
direction=ForwardScanDirection, count=0) at execMain.c:338
#13 0x00007f55fe590605 in pgss_ExecutorRun (queryDesc=0x2b89c70,
direction=ForwardScanDirection, count=0) at pg_stat_statements.c:877
#14 0x0000000000640751 in ExecutorRun (queryDesc=0x2b89c70,
direction=ForwardScanDirection, count=0) at execMain.c:284
#15 0x00000000007c331e in ProcessQuery (plan=0x2b873f0,
sourceText=0x2b89bd0 "insert into foo (index) select $1 from
generate_series(1,10000)",
params=0x2b89c20, dest=0xd73c20 <donothingDR>,
completionTag=0x7ffdf540a3f0 "") at pquery.c:187
#16 0x00000000007c4a0c in PortalRunMulti (portal=0x2ae7930,
isTopLevel=1 '\001', setHoldSnapshot=0 '\000', dest=0xd73c20
<donothingDR>,
altdest=0xd73c20 <donothingDR>, completionTag=0x7ffdf540a3f0 "")
at pquery.c:1303
#17 0x00000000007c4055 in PortalRun (portal=0x2ae7930,
count=9223372036854775807, isTopLevel=1 '\001', dest=0x2b5dc90,
altdest=0x2b5dc90,
completionTag=0x7ffdf540a3f0 "") at pquery.c:815
#18 0x00000000007bfb45 in exec_execute_message (portal_name=0x2b5d880
"", max_rows=9223372036854775807) at postgres.c:1977
#19 0x00000000007c25c7 in PostgresMain (argc=1, argv=0x2b05df8,
dbname=0x2aca3c0 "postgres", username=0x2b05de0 "edb") at
postgres.c:4133
#20 0x0000000000744d8f in BackendRun (port=0x2aefa60) at postmaster.c:4260
#21 0x0000000000744523 in BackendStartup (port=0x2aefa60) at postmaster.c:3934
#22 0x0000000000740f9c in ServerLoop () at postmaster.c:1691
#23 0x0000000000740623 in PostmasterMain (argc=4, argv=0x2ac81f0) at
postmaster.c:1299
#24 0x00000000006940fe in main (argc=4, argv=0x2ac81f0) at main.c:228

Please let me know for any further inputs.

[1]- https://www.postgresql.org/message-id/CAE9k0Pmxh-4NAr4GjzDDFHdBKDrKy2FV-Z%2B2Tp8vb2Kmxu%3D6zg%40mail.gmail.com

With Regards,
Ashutosh Sharma
EnterpriseDB: http://www.enterprisedb.com

On Wed, Sep 14, 2016 at 2:45 PM, Ashutosh Sharma <ashu(dot)coek88(at)gmail(dot)com> wrote:
> Hi All,
>
> I am getting following error when running the test script shared by
> Jeff -[1] . The error is observed upon executing the test script for
> around 3-4 hrs.
>
> 57869 INSERT XX000 2016-09-14 07:58:01.211 IST:ERROR: lock
> buffer_content 1 is not held
> 57869 INSERT XX000 2016-09-14 07:58:01.211 IST:STATEMENT: insert into
> foo (index) select $1 from generate_series(1,10000)
>
> 124388 INSERT XX000 2016-09-14 11:24:13.593 IST:ERROR: lock
> buffer_content 10 is not held
> 124388 INSERT XX000 2016-09-14 11:24:13.593 IST:STATEMENT: insert
> into foo (index) select $1 from generate_series(1,10000)
>
> 124381 INSERT XX000 2016-09-14 11:24:13.594 IST:ERROR: lock
> buffer_content 10 is not held
> 124381 INSERT XX000 2016-09-14 11:24:13.594 IST:STATEMENT: insert
> into foo (index) select $1 from generate_series(1,10000)
>
> [1]- https://www.postgresql.org/message-id/CAMkU%3D1xRt8jBBB7g_7K41W00%3Dbr9UrxMVn_rhWhKPLaHfEdM5A%40mail.gmail.com
>
> Please note that i am performing the test on latest patch for
> concurrent hash index and WAL log in hash index shared by Amit
> yesterday.
>
>
> With Regards,
> Ashutosh Sharma
> EnterpriseDB: http://www.enterprisedb.com
>
>
>
> On Wed, Sep 14, 2016 at 12:04 AM, Jesper Pedersen
> <jesper(dot)pedersen(at)redhat(dot)com> wrote:
>> On 09/13/2016 07:41 AM, Amit Kapila wrote:
>>>>
>>>> README:
>>>> +in_complete split flag. The reader algorithm works correctly, as it
>>>> will
>>>> scan
>>>>
>>>> What flag ?
>>>>
>>>
>>> in-complete-split flag which indicates that split has to be finished
>>> for that particular bucket. The value of these flags are
>>> LH_BUCKET_NEW_PAGE_SPLIT and LH_BUCKET_OLD_PAGE_SPLIT for new and old
>>> bucket respectively. It is set in hasho_flag in special area of page.
>>> I have slightly expanded the definition in README, but not sure if it
>>> is good idea to mention flags defined in hash.h. Let me know, if still
>>> it is unclear or you want some thing additional to be added in README.
>>>
>>
>> I think it is better now.
>>
>>>> hashxlog.c:
>>>>
>>>> hash_xlog_move_page_contents
>>>> hash_xlog_squeeze_page
>>>>
>>>> Both have "bukcetbuf" (-> "bucketbuf"), and
>>>>
>>>> + if (BufferIsValid(bukcetbuf));
>>>>
>>>> ->
>>>>
>>>> + if (BufferIsValid(bucketbuf))
>>>>
>>>> and indent following line:
>>>>
>>>> LockBufferForCleanup(bukcetbuf);
>>>>
>>>> hash_xlog_delete
>>>>
>>>> has the "if" issue too.
>>>>
>>>
>>> Fixed all the above cosmetic issues.
>>>
>>
>> I meant there is an extra ';' on the "if" statements:
>>
>> + if (BufferIsValid(bukcetbuf)); <--
>>
>> in hash_xlog_move_page_contents, hash_xlog_squeeze_page and
>> hash_xlog_delete.
>>
>>
>> Best regards,
>> Jesper
>>
>>
>>
>>
>>
>> --
>> Sent via pgsql-hackers mailing list (pgsql-hackers(at)postgresql(dot)org)
>> To make changes to your subscription:
>> http://www.postgresql.org/mailpref/pgsql-hackers