Re: Query execution time Vs Cost

Hi Justin,

Thanks a lot for the detailed analysis and explanation for slowness that
was seen. Pointed noted related to the vacuum tuning option.

Regards, Amarendra


On Sat, Sep 14, 2019 at 4:36 AM Justin Pryzby <[email protected]> wrote:

> On Fri, Sep 13, 2019 at 04:38:50PM +0530, Amarendra Konda wrote:
> > As part of one query tuning, it was observed that query execution time
> was
> > more even though cost was decreased.
>
> ..
>
> > May i know the reason behind in increase in response time, even though
> cost
> > was reduced by 6.4 times.
>
> The "cost" is postgres model for how expensive a plan will be, based on
> table
> statistics, and parameters like seq/rand_page_cost, etc.  It's an imperfect
> model and not exact.
>
> > *Initial Query*
> >
> > => explain(analyze,buffers,costs)  SELECT    ku.user_id
> > >     FROM      konotor_user ku
> > >  LEFT JOIN agent_details ad
> > >  ON        ku.user_id = ad.user_id
> > >  WHERE     ku.app_id = '12132818272260'
> > >  AND       (ku.user_type = 1 OR ku.user_type = 2)
> > >  AND       (ad.deleted isnull OR ad.deleted = 0)
> > >  AND       ku.user_id NOT IN (
> > >                        SELECT     gu.user_id
> > >                        FROM       group_user gu
> > >                        INNER JOIN groups
> > >                        ON         gu.group_id = groups.group_id
> > >                        AND        app_id = ku.app_id
> > >                        WHERE      gu.user_id = ku.user_id
> > >                        AND        groups.app_id = ku.app_id
> > >                        AND        groups.deleted = false);
>
> It seems to me the major difference is in group_user JOIN groups.
>
> In the fast query, it did
> >                  ->  Index Only Scan using uk_groupid_userid on
> group_user gu  (cost=0.29..8.30 rows=1 width=16) (actual time=0.001..0.001
> rows=0 loops=15832)
> >                        Index Cond: ((group_id = groups.group_id) AND
> (user_id = ku.user_id))
> >                        Heap Fetches: 455
> >                        Buffers: shared hit=32210
>
> => 15832*0.001sec = 15ms
>
> In the slow query it did:
> >          ->  Index Only Scan using uk_groupid_userid on group_user gu
> (cost=0.29..115.12 rows=2 width=16) (actual time=0.135..0.135 rows=1
> loops=785)
> >                Index Cond: (user_id = ku.user_id)
> >                Heap Fetches: 456
> >                Buffers: shared hit=45529
>
> => 785*0.115sec = 90ms
>
> It scanned using non-leading columns of index, so it took 6x longer even
> though
> it did 20x fewer loops.  Also it did 456 heap fetches (which were probably
> nonsequential).  Vacuuming the table will probably help; if so, you should
> consider setting parameter to encourage more frequent autovacuums:
> | ALTER TABLE group_user SET (AUTOVACUUM_VACUUM_SCALE_FACTOR=0.005);
>
> Justin
>