Re: pg14b1 stuck in lazy_scan_prune/heap_page_prune of pg_statistic

On Sun, Jun 06, 2021 at 01:59:10PM -0400, Tom Lane wrote:
> Matthias van de Meent <boekewurm+postgres(at)gmail(dot)com> writes:
> > On Sun, 6 Jun 2021 at 18:35, Justin Pryzby <pryzby(at)telsasoft(dot)com> wrote:
> >> However, I also found an autovacuum chewing 100% CPU, and it appears the
> >> problem is actually because autovacuum has locked a page of pg-statistic, and
> >> every other process then gets stuck waiting in the planner. I checked a few
> >> and found these:
>
> > My suspicion is that for some tuple on that page
> > HeapTupleSatisfiesVacuum() returns HEAPTUPLE_DEAD for a tuple that it
> > thinks should have been cleaned up by heap_page_prune, but isn't. This
> > would result in an infinite loop in lazy_scan_prune where the
> > condition on vacuumlazy.c:1800 will always be true, but the retry will
> > not do the job it's expected to do.
>
> Since Justin's got a debugger on the process already, it probably
> wouldn't be too hard to confirm or disprove that theory by stepping
> through the code.

Breakpoint 2, HeapTupleSatisfiesVacuum (htup=htup(at)entry=0x7fff7e4a9ca0, OldestXmin=926025113, buffer=buffer(at)entry=411) at heapam_visibility.c:1163
1163 heapam_visibility.c: No such file or directory.
(gdb) fin
Run till exit from #0 HeapTupleSatisfiesVacuum (htup=htup(at)entry=0x7fff7e4a9ca0, OldestXmin=926025113, buffer=buffer(at)entry=411) at heapam_visibility.c:1163
lazy_scan_prune (vacrel=vacrel(at)entry=0x12b42d0, buf=buf(at)entry=411, blkno=blkno(at)entry=1, page=page(at)entry=0x2aaaab54be00 "J\f", vistest=vistest(at)entry=0xe7bcc0 <GlobalVisCatalogRels>, prunestate=prunestate(at)entry=0x7fff7e4aae40)
at vacuumlazy.c:1790
1790 vacuumlazy.c: No such file or directory.
Value returned is $23 = HEAPTUPLE_DEAD

offnum = 6
tuple = {t_len = 259, t_self = {ip_blkid = {bi_hi = 0, bi_lo = 1}, ip_posid = 6}, t_tableOid = 2619, t_data = 0x2aaaab54db28}
res = HEAPTUPLE_DEAD

(gdb) p *itemid
$51 = {lp_off = 7464, lp_flags = 1, lp_len = 259}

(gdb) p *tuple->t_data
$54 = {t_choice = {t_heap = {t_xmin = 926014884, t_xmax = 926025112, t_field3 = {t_cid = 0, t_xvac = 0}}, t_datum = {datum_len_ = 926014884, datum_typmod = 926025112, datum_typeid = 0}}, t_ctid = {ip_blkid = {bi_hi = 0,
bi_lo = 1}, ip_posid = 1}, t_infomask2 = 49183, t_infomask = 9475, t_hoff = 32 ' ', t_bits = 0x2aaaab54db3f "\377\377\177\004"}

lp_flags = LP_NORMAL 1 ??
t_infomask2 = HEAP_ONLY_TUPLE | HEAP_HOT_UPDATED + 31 atts
infomask = HEAP_UPDATED | HEAP_XMAX_COMMITTED | HEAP_XMIN_COMMITTED | HEAP_HASVARWIDTH | HEAP_HASNULL

--
Justin