Re: Planning time in explain/explain analyze

Robert Haas <robertmhaas(at)gmail(dot)com> writes:
> On Thu, Jan 9, 2014 at 11:45 PM, Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us> wrote:
>> Uh, no, wasn't my suggestion. Doesn't that design imply measuring *every*
>> planning cycle, explain or no? I was thinking more of just putting the
>> timing calls into explain.c.

> The problem is that you really can't do it that way.
> ExplainOneQuery() is a good place to add the timing calls in general,
> but ExplainExecuteQuery() in prepare.c never calls it; it does
> GetCachedPlan(), which ultimately calls pg_plan_query() after about
> four levels of indirection, and then passes the resulting plan
> directly to ExplainOnePlan(). So if you only add timing calls to
> explain.c, you can't handle anything that goes through
> ExplainExecuteQuery(), which is confusingly in prepare.c rather than
> explain.c.

Yeah, the factoring between explain.c and prepare.c has never been very
nice. I'm not sure what would be a cleaner design offhand, but I suspect
there is one.

> One reasonably principled solution is to just give up on showing the
> plan time for prepared queries altogether.

That would work for me, especially given the lack of clarity about what
ought to be measured in that case.

> If we don't want to adopt
> that approach, then I think the right way to do this is to add a "bool
> timing" argument to pg_plan_query(). When set, pg_plan_query()
> measures the time before and after calling planner() and stores it in
> the PlannedStmt.

I don't find that to be exactly a "low footprint" change; it's dumping
an EXPLAIN concern all over a public API *and* a public data structure.
It might be roughly comparable in terms of number of lines in the patch,
but in terms of modularity and abstraction it's not comparable in the
least.

I'm for doing the measurement in ExplainOneQuery() and not printing
anything in code paths that don't go through there.

regards, tom lane