Subject: [PATCH v2 1/1] add timing information to pg_upgrade

From: Nathan Bossart <[email-masked]>
Date: Thu, 27 Jul 2023 16:16:45 -0700

---
 src/bin/pg_upgrade/util.c | 55 ++++++++++++++++++++++++++++++++++++++-
 1 file changed, 54 insertions(+), 1 deletion(-)

diff --git a/src/bin/pg_upgrade/util.c b/src/bin/pg_upgrade/util.c
index 21ba4c8f12..25e43a593a 100644
--- a/src/bin/pg_upgrade/util.c
+++ b/src/bin/pg_upgrade/util.c
@@ -9,14 +9,19 @@
 
 #include "postgres_fe.h"
 
+#include <math.h>
 #include <signal.h>
 
 #include "common/username.h"
 #include "pg_upgrade.h"
+#include "portability/instr_time.h"
 
 LogOpts		log_opts;
 
+static instr_time step_start;
+
 static void pg_log_v(eLogType type, const char *fmt, va_list ap) pg_attribute_printf(2, 0);
+static char *get_time_str(double time_ms);

 /*
@@ -137,6 +142,8 @@ prep_status(const char *fmt,...)
 
 	/* trim strings */
 	pg_log(PG_REPORT_NONL, "%-*s", MESSAGE_WIDTH, message);
+
+	INSTR_TIME_SET_CURRENT(step_start);
 }
 
 /*
@@ -170,6 +177,8 @@ prep_status_progress(const char *fmt,...)
 		pg_log(PG_REPORT, "%-*s", MESSAGE_WIDTH, message);
 	else
 		pg_log(PG_REPORT_NONL, "%-*s", MESSAGE_WIDTH, message);
+
+	INSTR_TIME_SET_CURRENT(step_start);
 }
 
 static void
@@ -280,11 +289,55 @@ pg_fatal(const char *fmt,...)
 }

+static char *
+get_time_str(double time_ms)
+{
+	double		seconds;
+	double		minutes;
+	double		hours;
+	double		days;
+
+	if (time_ms < 1000.0)
+		return psprintf("%.3f ms", time_ms);
+
+	seconds = time_ms / 1000.0;
+	minutes = floor(seconds / 60.0);
+	seconds -= 60.0 * minutes;
+	if (minutes < 60.0)
+		return psprintf("%.3f ms (%02d:%06.3f)",
+						time_ms, (int) minutes, seconds);
+
+	hours = floor(minutes / 60.0);
+	minutes -= 60.0 * hours;
+	if (hours < 24.0)
+		return psprintf("%.3f ms (%02d:%02d:%06.3f)",
+						time_ms, (int) hours, (int) minutes, seconds);
+
+	days = floor(hours / 24.0);
+	hours -= 24.0 * days;
+	return psprintf("%.3f ms (%.0f d %02d:%02d:%06.3f)",
+					time_ms, days, (int) hours, (int) minutes, seconds);
+}
+
+
 void
 check_ok(void)
 {
+	instr_time	step_end;
+	char	   *step_time;
+
+	Assert(!INSTR_TIME_IS_ZERO(step_start));
+
+	INSTR_TIME_SET_CURRENT(step_end);
+	INSTR_TIME_SUBTRACT(step_end, step_start);
+	step_time = get_time_str(INSTR_TIME_GET_MILLISEC(step_end));
+
+	/* reset start time */
+	INSTR_TIME_SET_ZERO(step_start);
+
 	/* all seems well */
-	report_status(PG_REPORT, "ok");
+	report_status(PG_REPORT, "ok\t%s", step_time);
+	pfree(step_time);
 }

-- 
2.25.1

--vtzGhvizbBRQ85DL--