pgsql: Include planning time in EXPLAIN ANALYZE output.

On Wed, Jan 29, 2014 at 1:10 PM, Robert Haas <rhaas@postgresql.org> wrote:

Include planning time in EXPLAIN ANALYZE output.

Isn't it perhaps a little confusing that "Planning time" may well
exceed "Total runtime"? I'm aware that we aren't super clear on the
accounting here generally, as with pg_stat_statements, which doesn't
include planning time in total_time, while we aren't even explicit
about that in the documentation. But even still, seeing the two
side-by-side, with planning time > total runtime did give me pause.

--
Peter Geoghegan

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

Peter Geoghegan <pg@heroku.com> writes:

On Wed, Jan 29, 2014 at 1:10 PM, Robert Haas <rhaas@postgresql.org> wrote:

Include planning time in EXPLAIN ANALYZE output.

Isn't it perhaps a little confusing that "Planning time" may well
exceed "Total runtime"?

Perhaps s/Total runtime/Execution time/ ?

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 Sun, Feb 2, 2014 at 8:13 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:

Perhaps s/Total runtime/Execution time/ ?

+1

--
Peter Geoghegan

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

On 03/02/14 09:44, Peter Geoghegan wrote:

On Sun, Feb 2, 2014 at 8:13 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:

Perhaps s/Total runtime/Execution time/ ?

+1

If the planning was ever made into a parallel process, then 'elapsed
time' would be less than the 'processor time'. So what does 'Execution
time' mean?

Can I assume:
'Total runtime' is 'elapsed time'
and
'Execution time' is 'processor time'.

In a parallel implementation, one would likely want both.

Possible this is not an issue now, and I'm thinking to far ahead!

Cheers,
Gavin

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

Gavin Flower <GavinFlower@archidevsys.co.nz> writes:

Can I assume:
'Total runtime' is 'elapsed time'
and
'Execution time' is 'processor time'.

No. It's going to be elapsed time, either way.

In a parallel implementation, one would likely want both.

When and if we have that, we can argue about what to measure.

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 Sun, Feb 2, 2014 at 11:13 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:

Peter Geoghegan <pg@heroku.com> writes:

On Wed, Jan 29, 2014 at 1:10 PM, Robert Haas <rhaas@postgresql.org> wrote:

Include planning time in EXPLAIN ANALYZE output.

Isn't it perhaps a little confusing that "Planning time" may well
exceed "Total runtime"?

Perhaps s/Total runtime/Execution time/ ?

I'm not really feeling a compelling need to change that. We've been
displaying total runtime - described exactly that way - for many
releases and it's surely is confusing to the novice that the time
reported can be much less than the time reported by psql's \timing
option, usually because of planning time. But adding the planning
time to the output seems to me to make that better, not worse. If the
user can't figure out that runtime != planning time, I'm not sure
they'll be able to figure out execution time != planning time, either.

One of the reasons it's called "Total runtime", or so I've always
assumed, is because it's more inclusive than the time shown for the
root node of the plan tree. Specifically, it includes the time
required to fire triggers.

--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

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

On Mon, Feb 3, 2014 at 4:15 AM, Robert Haas <robertmhaas@gmail.com> wrote:

I'm not really feeling a compelling need to change that. We've been
displaying total runtime - described exactly that way - for many
releases and it's surely is confusing to the novice that the time
reported can be much less than the time reported by psql's \timing
option, usually because of planning time.

I think that has a lot more to do with network roundtrip time and
protocol/serialization overhead.

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

Peter Geoghegan <pg@heroku.com> writes:

On Mon, Feb 3, 2014 at 4:15 AM, Robert Haas <robertmhaas@gmail.com> wrote:

I'm not really feeling a compelling need to change that. We've been
displaying total runtime - described exactly that way - for many
releases and it's surely is confusing to the novice that the time
reported can be much less than the time reported by psql's \timing
option, usually because of planning time.

I think that has a lot more to do with network roundtrip time and
protocol/serialization overhead.

The problem I'm having with the way it stands now is that one would
reasonably expect that "Total time" is the total of all times counted
by EXPLAIN, including main plan execution time, trigger firing time,
and now planning time. Since it is not, any longer, a total, I think
renaming it would be a good idea. I'm not wedded to "execution time"
in particular, but I don't like "total".

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

* Tom Lane (tgl@sss.pgh.pa.us) wrote:

The problem I'm having with the way it stands now is that one would
reasonably expect that "Total time" is the total of all times counted
by EXPLAIN, including main plan execution time, trigger firing time,
and now planning time. Since it is not, any longer, a total, I think
renaming it would be a good idea. I'm not wedded to "execution time"
in particular, but I don't like "total".

Agreed.

Thanks,

Stephen

On Mon, Feb 3, 2014 at 07:13:46PM -0500, Stephen Frost wrote:

* Tom Lane (tgl@sss.pgh.pa.us) wrote:

The problem I'm having with the way it stands now is that one would
reasonably expect that "Total time" is the total of all times counted
by EXPLAIN, including main plan execution time, trigger firing time,
and now planning time. Since it is not, any longer, a total, I think
renaming it would be a good idea. I'm not wedded to "execution time"
in particular, but I don't like "total".

Agreed.

Where are we on this? I still see:

test=> EXPLAIN ANALYZE SELECT 1;
QUERY PLAN
------------------------------------------------------------------------------------
Result (cost=0.00..0.01 rows=1 width=0) (actual time=0.001..0.001 rows=1 loops=1)
Planning time: 0.009 ms
--> Total runtime: 0.009 ms
(3 rows)

--
Bruce Momjian <bruce@momjian.us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ Everyone has their own god. +

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

Bruce Momjian <bruce@momjian.us> writes:

Where are we on this? I still see:

test=> EXPLAIN ANALYZE SELECT 1;
QUERY PLAN
------------------------------------------------------------------------------------
Result (cost=0.00..0.01 rows=1 width=0) (actual time=0.001..0.001 rows=1 loops=1)
Planning time: 0.009 ms
--> Total runtime: 0.009 ms
(3 rows)

There seemed to be a clear majority of votes in favor of changing it to
say "Execution time". Robert was arguing for no change, but I don't think
that's tenable in view of the fact that the addition of the "Planning
time" line is already a change, and one that makes the old wording
confusing.

I'll go change it.

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

I found a bit confusing, when planning time is greater total time, so
+1 for execution time.

On Thu, Apr 17, 2014 at 3:35 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:

Bruce Momjian <bruce@momjian.us> writes:

Where are we on this? I still see:

test=> EXPLAIN ANALYZE SELECT 1;
QUERY PLAN
------------------------------------------------------------------------------------
Result (cost=0.00..0.01 rows=1 width=0) (actual time=0.001..0.001 rows=1 loops=1)
Planning time: 0.009 ms
--> Total runtime: 0.009 ms
(3 rows)

There seemed to be a clear majority of votes in favor of changing it to
say "Execution time". Robert was arguing for no change, but I don't think
that's tenable in view of the fact that the addition of the "Planning
time" line is already a change, and one that makes the old wording
confusing.

I'll go change it.

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

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

On 04/17/2014 01:35 AM, Tom Lane wrote:

I'll go change it.

Thanks for fixing this. The new name "Execution time" is much clearer.

--
Andreas Karlsson

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