Date: Mon, 31 Jul 2023 11:37:02 -0700
From: Nathan Bossart <nathandbossart@gmail.com>
To: Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
Cc: PostgreSQL-development <pgsql-hackers@postgresql.org>
Subject: Re: add timing information to pg_upgrade
Message-ID: <20230731183702.GA537853@nathanxps13>
References: <20230727235134.GA3658499@nathanxps13>
 <CALj2ACUT86rjj5Vf5gt-bceUx4C43vcML7zbNW4NyGyo-iN3xw@mail.gmail.com>
 <20230728173814.GA3765390@nathanxps13>
 <20230728184735.GC3661419@nathanxps13>
 <CALj2ACVVvk1cYLtWVxHv=Z1Ubq=UES9fhKbUU4c9k4W+fEDnbw@mail.gmail.com>
 <20230729211418.GA189222@nathanxps13>
 <CALj2ACUEkFmk8x8XTuN=ZgEMtQ6zuZP2jDy4Ri-woaL0i1ABfg@mail.gmail.com>
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="AhhlLboLdkugWU4S"
Content-Disposition: inline
In-Reply-To: 
 <CALj2ACUEkFmk8x8XTuN=ZgEMtQ6zuZP2jDy4Ri-woaL0i1ABfg@mail.gmail.com>
Archived-At: 
 <https://www.postgresql.org/message-id/20230731183702.GA537853%40nathanxps13>
Precedence: bulk


--AhhlLboLdkugWU4S
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline

On Mon, Jul 31, 2023 at 11:34:57AM +0530, Bharath Rupireddy wrote:
> Either of "Checking for \"aclitem\" data type usage" or "Checking for
> \"aclitem\" data type in user tables"  seems okay to me, however, I
> prefer the second wording.

Okay.  I used the second wording for all the data type checks in v3.  I
also marked the timing strings for translation.  I considered trying to
extract psql's PrintTiming() so that it could be reused in other utilities,
but the small differences would likely make translation difficult, and the
logic isn't terribly long or sophisticated.

My only remaining concern is that this timing information could cause
pg_upgrade's output to exceed 80 characters per line.  I don't know if this
is something that folks are very worried about in 2023, but it still seemed
worth bringing up.

-- 
Nathan Bossart
Amazon Web Services: https://aws.amazon.com

--AhhlLboLdkugWU4S
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v3-0001-harmonize-data-type-status-messages-in-pg_upgrade.patch"

From c52513341fb2a315203e9ba5dd95761220744a74 Mon Sep 17 00:00:00 2001
From: Nathan Bossart <nathan@postgresql.org>
Date: Mon, 31 Jul 2023 11:02:27 -0700
Subject: [PATCH v3 1/2] harmonize data type status messages in pg_upgrade

---
 src/bin/pg_upgrade/check.c   | 4 ++--
 src/bin/pg_upgrade/version.c | 6 +++---
 2 files changed, 5 insertions(+), 5 deletions(-)

diff --git a/src/bin/pg_upgrade/check.c b/src/bin/pg_upgrade/check.c
index 64024e3b9e..38a4227be0 100644
--- a/src/bin/pg_upgrade/check.c
+++ b/src/bin/pg_upgrade/check.c
@@ -1215,7 +1215,7 @@ check_for_aclitem_data_type_usage(ClusterInfo *cluster)
 {
 	char		output_path[MAXPGPATH];
 
-	prep_status("Checking for incompatible \"aclitem\" data type in user tables");
+	prep_status("Checking for \"aclitem\" data type in user tables");
 
 	snprintf(output_path, sizeof(output_path), "tables_using_aclitem.txt");
 
@@ -1243,7 +1243,7 @@ check_for_jsonb_9_4_usage(ClusterInfo *cluster)
 {
 	char		output_path[MAXPGPATH];
 
-	prep_status("Checking for incompatible \"jsonb\" data type");
+	prep_status("Checking for \"jsonb\" data type in user tables");
 
 	snprintf(output_path, sizeof(output_path), "%s/%s",
 			 log_opts.basedir,
diff --git a/src/bin/pg_upgrade/version.c b/src/bin/pg_upgrade/version.c
index 403a6d7cfa..9755af920f 100644
--- a/src/bin/pg_upgrade/version.c
+++ b/src/bin/pg_upgrade/version.c
@@ -181,7 +181,7 @@ old_9_3_check_for_line_data_type_usage(ClusterInfo *cluster)
 {
 	char		output_path[MAXPGPATH];
 
-	prep_status("Checking for incompatible \"line\" data type");
+	prep_status("Checking for \"line\" data type in user tables");
 
 	snprintf(output_path, sizeof(output_path), "%s/%s",
 			 log_opts.basedir,
@@ -221,7 +221,7 @@ old_9_6_check_for_unknown_data_type_usage(ClusterInfo *cluster)
 {
 	char		output_path[MAXPGPATH];
 
-	prep_status("Checking for invalid \"unknown\" user columns");
+	prep_status("Checking for \"unknown\" data type in user tables");
 
 	snprintf(output_path, sizeof(output_path), "%s/%s",
 			 log_opts.basedir,
@@ -366,7 +366,7 @@ old_11_check_for_sql_identifier_data_type_usage(ClusterInfo *cluster)
 {
 	char		output_path[MAXPGPATH];
 
-	prep_status("Checking for invalid \"sql_identifier\" user columns");
+	prep_status("Checking for \"sql_identifier\" data type in user tables");
 
 	snprintf(output_path, sizeof(output_path), "%s/%s",
 			 log_opts.basedir,
-- 
2.25.1


--AhhlLboLdkugWU4S
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v3-0002-add-timing-information-to-pg_upgrade.patch"

From 99ba1903472b72480d4ace13568300f35320cbaf Mon Sep 17 00:00:00 2001
From: Nathan Bossart <nathan@postgresql.org>
Date: Thu, 27 Jul 2023 16:16:45 -0700
Subject: [PATCH v3 2/2] add timing information to pg_upgrade

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


--AhhlLboLdkugWU4S--