Thread: \timing interval
\timing is great.
\timing is helpful.
\timing has made me really good at mentally estimating numbers modulo 3600000.
\timing is helpful.
\timing has made me really good at mentally estimating numbers modulo 3600000.
Wouldn't it be great if we had a way of printing timing in more human friendly formats?
Attached is a patch that allows the following (new/interesting bits in bold):
# \timing offTiming is off.# select pg_sleep(1);pg_sleep----------(1 row)# \timingTiming is on.# select pg_sleep(1);pg_sleep----------(1 row)Time: 1002.959 ms# \timing intervalTiming is interval.# select pg_sleep(1);pg_sleep----------(1 row)Time: 00:00:01.003# \timingTiming is off.
As demonstrated, "interval" toggles to "off". There is no way to toggle to "interval".
I'm pretty flexible on how something like this gets invoked. We could leave timing alone and create a format variable. We could actually leverage the pre-existing interval-to-string code, etc.
Note: the current patch includes no doc changes. I'd figure I'd wait to do that after this patch or another gains some traction.
Attachment
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
2016-07-08 0:13 GMT+02:00 Peter Geoghegan <pg@heroku.com>:
+1
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.
+1
Pavel
--
Peter Geoghegan
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
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
2016-07-09 18:59 GMT+02:00 Tom Lane <tgl@sss.pgh.pa.us>:
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?
\pset is good idea
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".
the value without units and without leading zeroes is not clear
Regards
Pavel
regards, tom lane
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
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
On Sat, Jul 9, 2016 at 3:35 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
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
I thought about a pset option as well, and I'd be fine with that, and I don't think it'd be any harder to do it that way.
As for the leading zeros, I was following the format of the namesake interval, adjusting for psql's existing max-3 decimal points on the milliseconds.
# select INTERVAL '1 hours 2 minutes 3 seconds 4.567 milliseconds';
interval
-----------------
01:02:03.004567
# select INTERVAL '112345689 milliseconds';
interval
--------------
31:12:25.689
# select INTERVAL '1123456890 milliseconds';
interval
--------------
312:04:16.89
I'm not wild about the leading zero either, but I see where it's needed for context absent d/h/m/s units, and I had concerns about internationalization issues with unit abbreviations.
A quick googling of "iso time duration format" yielded more heat than light. My one takeaway was that they require the leading zeros.
So what's everybody think of this?:
Keep \timing as-is.
Add \pset timing_format (or a better name, please suggest one), which can have at least some of these options:
- milliseconds - this would be the default value with current behavior, and an unset pset would assume this value.
- seconds - current ms value / 1000 and re-labeld s- minutes - current ms value / 60000 and re-labeled m- interval - follows the output format that we already use for INTERVAL types.- short - just like "interval" but trimming leading zeros and places. Precision is kept at .xxx ms for context- pretty - 4d, 3h, 2m, 11s, 45.678ms
The actual act of printing the timing value only happens in two places, so replacing each with a single function is trivial.
On Sat, Jul 9, 2016 at 4:00 PM, Andrew Gierth <andrew@tao11.riddles.org.uk> 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)
That'd be fine too, it's not like we're doing anything with the rest of that line.
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 Mon, Jul 11, 2016 at 8:35 AM, Peter Eisentraut <peter.eisentraut@2ndquadrant.com> wrote:
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
If the query took less than a second, timing display is unchanged.
Otherwise, print the ms time, followed by a more human readable form accurate to 0.001s.
# select 1; select pg_sleep(1); select pg_sleep(71); select pg_sleep (3601); select pg_sleep(24*3601);?column?----------1(1 row)Time: 1.575 mspg_sleep----------(1 row)Time: 1002.568 ms (1.003s)pg_sleep----------(1 row)Time: 71041.022 ms (1m 11.041s)pg_sleep----------(1 row)Time: 3601083.544 ms (1h 0m 1.084s)pg_sleep----------(1 row)Time: 86424018.416 ms (1d 0h 0m 24.018s)
As-is, there isn't much that could be done for regression or documentation changes, so I'll just leave this here.
Attachment
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.
On Wed, Aug 24, 2016 at 10:36 PM, Gerdan Santos <gerdan@gmail.com> wrote:
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.
Thanks for reviewing! I'm not really sure how to proceed, so I'll try to summarize where it stands. Apologies if I mischaracterize/misattribute/misremember someone's position.
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:
1. keep the format exactly as is, ignoring locale issues
+ It's already done
+ It's already done
+ lightweight
+TomL believes there will be no confusion
+TomL believes there will be no confusion
- others disagree
2. we fish out the proper locale-specific abbreviations for days/hours/minutes/seconds
2. we fish out the proper locale-specific abbreviations for days/hours/minutes/seconds
+ no additional settings
+ locale stuff can't be that hard
- I've never dealt with it (American, surprise)
3. ignore locales and fall back to a left-trimmed DDD HH:MM:SS.mmm format
+ Easy to revert to that code
+ Easy to revert to that code
+ My original format and one PeterE advocated
- others disliked
- others disliked
4. we have a \pset that sets fixed scale (seconds, minutes, hours, days), sliding scale (what's displayed now), or interval
+ some flexibility with some easy config values
- still have the locale issue
- still have the locale issue
- likely will miss a format somebody wanted
4. The \pset option is a time format string like "%d %h:%m:%s".
4. The \pset option is a time format string like "%d %h:%m:%s".
+ maximum flexibility
+ sidesteps the locale issue by putting it in the user's hands
- those format strings are sometimes tough for users to grok
- ISO 8601 isn't much of a help as it doesn't handle milliseconds
- additional config variable
- documentation changes
- debate about what the default should be. GOTO 1.
I personally would be happy with any of these options, so I think we get some more feedback to see if a consensus emerges. It's a tiny patch and trivial to test, so we have time(ing) on our side.
I personally would be happy with any of these options, so I think we get some more feedback to see if a consensus emerges. It's a tiny patch and trivial to test, so we have time(ing) on our side.
OK. as I said just got confused if there was any way to disable. anyway the code is ok, does what it says and is well formatted.
--
I will change now!
So sorry, for my confused.
Thnks!
Em quinta-feira, 25 de agosto de 2016, Corey Huinker <corey.huinker@gmail.com> escreveu:
Em quinta-feira, 25 de agosto de 2016, Corey Huinker <corey.huinker@gmail.com> escreveu:
On Wed, Aug 24, 2016 at 10:36 PM, Gerdan Santos <gerdan@gmail.com> wrote: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.Thanks for reviewing! I'm not really sure how to proceed, so I'll try to summarize where it stands. Apologies if I mischaracterize/misattribute/misremember someone's position. 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:1. keep the format exactly as is, ignoring locale issues
+ It's already done+ lightweight
+TomL believes there will be no confusion- others disagree
2. we fish out the proper locale-specific abbreviations for days/hours/minutes/seconds+ no additional settings+ locale stuff can't be that hard- I've never dealt with it (American, surprise)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 disliked4. we have a \pset that sets fixed scale (seconds, minutes, hours, days), sliding scale (what's displayed now), or interval+ some flexibility with some easy config values
- still have the locale issue- likely will miss a format somebody wanted
4. The \pset option is a time format string like "%d %h:%m:%s".+ maximum flexibility+ sidesteps the locale issue by putting it in the user's hands- those format strings are sometimes tough for users to grok- ISO 8601 isn't much of a help as it doesn't handle milliseconds- additional config variable- documentation changes- debate about what the default should be. GOTO 1.
I personally would be happy with any of these options, so I think we get some more feedback to see if a consensus emerges. It's a tiny patch and trivial to test, so we have time(ing) on our side.
--
Gerdan Rezende dos Santos
PostgreSQL & EnterpriseDB Specialist, Support, Training & Services
+55 (61) 9645-1525
PostgreSQL & EnterpriseDB Specialist, Support, Training & Services
+55 (61) 9645-1525
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 */
On Thu, Sep 1, 2016 at 12:14 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
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
Some kind of units on the parenthetical format would be helpful. Glancing at several of these values it takes me a couple of seconds to decide what I'm reading.
Peter van Hardenberg
San Francisco, California
"Everything was beautiful, and nothing hurt."—Kurt Vonnegut
San Francisco, California
"Everything was beautiful, and nothing hurt."—Kurt Vonnegut
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
On Sun, Sep 4, 2016 at 7:05 PM, Jim Nasby <Jim.Nasby@bluetreble.com> wrote:
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?
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.
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.
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
... and it would probably greatly reduce the amount of mailing list traffic asking for version if nothing else.
That was the major reason for wanting it.
The second is that if an explain were posted to a forum like stackexchange, the reader wouldn't have to wonder what version produced the plan.
<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.
2016-09-08 13:10 GMT+02:00 Craig Ringer <craig.ringer@2ndquadrant.com>:
On 4 Sep. 2016 3:36 am, "Tom Lane" <tgl@sss.pgh.pa.us> wrote:
>> After further thought I concluded that not providing any labeling of
> days is a bad idea.Yeah. I think labeling days is definitely good. I'm glad you changed that.
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 human readability. I see the value of retaining full precision too, though, and don't feel strongly about it.
It should be hard to read without units. I know so now it is maybe late, but the current output is not too readable for me. I miss units - 10s, 1m20.5s, 1h 30m 5s
Regards
Pavel