From 10d3c94e9e38c29086627631564c9e6d4d620ca2 Mon Sep 17 00:00:00 2001 From: Justin Pryzby Date: Sun, 15 Dec 2019 17:00:29 -0600 Subject: [PATCH v1 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 c8d5538..08ad6b5 100644 --- a/src/backend/access/heap/vacuumlazy.c +++ b/src/backend/access/heap/vacuumlazy.c @@ -326,6 +326,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. @@ -1429,8 +1430,11 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats, /* Do post-vacuum cleanup and statistics update for each index */ if (vacrelstats->useindex) { - for (i = 0; i < nindexes; i++) + for (i = 0; i < nindexes; i++) { + ereport(DEBUG1, (errmsg("cleaning up index \"%s\"", + RelationGetRelationName(Irel[i])))); lazy_cleanup_index(Irel[i], indstats[i], vacrelstats); + } } /* If no indexes, make log report that lazy_vacuum_heap would've made */ @@ -1503,8 +1507,11 @@ lazy_vacuum_all_indexes(Relation onerel, LVRelStats *vacrelstats, PROGRESS_VACUUM_PHASE_VACUUM_INDEX); /* Remove index entries */ - for (i = 0; i < nindexes; i++) + for (i = 0; i < nindexes; i++) { + ereport(DEBUG1, (errmsg("\"%s\": vacuuming index", + RelationGetRelationName(Irel[i])))); lazy_vacuum_index(Irel[i], &indstats[i], vacrelstats); + } /* Increase and report the number of index scans */ vacrelstats->num_index_scans++; @@ -1538,6 +1545,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)); @@ -1589,7 +1598,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), @@ -1780,7 +1789,7 @@ lazy_vacuum_index(Relation indrel, *stats = index_bulk_delete(&ivinfo, *stats, lazy_tid_reaped, (void *) vacrelstats); - ereport(elevel, + ereport(DEBUG1, (errmsg("scanned index \"%s\" to remove %d row versions", RelationGetRelationName(indrel), vacrelstats->num_dead_tuples), @@ -1833,7 +1842,7 @@ lazy_cleanup_index(Relation indrel, InvalidMultiXactId, false); - ereport(elevel, + ereport(DEBUG1, (errmsg("index \"%s\" now contains %.0f row versions in %u pages", RelationGetRelationName(indrel), stats->num_index_tuples, @@ -1901,6 +1910,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