\timing interval

Started by Corey Huinkeralmost 10 years ago48 messageshackers
Jump to latest
#1Corey Huinker
corey.huinker@gmail.com

\timing is great.
\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 off
Timing is off.
# select pg_sleep(1);
pg_sleep
----------

(1 row)

# \timing
Timing is on.
# select pg_sleep(1);
pg_sleep
----------

(1 row)

Time: 1002.959 ms
*# \timing interval*
*Timing is interval.*
# select pg_sleep(1);
pg_sleep
----------

(1 row)

*Time: 00:00:01.003*
# \timing
Timing 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.

Attachments:

0001-psql-timing-interval.difftext/plain; charset=US-ASCII; name=0001-psql-timing-interval.diffDownload+82-18
In reply to: Corey Huinker (#1)
Re: \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

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

#3Pavel Stehule
pavel.stehule@gmail.com
In reply to: Peter Geoghegan (#2)
Re: \timing interval

2016-07-08 0:13 GMT+02:00 Peter Geoghegan <pg@heroku.com>:

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

Show quoted text

--
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

#4Peter Eisentraut
peter_e@gmx.net
In reply to: Corey Huinker (#1)
Re: \timing interval

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

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

#5Tom Lane
tgl@sss.pgh.pa.us
In reply to: Peter Eisentraut (#4)
Re: \timing interval

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

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

#6Bruce Momjian
bruce@momjian.us
In reply to: Tom Lane (#5)
Re: \timing interval

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

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

#7Pavel Stehule
pavel.stehule@gmail.com
In reply to: Tom Lane (#5)
Re: \timing interval

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

Show quoted text

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

#8Peter Eisentraut
peter_e@gmx.net
In reply to: Tom Lane (#5)
Re: \timing interval

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

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

#9Tom Lane
tgl@sss.pgh.pa.us
In reply to: Peter Eisentraut (#8)
Re: \timing interval

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

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

#10Andrew Gierth
andrew@tao11.riddles.org.uk
In reply to: Tom Lane (#9)
Re: \timing interval

"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)

?

--
Andrew (irc:RhodiumToad)

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

#11Tom Lane
tgl@sss.pgh.pa.us
In reply to: Andrew Gierth (#10)
Re: \timing interval

Andrew Gierth <andrew@tao11.riddles.org.uk> writes:

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

Hmm ... worksforme.

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

#12Corey Huinker
corey.huinker@gmail.com
In reply to: Tom Lane (#9)
Re: \timing interval

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.

#13Corey Huinker
corey.huinker@gmail.com
In reply to: Andrew Gierth (#10)
Re: \timing interval

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.

#14Alvaro Herrera
alvherre@2ndquadrant.com
In reply to: Andrew Gierth (#10)
Re: \timing interval

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

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

In reply to: Alvaro Herrera (#14)
Re: \timing interval

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

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

#16Gavin Flower
GavinFlower@archidevsys.co.nz
In reply to: Andrew Gierth (#10)
Re: \timing interval

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

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

#17Andrew Gierth
andrew@tao11.riddles.org.uk
In reply to: Gavin Flower (#16)
Re: \timing interval

"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.

--
Andrew (irc:RhodiumToad)

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

#18Gavin Flower
GavinFlower@archidevsys.co.nz
In reply to: Andrew Gierth (#17)
Re: \timing interval

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!

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

#19Peter Eisentraut
peter_e@gmx.net
In reply to: Andrew Gierth (#10)
Re: \timing interval

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

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

#20Corey Huinker
corey.huinker@gmail.com
In reply to: Peter Eisentraut (#19)
Re: \timing interval

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

Ok, here's what I came up with (with time to test it).

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 ms
pg_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.

Attachments:

0001-print-timing-verbose.difftext/plain; charset=US-ASCII; name=0001-print-timing-verbose.diffDownload+54-2
#21Peter Eisentraut
peter_e@gmx.net
In reply to: Corey Huinker (#20)
#22Tom Lane
tgl@sss.pgh.pa.us
In reply to: Peter Eisentraut (#21)
#23Stephen Frost
sfrost@snowman.net
In reply to: Tom Lane (#22)
#24Peter Eisentraut
peter_e@gmx.net
In reply to: Tom Lane (#22)
In reply to: Peter Eisentraut (#24)
In reply to: Gerdan Rezende dos Santos (#25)
#27Corey Huinker
corey.huinker@gmail.com
In reply to: Gerdan Rezende dos Santos (#26)
In reply to: Corey Huinker (#27)
In reply to: Gerdan Rezende dos Santos (#28)
#30Tom Lane
tgl@sss.pgh.pa.us
In reply to: Corey Huinker (#27)
#31Tom Lane
tgl@sss.pgh.pa.us
In reply to: Tom Lane (#30)
#32Corey Huinker
corey.huinker@gmail.com
In reply to: Tom Lane (#31)
#33Tom Lane
tgl@sss.pgh.pa.us
In reply to: Tom Lane (#31)
#34Tom Lane
tgl@sss.pgh.pa.us
In reply to: Corey Huinker (#32)
#35Corey Huinker
corey.huinker@gmail.com
In reply to: Tom Lane (#33)
#36Tom Lane
tgl@sss.pgh.pa.us
In reply to: Corey Huinker (#35)
#37Corey Huinker
corey.huinker@gmail.com
In reply to: Tom Lane (#36)
#38Tom Lane
tgl@sss.pgh.pa.us
In reply to: Corey Huinker (#37)
In reply to: Tom Lane (#38)
#40Tom Lane
tgl@sss.pgh.pa.us
In reply to: Peter van Hardenberg (#39)
#41Tom Lane
tgl@sss.pgh.pa.us
In reply to: Tom Lane (#38)
#42Jim Nasby
Jim.Nasby@BlueTreble.com
In reply to: Tom Lane (#41)
#43Corey Huinker
corey.huinker@gmail.com
In reply to: Jim Nasby (#42)
#44Tom Lane
tgl@sss.pgh.pa.us
In reply to: Corey Huinker (#43)
#45Jim Nasby
Jim.Nasby@BlueTreble.com
In reply to: Tom Lane (#44)
#46Corey Huinker
corey.huinker@gmail.com
In reply to: Jim Nasby (#45)
#47Craig Ringer
craig@2ndquadrant.com
In reply to: Tom Lane (#41)
#48Pavel Stehule
pavel.stehule@gmail.com
In reply to: Craig Ringer (#47)