Re: [WIP] showing index maintenance on EXPLAIN

On Wed, May 7, 2014 at 10:52 PM, Amit Kapila <amit(dot)kapila16(at)gmail(dot)com> wrote:
> On Thu, May 8, 2014 at 5:30 AM, Jaime Casanova <jaime(at)2ndquadrant(dot)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)

so i want to answer questions like, how much an index is hurting write
performance? once i know that i can look for alternative solutions.
In that vein, it was interesting to see how fastupdate affect
performance in a GIN index using gin_trgm_ops (5 times slower with
fastupdate=off)

(fastupdate=on) Index idx_ggin on t1: time=0.418 rows=1
(fastupdate=off) Index idx_ggin on t1: time=2.205 rows=1

this is not different to showing trigger time info, which we already do

--
Jaime Casanova www.2ndQuadrant.com
Professional PostgreSQL: Soporte 24x7 y capacitación
Phone: +593 4 5107566 Cell: +593 987171157