Re: So why is EXPLAIN printing only *plan* time?

From: Josh Berkus <josh(at)agliodbs(dot)com>
To: Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us>, pgsql-hackers(at)postgreSQL(dot)org
Subject: Re: So why is EXPLAIN printing only *plan* time?
Date: 2014-04-27 21:48:27
Message-ID: 535D7B2B.2010007@agliodbs.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

Tom,

> I'd been a bit suspicious of the recent patch to add $SUBJECT
> without the other pre-execution components, but it just now
> occurred to me that there's at least one reason why this might
> be a significant omission: any delay caused by waiting to acquire
> locks on the query's tables will be spent in the parser.

Well, if I could have a pony, I would like the ability to break out
lockwait vs. other planning time. The two can be significantly
different, especially in cases where users are trying to pin down why a
particular query has a high degree of variance in response times.

> It's probably okay to omit raw parsing time (that is, flex+bison),
> even though profiling sometimes suggests that that's a nontrivial
> cost. It's completely predictable and more or less linear in the
> query string length, so there are not likely to be any surprises
> for users in that time.

Just because it's predictable doesn't mean that users expect it.
Frankly, I'd like to have raw parse time available so that I could show
users exactly how long it takes to process a query with an IN() list
1000 items long, as a demonstration of why they shouldn't do that.

> We've already got log_lock_waits.

That's not useful for interactive query debugging, especially since
log_lock_waits only returns lock waits which are longer than
deadlock_timeout.

> I'm not that eager to try to make
> EXPLAIN print the same info, and even if I was, it would be a large and
> invasive patch.

I understand that we're not getting that for 9.4, but I'd like to keep
it on the table in case someone wants to work on it in the future. It
would be a useful feature.

> The concern I had here was just that if an EXPLAIN does
> get delayed by parse-time lock waits, it'd be nice if the printed times
> added up to something approaching the observed runtime.

Yes, definitely. Maybe we should call it something other than "planning
time", so that when we have the ability to display each stage separately
in the future, we don't confuse people? Maybe "query setup time"?

--
Josh Berkus
PostgreSQL Experts Inc.
http://pgexperts.com

In response to

Browse pgsql-hackers by date

  From Date Subject
Next Message Tom Lane 2014-04-27 21:49:53 Re: Composite Datums containing toasted fields are a bad idea(?)
Previous Message Stephen Frost 2014-04-27 21:25:18 Re: So why is EXPLAIN printing only *plan* time?