Hi,
I have created a small patch to postgres source (in particular the
psql part of it) that modifies the way time spent executing the SQL
commands is printed out.

The idea is to have a human readable time printed, e.g.:
Time: 1:32:15.45 m:s:ms
Time: 2_10:12:55:444.033 d_h:m:s:ms

Attached you can find a patch without any regression tests for that as
this is practically impossible to test with regression tests. The
duration of an SQL command (even though using pg_sleep) would differ
on each machine and even between consecutive runs. Therefore one
cannot specify a static expected output.
My patch is relative to origin/REL9_4_STABLE branch as that is the one
I started from.

My plea is to have this change merged into the main stream so that it
becomes available in upcoming releases.

This modification does not require any interaction with user.
It may create backward compatibility issues if some SQL developers
assumed that the format is always <milis>.<micros>.

regards
bogdan

>From 25b2e3f9d888ecf0cc6fe0fbb569004cf9ce315b Mon Sep 17 00:00:00 2001
From: Bogdan Pilch <bogdan.pi...@opensynergy.com>
Date: Sat, 16 Aug 2014 23:20:18 +0200
Subject: [PATCH] BPI: Implemented enhancement f timing feature (displaying
 time in a more readable way).

---
 src/bin/psql/common.c | 75 +++++++++++++++++++++++++++++++++++++++++++++++++--
 1 file changed, 73 insertions(+), 2 deletions(-)

diff --git a/src/bin/psql/common.c b/src/bin/psql/common.c
index c08c813..9c7f1ff 100644
--- a/src/bin/psql/common.c
+++ b/src/bin/psql/common.c
@@ -25,10 +25,18 @@
 #include "mbprint.h"
 
 
+#define TIMING_BUFFER_SIZE 64
+
+#define SECONDS_DENOMINATOR (1000.0)
+#define MINUTES_DENOMINATOR (60.0 * SECONDS_DENOMINATOR)
+#define HOURS_DENOMINATOR (60.0 * MINUTES_DENOMINATOR)
+#define DAYS_DENOMINATOR (24.0 * HOURS_DENOMINATOR)
+
 
 static bool ExecQueryUsingCursor(const char *query, double *elapsed_msec);
 static bool command_no_begin(const char *query);
 static bool is_select_command(const char *query);
+void ms2str_format(double intime, char *out);
 
 /*
  * setQFout
@@ -880,6 +888,7 @@ SendQuery(const char *query)
 	bool		OK = false;
 	bool		on_error_rollback_savepoint = false;
 	static bool on_error_rollback_warning = false;
+	char timing_buf[TIMING_BUFFER_SIZE];
 
 	if (!pset.db)
 	{
@@ -1063,8 +1072,11 @@ SendQuery(const char *query)
 	PQclear(results);
 
 	/* Possible microtiming output */
-	if (pset.timing)
-		printf(_("Time: %.3f ms\n"), elapsed_msec);
+	if (pset.timing) {
+		ms2str_format(elapsed_msec, timing_buf);
+		//printf(_("Time: %.3f ms\n"), elapsed_msec);
+		printf(_("Time: %s\n"), timing_buf);
+	}
 
 	/* check for events that may occur during query execution */
 
@@ -1748,3 +1760,62 @@ expand_tilde(char **filename)
 
 	return;
 }
+
+/*
+ * Fill in the supplied buffer with nice time broken down to dd:hh:mm:ss:ms.us
+ *
+ */
+void ms2str_format(double intime, char *out)
+{
+	int days, hours, minutes, seconds;
+	double ms;
+
+	days = (int) (intime / (DAYS_DENOMINATOR));
+	intime -= ((double)days * DAYS_DENOMINATOR);
+	hours = (int) (intime / (HOURS_DENOMINATOR));
+	intime -= ((double)hours * HOURS_DENOMINATOR);
+	minutes = (int) (intime / (MINUTES_DENOMINATOR));
+	intime -= ((double)minutes * MINUTES_DENOMINATOR);
+	seconds = (int) (intime / (SECONDS_DENOMINATOR));
+	intime -= ((double)seconds * SECONDS_DENOMINATOR);
+	ms = (intime);
+
+	if (days > 0)
+		sprintf(out, "%d_%d:%d:%d:%.02f d_h:m:s:ms", days, hours, minutes, seconds, ms);
+	else if (hours > 0)
+		sprintf(out, "%d:%d:%d:%.02f h:m:s:ms", hours, minutes, seconds, ms);
+	else if (minutes > 0)
+		sprintf(out, "%d:%d:%.02f m:s:ms", minutes, seconds, ms);
+	else if (seconds > 0)
+		sprintf(out, "%d:%.02f s:ms", seconds, ms);
+	else
+		sprintf(out, "%.02f ms", ms);
+}
-- 
1.9.1

-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Reply via email to