Re: C_C_A animal on HEAD gets stuck in initdb

* Thomas Munro wrote:

> On Mon, Apr 1, 2019 at 9:39 PM Christian Ullrich <chris(at)chrullrich(dot)net> wrote:
>> my CLOBBER_CACHE_ALWAYS animal, jaguarundi, has gotten stuck in "make
>> check"'s initdb three times in a row now.
>
> Could it be the same as this?
>
> https://www.postgresql.org/message-id/CA%2BhUKGLCwPF0S4Mk7S8qw%2BDK0Bq65LueN9rofAA3HHSYikW-Zw%40mail.gmail.com
>
> I see that its first failure was after commit 558a9165e0 (along with others).

It does look very similar. I don't have a working gdb on the box, hence
this is from lldb.

(lldb) bt
* thread #1, name = 'postgres'
* frame #0: 0x00000008020e4ce8 libc.so.7`_umtx_op + 8
frame #1: 0x00000008020d0e5e libc.so.7`_sem_clockwait_np [inlined]
usem_wait(sem=<unavailable>, clock_id=0, rmtp=<unavailable>) at
cancelpoints_sem_new.c:365
frame #2: 0x00000008020d0e4f
libc.so.7`_sem_clockwait_np(sem=<unavailable>, clock_id=0,
flags=<unavailable>, rqtp=0x0000000000000000, rmtp=<unavailable>) at
cancelpoints_sem_new.c:424
frame #3: 0x00000000007104e8
postgres`PGSemaphoreLock(sema=0x00000008032031b0) at pg_sema.c:316
frame #4: 0x0000000000796889
postgres`LWLockAcquire(lock=0x0000000803725924, mode=LW_SHARED) at
lwlock.c:1244
frame #5: 0x000000000077157a
postgres`LockBuffer(buffer=<unavailable>, mode=1) at bufmgr.c:0
frame #6: 0x00000000004f54f1 postgres`_bt_getroot [inlined]
_bt_getbuf(rel=<unavailable>, blkno=<unavailable>, access=1) at
nbtpage.c:806
frame #7: 0x00000000004f54cd
postgres`_bt_getroot(rel=0x000000080314d080, access=1) at nbtpage.c:323
frame #8: 0x00000000004fa7fa
postgres`_bt_search(rel=0x000000080314d080, key=0x00007fffffffb508,
bufP=0x00007fffffffbf28, access=1, snapshot=0x0000000000dccc48) at
nbtsearch.c:99
frame #9: 0x00000000004fbe5a
postgres`_bt_first(scan=0x00000008031bb4f0, dir=<unavailable>) at
nbtsearch.c:1247
frame #10: 0x00000000004f9736
postgres`btgettuple(scan=0x00000008031bb4f0, dir=ForwardScanDirection)
at nbtree.c:245
frame #11: 0x00000000004efec1
postgres`index_getnext_tid(scan=0x00000008031bb4f0,
direction=<unavailable>) at indexam.c:550
frame #12: 0x00000000004f0052
postgres`index_getnext_slot(scan=0x00000008031bb4f0,
direction=ForwardScanDirection, slot=0x00000008031bcf80) at indexam.c:642
frame #13: 0x00000000004eefc2
postgres`systable_getnext(sysscan=0x00000008031bdcd0) at genam.c:450
frame #14: 0x00000000008ccaf0
postgres`ScanPgRelation(targetRelId=<unavailable>,
indexOK=<unavailable>, force_non_historic=false) at relcache.c:365
frame #15: 0x00000000008c5ea6 postgres`RelationClearRelation at
relcache.c:2288
frame #16: 0x00000000008c5e51
postgres`RelationClearRelation(relation=0x00000008031460b0,
rebuild=true) at relcache.c:2421
frame #17: 0x00000000008c788d postgres`RelationCacheInvalidate at
relcache.c:2854
frame #18: 0x00000000008bd0aa postgres`AcceptInvalidationMessages
[inlined] InvalidateSystemCaches at inval.c:649
frame #19: 0x00000000008bd09b postgres`AcceptInvalidationMessages
at inval.c:708
frame #20: 0x000000000078a929 postgres`LockRelationOid(relid=1213,
lockmode=<unavailable>) at lmgr.c:133
frame #21: 0x000000000049baa2
postgres`relation_open(relationId=1213, lockmode=1) at relation.c:56
frame #22: 0x000000000051624c
postgres`table_open(relationId=<unavailable>, lockmode=<unavailable>) at
table.c:43
frame #23: 0x00000000008bc707
postgres`SearchCatCacheMiss(cache=0x000000080313e900, nkeys=1,
hashValue=1761185739, hashIndex=3, v1=1663, v2=0, v3=0, v4=0) at
catcache.c:1357
frame #24: 0x00000000008bae3b
postgres`SearchCatCacheInternal(cache=0x000000080313e900,
nkeys=<unavailable>, v1=<unavailable>, v2=<unavailable>,
v3=<unavailable>, v4=0) at catcache.c:1299
frame #25: 0x00000000008ce406
postgres`get_tablespace(spcid=<unavailable>) at spccache.c:136
frame #26: 0x00000000008ce4a9
postgres`get_tablespace_io_concurrency(spcid=<unavailable>) at
spccache.c:217
frame #27: 0x00000000004db9c6
postgres`heap_compute_xid_horizon_for_tuples(rel=0x00000008031460b0,
tids=0x00000008031ba7f8, nitems=<unavailable>) at heapam.c:6980
frame #28: 0x00000000004eed06
postgres`index_compute_xid_horizon_for_tuples [inlined]
table_compute_xid_horizon_for_tuples(rel=<unavailable>,
items=<unavailable>, nitems=<unavailable>) at tableam.h:973
frame #29: 0x00000000004eecf1
postgres`index_compute_xid_horizon_for_tuples(irel=<unavailable>,
hrel=0x00000008031460b0, ibuf=<unavailable>, itemnos=0x00007fffffffc7a0,
nitems=3) at genam.c:306
frame #30: 0x00000000004f6b14
postgres`_bt_delitems_delete(rel=0x000000080314d080, buf=49,
itemnos=<unavailable>, nitems=3, heapRel=<unavailable>) at nbtpage.c:1111
frame #31: 0x00000000004f4c2c
postgres`_bt_vacuum_one_page(rel=<unavailable>, buffer=<unavailable>,
heapRel=<unavailable>) at nbtinsert.c:2270
frame #32: 0x00000000004f13a2 postgres`_bt_doinsert [inlined]
_bt_findinsertloc(rel=<unavailable>, heapRel=0x00000008031460b0) at
nbtinsert.c:736
frame #33: 0x00000000004f136d
postgres`_bt_doinsert(rel=<unavailable>, itup=0x000000080306b678,
checkUnique=UNIQUE_CHECK_YES, heapRel=0x00000008031460b0) at nbtinsert.c:281
frame #34: 0x00000000004f9017
postgres`btinsert(rel=0x000000080314d080, values=<unavailable>,
isnull=<unavailable>, ht_ctid=0x00000008031b85c8, heapRel=<unavailable>,
checkUnique=<unavailable>, indexInfo=0x000000080c2a40a0) at nbtree.c:203
frame #35: 0x000000000063c992
postgres`ExecInsertIndexTuples(slot=<unavailable>, estate=<unavailable>,
noDupErr=false, specConflict=0x0000000000000000,
arbiterIndexes=0x0000000000000000) at execIndexing.c:391
frame #36: 0x0000000000667598
postgres`ExecUpdate(mtstate=<unavailable>, tupleid=0x00007fffffffdd00,
oldtuple=0x0000000000000000, slot=0x00000008031b8598,
planSlot=0x00000008031b82e8, epqstate=0x000000080c2a4b38,
estate=0x000000080306b118, canSetTag=<unavailable>) at
nodeModifyTable.c:1407
frame #37: 0x0000000000665d45
postgres`ExecModifyTable(pstate=<unavailable>) at nodeModifyTable.c:2182
frame #38: 0x000000000063e0ed postgres`standard_ExecutorRun
[inlined] ExecProcNode(node=<unavailable>) at executor.h:239
frame #39: 0x000000000063e0d8 postgres`standard_ExecutorRun
[inlined] ExecutePlan(estate=<unavailable>,
planstate=0x000000080c2a4a40, operation=<unavailable>, numberTuples=0,
direction=NoMovementScanDirection, dest=<unavailable>,
execute_once=<unavailable>) at execMain.c:1647
frame #40: 0x000000000063e09a
postgres`standard_ExecutorRun(queryDesc=<unavailable>,
direction=NoMovementScanDirection, count=0, execute_once=<unavailable>)
at execMain.c:365
frame #41: 0x00000000007abd6c
postgres`ProcessQuery(plan=0x000000080c29f380, sourceText="\nUPDATE
pg_class SET relacl = (SELECT array_agg(a.acl) FROM (SELECT
E'=r/\"pgbf\"' as acl UNION SELECT unnest(pg_catalog.acldefault(
CASE WHEN relkind = 'S' THEN 's' ELSE 'r'
END::\"char\",10::oid)) ) as a) WHERE relkind IN ('r', 'v', 'm', 'S')
AND relacl IS NULL;\n", params=0x0000000000000000,
queryEnv=0x0000000000000000, dest=0x0000000000ab4b38, completionTag="")
at pquery.c:161
frame #42: 0x00000000007ab340
postgres`PortalRunMulti(portal=0x000000080310c118, isTopLevel=true,
setHoldSnapshot=false, dest=0x0000000000ab4b38,
altdest=0x0000000000ab4b38, completionTag="") at pquery.c:0
frame #43: 0x00000000007aac69
postgres`PortalRun(portal=0x000000080310c118, count=<unavailable>,
isTopLevel=true, run_once=<unavailable>, dest=0x0000000000ab4b38,
altdest=0x0000000000ab4b38, completionTag="") at pquery.c:796
frame #44: 0x00000000007a9bda
postgres`exec_simple_query(query_string="\nUPDATE pg_class SET relacl
= (SELECT array_agg(a.acl) FROM (SELECT E'=r/\"pgbf\"' as acl UNION
SELECT unnest(pg_catalog.acldefault( CASE WHEN relkind = 'S' THEN 's'
ELSE 'r' END::\"char\",10::oid)) ) as a) WHERE relkind IN
('r', 'v', 'm', 'S') AND relacl IS NULL;\n") at postgres.c:1215
frame #45: 0x00000000007a7b07
postgres`PostgresMain(argc=<unavailable>, argv=<unavailable>,
dbname=<unavailable>, username=<unavailable>) at postgres.c:0
frame #46: 0x000000000068fbfb postgres`main(argc=10,
argv=0x00007fffffffe2d8) at main.c:224
frame #47: 0x000000000048e7df postgres`_start + 383

--
Christian