From 0a5f3ad741468c1c4bdbffb48b69f6610524e6d7 Mon Sep 17 00:00:00 2001 From: Justin Pryzby Date: Sun, 15 Dec 2019 17:00:29 -0600 Subject: [PATCH v2 4/6] 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 | 20 +++++++++++++++----- 1 file changed, 15 insertions(+), 5 deletions(-) diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c index f45968c..2e1e8cc 100644 --- a/src/backend/access/heap/vacuumlazy.c +++ b/src/backend/access/heap/vacuumlazy.c @@ -506,6 +506,7 @@ heap_vacuum_rel(Relation onerel, VacuumParams *params, /* Report that we are now doing final cleanup */ pgstat_progress_update_param(PROGRESS_VACUUM_PHASE, PROGRESS_VACUUM_PHASE_FINAL_CLEANUP); + elog(DEBUG1, "cleaning up"); /* * Update statistics in pg_class. @@ -1757,9 +1758,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 */ @@ -1794,6 +1798,8 @@ lazy_vacuum_heap(Relation onerel, LVRelStats *vacrelstats) /* Report that we are now vacuuming the heap */ pgstat_progress_update_param(PROGRESS_VACUUM_PHASE, PROGRESS_VACUUM_PHASE_VACUUM_HEAP); + ereport(DEBUG1, (errmsg("\"%s\": vacuuming heap", + RelationGetRelationName(onerel)))); /* Setup error traceback support for ereport() */ errcbarg.relnamespace = get_namespace_name(RelationGetNamespace(onerel)); @@ -1845,7 +1851,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), @@ -2323,10 +2329,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); + } } } @@ -2366,7 +2375,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), @@ -2409,7 +2418,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, @@ -2475,6 +2484,7 @@ lazy_truncate_heap(Relation onerel, LVRelStats *vacrelstats) /* Report that we are now truncating */ pgstat_progress_update_param(PROGRESS_VACUUM_PHASE, PROGRESS_VACUUM_PHASE_TRUNCATE); + elog(DEBUG1, "truncating heap"); /* * Loop until no more truncating can be done. -- 2.7.4