From 55fea31f5d3d99a94eba206ec5a75f94e1f43097 Mon Sep 17 00:00:00 2001 From: Justin Pryzby Date: Sun, 15 Dec 2019 17:00:29 -0600 Subject: [PATCH v3 4/4] reduce to DEBUG status logged from vacuum_heap/index.. ..since they can run multiple times, which is both excessively noisy, and confusing, due to showing multiple, multi-line messages with rusage. Also output (at DEBUG) a message indicating the action to be taken, before starting it. To avoid outputting a message about completion of one step, and taking a long time before outputting anything about the next/current step. I'm taking as a guiding principle to elog whenever calling pgstat_progress_update_param. --- src/backend/access/heap/vacuumlazy.c | 24 +++++++++++++++++------- 1 file changed, 17 insertions(+), 7 deletions(-) diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c index 6f85af7..95d999f 100644 --- a/src/backend/access/heap/vacuumlazy.c +++ b/src/backend/access/heap/vacuumlazy.c @@ -501,6 +501,7 @@ heap_vacuum_rel(Relation onerel, VacuumParams *params, lazy_truncate_heap(onerel, vacrelstats); /* Report that we are now doing final cleanup */ + elog(DEBUG1, "cleaning up"); pgstat_progress_update_param(PROGRESS_VACUUM_PHASE, PROGRESS_VACUUM_PHASE_FINAL_CLEANUP); @@ -1773,9 +1774,12 @@ lazy_vacuum_all_indexes(Relation onerel, Relation *Irel, { int idx; - for (idx = 0; idx < nindexes; idx++) + for (idx = 0; idx < nindexes; idx++) { + ereport(DEBUG1, (errmsg("\"%s\": vacuuming index", + RelationGetRelationName(Irel[idx])))); lazy_vacuum_index(Irel[idx], &stats[idx], vacrelstats->dead_tuples, vacrelstats->old_live_tuples); + } } /* Increase and report the number of index scans */ @@ -1805,6 +1809,8 @@ lazy_vacuum_heap(Relation onerel, LVRelStats *vacrelstats) Buffer vmbuffer = InvalidBuffer; /* Report that we are now vacuuming the heap */ + ereport(DEBUG1, (errmsg("\"%s\": vacuuming heap", + RelationGetRelationName(onerel)))); pgstat_progress_update_param(PROGRESS_VACUUM_PHASE, PROGRESS_VACUUM_PHASE_VACUUM_HEAP); @@ -1848,7 +1854,7 @@ lazy_vacuum_heap(Relation onerel, LVRelStats *vacrelstats) vmbuffer = InvalidBuffer; } - ereport(elevel, + ereport(DEBUG1, (errmsg("\"%s\": removed %d row versions in %d pages", RelationGetRelationName(onerel), tupindex, npages), @@ -2093,13 +2099,13 @@ lazy_parallel_vacuum_indexes(Relation *Irel, IndexBulkDeleteResult **stats, } if (lps->lvshared->for_cleanup) - ereport(elevel, + ereport(DEBUG1, (errmsg(ngettext("launched %d parallel vacuum worker for index cleanup (planned: %d)", "launched %d parallel vacuum workers for index cleanup (planned: %d)", lps->pcxt->nworkers_launched), lps->pcxt->nworkers_launched, nworkers))); else - ereport(elevel, + ereport(DEBUG1, (errmsg(ngettext("launched %d parallel vacuum worker for index vacuuming (planned: %d)", "launched %d parallel vacuum workers for index vacuuming (planned: %d)", lps->pcxt->nworkers_launched), @@ -2326,10 +2332,13 @@ lazy_cleanup_all_indexes(Relation *Irel, IndexBulkDeleteResult **stats, } else { - for (idx = 0; idx < nindexes; idx++) + for (idx = 0; idx < nindexes; idx++) { + ereport(DEBUG1, (errmsg("cleaning up index \"%s\"", + RelationGetRelationName(Irel[idx])))); lazy_cleanup_index(Irel[idx], &stats[idx], vacrelstats->new_rel_tuples, vacrelstats->tupcount_pages < vacrelstats->rel_pages); + } } } @@ -2369,7 +2378,7 @@ lazy_vacuum_index(Relation indrel, IndexBulkDeleteResult **stats, else msg = gettext_noop("scanned index \"%s\" to remove %d row versions"); - ereport(elevel, + ereport(DEBUG1, (errmsg(msg, RelationGetRelationName(indrel), dead_tuples->num_tuples), @@ -2412,7 +2421,7 @@ lazy_cleanup_index(Relation indrel, else msg = gettext_noop("index \"%s\" now contains %.0f row versions in %u pages"); - ereport(elevel, + ereport(DEBUG1, (errmsg(msg, RelationGetRelationName(indrel), (*stats)->num_index_tuples, @@ -2476,6 +2485,7 @@ lazy_truncate_heap(Relation onerel, LVRelStats *vacrelstats) pg_rusage_init(&ru0); /* Report that we are now truncating */ + elog(DEBUG1, "truncating heap"); pgstat_progress_update_param(PROGRESS_VACUUM_PHASE, PROGRESS_VACUUM_PHASE_TRUNCATE); -- 2.7.4