Subject: [PATCH v1 4/6] reduce to DEBUG status logged from vacuum_heap/index..

From: Justin Pryzby <[email-masked]>
Date: Sun, 15 Dec 2019 17:00:29 -0600

..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

--bygAmIonOAIqBxQB
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
 filename="v1-0005-Report-number-of-pages_allvisible-frozen.patch"