Обсуждение: \timing interval

On Thu, Jul 7, 2016 at 2:52 PM, Corey Huinker <corey.huinker@gmail.com> wrote:
> Wouldn't it be great if we had a way of printing timing in more human
> friendly formats?

Yes, it would. I've thought about doing this myself. So, +1 to the idea from me.


-- 
Peter Geoghegan

On 7/7/16 5:52 PM, Corey Huinker wrote:
> Wouldn't it be great if we had a way of printing timing in more human
> friendly formats?

Something like what you are proposing might as well be the default and 
only format.

-- 
Peter Eisentraut              http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Peter Eisentraut <peter.eisentraut@2ndquadrant.com> writes:
> On 7/7/16 5:52 PM, Corey Huinker wrote:
>> Wouldn't it be great if we had a way of printing timing in more human
>> friendly formats?

> Something like what you are proposing might as well be the default and 
> only format.

NAK --- if you're trying to do arithmetic on the numbers, converting
them to hh:mm:ss notation isn't the best first step.  I think a separate
setting somewhere to select the format would be good.  Please *don't*
do "\timing interval" as that confuses the on/off state with the
formatting selection.  Maybe a \pset option?

Also, might I suggest that leading zeroes in such a format are not
helpful?  That is, I'd want to see "1:02.345" not "00:01:02.345".
        regards, tom lane

On Sat, Jul 9, 2016 at 5:59 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Also, might I suggest that leading zeroes in such a format are not
> helpful?  That is, I'd want to see "1:02.345" not "00:01:02.345".


Or 1m 2s 345ms

-- 
greg

On 7/9/16 12:59 PM, Tom Lane wrote:
> NAK --- if you're trying to do arithmetic on the numbers, converting
> them to hh:mm:ss notation isn't the best first step.  I think a separate
> setting somewhere to select the format would be good.  Please *don't*
> do "\timing interval" as that confuses the on/off state with the
> formatting selection.  Maybe a \pset option?

I'm not quite sure what you mean by wanting to do arithmetic on the 
numbers.  My phrasing of the problem is that after a long query, you 
might get output like this:

Time: 1234567.666 ms

which is pretty useless.

So I would like to have a format that is a bit more sensitive to the 
scale of the numbers.  And I would like that by default, because I don't 
really want to have to fiddle with the format and then have to re-run 
the long query.  (Then I'd just do the division by 3600 or whatever 
myself, and we haven't really improved usability.)

I'm not wedded to any particular format, but I think we can come up with 
one that works in most situations.

-- 
Peter Eisentraut              http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Peter Eisentraut <peter.eisentraut@2ndquadrant.com> writes:
> I'm not quite sure what you mean by wanting to do arithmetic on the 
> numbers.  My phrasing of the problem is that after a long query, you 
> might get output like this:
> Time: 1234567.666 ms
> which is pretty useless.

What I mean by that is that not infrequently, I'll run the same query
several times and then want to average the results.  That's easy with awk
or similar scripts as long as the numbers are in straight decimal.

I don't mind if we provide a way to print in Babylonian-inspired
notation(s) as well, but I'm going to be seriously annoyed if that's
the only way to get the output.
        regards, tom lane

>>>>> "Tom" == Tom Lane <tgl@sss.pgh.pa.us> writes:
> Peter Eisentraut <peter.eisentraut@2ndquadrant.com> writes:>> I'm not quite sure what you mean by wanting to do
arithmeticon the >> numbers.  My phrasing of the problem is that after a long query, you >> might get output like
this:>>Time: 1234567.666 ms>> which is pretty useless.
 
Tom> What I mean by that is that not infrequently, I'll run the sameTom> query several times and then want to average
theresults.  That'sTom> easy with awk or similar scripts as long as the numbers are inTom> straight decimal.
 
Tom> I don't mind if we provide a way to print in Babylonian-inspiredTom> notation(s) as well, but I'm going to be
seriouslyannoyed ifTom> that's the only way to get the output.
 

How about

Time: 1234567.666 ms (20m 34.6s)

?

-- 
Andrew (irc:RhodiumToad)

Andrew Gierth <andrew@tao11.riddles.org.uk> writes:
> How about
> Time: 1234567.666 ms (20m 34.6s)

Hmm ... worksforme.
        regards, tom lane

Andrew Gierth wrote:

> How about
> 
> Time: 1234567.666 ms (20m 34.6s)
> 
> ?

+1 LGTM

-- 
Álvaro Herrera                http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

On Sat, Jul 9, 2016 at 1:48 PM, Alvaro Herrera <alvherre@2ndquadrant.com> wrote:
>> How about
>>
>> Time: 1234567.666 ms (20m 34.6s)
>>
>> ?
>
> +1 LGTM

+1


-- 
Peter Geoghegan

On 10/07/16 08:00, Andrew Gierth wrote:
>>>>>> "Tom" == Tom Lane <tgl@sss.pgh.pa.us> writes:
>   > Peter Eisentraut <peter.eisentraut@2ndquadrant.com> writes:
>   >> I'm not quite sure what you mean by wanting to do arithmetic on the
>   >> numbers.  My phrasing of the problem is that after a long query, you
>   >> might get output like this:
>   >> Time: 1234567.666 ms
>   >> which is pretty useless.
>
>   Tom> What I mean by that is that not infrequently, I'll run the same
>   Tom> query several times and then want to average the results.  That's
>   Tom> easy with awk or similar scripts as long as the numbers are in
>   Tom> straight decimal.
>
>   Tom> I don't mind if we provide a way to print in Babylonian-inspired
>   Tom> notation(s) as well, but I'm going to be seriously annoyed if
>   Tom> that's the only way to get the output.
>
> How about
>
> Time: 1234567.666 ms (20m 34.6s)
>
> ?
>
I like that, but I think the human form should retain the 3 decimal places.

In a few years, we may well have enormously multiprocessor computers 
with massive very fast permanent 'RAM' where the entire database is 
always in memory, so timing to the nearest microsecond could be useful.  
Obviously microsecond precision would be silly now, and would probably 
never warrant being the default (I'd be happy to be proved wrong here!), 
but it might be worthwhile putting in as an option - while people are 
looking at the relevant areas of the code.

Am inspired by the man page for 'ls': [...] The  SIZE  argument is  an  
integer and optional unit (example: 10K is 10*1024). Units are 
K,M,G,T,P,E,Z,Y  (powers  of  1024) [...]" Obviously learnt from the 
lessons of "640KB should be enough for everyone" stupidity!


Cheers,
Gavin

>>>>> "Gavin" == Gavin Flower <GavinFlower@archidevsys.co.nz> writes:
>> How about>> >> Time: 1234567.666 ms (20m 34.6s)
Gavin> I like that, but I think the human form should retain the 3Gavin> decimal places.

Scale it.

Time: 12.345 ms (0.012345s)

Time: 1234.567 ms (1.235s)

Time: 98765.432 ms (98.8s)

Time: 123456.789 ms (2m 3.5s)

Time: 12345678.666 ms (3h 24m 46s)
Gavin> In a few years, we may well have enormously multiprocessorGavin> computers with massive very fast permanent
'RAM'where theGavin> entire database is always in memory, so timing to the nearestGavin> microsecond could be useful.
 

But the original microsecond-resolution value is still right there, so I
don't see the issue.

-- 
Andrew (irc:RhodiumToad)

On 10/07/16 12:08, Andrew Gierth wrote:
>>>>>> "Gavin" == Gavin Flower <GavinFlower@archidevsys.co.nz> writes:
>   >> How about
>   >>
>   >> Time: 1234567.666 ms (20m 34.6s)
>
>   Gavin> I like that, but I think the human form should retain the 3
>   Gavin> decimal places.
>
> Scale it.
>
> Time: 12.345 ms (0.012345s)
>
> Time: 1234.567 ms (1.235s)
>
> Time: 98765.432 ms (98.8s)
>
> Time: 123456.789 ms (2m 3.5s)
>
> Time: 12345678.666 ms (3h 24m 46s)
>
>   Gavin> In a few years, we may well have enormously multiprocessor
>   Gavin> computers with massive very fast permanent 'RAM' where the
>   Gavin> entire database is always in memory, so timing to the nearest
>   Gavin> microsecond could be useful.
>
> But the original microsecond-resolution value is still right there, so I
> don't see the issue.
>
Sorry misunderstood, thought it was milliseconds!

On 7/9/16 4:00 PM, Andrew Gierth wrote:
> How about
>
> Time: 1234567.666 ms (20m 34.6s)

That's similar to what I had in mind, so I'd be happy with that.

-- 
Peter Eisentraut              http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

On 7/13/16 2:06 PM, Corey Huinker wrote:
> Time: 71041.022 ms (1m 11.041s)
>  pg_sleep
> ----------
> 
> (1 row)
> 
> Time: 3601083.544 ms (1h 0m 1.084s)
>  pg_sleep
> ----------
> 
> (1 row)

That works for me, except that the abbreviation for minute is "min".

-- 
Peter Eisentraut              http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Peter Eisentraut <peter.eisentraut@2ndquadrant.com> writes:
> On 7/13/16 2:06 PM, Corey Huinker wrote:
>> Time: 3601083.544 ms (1h 0m 1.084s)

> That works for me, except that the abbreviation for minute is "min".

Meh ... if we're using one-letter abbreviations for hour and second,
using three letters for minute seems just arbitrarily inconsistent.
There is zero possibility that anyone would misunderstand what unit
the "m" stands for.  See also the typical output of time(1):

$ time sleep 1

real    0m1.002s
user    0m0.001s
sys     0m0.002s

(Well, I guess that's bash's builtin rather than /usr/bin/time,
but the point stands: "m" is widely accepted in this context.)
        regards, tom lane

* Tom Lane (tgl@sss.pgh.pa.us) wrote:
> Peter Eisentraut <peter.eisentraut@2ndquadrant.com> writes:
> > On 7/13/16 2:06 PM, Corey Huinker wrote:
> >> Time: 3601083.544 ms (1h 0m 1.084s)
>
> > That works for me, except that the abbreviation for minute is "min".
>
> Meh ... if we're using one-letter abbreviations for hour and second,
> using three letters for minute seems just arbitrarily inconsistent.
> There is zero possibility that anyone would misunderstand what unit
> the "m" stands for.  See also the typical output of time(1):
>
> $ time sleep 1
>
> real    0m1.002s
> user    0m0.001s
> sys     0m0.002s
>
> (Well, I guess that's bash's builtin rather than /usr/bin/time,
> but the point stands: "m" is widely accepted in this context.)

Agreed.

Thanks!

Stephen

On 7/15/16 11:23 AM, Tom Lane wrote:
> Meh ... if we're using one-letter abbreviations for hour and second,
> using three letters for minute seems just arbitrarily inconsistent.

Well, it's the SI abbreviation.

We also need to think through localization options.

Using the 01:02:03.004 format would sidestep most of that.

Or we can still give users the option to set it to whatever they want.

-- 
Peter Eisentraut              http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

The following review has been posted through the commitfest application:
make installcheck-world:  tested, failed
Implements feature:       tested, failed
Spec compliant:           tested, failed
Documentation:            tested, failed

I could not find a way to disable this functionality , I see that the impact can be big as it is changed the output
structure\timing without a mode to disable it. I even finding great functionality but need a way to set to default. 

The new status of this patch is: Waiting on Author

The following review has been posted through the commitfest application:
make installcheck-world:  tested, passed
Implements feature:       tested, passed
Spec compliant:           tested, passed
Documentation:            tested, passed

Sorry, my mistake!

I could not find a way to disable this functionality , I see that the impact can be big as it is changed the output
structure\timing without a mode to disable it. I even finding great functionality but need a way to set to default.
 

The following review has been posted through the commitfest application:
make installcheck-world:  tested, passed
Implements feature:       tested, passed
Spec compliant:           tested, passed
Documentation:            tested, passed

I did some tests and found nothing special. The stated resource is implemented correctly.
He passes all regression tests and enables the use of the new features specified.


The new status of this patch is: Ready for Committer

[ This patch is marked Ready For Committer, and discussion seems to have
died off, so let's get on with committing something ... ]

Corey Huinker <corey.huinker@gmail.com> writes:
> Generally speaking, people disliked the third mode for \timing, and were
> generally fine with AndrewG's idea of printing the timing in both raw
> milliseconds and a more human-digestible format, which means that we can:

Yeah, there seemed to be general agreement on just appending a more human
readable format to the existing printout.

> 3. ignore locales and fall back to a left-trimmed DDD HH:MM:SS.mmm format
>      + Easy to revert to that code
>      + My original format and one PeterE advocated
>      - others disliked

I think this is the approach to go with as a starting point, since it
largely avoids both localization and units-naming concerns.  If someone
feels the desire to build a customizable output format, that can be dealt
with as a separate patch on top of this one ... but I really question that
it'd ever be worth the trouble.

So for clarity's sake: first suitable format among these:

Time: 59.999 ms
Time: 121.999 ms (2:01.999)
Time: 10921.999 ms (3:02:01.999)
Time: 356521.999 ms (4 3:02:01.999)

In an NLS-enabled build, the translator would be able to fool with the
punctuation, though I dunno whether any translators would need to.
        regards, tom lane

I wrote:
> So for clarity's sake: first suitable format among these:

> Time: 59.999 ms
> Time: 121.999 ms (2:01.999)
> Time: 10921.999 ms (3:02:01.999)
> Time: 356521.999 ms (4 3:02:01.999)

Sorry, that probably added no clarity at all, I was confusing
seconds with milliseconds in the example values :-(
        regards, tom lane

<div dir="ltr"><div class="gmail_extra"><div class="gmail_quote">On Thu, Sep 1, 2016 at 2:17 PM, Tom Lane <span
dir="ltr"><<ahref="mailto:tgl@sss.pgh.pa.us" target="_blank">tgl@sss.pgh.pa.us</a>></span> wrote:<br
/><blockquoteclass="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><span class="">I
wrote:<br/> > So for clarity's sake: first suitable format among these:<br /><br /> > Time: 59.999 ms<br /> >
Time:121.999 ms (2:01.999)<br /> > Time: 10921.999 ms (3:02:01.999)<br /> > Time: 356521.999 ms (4
3:02:01.999)<br/><br /></span>Sorry, that probably added no clarity at all, I was confusing<br /> seconds with
millisecondsin the example values :-(<br /><br />                         regards, tom lane<br /></blockquote></div><br
/>Ididn't scan your examples for correctness, but the parentheticals matched my own idea for what "left-trimmed"
meant.</div><divclass="gmail_extra"><br /></div><div class="gmail_extra">I'm going to hold off a bit to see if anybody
elsechimes in, and if not I'm going to deliver a patch.<br /><br /></div></div> 

I wrote:
> Sorry, that probably added no clarity at all, I was confusing
> seconds with milliseconds in the example values :-(

After a bit of further fooling with sample values, I propose this
progression:

Time: 0.100 ms
Time: 1.200 ms
Time: 1001.200 ms (0:01.001)
Time: 12001.200 ms (0:12.001)
Time: 60001.200 ms (1:00.001)
Time: 720001.200 ms (12:00.001)
Time: 3660001.200 ms (1: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: 10000000000000000000.000 ms (115740740740 17:46:40.000)

Note that times from 1 second to 1 hour all get the nn:nn.nnn
treatment.  I experimented with these variants for sub-minute times:

Time: 1001.200 ms (1.001)
Time: 12001.200 ms (12.001)
Time: 1001.200 ms (1.001 s)
Time: 12001.200 ms (12.001 s)

but it seems like the first variant is not terribly intelligible and
the second variant is inconsistent with what happens for longer times.
Adding a zero minutes field is a subtler way of cueing the reader that
it's mm:ss.
        regards, tom lane

Corey Huinker <corey.huinker@gmail.com> writes:
> I'm going to hold off a bit to see if anybody else chimes in, and if not
> I'm going to deliver a patch.

I've already been updating yours, no need for another.
        regards, tom lane

<div dir="ltr"><div class="gmail_extra"><div class="gmail_quote">On Thu, Sep 1, 2016 at 2:43 PM, Tom Lane <span
dir="ltr"><<ahref="mailto:tgl@sss.pgh.pa.us" target="_blank">tgl@sss.pgh.pa.us</a>></span> wrote:<br
/><blockquoteclass="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid
rgb(204,204,204);padding-left:1ex"><spanclass="gmail-">I wrote:<br /> > Sorry, that probably added no clarity at
all,I was confusing<br /> > seconds with milliseconds in the example values :-(<br /><br /></span>After a bit of
furtherfooling with sample values, I propose this<br /> progression:<br /><br /> Time: 0.100 ms<br /> Time: 1.200 ms<br
/>Time: 1001.200 ms (0:01.001)<br /> Time: 12001.200 ms (0:12.001)<br /> Time: 60001.200 ms (1:00.001)<br /> Time:
720001.200ms (12:00.001)<br /> Time: 3660001.200 ms (1:01:00.001)<br /> Time: 43920001.200 ms (12:12:00.001)<br />
Time:176460001.200 ms (2 01:01:00.001)<br /> Time: 216720001.200 ms (2 12:12:00.001)<br /> Time:
10000000000000000000.000ms (115740740740 17:46:40.000)<br /><br /> Note that times from 1 second to 1 hour all get the
nn:nn.nnn<br/> treatment.  I experimented with these variants for sub-minute times:<br /><br /> Time: 1001.200 ms
(1.001)<br/> Time: 12001.200 ms (12.001)<br /> Time: 1001.200 ms (1.001 s)<br /> Time: 12001.200 ms (12.001 s)<br /><br
/>but it seems like the first variant is not terribly intelligible and<br /> the second variant is inconsistent with
whathappens for longer times.<br /> Adding a zero minutes field is a subtler way of cueing the reader that<br /> it's
mm:ss.<br/><br />                         regards, tom lane<br /></blockquote></div><br />Well, if we're looking to be
consistent,here's what interval does now:<br /><br /><div class="gmail_extra"><span
style="font-family:monospace,monospace">#select '1 second 1 millisecond'::interval, '1 minute 2
milliseconds'::interval,'1 hour 30 milliseconds'::interval, '1 day 1 hour 999 milliseconds'::interval, '1 week 1 day 1
hour'::interval;</span><br/></div><div class="gmail_extra"><font face="monospace, monospace"><div class="gmail_extra"> 
 interval  |   interval   |  interval   |      interval      |    interval</div><div
class="gmail_extra">--------------+--------------+-------------+--------------------+-----------------</div><div
class="gmail_extra"> 00:00:01.001| 00:01:00.002 | 01:00:00.03 | 1 day 01:00:00.999 | 8 days 01:00:00</div><div
class="gmail_extra">(1row)</div><br /></font><br />Should we just plug into whatever code that uses? It's slightly
different:<br/><br /><div class="gmail_extra"><font face="monospace, monospace"># select interval
'10000000000000000000.001milliseconds'::interval;</font></div><div class="gmail_extra"><font face="monospace,
monospace">ERROR: interval field value out of range: "10000000000000000000.001 milliseconds"</font></div><div
class="gmail_extra"><fontface="monospace, monospace">LINE 1: select interval '10000000000000000000.001
milliseconds'::int...</font></div><divclass="gmail_extra"><font face="monospace, monospace">                       
^</font></div><divclass="gmail_extra"><font face="monospace, monospace"># select interval '216720001.200
milliseconds';</font></div><divclass="gmail_extra"><font face="monospace, monospace">   interval</font></div><div
class="gmail_extra"><fontface="monospace, monospace">---------------</font></div><div class="gmail_extra"><font
face="monospace,monospace"> 60:12:00.0012</font></div><div class="gmail_extra"><font face="monospace, monospace">(1
row)</font></div><divclass="gmail_extra"><font face="monospace, monospace"><br /></font></div><div
class="gmail_extra"><fontface="monospace, monospace"># select interval '176460001.200 ms';</font></div><div
class="gmail_extra"><fontface="monospace, monospace">   interval</font></div><div class="gmail_extra"><font
face="monospace,monospace">---------------</font></div><div class="gmail_extra"><font face="monospace,
monospace"> 49:01:00.0012</font></div><divclass="gmail_extra"><font face="monospace, monospace">(1 row)</font></div><br
/></div></div></div>

Corey Huinker <corey.huinker@gmail.com> writes:
> On Thu, Sep 1, 2016 at 2:43 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> Note that times from 1 second to 1 hour all get the nn:nn.nnn
>> treatment.  I experimented with these variants for sub-minute times:
>> ...
>> but it seems like the first variant is not terribly intelligible and
>> the second variant is inconsistent with what happens for longer times.

> Well, if we're looking to be consistent, here's what interval does now:
> ...
> Should we just plug into whatever code that uses?

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.
        regards, tom lane

<div dir="ltr"><div class="gmail_extra"><div class="gmail_quote">On Thu, Sep 1, 2016 at 3:01 PM, Tom Lane <span
dir="ltr"><<ahref="mailto:tgl@sss.pgh.pa.us" target="_blank">tgl@sss.pgh.pa.us</a>></span> wrote:<br
/><blockquoteclass="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><span
class="">CoreyHuinker <<a href="mailto:corey.huinker@gmail.com">corey.huinker@gmail.com</a>> writes:<br /> >
OnThu, Sep 1, 2016 at 2:43 PM, Tom Lane <<a href="mailto:tgl@sss.pgh.pa.us">tgl@sss.pgh.pa.us</a>> wrote:<br
/></span><spanclass="">>> Note that times from 1 second to 1 hour all get the nn:nn.nnn<br /> >>
treatment. I experimented with these variants for sub-minute times:<br /></span>>> ...<br /><span
class="">>>but it seems like the first variant is not terribly intelligible and<br /> >> the second variant
isinconsistent with what happens for longer times.<br /><br /></span><span class="">> Well, if we're looking to be
consistent,here's what interval does now:<br /></span>> ...<br /><span class="">> Should we just plug into
whatevercode that uses?<br /><br /></span>Well, that code's on the backend side so we're not going to just call it<br
/>in any case.  And I think we don't want to be quite so verbose as to go up<br /> to hh:mm:ss.fff as soon as we get
past1 second.  However, comparing that<br /> output to what I had suggests that maybe it's better to keep a leading<br
/>zero in two-digit fields, that is render times like "00:01.234",<br /> "01:23.456", or "01:23:45.678" rather than
suppressingthe initial zero as<br /> I had in my examples.  It's an extra character but I think it reinforces<br /> the
meaning.<br/><br />                         regards, tom lane<br /></blockquote></div><br /></div><div
class="gmail_extra">+1</div><divclass="gmail_extra">The larger jump in widths from no MM:SS to HH:MM:SS is a good
visualcue. Jumping from MM:SS to H:MM:SS to HH:MM:SS would be more subtle and possibly confusing.</div><div
class="gmail_extra"><br/></div><div class="gmail_extra"><br /></div><div class="gmail_extra"><br /></div></div> 

Corey Huinker <corey.huinker@gmail.com> writes:
> On Thu, Sep 1, 2016 at 3:01 PM, Tom Lane <tgl@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 */

Peter van Hardenberg <pvh@pvh.ca> writes:
> Some kind of units on the parenthetical format would be helpful.

I was really hoping to not re-open that can of worms :-(
        regards, tom lane

I wrote:
> 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)

After further thought I concluded that not providing any labeling of
days is a bad idea.  The hours, minutes, and seconds fields seem
reasonably self-explanatory given the formatting, but days not so much.
(I'm not sure whether that is the whole of Peter van H's objection,
but surely it's part of it.)  I pushed the patch using this:

Time: 176460001.200 ms (2 d 01:01:00.001)

and all else as before.
        regards, tom lane

On 9/3/16 2:35 PM, Tom Lane wrote:
> I pushed the patch using this:
>
> Time: 176460001.200 ms (2 d 01:01:00.001)
>
> and all else as before.

I'd find this useful in the final output of EXPLAIN ANALYZE as well; any 
objections to adding it?
-- 
Jim Nasby, Data Architect, Blue Treble Consulting, Austin TX
Experts in Analytics, Data Architecture and PostgreSQL
Data in Trouble? Get it in Treble! http://BlueTreble.com
855-TREBLE2 (855-873-2532)   mobile: 512-569-9461

Corey Huinker <corey.huinker@gmail.com> writes:
> On Sun, Sep 4, 2016 at 7:05 PM, Jim Nasby <Jim.Nasby@bluetreble.com> wrote:
>> I'd find this useful in the final output of EXPLAIN ANALYZE as well; any
>> objections to adding it?

> It's sorta out of my hands now, but what Tom said earlier is that because
> this is client-side code, it wouldn't use existing interval code.
> EXPLAIN *is* server-side, we couldn't use this code, but we could leverage
> existing interval code there to achieve a similar concept.

If we like this specific output format, I'd be inclined to just
copy-and-paste the code from psql.  I seriously doubt that getting type
interval involved in the discussion would lead to a shorter or
better-performing solution.

> I have another thing I'd like to add to EXPLAIN output : server version
> number output. So maybe we can pick those up in another thread.

Ugh.  There are multiple ways to get that already, and it's not like
space in EXPLAIN's output is not a precious resource.
        regards, tom lane

On 9/6/16 1:45 PM, Tom Lane wrote:
>> It's sorta out of my hands now, but what Tom said earlier is that because
>> > this is client-side code, it wouldn't use existing interval code.
>> > EXPLAIN *is* server-side, we couldn't use this code, but we could leverage
>> > existing interval code there to achieve a similar concept.
> If we like this specific output format, I'd be inclined to just
> copy-and-paste the code from psql.  I seriously doubt that getting type
> interval involved in the discussion would lead to a shorter or
> better-performing solution.

If we could actually execute user functions as part of EXPLAIN 
generating it's output then it might be a lot less invasive... but I 
don't think that's an option.

>> > I have another thing I'd like to add to EXPLAIN output : server version
>> > number output. So maybe we can pick those up in another thread.
> Ugh.  There are multiple ways to get that already, and it's not like
> space in EXPLAIN's output is not a precious resource.

I don't think adding a line would be that bad, and it would probably 
greatly reduce the amount of mailing list traffic asking for version if 
nothing else. It might also be useful to tools like 
https://explain.depesz.com/. If nothing else it's probably worth adding 
to the non-text output formats.
-- 
Jim Nasby, Data Architect, Blue Treble Consulting, Austin TX
Experts in Analytics, Data Architecture and PostgreSQL
Data in Trouble? Get it in Treble! http://BlueTreble.com
855-TREBLE2 (855-873-2532)   mobile: 512-569-9461

<p dir="ltr"><p dir="ltr">On 4 Sep. 2016 3:36 am, "Tom Lane" <<a
href="mailto:tgl@sss.pgh.pa.us">tgl@sss.pgh.pa.us</a>>wrote:<br /> ><p dir="ltr">> After further thought I
concludedthat not providing any labeling of<br /> > days is a bad idea. <p dir="ltr">Yeah. I think labeling days is
definitelygood. I'm glad you changed that.<p dir="ltr">Personally I'd like to trim milliseconds when dealing with
minute+long runs and seconds from hour+ runs too, since it's all there in the ms output and the units output is for
humanreadability. I see the value of retaining full precision too, though, and don't feel strongly about it.