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@chrullrich.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