From ee88cec87714420f195bc05d3a1e154c1aa759d6 Mon Sep 17 00:00:00 2001 From: Peter Geoghegan Date: Sun, 21 Nov 2021 14:47:11 -0800 Subject: [PATCH v5 2/5] Improve log_autovacuum_min_duration output. 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. Note that the new instrumentation doesn't say anything about pages that we failed to acquire a cleanup lock on when we see that there were no missed dead tuples on the page. Also report on visibility map pages skipped by VACUUM, without regard for whether the pages were all-frozen or just all-visible. Also report when and how relfrozenxid is advanced by VACUUM, including non-aggressive VACUUM. Apart from being useful on its own, this might enable future work that teaches non-aggressive VACUUM to be more concerned about advancing relfrozenxid sooner rather than later. Also report number of tuples frozen. This will become more important when the later patch to perform opportunistic tuple freezing is committed. Also enhance how we report OldestXmin cutoff by putting it in context: show how far behind it is at the _end_ of the VACUUM operation. Deliberately don't do anything with VACUUM VERBOSE in this commit, since a pending patch will generalize the log_autovacuum_min_duration code to produce VACUUM VERBOSE output as well [1]. That'll get committed first. [1] https://commitfest.postgresql.org/36/3431/ --- src/include/commands/vacuum.h | 2 + src/backend/access/heap/vacuumlazy.c | 108 +++++++++++++++++++-------- src/backend/commands/analyze.c | 3 + src/backend/commands/vacuum.c | 9 +++ 4 files changed, 91 insertions(+), 31 deletions(-) diff --git a/src/include/commands/vacuum.h b/src/include/commands/vacuum.h index 5a36049be..772a257fc 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 148129e59..2950df1ce 100644 --- a/src/backend/access/heap/vacuumlazy.c +++ b/src/backend/access/heap/vacuumlazy.c @@ -197,6 +197,7 @@ typedef struct LVRelState BlockNumber frozenskipped_pages; /* # frozen pages skipped via VM */ BlockNumber pages_removed; /* pages remove by 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 */ @@ -209,9 +210,10 @@ typedef struct LVRelState int num_index_scans; /* Counters that follow are only for scanned_pages */ int64 tuples_deleted; /* # deleted from table */ + int64 tuples_frozen; /* # frozen by us */ 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 +319,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; @@ -535,9 +539,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 { @@ -546,7 +552,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); } /* @@ -562,7 +569,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(); /* and log the action if appropriate */ @@ -576,6 +584,7 @@ heap_vacuum_rel(Relation rel, VacuumParams *params, { StringInfoData buf; char *msgfmt; + int32 diff; TimestampDifference(starttime, endtime, &secs, &usecs); @@ -622,16 +631,41 @@ 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 skipped using visibility map (%.2f%% of total)\n"), vacrel->pages_removed, vacrel->rel_pages, - vacrel->frozenskipped_pages); + orig_rel_pages - vacrel->scanned_pages, + orig_rel_pages == 0 ? 0 : + 100.0 * (orig_rel_pages - 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 newly frozen), %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->tuples_frozen, + (long long) vacrel->recently_dead_tuples); + if (vacrel->missed_dead_tuples > 0) + appendStringInfo(&buf, + _("tuples missed: %lld dead from %u contended pages\n"), + (long long) vacrel->missed_dead_tuples, + vacrel->missed_dead_pages); + diff = (int32) (ReadNextTransactionId() - OldestXmin); + appendStringInfo(&buf, + _("removable cutoff: %u, which is %d xids behind next\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) @@ -787,13 +821,16 @@ lazy_scan_heap(LVRelState *vacrel, int nworkers) vacrel->frozenskipped_pages = 0; vacrel->pages_removed = 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->tuples_frozen = 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; @@ -1340,7 +1377,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. @@ -1405,7 +1443,8 @@ lazy_scan_heap(LVRelState *vacrel, int nworkers) initStringInfo(&buf); appendStringInfo(&buf, _("%lld dead row versions cannot be removed yet, oldest xmin: %u\n"), - (long long) vacrel->new_dead_tuples, vacrel->OldestXmin); + (long long) vacrel->recently_dead_tuples, + vacrel->OldestXmin); appendStringInfo(&buf, _("%s."), pg_rusage_show(&ru0)); ereport(elevel, @@ -1586,7 +1625,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; @@ -1603,7 +1642,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; @@ -1762,11 +1801,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: @@ -1941,8 +1980,9 @@ retry: /* Finally, add page-local counts to whole-VACUUM counts */ vacrel->tuples_deleted += tuples_deleted; + vacrel->tuples_frozen += nfrozen; 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; } @@ -1995,7 +2035,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]; @@ -2007,7 +2048,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; @@ -2081,16 +2123,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: @@ -2118,13 +2159,15 @@ lazy_scan_noprune(LVRelState *vacrel, * * We are not prepared to handle the corner case where a single pass * strategy VACUUM cannot get a cleanup lock, and we then find LP_DEAD - * items. + * items. Count the LP_DEAD items as missed_dead_tuples instead. This + * is slightly dishonest, but it's better than maintaining code to do + * heap vacuuming for this one narrow corner case. */ if (lpdead_items > 0) *hastup = true; *hasfreespace = true; num_tuples += lpdead_items; - /* TODO HEAPTUPLE_DEAD style instrumentation needed here, too */ + missed_dead_tuples += lpdead_items; } else if (lpdead_items > 0) { @@ -2159,9 +2202,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; @@ -2234,8 +2280,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 @@ -3375,7 +3421,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 cd77907fc..afd1cb8f5 100644 --- a/src/backend/commands/analyze.c +++ b/src/backend/commands/analyze.c @@ -651,6 +651,7 @@ do_analyze_rel(Relation onerel, VacuumParams *params, hasindex, InvalidTransactionId, InvalidMultiXactId, + NULL, NULL, in_outer_xact); /* Same for indexes */ @@ -667,6 +668,7 @@ do_analyze_rel(Relation onerel, VacuumParams *params, false, InvalidTransactionId, InvalidMultiXactId, + NULL, NULL, in_outer_xact); } } @@ -679,6 +681,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 c94c187d3..d1d38d509 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