Corey Huinker <corey.huin...@gmail.com> writes:
> On Thu, Sep 1, 2016 at 3:01 PM, Tom Lane <t...@sss.pgh.pa.us> wrote:
>> Well, that code's on the backend side so we're not going to just call it
>> in any case. And I think we don't want to be quite so verbose as to go up
>> to hh:mm:ss.fff as soon as we get past 1 second. However, comparing that
>> output to what I had suggests that maybe it's better to keep a leading
>> zero in two-digit fields, that is render times like "00:01.234",
>> "01:23.456", or "01:23:45.678" rather than suppressing the initial zero as
>> I had in my examples. It's an extra character but I think it reinforces
>> the meaning.
> +1
> The larger jump in widths from no MM:SS to HH:MM:SS is a good visual cue.
> Jumping from MM:SS to H:MM:SS to HH:MM:SS would be more subtle and possibly
> confusing.
Attached is an updated patch that does it like that. Sample output
(generated by forcing specific arguments to PrintTiming):
Time: 0.100 ms
Time: 1.200 ms
Time: 1001.200 ms (00:01.001)
Time: 12001.200 ms (00:12.001)
Time: 60001.200 ms (01:00.001)
Time: 720001.200 ms (12:00.001)
Time: 3660001.200 ms (01:01:00.001)
Time: 43920001.200 ms (12:12:00.001)
Time: 176460001.200 ms (2 01:01:00.001)
Time: 216720001.200 ms (2 12:12:00.001)
Time: 8816460001.200 ms (102 01:01:00.001)
Time: 8856720001.200 ms (102 12:12:00.001)
Barring objections I'll commit this soon.
regards, tom lane
diff --git a/doc/src/sgml/ref/psql-ref.sgml b/doc/src/sgml/ref/psql-ref.sgml
index 8a66ce7..88e2f66 100644
*** a/doc/src/sgml/ref/psql-ref.sgml
--- b/doc/src/sgml/ref/psql-ref.sgml
*************** testdb=> <userinput>\setenv LESS -imx
*** 2789,2796 ****
<term><literal>\timing [ <replaceable class="parameter">on</replaceable> | <replaceable class="parameter">off</replaceable> ]</literal></term>
<listitem>
<para>
! Without parameter, toggles a display of how long each SQL statement
! takes, in milliseconds. With parameter, sets same.
</para>
</listitem>
</varlistentry>
--- 2789,2798 ----
<term><literal>\timing [ <replaceable class="parameter">on</replaceable> | <replaceable class="parameter">off</replaceable> ]</literal></term>
<listitem>
<para>
! With a parameter, turns displaying of how long each SQL statement
! takes on or off. Without a parameter, toggles the display between
! on and off. The display is in milliseconds; intervals longer than
! 1 second are also shown in days/hours/minutes/seconds format.
</para>
</listitem>
</varlistentry>
diff --git a/src/bin/psql/common.c b/src/bin/psql/common.c
index 7399950..a17f1de 100644
*** a/src/bin/psql/common.c
--- b/src/bin/psql/common.c
***************
*** 10,15 ****
--- 10,16 ----
#include <ctype.h>
#include <limits.h>
+ #include <math.h>
#include <signal.h>
#ifndef WIN32
#include <unistd.h> /* for write() */
*************** ClearOrSaveResult(PGresult *result)
*** 530,535 ****
--- 531,586 ----
}
}
+ /*
+ * Print microtiming output. Always print raw milliseconds; if the interval
+ * is >= 1 second, also break it down into days/hours/minutes/seconds.
+ */
+ static void
+ PrintTiming(double elapsed_msec)
+ {
+ double seconds;
+ double minutes;
+ double hours;
+ double days;
+
+ if (elapsed_msec < 1000.0)
+ {
+ /* This is the traditional (pre-v10) output format */
+ printf(_("Time: %.3f ms\n"), elapsed_msec);
+ return;
+ }
+
+ /*
+ * Note: we could print just seconds, in a format like %06.3f, when the
+ * total is less than 1min. But that's hard to interpret unless we tack
+ * on "s" or otherwise annotate it. Forcing the display to include
+ * minutes seems like a better solution.
+ */
+ seconds = elapsed_msec / 1000.0;
+ minutes = floor(seconds / 60.0);
+ seconds -= 60.0 * minutes;
+ if (minutes < 60.0)
+ {
+ printf(_("Time: %.3f ms (%02d:%06.3f)\n"),
+ elapsed_msec, (int) minutes, seconds);
+ return;
+ }
+
+ hours = floor(minutes / 60.0);
+ minutes -= 60.0 * hours;
+ if (hours < 24.0)
+ {
+ printf(_("Time: %.3f ms (%02d:%02d:%06.3f)\n"),
+ elapsed_msec, (int) hours, (int) minutes, seconds);
+ return;
+ }
+
+ days = floor(hours / 24.0);
+ hours -= 24.0 * days;
+ printf(_("Time: %.3f ms (%.0f %02d:%02d:%06.3f)\n"),
+ elapsed_msec, days, (int) hours, (int) minutes, seconds);
+ }
+
/*
* PSQLexec
*************** PSQLexecWatch(const char *query, const p
*** 679,685 ****
/* Possible microtiming output */
if (pset.timing)
! printf(_("Time: %.3f ms\n"), elapsed_msec);
return 1;
}
--- 730,736 ----
/* Possible microtiming output */
if (pset.timing)
! PrintTiming(elapsed_msec);
return 1;
}
*************** SendQuery(const char *query)
*** 1332,1338 ****
/* Possible microtiming output */
if (pset.timing)
! printf(_("Time: %.3f ms\n"), elapsed_msec);
/* check for events that may occur during query execution */
--- 1383,1389 ----
/* Possible microtiming output */
if (pset.timing)
! PrintTiming(elapsed_msec);
/* check for events that may occur during query execution */
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
