Re: BUG #16016: deadlock with startup process, AccessExclusiveLock on pg_statistic's toast table

From: Alexey Ermakov <alexey(dot)ermakov(at)dataegret(dot)com>
To: Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us>, Sergei Kornilov <sk(at)zsrv(dot)org>
Cc: "pgsql-bugs(at)lists(dot)postgresql(dot)org" <pgsql-bugs(at)lists(dot)postgresql(dot)org>
Subject: Re: BUG #16016: deadlock with startup process, AccessExclusiveLock on pg_statistic's toast table
Date: 2019-11-01 09:15:33
Message-ID: 5DBBF7B5.6040002@dataegret.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs

Hello,

On 9/23/19 01:06, Tom Lane wrote:
> If you have a test case, could you collect stack traces from each
> of the stuck processes? That would eliminate a lot of hypothesizing.
>
> regards, tom lane

I reproduced Sergei's test case on postgresql 11.5, replica hung up
almost immediately after pgbench ran.

9907 - pid of startup process, 16387 - oid of test table, 2619 - oid of
pg_statistic, 2840 - oid of toast table of pg_statistic.

1) pgbench on replica with 1 concurrent processes (-c 1):

this case looks a bit different from what happened on initial report
(which recently happened again btw) because at this time I can't even
open new connection via psql or run query with pg_stat_activity - in
hangs (pg_locks query works).
perhaps because this time access exclusive lock is on pg_statistic table
too, not only on it's toast table.

select * from pg_locks;
locktype | database | relation | page | tuple | virtualxid |
transactionid | classid | objid | objsubid | virtualtransaction | pid
| mode | granted | fastpath
------------+----------+----------+------+-------+------------+---------------+---------+-------+----------+--------------------+-------+---------------------+---------+----------
relation | 13217 | 11645 | | | |
| | | | 2/73518 | 17266 | AccessShareLock |
t | t
virtualxid | | | | | 2/73518
| | | | | 2/73518 | 17266 |
ExclusiveLock | t | t
virtualxid | | | | | 3/4590466
| | | | | 3/4590466 | 32074 |
ExclusiveLock | t | t
virtualxid | | | | | 1/1 |
| | | | 1/0 | 9907 | ExclusiveLock |
t | t
relation | 13217 | 2841 | | | |
| | | | 1/0 | 9907 | AccessExclusiveLock |
t | f
relation | 13217 | 2619 | | | |
| | | | 3/4590466 | 32074 | AccessShareLock |
f | f
relation | 13217 | 2840 | | | |
| | | | 1/0 | 9907 | AccessExclusiveLock |
t | f
relation | 13217 | 5364206 | | | |
| | | | 1/0 | 9907 | AccessExclusiveLock |
t | f
relation | 13217 | 2619 | | | |
| | | | 1/0 | 9907 | AccessExclusiveLock |
t | f
relation | 13217 | 5364204 | | | |
| | | | 1/0 | 9907 | AccessExclusiveLock |
t | f
relation | 13217 | 16387 | | | |
| | | | 3/4590466 | 32074 | AccessShareLock |
t | f
relation | 13217 | 5364201 | | | |
| | | | 1/0 | 9907 | AccessExclusiveLock |
t | f
(12 rows)

stack trace of startup process 9907:
#0 0x00007fdff4a025b3 in __select_nocancel () at
../sysdeps/unix/syscall-template.S:84
#1 0x00005608fde0c6cd in pg_usleep (microsec=<optimized out>) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/port/pgsleep.c:56
#2 0x00005608fdc94126 in WaitExceedsMaxStandbyDelay () at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/ipc/standby.c:201
#3 ResolveRecoveryConflictWithVirtualXIDs (waitlist=0x5608fe46a450,
reason=reason(at)entry=PROCSIG_RECOVERY_CONFLICT_SNAPSHOT) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/ipc/standby.c:262
#4 0x00005608fdc9434a in ResolveRecoveryConflictWithVirtualXIDs
(reason=PROCSIG_RECOVERY_CONFLICT_SNAPSHOT, waitlist=<optimized out>) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/ipc/standby.c:315
#5 ResolveRecoveryConflictWithSnapshot (latestRemovedXid=<optimized
out>, node=...) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/ipc/standby.c:313
#6 0x00005608fda04ddc in heap_xlog_clean (record=0x5608fe426578) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/access/heap/heapam.c:8238
#7 heap2_redo (record=0x5608fe426578) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/access/heap/heapam.c:9391
#8 0x00005608fda4b974 in StartupXLOG () at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/access/transam/xlog.c:7306
#9 0x00005608fdc3b4d3 in StartupProcessMain () at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/postmaster/startup.c:211
#10 0x00005608fda5b763 in AuxiliaryProcessMain (argc=argc(at)entry=2,
argv=argv(at)entry=0x7ffc9277c7e0) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/bootstrap/bootstrap.c:441
#11 0x00005608fdc381e3 in StartChildProcess (type=StartupProcess) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/postmaster/postmaster.c:5337
#12 0x00005608fdc3af5e in PostmasterMain (argc=5, argv=<optimized out>)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/postmaster/postmaster.c:1372
#13 0x00005608fd9c0075 in main (argc=5, argv=0x5608fe425820) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/main/main.c:228

stack trace of backend 32074:
#0 0x00007fdff4a0c9f3 in __epoll_wait_nocancel () at
../sysdeps/unix/syscall-template.S:84
#1 0x00005608fdc8cb51 in WaitEventSetWaitBlock (nevents=1,
occurred_events=0x7ffc9277a6f0, cur_timeout=-1, set=0x5608fe42bed8) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/ipc/latch.c:1048
#2 WaitEventSetWait (set=set(at)entry=0x5608fe42bed8,
timeout=timeout(at)entry=-1,
occurred_events=occurred_events(at)entry=0x7ffc9277a6f0,
nevents=nevents(at)entry=1, wait_event_info=wait_event_info(at)entry=50331648)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/ipc/latch.c:1000
#3 0x00005608fdc8cfc4 in WaitLatchOrSocket (latch=0x7fdfebbf1594,
wakeEvents=wakeEvents(at)entry=1, sock=sock(at)entry=-1, timeout=-1,
timeout(at)entry=0, wait_event_info=50331648)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/ipc/latch.c:385
#4 0x00005608fdc8d075 in WaitLatch (latch=<optimized out>,
wakeEvents=wakeEvents(at)entry=1, timeout=timeout(at)entry=0,
wait_event_info=<optimized out>)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/ipc/latch.c:339
#5 0x00005608fdc9d591 in ProcSleep
(locallock=locallock(at)entry=0x5608fe4488e0,
lockMethodTable=lockMethodTable(at)entry=0x5608fe2321e0 <default_lockmethod>)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/lmgr/proc.c:1272
#6 0x00005608fdc97c99 in WaitOnLock
(locallock=locallock(at)entry=0x5608fe4488e0,
owner=owner(at)entry=0x5608fe474370) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/lmgr/lock.c:1744
#7 0x00005608fdc98fe1 in LockAcquireExtended
(locktag=locktag(at)entry=0x7ffc9277aac0, lockmode=lockmode(at)entry=1,
sessionLock=sessionLock(at)entry=false, dontWait=dontWait(at)entry=false,
reportMemoryError=reportMemoryError(at)entry=true,
locallockp=locallockp(at)entry=0x7ffc9277aab8) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/lmgr/lock.c:1026
#8 0x00005608fdc96648 in LockRelationOid (relid=2619, lockmode=1) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/lmgr/lmgr.c:113
#9 0x00005608fd9fb4cd in relation_open (relationId=2619,
lockmode=<optimized out>) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/access/heap/heapam.c:1132
#10 0x00005608fd9fb6de in heap_open (relationId=<optimized out>,
lockmode=lockmode(at)entry=1) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/access/heap/heapam.c:1298
#11 0x00005608fddafb81 in SearchCatCacheMiss
(cache=cache(at)entry=0x5608fe498500, nkeys=nkeys(at)entry=3,
hashValue=hashValue(at)entry=2374461275, hashIndex=hashIndex(at)entry=91,
v1=v1(at)entry=16387, v2=v2(at)entry=1, v3=0, v4=0)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/utils/cache/catcache.c:1375
#12 0x00005608fddb093f in SearchCatCacheInternal (v4=0, v3=0,
v2=<optimized out>, v1=<optimized out>, nkeys=3, cache=0x5608fe498500)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/utils/cache/catcache.c:1317
#13 SearchCatCache3 (cache=0x5608fe498500, v1=16387, v2=1, v3=0) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/utils/cache/catcache.c:1201
#14 0x00005608fddc2f18 in SearchSysCache3 (cacheId=cacheId(at)entry=57,
key1=<optimized out>, key2=<optimized out>, key3=<optimized out>) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/utils/cache/syscache.c:1141
#15 0x00005608fdd76ca6 in examine_simple_variable (var=<optimized out>,
var=<optimized out>, vardata=0x7ffc9277aeb0, root=<optimized out>) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/utils/adt/selfuncs.c:5037
#16 examine_variable (root=root(at)entry=0x5608fe4f5fd8, node=<optimized
out>, varRelid=varRelid(at)entry=0, vardata=vardata(at)entry=0x7ffc9277aeb0)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/utils/adt/selfuncs.c:4821
#17 0x00005608fdd772c7 in get_restriction_variable (root=0x5608fe4f5fd8,
args=<optimized out>, varRelid=0, vardata=0x7ffc9277aeb0,
other=0x7ffc9277aea8, varonleft=0x7ffc9277aea6)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/utils/adt/selfuncs.c:4683
#18 0x00005608fdd783f6 in eqsel_internal (fcinfo=<optimized out>,
negate=negate(at)entry=false) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/utils/adt/selfuncs.c:279
#19 0x00005608fdd786eb in eqsel (fcinfo=<optimized out>) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/utils/adt/selfuncs.c:243
#20 0x00005608fddd1cf5 in OidFunctionCall4Coll (functionId=<optimized
out>, collation=collation(at)entry=0, arg1=arg1(at)entry=94596626341848,
arg2=arg2(at)entry=96, arg3=arg3(at)entry=94596626343080, arg4=arg4(at)entry=0)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/utils/fmgr/fmgr.c:1501
#21 0x00005608fdc1c07d in restriction_selectivity
(root=root(at)entry=0x5608fe4f5fd8, operatorid=96, args=0x5608fe4f64a8,
inputcollid=0, varRelid=varRelid(at)entry=0)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/optimizer/util/plancat.c:1813
#22 0x00005608fdbdba11 in clause_selectivity
(root=root(at)entry=0x5608fe4f5fd8, clause=<optimized out>,
varRelid=varRelid(at)entry=0, jointype=jointype(at)entry=JOIN_INNER,
sjinfo=sjinfo(at)entry=0x0)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/optimizer/path/clausesel.c:748
#23 0x00005608fdbdbbcb in clauselist_selectivity
(root=root(at)entry=0x5608fe4f5fd8, clauses=0x5608fe4f6d38,
varRelid=varRelid(at)entry=0, jointype=jointype(at)entry=JOIN_INNER,
sjinfo=sjinfo(at)entry=0x0)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/optimizer/path/clausesel.c:117
#24 0x00005608fdbe19b1 in set_baserel_size_estimates
(root=root(at)entry=0x5608fe4f5fd8, rel=rel(at)entry=0x5608fe4f6628) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/optimizer/path/costsize.c:4308
#25 0x00005608fdbda64c in set_plain_rel_size (rte=<optimized out>,
rel=0x5608fe4f6628, root=0x5608fe4f5fd8) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/optimizer/path/allpaths.c:532
#26 set_rel_size (root=root(at)entry=0x5608fe4f5fd8,
rel=rel(at)entry=0x5608fe4f6628, rti=rti(at)entry=1, rte=<optimized out>) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/optimizer/path/allpaths.c:369
#27 0x00005608fdbdb37e in set_base_rel_sizes (root=<optimized out>) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/optimizer/path/allpaths.c:281
#28 make_one_rel (root=root(at)entry=0x5608fe4f5fd8,
joinlist=joinlist(at)entry=0x5608fe4f69d8) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/optimizer/path/allpaths.c:179
#29 0x00005608fdbfa130 in query_planner (root=root(at)entry=0x5608fe4f5fd8,
tlist=tlist(at)entry=0x5608fe4f6408,
qp_callback=qp_callback(at)entry=0x5608fdbfb530 <standard_qp_callback>,
qp_extra=qp_extra(at)entry=0x7ffc9277b760)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/optimizer/plan/planmain.c:265
#30 0x00005608fdbfe94b in grouping_planner
(root=root(at)entry=0x5608fe4f5fd8,
inheritance_update=inheritance_update(at)entry=false,
tuple_fraction=<optimized out>, tuple_fraction(at)entry=0)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/optimizer/plan/planner.c:1942
#31 0x00005608fdc00d36 in subquery_planner
(glob=glob(at)entry=0x5608fe42c128, parse=parse(at)entry=0x5608fe42bb38,
parent_root=parent_root(at)entry=0x0,
hasRecursion=hasRecursion(at)entry=false,
tuple_fraction=tuple_fraction(at)entry=0)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/optimizer/plan/planner.c:966
#32 0x00005608fdc01d15 in standard_planner (parse=0x5608fe42bb38,
cursorOptions=256, boundParams=<optimized out>) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/optimizer/plan/planner.c:405
#33 0x00005608fdcaec59 in pg_plan_query
(querytree=querytree(at)entry=0x5608fe42bb38,
cursorOptions=cursorOptions(at)entry=256, boundParams=boundParams(at)entry=0x0)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/tcop/postgres.c:832
#34 0x00005608fdcaed36 in pg_plan_queries (querytrees=<optimized out>,
cursorOptions=cursorOptions(at)entry=256,
boundParams=boundParams(at)entry=0x0) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/tcop/postgres.c:898
#35 0x00005608fdcaf267 in exec_simple_query (query_string=0x5608fe42ab10
"select * from tablename where i = 6;") at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/tcop/postgres.c:1073
#36 0x00005608fdcb064b in PostgresMain (argc=<optimized out>,
argv=argv(at)entry=0x5608fe472900, dbname=0x5608fe472858 "postgres",
username=<optimized out>)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/tcop/postgres.c:4182
#37 0x00005608fd9becd2 in BackendRun (port=0x5608fe46b070) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/postmaster/postmaster.c:4358
#38 BackendStartup (port=0x5608fe46b070) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/postmaster/postmaster.c:4030
#39 ServerLoop () at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/postmaster/postmaster.c:1707
#40 0x00005608fdc3af82 in PostmasterMain (argc=5, argv=<optimized out>)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/postmaster/postmaster.c:1380
#41 0x00005608fd9c0075 in main (argc=5, argv=0x5608fe425820) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/main/main.c:228

2) pgbench on replica with 2 concurrent processes (-c 2):
this case also looks a bit different from initial report, here we have
AccessExclusiveLock on test table, not on pg_statistic's toast table:

select * from pg_stat_activity (both backend connections are waiting
until max_standby_streaming_delay timeout happened):
...
-[ RECORD 2 ]----+--------------------------------------
datid | 13217
datname | postgres
pid | 21152
usesysid | 10
usename | postgres
application_name | pgbench
client_addr |
client_hostname |
client_port | -1
backend_start | 2019-11-01 13:00:59.910532+06
xact_start | 2019-11-01 13:01:08.160028+06
query_start | 2019-11-01 13:01:08.160028+06
state_change | 2019-11-01 13:01:08.160029+06
wait_event_type | Lock
wait_event | relation
state | active
backend_xid |
backend_xmin | 473235
query | select * from tablename where i = 89;
backend_type | client backend
-[ RECORD 3 ]----+--------------------------------------
datid | 13217
datname | postgres
pid | 21153
usesysid | 10
usename | postgres
application_name | pgbench
client_addr |
client_hostname |
client_port | -1
backend_start | 2019-11-01 13:00:59.913201+06
xact_start | 2019-11-01 13:01:08.159873+06
query_start | 2019-11-01 13:01:08.159873+06
state_change | 2019-11-01 13:01:08.159873+06
wait_event_type | Lock
wait_event | relation
state | active
backend_xid |
backend_xmin | 473235
query | select * from tablename where i = 72;
backend_type | client backend
-[ RECORD 4 ]----+--------------------------------------
datid |
datname |
pid | 9907
usesysid |
usename |
application_name |
client_addr |
client_hostname |
client_port |
backend_start | 2019-10-31 19:11:55.514707+06
xact_start |
query_start |
state_change |
wait_event_type |
wait_event |
state |
backend_xid |
backend_xmin |
query |
backend_type | startup
...

select * from pg_locks:
locktype | database | relation | page | tuple | virtualxid |
transactionid | classid | objid | objsubid | virtualtransaction | pid
| mode | granted | fastpath
------------+----------+----------+------+-------+------------+---------------+---------+-------+----------+--------------------+-------+---------------------+---------+----------
relation | 13217 | 11645 | | | |
| | | | 2/30436 | 17266 |
AccessShareLock | t | t
virtualxid | | | | | 2/30436
| | | | | 2/30436 |
17266 | ExclusiveLock | t | t
virtualxid | | | | | 4/2366585
| | | | | 4/2366585 |
21153 | ExclusiveLock | t | t
virtualxid | | | | | 3/2624520
| | | | | 3/2624520 |
21152 | ExclusiveLock | t | t
virtualxid | | | | | 1/1
| | | | | 1/0 |
9907 | ExclusiveLock | t | t
relation | 13217 | 16387 | | | |
| | | | 1/0 | 9907 |
AccessExclusiveLock | t | f
relation | 13217 | 16387 | | | |
| | | | 3/2624520 | 21152 |
AccessShareLock | f | f
relation | 13217 | 16387 | | | |
| | | | 4/2366585 | 21153 |
AccessShareLock | f | f
(8 rows)

stack trace of startup process 9907:

#0 0x00007fdff4a025b3 in __select_nocancel () at
../sysdeps/unix/syscall-template.S:84
#1 0x00005608fde0c6cd in pg_usleep (microsec=<optimized out>) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/port/pgsleep.c:56
#2 0x00005608fdc94126 in WaitExceedsMaxStandbyDelay () at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/ipc/standby.c:201
#3 ResolveRecoveryConflictWithVirtualXIDs (waitlist=0x5608fe46a450,
reason=reason(at)entry=PROCSIG_RECOVERY_CONFLICT_SNAPSHOT) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/ipc/standby.c:262
#4 0x00005608fdc9434a in ResolveRecoveryConflictWithVirtualXIDs
(reason=PROCSIG_RECOVERY_CONFLICT_SNAPSHOT, waitlist=<optimized out>) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/ipc/standby.c:315
#5 ResolveRecoveryConflictWithSnapshot
(latestRemovedXid=latestRemovedXid(at)entry=473242, node=...) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/ipc/standby.c:313
#6 0x00005608fda1d8b2 in btree_xlog_delete (record=0x5608fe426578) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/access/nbtree/nbtxlog.c:703
#7 btree_redo (record=0x5608fe426578) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/access/nbtree/nbtxlog.c:1023
#8 0x00005608fda4b974 in StartupXLOG () at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/access/transam/xlog.c:7306
#9 0x00005608fdc3b4d3 in StartupProcessMain () at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/postmaster/startup.c:211
#10 0x00005608fda5b763 in AuxiliaryProcessMain (argc=argc(at)entry=2,
argv=argv(at)entry=0x7ffc9277c7e0) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/bootstrap/bootstrap.c:441
#11 0x00005608fdc381e3 in StartChildProcess (type=StartupProcess) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/postmaster/postmaster.c:5337
#12 0x00005608fdc3af5e in PostmasterMain (argc=5, argv=<optimized out>)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/postmaster/postmaster.c:1372
#13 0x00005608fd9c0075 in main (argc=5, argv=0x5608fe425820) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/main/main.c:228

backend 21153:
#0 0x00007fdff4a0c9f3 in __epoll_wait_nocancel () at
../sysdeps/unix/syscall-template.S:84
#1 0x00005608fdc8cb51 in WaitEventSetWaitBlock (nevents=1,
occurred_events=0x7ffc9277b1a0, cur_timeout=-1, set=0x5608fe42c8b8) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/ipc/latch.c:1048
#2 WaitEventSetWait (set=set(at)entry=0x5608fe42c8b8,
timeout=timeout(at)entry=-1,
occurred_events=occurred_events(at)entry=0x7ffc9277b1a0,
nevents=nevents(at)entry=1, wait_event_info=wait_event_info(at)entry=50331648)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/ipc/latch.c:1000
#3 0x00005608fdc8cfc4 in WaitLatchOrSocket (latch=0x7fdfebbf0ba4,
wakeEvents=wakeEvents(at)entry=1, sock=sock(at)entry=-1, timeout=-1,
timeout(at)entry=0, wait_event_info=50331648)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/ipc/latch.c:385
#4 0x00005608fdc8d075 in WaitLatch (latch=<optimized out>,
wakeEvents=wakeEvents(at)entry=1, timeout=timeout(at)entry=0,
wait_event_info=<optimized out>)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/ipc/latch.c:339
#5 0x00005608fdc9d591 in ProcSleep
(locallock=locallock(at)entry=0x5608fe448940,
lockMethodTable=lockMethodTable(at)entry=0x5608fe2321e0 <default_lockmethod>)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/lmgr/proc.c:1272
#6 0x00005608fdc97c99 in WaitOnLock
(locallock=locallock(at)entry=0x5608fe448940,
owner=owner(at)entry=0x5608fe474370) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/lmgr/lock.c:1744
#7 0x00005608fdc98fe1 in LockAcquireExtended
(locktag=locktag(at)entry=0x7ffc9277b570, lockmode=lockmode(at)entry=1,
sessionLock=sessionLock(at)entry=false, dontWait=dontWait(at)entry=false,
reportMemoryError=reportMemoryError(at)entry=true,
locallockp=locallockp(at)entry=0x7ffc9277b568) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/lmgr/lock.c:1026
#8 0x00005608fdc96648 in LockRelationOid (relid=16387, lockmode=1) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/lmgr/lmgr.c:113
#9 0x00005608fda6a4cd in RangeVarGetRelidExtended
(relation=0x5608fe42b650, lockmode=1, flags=1,
callback=callback(at)entry=0x0, callback_arg=callback_arg(at)entry=0x0)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/catalog/namespace.c:379
#10 0x00005608fd9fb629 in relation_openrv_extended (relation=<optimized
out>, lockmode=<optimized out>, missing_ok=<optimized out>) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/access/heap/heapam.c:1250
#11 0x00005608fd9fb841 in heap_openrv_extended
(relation=relation(at)entry=0x5608fe42b650, lockmode=lockmode(at)entry=1,
missing_ok=missing_ok(at)entry=true)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/access/heap/heapam.c:1358
#12 0x00005608fdac6049 in parserOpenTable (pstate=0x5608fe42ba28,
relation=0x5608fe42b650, lockmode=1) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/parser/parse_relation.c:1152
#13 0x00005608fdac7a6a in addRangeTableEntry
(pstate=pstate(at)entry=0x5608fe42ba28,
relation=relation(at)entry=0x5608fe42b650, alias=0x0, inh=<optimized out>,
inFromCl=inFromCl(at)entry=true)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/parser/parse_relation.c:1217
#14 0x00005608fdab2369 in transformTableEntry (r=0x5608fe42b650,
pstate=0x5608fe42ba28) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/parser/parse_clause.c:435
#15 transformFromClauseItem (pstate=pstate(at)entry=0x5608fe42ba28,
n=0x5608fe42b650, top_rte=top_rte(at)entry=0x7ffc9277b858,
top_rti=top_rti(at)entry=0x7ffc9277b854,
namespace=namespace(at)entry=0x7ffc9277b860)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/parser/parse_clause.c:1122
#16 0x00005608fdab3835 in transformFromClause
(pstate=pstate(at)entry=0x5608fe42ba28, frmList=<optimized out>) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/parser/parse_clause.c:139
#17 0x00005608fda90804 in transformSelectStmt (stmt=0x5608fe42b898,
pstate=0x5608fe42ba28) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/parser/analyze.c:1240
#18 transformStmt (pstate=pstate(at)entry=0x5608fe42ba28,
parseTree=0x5608fe42b898) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/parser/analyze.c:301
#19 0x00005608fda92550 in transformOptionalSelectInto
(pstate=pstate(at)entry=0x5608fe42ba28, parseTree=<optimized out>) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/parser/analyze.c:246
#20 0x00005608fda925d5 in transformTopLevelStmt
(pstate=pstate(at)entry=0x5608fe42ba28,
parseTree=parseTree(at)entry=0x5608fe42b9a8) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/parser/analyze.c:196
#21 0x00005608fda92648 in parse_analyze (parseTree=0x5608fe42b9a8,
sourceText=sourceText(at)entry=0x5608fe42ab10 "select * from tablename
where i = 72;", paramTypes=0x0, numParams=0, queryEnv=0x0)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/parser/analyze.c:116
#22 0x00005608fdcaeb07 in pg_analyze_and_rewrite
(parsetree=parsetree(at)entry=0x5608fe42b9a8,
query_string=query_string(at)entry=0x5608fe42ab10 "select * from tablename
where i = 72;", paramTypes=paramTypes(at)entry=0x0,
numParams=numParams(at)entry=0, queryEnv=queryEnv(at)entry=0x0) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/tcop/postgres.c:689
#23 0x00005608fdcaf258 in exec_simple_query (query_string=0x5608fe42ab10
"select * from tablename where i = 72;") at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/tcop/postgres.c:1070
#24 0x00005608fdcb064b in PostgresMain (argc=<optimized out>,
argv=argv(at)entry=0x5608fe472900, dbname=0x5608fe472858 "postgres",
username=<optimized out>)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/tcop/postgres.c:4182
#25 0x00005608fd9becd2 in BackendRun (port=0x5608fe46b070) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/postmaster/postmaster.c:4358
#26 BackendStartup (port=0x5608fe46b070) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/postmaster/postmaster.c:4030
#27 ServerLoop () at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/postmaster/postmaster.c:1707
#28 0x00005608fdc3af82 in PostmasterMain (argc=5, argv=<optimized out>)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/postmaster/postmaster.c:1380
#29 0x00005608fd9c0075 in main (argc=5, argv=0x5608fe425820) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/main/main.c:228

backend 21152 (looks the same):
#0 0x00007fdff4a0c9f3 in __epoll_wait_nocancel () at
../sysdeps/unix/syscall-template.S:84
#1 0x00005608fdc8cb51 in WaitEventSetWaitBlock (nevents=1,
occurred_events=0x7ffc9277b1a0, cur_timeout=-1, set=0x5608fe42c8b8) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/ipc/latch.c:1048
#2 WaitEventSetWait (set=set(at)entry=0x5608fe42c8b8,
timeout=timeout(at)entry=-1,
occurred_events=occurred_events(at)entry=0x7ffc9277b1a0,
nevents=nevents(at)entry=1, wait_event_info=wait_event_info(at)entry=50331648)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/ipc/latch.c:1000
#3 0x00005608fdc8cfc4 in WaitLatchOrSocket (latch=0x7fdfebbf1244,
wakeEvents=wakeEvents(at)entry=1, sock=sock(at)entry=-1, timeout=-1,
timeout(at)entry=0, wait_event_info=50331648)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/ipc/latch.c:385
#4 0x00005608fdc8d075 in WaitLatch (latch=<optimized out>,
wakeEvents=wakeEvents(at)entry=1, timeout=timeout(at)entry=0,
wait_event_info=<optimized out>)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/ipc/latch.c:339
#5 0x00005608fdc9d591 in ProcSleep
(locallock=locallock(at)entry=0x5608fe448940,
lockMethodTable=lockMethodTable(at)entry=0x5608fe2321e0 <default_lockmethod>)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/lmgr/proc.c:1272
#6 0x00005608fdc97c99 in WaitOnLock
(locallock=locallock(at)entry=0x5608fe448940,
owner=owner(at)entry=0x5608fe474370) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/lmgr/lock.c:1744
#7 0x00005608fdc98fe1 in LockAcquireExtended
(locktag=locktag(at)entry=0x7ffc9277b570, lockmode=lockmode(at)entry=1,
sessionLock=sessionLock(at)entry=false, dontWait=dontWait(at)entry=false,
reportMemoryError=reportMemoryError(at)entry=true,
locallockp=locallockp(at)entry=0x7ffc9277b568) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/lmgr/lock.c:1026
#8 0x00005608fdc96648 in LockRelationOid (relid=16387, lockmode=1) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/storage/lmgr/lmgr.c:113
#9 0x00005608fda6a4cd in RangeVarGetRelidExtended
(relation=0x5608fe42b650, lockmode=1, flags=1,
callback=callback(at)entry=0x0, callback_arg=callback_arg(at)entry=0x0)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/catalog/namespace.c:379
#10 0x00005608fd9fb629 in relation_openrv_extended (relation=<optimized
out>, lockmode=<optimized out>, missing_ok=<optimized out>) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/access/heap/heapam.c:1250
#11 0x00005608fd9fb841 in heap_openrv_extended
(relation=relation(at)entry=0x5608fe42b650, lockmode=lockmode(at)entry=1,
missing_ok=missing_ok(at)entry=true)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/access/heap/heapam.c:1358
#12 0x00005608fdac6049 in parserOpenTable (pstate=0x5608fe42ba28,
relation=0x5608fe42b650, lockmode=1) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/parser/parse_relation.c:1152
#13 0x00005608fdac7a6a in addRangeTableEntry
(pstate=pstate(at)entry=0x5608fe42ba28,
relation=relation(at)entry=0x5608fe42b650, alias=0x0, inh=<optimized out>,
inFromCl=inFromCl(at)entry=true)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/parser/parse_relation.c:1217
#14 0x00005608fdab2369 in transformTableEntry (r=0x5608fe42b650,
pstate=0x5608fe42ba28) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/parser/parse_clause.c:435
#15 transformFromClauseItem (pstate=pstate(at)entry=0x5608fe42ba28,
n=0x5608fe42b650, top_rte=top_rte(at)entry=0x7ffc9277b858,
top_rti=top_rti(at)entry=0x7ffc9277b854,
namespace=namespace(at)entry=0x7ffc9277b860)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/parser/parse_clause.c:1122
#16 0x00005608fdab3835 in transformFromClause
(pstate=pstate(at)entry=0x5608fe42ba28, frmList=<optimized out>) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/parser/parse_clause.c:139
#17 0x00005608fda90804 in transformSelectStmt (stmt=0x5608fe42b898,
pstate=0x5608fe42ba28) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/parser/analyze.c:1240
#18 transformStmt (pstate=pstate(at)entry=0x5608fe42ba28,
parseTree=0x5608fe42b898) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/parser/analyze.c:301
#19 0x00005608fda92550 in transformOptionalSelectInto
(pstate=pstate(at)entry=0x5608fe42ba28, parseTree=<optimized out>) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/parser/analyze.c:246
#20 0x00005608fda925d5 in transformTopLevelStmt
(pstate=pstate(at)entry=0x5608fe42ba28,
parseTree=parseTree(at)entry=0x5608fe42b9a8) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/parser/analyze.c:196
#21 0x00005608fda92648 in parse_analyze (parseTree=0x5608fe42b9a8,
sourceText=sourceText(at)entry=0x5608fe42ab10 "select * from tablename
where i = 89;", paramTypes=0x0, numParams=0, queryEnv=0x0)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/parser/analyze.c:116
#22 0x00005608fdcaeb07 in pg_analyze_and_rewrite
(parsetree=parsetree(at)entry=0x5608fe42b9a8,
query_string=query_string(at)entry=0x5608fe42ab10 "select * from tablename
where i = 89;", paramTypes=paramTypes(at)entry=0x0,
numParams=numParams(at)entry=0, queryEnv=queryEnv(at)entry=0x0) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/tcop/postgres.c:689
#23 0x00005608fdcaf258 in exec_simple_query (query_string=0x5608fe42ab10
"select * from tablename where i = 89;") at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/tcop/postgres.c:1070
#24 0x00005608fdcb064b in PostgresMain (argc=<optimized out>,
argv=argv(at)entry=0x5608fe472900, dbname=0x5608fe472858 "postgres",
username=<optimized out>)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/tcop/postgres.c:4182
#25 0x00005608fd9becd2 in BackendRun (port=0x5608fe46b070) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/postmaster/postmaster.c:4358
#26 BackendStartup (port=0x5608fe46b070) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/postmaster/postmaster.c:4030
#27 ServerLoop () at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/postmaster/postmaster.c:1707
#28 0x00005608fdc3af82 in PostmasterMain (argc=5, argv=<optimized out>)
at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/postmaster/postmaster.c:1380
#29 0x00005608fd9c0075 in main (argc=5, argv=0x5608fe425820) at
/build/postgresql-11-d6c2wG/postgresql-11-11.5/build/../src/backend/main/main.c:228

Hope that will help, I'll try to reproduce issue without vacuum full, so
far no luck.

--
Thanks,
Alexey Ermakov

In response to

Responses

Browse pgsql-bugs by date

  From Date Subject
Next Message Dmitry Dolgov 2019-11-01 15:56:30 Re: BUG #16016: deadlock with startup process, AccessExclusiveLock on pg_statistic's toast table
Previous Message Sergei Kornilov 2019-10-31 14:41:54 Re: BUG #16092: json[b]_to_recordset and json[b]_populate_record do not read properties with mixed-case names