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 <pryzby(at)telsasoft(dot)com> 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
>