Location via proxy:   [ UP ]  
[Report a bug]   [Manage cookies]                
Skip to content

Commit 6591f42

Browse files
committed
Improve readability of the output of psql's \timing command.
In addition to the existing decimal-milliseconds output value, display the same value in mm:ss.fff format if it exceeds one second. Tack on hours and even days fields if the interval is large enough. This avoids needing mental arithmetic to convert the values into customary time units. Corey Huinker, reviewed by Gerdan Santos; bikeshedding by many Discussion: <CADkLM=dbC4R8sbbuFXQVBFWoJGQkTEW8RWnC0PbW9nZsovZpJQ@mail.gmail.com>
1 parent 600dc4c commit 6591f42

File tree

2 files changed

+59
-4
lines changed

2 files changed

+59
-4
lines changed

doc/src/sgml/ref/psql-ref.sgml

+5-2
Original file line numberDiff line numberDiff line change
@@ -2789,8 +2789,11 @@ testdb=&gt; <userinput>\setenv LESS -imx4F</userinput>
27892789
<term><literal>\timing [ <replaceable class="parameter">on</replaceable> | <replaceable class="parameter">off</replaceable> ]</literal></term>
27902790
<listitem>
27912791
<para>
2792-
Without parameter, toggles a display of how long each SQL statement
2793-
takes, in milliseconds. With parameter, sets same.
2792+
With a parameter, turns displaying of how long each SQL statement
2793+
takes on or off. Without a parameter, toggles the display between
2794+
on and off. The display is in milliseconds; intervals longer than
2795+
1 second are also shown in minutes:seconds format, with hours and
2796+
days fields added if needed.
27942797
</para>
27952798
</listitem>
27962799
</varlistentry>

src/bin/psql/common.c

+54-2
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,7 @@
1010

1111
#include <ctype.h>
1212
#include <limits.h>
13+
#include <math.h>
1314
#include <signal.h>
1415
#ifndef WIN32
1516
#include <unistd.h> /* for write() */
@@ -531,6 +532,57 @@ ClearOrSaveResult(PGresult *result)
531532
}
532533

533534

535+
/*
536+
* Print microtiming output. Always print raw milliseconds; if the interval
537+
* is >= 1 second, also break it down into days/hours/minutes/seconds.
538+
*/
539+
static void
540+
PrintTiming(double elapsed_msec)
541+
{
542+
double seconds;
543+
double minutes;
544+
double hours;
545+
double days;
546+
547+
if (elapsed_msec < 1000.0)
548+
{
549+
/* This is the traditional (pre-v10) output format */
550+
printf(_("Time: %.3f ms\n"), elapsed_msec);
551+
return;
552+
}
553+
554+
/*
555+
* Note: we could print just seconds, in a format like %06.3f, when the
556+
* total is less than 1min. But that's hard to interpret unless we tack
557+
* on "s" or otherwise annotate it. Forcing the display to include
558+
* minutes seems like a better solution.
559+
*/
560+
seconds = elapsed_msec / 1000.0;
561+
minutes = floor(seconds / 60.0);
562+
seconds -= 60.0 * minutes;
563+
if (minutes < 60.0)
564+
{
565+
printf(_("Time: %.3f ms (%02d:%06.3f)\n"),
566+
elapsed_msec, (int) minutes, seconds);
567+
return;
568+
}
569+
570+
hours = floor(minutes / 60.0);
571+
minutes -= 60.0 * hours;
572+
if (hours < 24.0)
573+
{
574+
printf(_("Time: %.3f ms (%02d:%02d:%06.3f)\n"),
575+
elapsed_msec, (int) hours, (int) minutes, seconds);
576+
return;
577+
}
578+
579+
days = floor(hours / 24.0);
580+
hours -= 24.0 * days;
581+
printf(_("Time: %.3f ms (%.0f d %02d:%02d:%06.3f)\n"),
582+
elapsed_msec, days, (int) hours, (int) minutes, seconds);
583+
}
584+
585+
534586
/*
535587
* PSQLexec
536588
*
@@ -679,7 +731,7 @@ PSQLexecWatch(const char *query, const printQueryOpt *opt)
679731

680732
/* Possible microtiming output */
681733
if (pset.timing)
682-
printf(_("Time: %.3f ms\n"), elapsed_msec);
734+
PrintTiming(elapsed_msec);
683735

684736
return 1;
685737
}
@@ -1332,7 +1384,7 @@ SendQuery(const char *query)
13321384

13331385
/* Possible microtiming output */
13341386
if (pset.timing)
1335-
printf(_("Time: %.3f ms\n"), elapsed_msec);
1387+
PrintTiming(elapsed_msec);
13361388

13371389
/* check for events that may occur during query execution */
13381390

0 commit comments

Comments
 (0)