Re: [WIP] showing index maintenance on EXPLAIN

On Thu, May 8, 2014 at 2:31 AM, Jaime Casanova <jaime@2ndquadrant.com> wrote:
> On Wed, May 7, 2014 at 10:52 PM, Amit Kapila <amit.kapila16@gmail.com> wrote:
>> On Thu, May 8, 2014 at 5:30 AM, Jaime Casanova <jaime@2ndquadrant.com> wrote:
>>> Hi,
>>>
>>> This patch implements $subject only when ANALYZE and VERBOSE are on.
>>> I made it that way because for years nobody seemed interested in this
>>> info (at least no one did it) so i decided that maybe is to much
>>> information for most people (actually btree indexes are normally very
>>> fast).
>>
>>
>> Why to capture only for Index Insert/Update and not for Read; is it
>> because Read will be always fast ot implementation complexity?
>>
>
> EXPLAIN ANALYZE already shows that on any SELECT that uses an index in
> some way. Or are you thinking on something else?
>
>> Why not similar timings for heap?
>>
>
> well "actual time" shows us total time of the operation so just
> deducting the time spent on triggers, indexes and planning seems like
> a way to get "heap modification time".
>
> yes, maybe we still need some additional data. for example, i could
> want to know how much time we spent extending a relation.
>
>> Why can't we print when only Analyze is used with Explain, the
>> execution time is printed with Analyze option?
>>
>
> i'm not sure the info is useful for everyone, i'm not opposed to show
> it all the time though
>
>> Could you please tell in what all kind of scenario's, do you expect it
>> to be useful?
>> One I could think is that if there are multiple indexes on a table and user
>> wants to find out if any particular index is consuming more time.
>>
>
> exactly my use case. consider this plan (we spent 78% of the time
> updating the index uniq_idx_on_text):
>
>    QUERY PLAN
> --------------------------------------------------------------------------------------------
>  Insert on public.t1 (actual time=0.540..0.540 rows=0 loops=1)
>    ->  Result (actual time=0.046..0.049 rows=1 loops=1)
>          Output: <some long data here>
>  Index uniq_idx_on_text on t1: time=0.421 rows=1
>  Index t1_pkey on t1: time=0.027 rows=1
>  Total runtime: 0.643 ms
> (6 rows)

I would have expected the information about index maintenance times to
be associated with the Insert node, not the plan overall.  IIUC, you
could have more than one such node if, for example, there are
writeable CTEs involved.

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