From 18380fbc60810eeea2b60ba33e7a2850d0212fdd Mon Sep 17 00:00:00 2001
From: Peter Geoghegan <pg@bowt.ie>
Date: Sun, 21 Nov 2021 14:47:11 -0800
Subject: [PATCH v7 2/6] Add VACUUM instrumentation for scanned pages,
 relfrozenxid.

Report on scanned pages within VACUUM VERBOSE and autovacuum logging.
These are pages that were physically scanned during the VACUUM
operation, including pages that are marked all-visible in the visibility
map that were nevertheless scanned (typically because the visibility map
skipping decided not to skip a skippable page that is physically
surrounded by non-skippable pages).

Also report when relfrozenxid is advanced by VACUUM, and by how much.
Rename the user-visible OldestXmin output field to "removal cutoff", and
show some supplementary information: how far behind the cutoff is
(number of XIDs behind) by the time the VACUUM operation finished.  This
should give users some chance of figuring out what's _not_ working, and
highlights the relationship between OldestXmin and the relfrozenxid.

Finally, add instrumentation of "missed dead tuples", and the number of
pages that had at least one such tuple.  These are fully DEAD (not just
RECENTLY_DEAD) tuples with storage that could not be pruned due to an
inability to acquire a cleanup lock.  This is a replacement for the
"skipped due to pin" instrumentation removed by the previous commit.  It
shows more details than before for pages where failing to get a cleanup
lock actually mattered (those with missed dead tuples), and shows
nothing for pages where no real work was missed.  In practice there
seems to be far more of the latter than of the former, so the signal to
noise ratio is much improved.

Author: Peter Geoghegan <pg@bowt.ie>
Reviewed-By: Andres Freund <andres@anarazel.de>
Discussion: https://postgr.es/m/CAH2-Wznp=c=Opj8Z7RMR3G=ec3_JfGYMN_YvmCEjoPCHzWbx0g@mail.gmail.com
---
 src/include/commands/vacuum.h        |  2 +
 src/backend/access/heap/vacuumlazy.c | 97 +++++++++++++++++++---------
 src/backend/commands/analyze.c       |  3 +
 src/backend/commands/vacuum.c        |  9 +++
 4 files changed, 82 insertions(+), 29 deletions(-)

diff --git a/src/include/commands/vacuum.h b/src/include/commands/vacuum.h
index 5d0bdfa42..e5e548d6b 100644
--- a/src/include/commands/vacuum.h
+++ b/src/include/commands/vacuum.h
@@ -283,6 +283,8 @@ extern void vac_update_relstats(Relation relation,
 								bool hasindex,
 								TransactionId frozenxid,
 								MultiXactId minmulti,
+								bool *frozenxid_updated,
+								bool *minmulti_updated,
 								bool in_outer_xact);
 extern void vacuum_set_xid_limits(Relation rel,
 								  int freeze_min_age, int freeze_table_age,
diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index a9c83f6dc..71378740c 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -198,6 +198,7 @@ typedef struct LVRelState
 	BlockNumber frozenskipped_pages;	/* # frozen pages skipped via VM */
 	BlockNumber removed_pages;	/* # pages removed by relation truncation */
 	BlockNumber lpdead_item_pages;	/* # pages with LP_DEAD items */
+	BlockNumber missed_dead_pages;	/* # pages with missed dead tuples */
 	BlockNumber nonempty_pages; /* actually, last nonempty page + 1 */
 
 	/* Statistics output by us, for table */
@@ -211,8 +212,8 @@ typedef struct LVRelState
 	/* Counters that follow are only for scanned_pages */
 	int64		tuples_deleted; /* # deleted from table */
 	int64		lpdead_items;	/* # deleted from indexes */
-	int64		new_dead_tuples;	/* new estimated total # of dead items in
-									 * table */
+	int64		recently_dead_tuples;	/* # dead, but not yet removable */
+	int64		missed_dead_tuples; /* # removable, but not removed */
 	int64		num_tuples;		/* total number of nonremovable tuples */
 	int64		live_tuples;	/* live tuples (reltuples estimate) */
 } LVRelState;
@@ -317,6 +318,8 @@ heap_vacuum_rel(Relation rel, VacuumParams *params,
 				write_rate;
 	bool		aggressive,
 				skipwithvm;
+	bool		frozenxid_updated,
+				minmulti_updated;
 	BlockNumber orig_rel_pages;
 	char	  **indnames = NULL;
 	TransactionId xidFullScanLimit;
@@ -538,9 +541,11 @@ heap_vacuum_rel(Relation rel, VacuumParams *params,
 	{
 		/* Cannot advance relfrozenxid/relminmxid -- just update pg_class */
 		Assert(!aggressive);
+		frozenxid_updated = minmulti_updated = false;
 		vac_update_relstats(rel, new_rel_pages, new_live_tuples,
 							new_rel_allvisible, vacrel->nindexes > 0,
-							InvalidTransactionId, InvalidMultiXactId, false);
+							InvalidTransactionId, InvalidMultiXactId,
+							NULL, NULL, false);
 	}
 	else
 	{
@@ -549,7 +554,8 @@ heap_vacuum_rel(Relation rel, VacuumParams *params,
 			   orig_rel_pages);
 		vac_update_relstats(rel, new_rel_pages, new_live_tuples,
 							new_rel_allvisible, vacrel->nindexes > 0,
-							FreezeLimit, MultiXactCutoff, false);
+							FreezeLimit, MultiXactCutoff,
+							&frozenxid_updated, &minmulti_updated, false);
 	}
 
 	/*
@@ -565,7 +571,8 @@ heap_vacuum_rel(Relation rel, VacuumParams *params,
 	pgstat_report_vacuum(RelationGetRelid(rel),
 						 rel->rd_rel->relisshared,
 						 Max(new_live_tuples, 0),
-						 vacrel->new_dead_tuples);
+						 vacrel->recently_dead_tuples +
+						 vacrel->missed_dead_tuples);
 	pgstat_progress_end_command();
 
 	if (instrument)
@@ -578,6 +585,7 @@ heap_vacuum_rel(Relation rel, VacuumParams *params,
 		{
 			StringInfoData buf;
 			char	   *msgfmt;
+			int32		diff;
 
 			TimestampDifference(starttime, endtime, &secs, &usecs);
 
@@ -629,16 +637,40 @@ heap_vacuum_rel(Relation rel, VacuumParams *params,
 							 vacrel->relnamespace,
 							 vacrel->relname,
 							 vacrel->num_index_scans);
-			appendStringInfo(&buf, _("pages: %u removed, %u remain, %u skipped frozen\n"),
+			appendStringInfo(&buf, _("pages: %u removed, %u remain, %u scanned (%.2f%% of total)\n"),
 							 vacrel->removed_pages,
 							 vacrel->rel_pages,
-							 vacrel->frozenskipped_pages);
+							 vacrel->scanned_pages,
+							 orig_rel_pages == 0 ? 0 :
+							 100.0 * vacrel->scanned_pages / orig_rel_pages);
 			appendStringInfo(&buf,
-							 _("tuples: %lld removed, %lld remain, %lld are dead but not yet removable, oldest xmin: %u\n"),
+							 _("tuples: %lld removed, %lld remain, %lld are dead but not yet removable\n"),
 							 (long long) vacrel->tuples_deleted,
 							 (long long) vacrel->new_rel_tuples,
-							 (long long) vacrel->new_dead_tuples,
-							 OldestXmin);
+							 (long long) vacrel->recently_dead_tuples);
+			if (vacrel->missed_dead_tuples > 0)
+				appendStringInfo(&buf,
+								 _("tuples missed: %lld dead from %u pages not removed due to cleanup lock contention\n"),
+								 (long long) vacrel->missed_dead_tuples,
+								 vacrel->missed_dead_pages);
+			diff = (int32) (ReadNextTransactionId() - OldestXmin);
+			appendStringInfo(&buf,
+							 _("removable cutoff: %u, older by %d xids when operation ended\n"),
+							 OldestXmin, diff);
+			if (frozenxid_updated)
+			{
+				diff = (int32) (FreezeLimit - vacrel->relfrozenxid);
+				appendStringInfo(&buf,
+								 _("new relfrozenxid: %u, which is %d xids ahead of previous value\n"),
+								 FreezeLimit, diff);
+			}
+			if (minmulti_updated)
+			{
+				diff = (int32) (MultiXactCutoff - vacrel->relminmxid);
+				appendStringInfo(&buf,
+								 _("new relminmxid: %u, which is %d mxids ahead of previous value\n"),
+								 MultiXactCutoff, diff);
+			}
 			if (orig_rel_pages > 0)
 			{
 				if (vacrel->do_index_vacuuming)
@@ -779,13 +811,15 @@ lazy_scan_heap(LVRelState *vacrel, int nworkers)
 	vacrel->frozenskipped_pages = 0;
 	vacrel->removed_pages = 0;
 	vacrel->lpdead_item_pages = 0;
+	vacrel->missed_dead_pages = 0;
 	vacrel->nonempty_pages = 0;
 
 	/* Initialize instrumentation counters */
 	vacrel->num_index_scans = 0;
 	vacrel->tuples_deleted = 0;
 	vacrel->lpdead_items = 0;
-	vacrel->new_dead_tuples = 0;
+	vacrel->recently_dead_tuples = 0;
+	vacrel->missed_dead_tuples = 0;
 	vacrel->num_tuples = 0;
 	vacrel->live_tuples = 0;
 
@@ -1334,7 +1368,8 @@ lazy_scan_heap(LVRelState *vacrel, int nworkers)
 	 * (unlikely) scenario that new_live_tuples is -1, take it as zero.
 	 */
 	vacrel->new_rel_tuples =
-		Max(vacrel->new_live_tuples, 0) + vacrel->new_dead_tuples;
+		Max(vacrel->new_live_tuples, 0) + vacrel->recently_dead_tuples +
+		vacrel->missed_dead_tuples;
 
 	/*
 	 * Release any remaining pin on visibility map page.
@@ -1542,7 +1577,7 @@ lazy_scan_prune(LVRelState *vacrel,
 	HTSV_Result res;
 	int			tuples_deleted,
 				lpdead_items,
-				new_dead_tuples,
+				recently_dead_tuples,
 				num_tuples,
 				live_tuples;
 	int			nnewlpdead;
@@ -1559,7 +1594,7 @@ retry:
 	/* Initialize (or reset) page-level counters */
 	tuples_deleted = 0;
 	lpdead_items = 0;
-	new_dead_tuples = 0;
+	recently_dead_tuples = 0;
 	num_tuples = 0;
 	live_tuples = 0;
 
@@ -1718,11 +1753,11 @@ retry:
 			case HEAPTUPLE_RECENTLY_DEAD:
 
 				/*
-				 * If tuple is recently deleted then we must not remove it
-				 * from relation.  (We only remove items that are LP_DEAD from
+				 * If tuple is recently dead then we must not remove it from
+				 * the relation.  (We only remove items that are LP_DEAD from
 				 * pruning.)
 				 */
-				new_dead_tuples++;
+				recently_dead_tuples++;
 				prunestate->all_visible = false;
 				break;
 			case HEAPTUPLE_INSERT_IN_PROGRESS:
@@ -1898,7 +1933,7 @@ retry:
 	/* Finally, add page-local counts to whole-VACUUM counts */
 	vacrel->tuples_deleted += tuples_deleted;
 	vacrel->lpdead_items += lpdead_items;
-	vacrel->new_dead_tuples += new_dead_tuples;
+	vacrel->recently_dead_tuples += recently_dead_tuples;
 	vacrel->num_tuples += num_tuples;
 	vacrel->live_tuples += live_tuples;
 }
@@ -1943,7 +1978,8 @@ lazy_scan_noprune(LVRelState *vacrel,
 	int			lpdead_items,
 				num_tuples,
 				live_tuples,
-				new_dead_tuples;
+				recently_dead_tuples,
+				missed_dead_tuples;
 	HeapTupleHeader tupleheader;
 	OffsetNumber deadoffsets[MaxHeapTuplesPerPage];
 
@@ -1955,7 +1991,8 @@ lazy_scan_noprune(LVRelState *vacrel,
 	lpdead_items = 0;
 	num_tuples = 0;
 	live_tuples = 0;
-	new_dead_tuples = 0;
+	recently_dead_tuples = 0;
+	missed_dead_tuples = 0;
 
 	maxoff = PageGetMaxOffsetNumber(page);
 	for (offnum = FirstOffsetNumber;
@@ -2029,16 +2066,15 @@ lazy_scan_noprune(LVRelState *vacrel,
 				/*
 				 * There is some useful work for pruning to do, that won't be
 				 * done due to failure to get a cleanup lock.
-				 *
-				 * TODO Add dedicated instrumentation for this case
 				 */
+				missed_dead_tuples++;
 				break;
 			case HEAPTUPLE_RECENTLY_DEAD:
 
 				/*
-				 * Count in new_dead_tuples, just like lazy_scan_prune
+				 * Count in recently_dead_tuples, just like lazy_scan_prune
 				 */
-				new_dead_tuples++;
+				recently_dead_tuples++;
 				break;
 			case HEAPTUPLE_INSERT_IN_PROGRESS:
 
@@ -2074,7 +2110,7 @@ lazy_scan_noprune(LVRelState *vacrel,
 			 */
 			*hastup = true;
 			num_tuples += lpdead_items;
-			/* TODO HEAPTUPLE_DEAD style instrumentation needed here, too */
+			missed_dead_tuples += lpdead_items;
 		}
 
 		/* Caller records free space, with or without LP_DEAD items */
@@ -2120,9 +2156,12 @@ lazy_scan_noprune(LVRelState *vacrel,
 	/*
 	 * Finally, add relevant page-local counts to whole-VACUUM counts
 	 */
-	vacrel->new_dead_tuples += new_dead_tuples;
+	vacrel->recently_dead_tuples += recently_dead_tuples;
+	vacrel->missed_dead_tuples += missed_dead_tuples;
 	vacrel->num_tuples += num_tuples;
 	vacrel->live_tuples += live_tuples;
+	if (missed_dead_tuples > 0)
+		vacrel->missed_dead_pages++;
 
 	/* Caller won't need to call lazy_scan_prune with same page */
 	return true;
@@ -2201,8 +2240,8 @@ lazy_vacuum(LVRelState *vacrel)
 		 * dead_items space is not CPU cache resident.
 		 *
 		 * We don't take any special steps to remember the LP_DEAD items (such
-		 * as counting them in new_dead_tuples report to the stats collector)
-		 * when the optimization is applied.  Though the accounting used in
+		 * as counting them in our final report to the stats collector) when
+		 * the optimization is applied.  Though the accounting used in
 		 * analyze.c's acquire_sample_rows() will recognize the same LP_DEAD
 		 * items as dead rows in its own stats collector report, that's okay.
 		 * The discrepancy should be negligible.  If this optimization is ever
@@ -3329,7 +3368,7 @@ update_index_statistics(LVRelState *vacrel)
 							false,
 							InvalidTransactionId,
 							InvalidMultiXactId,
-							false);
+							NULL, NULL, false);
 	}
 }
 
diff --git a/src/backend/commands/analyze.c b/src/backend/commands/analyze.c
index a0da998c2..736479295 100644
--- a/src/backend/commands/analyze.c
+++ b/src/backend/commands/analyze.c
@@ -645,6 +645,7 @@ do_analyze_rel(Relation onerel, VacuumParams *params,
 							hasindex,
 							InvalidTransactionId,
 							InvalidMultiXactId,
+							NULL, NULL,
 							in_outer_xact);
 
 		/* Same for indexes */
@@ -661,6 +662,7 @@ do_analyze_rel(Relation onerel, VacuumParams *params,
 								false,
 								InvalidTransactionId,
 								InvalidMultiXactId,
+								NULL, NULL,
 								in_outer_xact);
 		}
 	}
@@ -673,6 +675,7 @@ do_analyze_rel(Relation onerel, VacuumParams *params,
 		vac_update_relstats(onerel, -1, totalrows,
 							0, hasindex, InvalidTransactionId,
 							InvalidMultiXactId,
+							NULL, NULL,
 							in_outer_xact);
 	}
 
diff --git a/src/backend/commands/vacuum.c b/src/backend/commands/vacuum.c
index d1dadc54e..37413dd43 100644
--- a/src/backend/commands/vacuum.c
+++ b/src/backend/commands/vacuum.c
@@ -1315,6 +1315,7 @@ vac_update_relstats(Relation relation,
 					BlockNumber num_all_visible_pages,
 					bool hasindex, TransactionId frozenxid,
 					MultiXactId minmulti,
+					bool *frozenxid_updated, bool *minmulti_updated,
 					bool in_outer_xact)
 {
 	Oid			relid = RelationGetRelid(relation);
@@ -1390,22 +1391,30 @@ vac_update_relstats(Relation relation,
 	 * This should match vac_update_datfrozenxid() concerning what we consider
 	 * to be "in the future".
 	 */
+	if (frozenxid_updated)
+		*frozenxid_updated = false;
 	if (TransactionIdIsNormal(frozenxid) &&
 		pgcform->relfrozenxid != frozenxid &&
 		(TransactionIdPrecedes(pgcform->relfrozenxid, frozenxid) ||
 		 TransactionIdPrecedes(ReadNextTransactionId(),
 							   pgcform->relfrozenxid)))
 	{
+		if (frozenxid_updated)
+			*frozenxid_updated = true;
 		pgcform->relfrozenxid = frozenxid;
 		dirty = true;
 	}
 
 	/* Similarly for relminmxid */
+	if (minmulti_updated)
+		*minmulti_updated = false;
 	if (MultiXactIdIsValid(minmulti) &&
 		pgcform->relminmxid != minmulti &&
 		(MultiXactIdPrecedes(pgcform->relminmxid, minmulti) ||
 		 MultiXactIdPrecedes(ReadNextMultiXactId(), pgcform->relminmxid)))
 	{
+		if (minmulti_updated)
+			*minmulti_updated = true;
 		pgcform->relminmxid = minmulti;
 		dirty = true;
 	}
-- 
2.30.2

