log_planner_stats and prepared statements

Started by Bruce Momjianalmost 7 years ago3 messageshackers
Jump to latest
#1Bruce Momjian
bruce@momjian.us

I have found that log_planner_stats only outputs stats until the generic
plan is chosen. For example, if you run the following commands:

SET client_min_messages = 'log';
SET log_planner_stats = TRUE;

PREPARE e AS SELECT relkind FROM pg_class WHERE relname = $1 ORDER BY 1;

EXPLAIN ANALYZE VERBOSE EXECUTE e ('pg_class');
EXPLAIN ANALYZE VERBOSE EXECUTE e ('pg_class');
EXPLAIN ANALYZE VERBOSE EXECUTE e ('pg_class');
EXPLAIN ANALYZE VERBOSE EXECUTE e ('pg_class');
EXPLAIN ANALYZE VERBOSE EXECUTE e ('pg_class');
EXPLAIN ANALYZE VERBOSE EXECUTE e ('pg_class');
--> EXPLAIN ANALYZE VERBOSE EXECUTE e ('pg_class');

The last explain will _not_ show any log_planner_stats duration, though
it does show an EXPLAIN planning time:

Planning Time: 0.012 ms

It this expected behavior?

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

+ As you are, so once was I.  As I am, so you will be. +
+                      Ancient Roman grave inscription +
#2Tom Lane
tgl@sss.pgh.pa.us
In reply to: Bruce Momjian (#1)
Re: log_planner_stats and prepared statements

Bruce Momjian <bruce@momjian.us> writes:

I have found that log_planner_stats only outputs stats until the generic
plan is chosen. For example, if you run the following commands:

Uh, well, the planner doesn't get run after that point ...

regards, tom lane

#3Bruce Momjian
bruce@momjian.us
In reply to: Tom Lane (#2)
Re: log_planner_stats and prepared statements

On Wed, Apr 17, 2019 at 12:04:35AM -0400, Tom Lane wrote:

Bruce Momjian <bruce@momjian.us> writes:

I have found that log_planner_stats only outputs stats until the generic
plan is chosen. For example, if you run the following commands:

Uh, well, the planner doesn't get run after that point ...

Yes, that was my analysis too, but EXPLAIN still prints a planner line,
with a duration:

Planning Time: 0.674 ms
Planning Time: 0.240 ms
Planning Time: 0.186 ms
Planning Time: 0.158 ms
Planning Time: 0.159 ms
Planning Time: 0.169 ms
--> Planning Time: 0.012 ms

Is that consistent? I just don't know. What is that line measuring?

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

+ As you are, so once was I.  As I am, so you will be. +
+                      Ancient Roman grave inscription +