Query execution time Vs Cost

From: Amarendra Konda <amar(dot)vijaya(at)gmail(dot)com>
To: pgsql-performance(at)lists(dot)postgresql(dot)org
Subject: Query execution time Vs Cost
Date: 2019-09-13 11:08:50
Message-ID: CAJNAD0=+N7_EAUjUucndnSrgsWXPXP+ScS+6XzcLVv5F=gaQCg@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

Hi,
As part of one query tuning, it was observed that query execution time was
more even though cost was decreased.

*Initial Query :* Nested Loop Left Join (cost=159.88..*38530.02* rows=1
width=8) (actual time=0.387..*40.766* rows=300 loops=1)

*Changed Query :* Nested Loop Anti Join (cost=171.66..*5961.96* rows=1
width=8) (actual time=0.921..*110.862* rows=300 loops=1)

May i know the reason behind in increase in response time, even though cost
was reduced by 6.4 times.

Detailed execution plans can be found below along with the queries

*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);

QUERY PLAN

---------------------------------------------------------------------------------------------------------------------------------------------------------------
Nested Loop Left Join (cost=159.88..38530.02 rows=1 width=8) (actual
time=0.387..40.766 rows=300 loops=1)
Filter: ((ad.deleted IS NULL) OR (ad.deleted = 0))
Buffers: shared hit=52138
-> Bitmap Heap Scan on konotor_user ku (cost=159.73..38383.64 rows=712
width=8) (actual time=0.383..40.221 rows=300 loops=1)
Recheck Cond: (((app_id = '12132818272260'::bigint) AND (user_type
= 1)) OR ((app_id = '12132818272260'::bigint) AND (user_type = 2)))
Filter: (NOT (SubPlan 1))
Rows Removed by Filter: 485
Heap Blocks: exact=729
Buffers: shared hit=51838
-> BitmapOr (cost=159.73..159.73 rows=1425 width=0) (actual
time=0.112..0.112 rows=0 loops=1)
Buffers: shared hit=11
-> Bitmap Index Scan on konotor_user_app_id_user_type_idx
(cost=0.00..88.42 rows=786 width=0) (actual time=0.009..0.009 rows=1
loops=1)
Index Cond: ((app_id = '12132818272260'::bigint) AND
(user_type = 1))
Buffers: shared hit=4
-> Bitmap Index Scan on konotor_user_app_id_user_type_idx
(cost=0.00..70.95 rows=639 width=0) (actual time=0.101..0.101 rows=784
loops=1)
Index Cond: ((app_id = '12132818272260'::bigint) AND
(user_type = 2))
Buffers: shared hit=7
SubPlan 1
-> Nested Loop (cost=0.57..45.28 rows=1 width=8) (actual
time=0.049..0.049 rows=1 loops=785)
Buffers: shared hit=51098
-> Index Scan using groups_app_id_group_id_idx on groups
(cost=0.28..20.33 rows=3 width=8) (actual time=0.002..0.014 rows=20
loops=785)
Index Cond: (app_id = ku.app_id)
Filter: (NOT deleted)
Rows Removed by Filter: 2
Buffers: shared hit=18888
-> 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
-> Index Scan using agent_details_user_id_idx on agent_details ad
(cost=0.15..0.19 rows=1 width=10) (actual time=0.001..0.001 rows=0
loops=300)
Index Cond: (ku.user_id = user_id)
Buffers: shared hit=300
Planning time: 0.493 ms
Execution time: 40.901 ms

*Changed Query *

=> explain(analyze,buffers,costs) SELECT ku.user_id FROM konotor_user ku
> LEFT OUTER JOIN agent_details ad ON ku.user_id = ad.user_id LEFT OUTER JOIN
> (SELECT gu.user_id
> FROM group_user gu INNER JOIN groups ON
> gu.group_id = groups.group_id WHERE app_id='12132818272260' AND
> groups.deleted = false)t ON t.user_id= ku.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 t.user_id is NULL;

QUERY PLAN

-----------------------------------------------------------------------------------------------------------------------------------------------------------------
Nested Loop Anti Join (cost=171.66..5961.96 rows=1 width=8) (actual
time=0.921..110.862 rows=300 loops=1)
Buffers: shared hit=47730
-> Hash Left Join (cost=171.10..5730.86 rows=1 width=8) (actual
time=0.435..2.201 rows=785 loops=1)
Hash Cond: (ku.user_id = ad.user_id)
Filter: ((ad.deleted IS NULL) OR (ad.deleted = 0))
Buffers: shared hit=743
-> Bitmap Heap Scan on konotor_user ku (cost=160.09..5714.50
rows=1424 width=8) (actual time=0.208..1.327 rows=785 loops=1)
Recheck Cond: (((app_id = '12132818272260'::bigint) AND
(user_type = 1)) OR ((app_id = '12132818272260'::bigint) AND (user_type =
2)))
Heap Blocks: exact=729
Buffers: shared hit=740
-> BitmapOr (cost=160.09..160.09 rows=1425 width=0)
(actual time=0.116..0.116 rows=0 loops=1)
Buffers: shared hit=11
-> Bitmap Index Scan on
konotor_user_app_id_user_type_idx (cost=0.00..88.42 rows=786 width=0)
(actual time=0.010..0.010 rows=1 loops=1)
Index Cond: ((app_id = '12132818272260'::bigint)
AND (user_type = 1))
Buffers: shared hit=4
-> Bitmap Index Scan on
konotor_user_app_id_user_type_idx (cost=0.00..70.95 rows=639 width=0)
(actual time=0.105..0.105 rows=784 loops=1)
Index Cond: ((app_id = '12132818272260'::bigint)
AND (user_type = 2))
Buffers: shared hit=7
-> Hash (cost=6.56..6.56 rows=356 width=10) (actual
time=0.220..0.220 rows=356 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 23kB
Buffers: shared hit=3
-> Seq Scan on agent_details ad (cost=0.00..6.56 rows=356
width=10) (actual time=0.003..0.101 rows=356 loops=1)
Buffers: shared hit=3
-> Nested Loop (cost=0.57..115.82 rows=1 width=8) (actual
time=0.138..0.138 rows=1 loops=785)
Buffers: shared hit=46987
-> 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
-> Index Scan using groups_pkey on groups (cost=0.28..0.34
rows=1 width=8) (actual time=0.002..0.002 rows=1 loops=486)
Index Cond: (group_id = gu.group_id)
Filter: ((NOT deleted) AND (app_id =
'12132818272260'::bigint))
Rows Removed by Filter: 0
Buffers: shared hit=1458
Planning time: 0.534 ms
Execution time: 110.999 ms
(36 rows)

*PostgreSQL version : PostgreSQL 9.6.2 on x86_64-pc-linux-gnu, compiled by
gcc (GCC) 4.8.3 20140911 (Red Hat 4.8.3-9), 64-bit*

Thanks in advance for your valuable time and inputs.

Regards, Amarendra

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Justin Pryzby 2019-09-13 23:06:15 Re: Query execution time Vs Cost
Previous Message Dinesh Somani 2019-09-12 16:25:39 Re: select distinct runs slow on pg 10.6