From e270ddb7e599e22b90b4d6702596770f67569f07 Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <bertranddrouvot.pg@gmail.com>
Date: Tue, 11 Feb 2025 07:37:05 +0000
Subject: [PATCH v17 3/3] Add cost-based delay time to VACUUM/ANALYZE (VERBOSE)

This commit adds cost-based delay time to VACUUM/ANALYZE (VERBOSE) and to
autovacuum logs (if track_cost_delay_timing is enabled).
---
 doc/src/sgml/config.sgml             | 8 +++++---
 src/backend/access/heap/vacuumlazy.c | 6 ++++++
 src/backend/commands/analyze.c       | 6 ++++++
 3 files changed, 17 insertions(+), 3 deletions(-)
  49.4% doc/src/sgml/
  25.2% src/backend/access/heap/
  25.3% src/backend/commands/

diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index 79a66ba7181..15001c01046 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -8261,9 +8261,11 @@ COPY postgres_log FROM '/full/path/to/logfile.csv' WITH csv;
         platforms.  You can use the <xref linkend="pgtesttiming"/> tool to
         measure the overhead of timing on your system.  Cost-based vacuum delay
         timing information is displayed in
-        <link linkend="vacuum-progress-reporting"><structname>pg_stat_progress_vacuum</structname></link>
-        and
-        <link linkend="analyze-progress-reporting"><structname>pg_stat_progress_analyze</structname></link>.
+        <link linkend="vacuum-progress-reporting"><structname>pg_stat_progress_vacuum</structname></link>,
+        <link linkend="analyze-progress-reporting"><structname>pg_stat_progress_analyze</structname></link>,
+        in the output of <xref linkend="sql-vacuum"/> when the <literal>VERBOSE</literal>
+        option is used, by autovacuum for auto-vacuums and auto-analyzes,
+        when <xref linkend="guc-log-autovacuum-min-duration"/> is set.
         Only superusers and users with the appropriate <literal>SET</literal>
         privilege can change this setting.
        </para>
diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index e4d6d654c0a..735a60b3d9a 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -830,6 +830,12 @@ heap_vacuum_rel(Relation rel, VacuumParams *params,
 				appendStringInfo(&buf, _("I/O timings: read: %.3f ms, write: %.3f ms\n"),
 								 read_ms, write_ms);
 			}
+			if (track_cost_delay_timing)
+			{
+				double		delayed_ms = (double) MyBEEntry->st_progress_param[PROGRESS_VACUUM_DELAY_TIME] / 1000000.0;
+
+				appendStringInfo(&buf, _("delay time: %.3f ms\n"), delayed_ms);
+			}
 			if (secs_dur > 0 || usecs_dur > 0)
 			{
 				read_rate = (double) BLCKSZ * total_blks_read /
diff --git a/src/backend/commands/analyze.c b/src/backend/commands/analyze.c
index e4302f4cdb2..91751d15e66 100644
--- a/src/backend/commands/analyze.c
+++ b/src/backend/commands/analyze.c
@@ -816,6 +816,12 @@ do_analyze_rel(Relation onerel, VacuumParams *params,
 				appendStringInfo(&buf, _("I/O timings: read: %.3f ms, write: %.3f ms\n"),
 								 read_ms, write_ms);
 			}
+			if (track_cost_delay_timing)
+			{
+				double		delayed_ms = (double) MyBEEntry->st_progress_param[PROGRESS_ANALYZE_DELAY_TIME] / 1000000.0;
+
+				appendStringInfo(&buf, _("delay time: %.3f ms\n"), delayed_ms);
+			}
 			appendStringInfo(&buf, _("avg read rate: %.3f MB/s, avg write rate: %.3f MB/s\n"),
 							 read_rate, write_rate);
 			appendStringInfo(&buf, _("buffer usage: %lld hits, %lld reads, %lld dirtied\n"),
-- 
2.34.1