Planning time in explain/explain analyze

Hi,

A user asked in -performance[1] if there is a way to measure the
planning time. Other than measuring it in the client I do not think
there is so I quickly hacked a patched which adds "Planning time" to the
outputs of EXPLAIN and EXPLAIN ANALYZE.

Is this something useful? I think it is, since plan time can become an
issue for complex queries.

A couple of questions about the path: Should the planning time be added
to both EXPLAIN and EXPLAIN ANALYZE? And is the output obvious enough?

The patch does not include any changes to documentation or tests. I will
fix that if people think this patch is useful.

$ EXPLAIN SELECT * FROM pg_stat_activity;
QUERY PLAN

--------------------------------------------------------------------------------------------------
Nested Loop (cost=1.15..2.69 rows=1 width=337)
-> Hash Join (cost=1.02..2.41 rows=1 width=273)
Hash Cond: (s.usesysid = u.oid)
-> Function Scan on pg_stat_get_activity s (cost=0.00..1.00
rows=100 width=209)
-> Hash (cost=1.01..1.01 rows=1 width=68)
-> Seq Scan on pg_authid u (cost=0.00..1.01 rows=1
width=68)
-> Index Scan using pg_database_oid_index on pg_database d
(cost=0.13..0.27 rows=1 width=68)
Index Cond: (oid = s.datid)
Planning time: 0.258 ms
(9 rows)

$ EXPLAIN ANALYZE SELECT * FROM pg_stat_activity;
QUERY
PLAN
--------------------------------------------------------------------------------------------------------------------------------------------
Nested Loop (cost=1.15..2.69 rows=1 width=337) (actual
time=0.094..0.096 rows=1 loops=1)
-> Hash Join (cost=1.02..2.41 rows=1 width=273) (actual
time=0.078..0.079 rows=1 loops=1)
Hash Cond: (s.usesysid = u.oid)
-> Function Scan on pg_stat_get_activity s (cost=0.00..1.00
rows=100 width=209) (actual time=0.053..0.053 rows=1 loops=1)
-> Hash (cost=1.01..1.01 rows=1 width=68) (actual
time=0.014..0.014 rows=1 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 1kB
-> Seq Scan on pg_authid u (cost=0.00..1.01 rows=1
width=68) (actual time=0.007..0.009 rows=1 loops=1)
-> Index Scan using pg_database_oid_index on pg_database d
(cost=0.13..0.27 rows=1 width=68) (actual time=0.009..0.010 rows=1 loops=1)
Index Cond: (oid = s.datid)
Planning time: 0.264 ms
Total runtime: 0.158 ms
(11 rows)

Links

1.
http://www.postgresql.org/message-id/CACfv+pKNEmbQyJPCqRGsVmc_HvRGAi3d_Ge893N8qbX+ymhodA@mail.gmail.com

--
Andreas Karlsson