Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtp (Exim 4.80) (envelope-from ) id 1WpOd6-00066g-Ur for pgsql-performance@arkaria.postgresql.org; Tue, 27 May 2014 21:09:53 +0000 Received: from localhost ([127.0.0.1] helo=postgresql.org) by malur.postgresql.org with smtp (Exim 4.80) (envelope-from ) id 1WpOd6-00057V-EB for pgsql-performance@arkaria.postgresql.org; Tue, 27 May 2014 21:09:52 +0000 Received: from makus.postgresql.org ([2001:4800:1501:1::229]) by malur.postgresql.org with esmtps (TLS1.2:DHE_RSA_AES_256_CBC_SHA256:256) (Exim 4.80) (envelope-from ) id 1WpOd5-00057O-0B for pgsql-performance@postgresql.org; Tue, 27 May 2014 21:09:51 +0000 Received: from dub004-omc4s5.hotmail.com ([157.55.2.80]) by makus.postgresql.org with esmtp (Exim 4.80) (envelope-from ) id 1WpOd0-0007qF-KB for pgsql-performance@postgresql.org; Tue, 27 May 2014 21:09:49 +0000 Received: from DUB126-W47 ([157.55.2.72]) by DUB004-OMC4S5.hotmail.com with Microsoft SMTPSVC(7.5.7601.22678); Tue, 27 May 2014 14:09:44 -0700 X-TMN: [u/LLkSJCk5QXxkeof+QQNBuL7+T3Xqkz] X-Originating-Email: [grzegorz.olszewski@outlook.com] Message-ID: Content-Type: multipart/alternative; boundary="_779d6fd2-cb94-4e4e-8485-bfe14ad9be86_" From: Grzegorz Olszewski To: "pgsql-performance@postgresql.org" Subject: Planner doesn't take indexes into account Date: Tue, 27 May 2014 23:09:45 +0200 Importance: Normal MIME-Version: 1.0 X-OriginalArrivalTime: 27 May 2014 21:09:44.0932 (UTC) FILETIME=[FC045240:01CF79EF] X-Pg-Spam-Score: -1.9 (-) List-Archive: List-Help: List-ID: List-Owner: List-Post: List-Subscribe: List-Unsubscribe: X-Mailing-List: pgsql-performance Precedence: bulk Sender: pgsql-performance-owner@postgresql.org --_779d6fd2-cb94-4e4e-8485-bfe14ad9be86_ Content-Type: text/plain; charset="iso-8859-2" Content-Transfer-Encoding: quoted-printable Hi=2C I wonder why planner uses Seq Scan instead of Index Scan. Here is my table (partial): content.contents -------------------------+-----------------------------+-------------------= ---------------------------------------------- id | bigint | niepusty domy=B6ln= ie nextval('content.contents_id_seq'::regclass) version | integer | niepusty date_published | timestamp without time zone |=20 moderation_status | character varying(50) |=20 publication_status | character varying(30) |=20 And indexes (there are some other indexes too): "contents_id_pkey" PRIMARY KEY=2C btree (id) "contents_date_published_idx" btree (date_published) "contents_moderation_status_idx" btree (moderation_status) "contents_publication_status_idx" btree (publication_status) I tried also creating following indexes: "contents_date_published_publication_status_moderation_statu_idx" btree= (date_published=2C publication_status=2C moderation_status) "contents_publication_status_idx1" btree ((publication_status::text)) "contents_moderation_status_idx1" btree ((moderation_status::text)) Then for this query (genrated by Hibernate): explain (analyze=2C buffers) select count(*) as y0_ from content.contents t= his_ inner join content.content_categories cat1_ on this_.CONTENT_CATEGORY_= ID=3Dcat1_.ID where cat1_.name in ([...]) and this_.date_published<=3D'2014-05-26 12:23:31.557000 +02:00:00' and (this_.PUBLICATION_STATUS is null or this_.PUBLICATION_STATUS<>'DRAFT') and (this_.moderation_status is null or this_.moderation_status<>'DANGEROUS= ') and exists(select * from content.content_visibilities cv where cv.content_i= d =3D this_.ID and cv.user_group_id in (1=2C2))=3B Planner creates such plan: = QUERY PLAN = = =20 ---------------------------------------------------------------------------= ---------------------------------------------------------------------------= ---------------------------------------------------------------------------= --------------------------------------------- Hash Semi Join (cost=3D31706.84..106020.81 rows=3D21871 width=3D2076) (ac= tual time=3D1197.658..6012.406 rows=3D430218 loops=3D1) Hash Cond: (this_.id =3D cv.content_id) Buffers: shared hit=3D5 read=3D59031 written=3D3=2C temp read=3D47611 wr= itten=3D47549 -> Hash Join (cost=3D2.22..56618.11 rows=3D22881 width=3D2076) (actual= time=3D0.163..1977.304 rows=3D430221 loops=3D1) Hash Cond: (this_.content_category_id =3D cat1_.id) Buffers: shared hit=3D1 read=3D46829 written=3D1 -> Seq Scan on contents this_ (cost=3D0.00..54713.92 rows=3D4461= 76 width=3D2030) (actual time=3D0.048..915.724 rows=3D450517 loops=3D1) Filter: ((date_published <=3D '2014-05-26 12:23:31.557'::tim= estamp without time zone) AND ((publication_status IS NULL) OR ((publicatio= n_status)::text <> 'DRAFT'::text)) AND ((moderation_status IS NULL) OR ((mo= deration_status)::text <> 'DANGEROUS'::text))) Rows Removed by Filter: 50 Buffers: shared read=3D46829 written=3D1 -> Hash (cost=3D2.17..2.17 rows=3D4 width=3D46) (actual time=3D0= .089..0.089 rows=3D4 loops=3D1) Buckets: 1024 Batches: 1 Memory Usage: 1kB Buffers: shared hit=3D1 -> Seq Scan on content_categories cat1_ (cost=3D0.00..2.17= rows=3D4 width=3D46) (actual time=3D0.053..0.076 rows=3D4 loops=3D1) Filter: ((name)::text =3D ANY ('{przeglad-prasy/rp=2Cp= rzeglad-prasy/parkiet=2Ckomunikat-z-rynku-pap-emitent=2Ckomunikat-z-rynku-p= ap-depesze}'::text[])) Rows Removed by Filter: 74 Buffers: shared hit=3D1 -> Hash (cost=3D24435.09..24435.09 rows=3D443083 width=3D8) (actual ti= me=3D1197.146..1197.146 rows=3D447624 loops=3D1) Buckets: 4096 Batches: 32 Memory Usage: 560kB Buffers: shared hit=3D4 read=3D12202 written=3D2=2C temp written= =3D1467 -> Bitmap Heap Scan on content_visibilities cv (cost=3D7614.55..= 24435.09 rows=3D443083 width=3D8) (actual time=3D61.034..647.729 rows=3D447= 624 loops=3D1) Recheck Cond: (user_group_id =3D ANY ('{1=2C2}'::bigint[])) Buffers: shared hit=3D4 read=3D12202 written=3D2 -> Bitmap Index Scan on content_visibilities_user_group_id_= idx (cost=3D0.00..7503.78 rows=3D443083 width=3D0) (actual time=3D58.680..= 58.680 rows=3D447626 loops=3D1) Index Cond: (user_group_id =3D ANY ('{1=2C2}'::bigint[= ])) Buffers: shared hit=3D3 read=3D1226 Total runtime: 6364.689 ms (27 wierszy) The suspicious part is: -> Seq Scan on contents this_ (cost=3D0.00..54713.92 =0A= rows=3D446176 width=3D2030) (actual time=3D0.048..915.724 rows=3D450517 loo= ps=3D1) =0A= Filter: ((date_published <=3D '2014-05-26 12:23:31.557'::timestamp =0A= without time zone) AND ((publication_status IS NULL) OR =0A= ((publication_status)::text <> 'DRAFT'::text)) AND =0A= ((moderation_status IS NULL) OR ((moderation_status)::text <> =0A= 'DANGEROUS'::text))) I don't understand why planner doesn't use indexes. The problem is there ar= e about 0.5M rows satisfying condition (almost every row in the table). Cou= ld you please explain this behavior? I'm using PostgreSQL 9.2.8 on Ubuntu 12.04 LTS x86_64 Best regards=2C Grzegorz Olszewski = --_779d6fd2-cb94-4e4e-8485-bfe14ad9be86_ Content-Type: text/html; charset="iso-8859-2" Content-Transfer-Encoding: quoted-printable
Hi=2C

I wonder why planne= r uses Seq Scan instead of Index Scan.

Here is my table (partial):content.contents
-------------------------+---------------------------= --+-----------------------------------------------------------------
&nb= sp=3Bid =3B =3B =3B =3B =3B =3B =3B =3B&nbs= p=3B =3B =3B =3B =3B =3B =3B =3B =3B = =3B =3B =3B =3B | bigint =3B =3B =3B =3B = =3B =3B =3B =3B =3B =3B =3B =3B =3B =3B=  =3B =3B =3B =3B =3B =3B =3B | niepusty domy=B6= lnie nextval('content.contents_id_seq'::regclass)
 =3Bversion = =3B =3B =3B =3B =3B =3B =3B =3B =3B =3B=  =3B =3B =3B =3B =3B =3B | integer =3B =3B&= nbsp=3B =3B =3B =3B =3B =3B =3B =3B =3B&nbs= p=3B =3B =3B =3B =3B =3B =3B =3B =3B | niep= usty
 =3Bdate_published =3B =3B =3B =3B =3B = =3B =3B =3B =3B | timestamp without time zone |
 =3Bmod= eration_status =3B =3B =3B =3B =3B =3B | character = varying(50) =3B =3B =3B =3B =3B =3B |
 =3Bp= ublication_status =3B =3B =3B =3B =3B | character varyi= ng(30) =3B =3B =3B =3B =3B =3B |

And indexe= s (there are some other indexes too):
 =3B =3B =3B "contents= _id_pkey" PRIMARY KEY=2C btree (id)
 =3B =3B =3B "contents_d= ate_published_idx" btree (date_published)
 =3B =3B =3B "cont= ents_moderation_status_idx" btree (moderation_status)
 =3B =3B&n= bsp=3B "contents_publication_status_idx" btree (publication_status)

= I tried also creating following indexes:
 =3B =3B =3B "conte= nts_date_published_publication_status_moderation_statu_idx" btree (date_pub= lished=2C publication_status=2C moderation_status)
 =3B =3B = =3B "contents_publication_status_idx1" btree ((publication_status::text)) =3B =3B =3B "contents_moderation_status_idx1" btree ((modera= tion_status::text))

Then for this query (genrated by Hibernate):
= explain (analyze=2C buffers) select count(*) as y0_ from content.contents t= his_ inner join content.content_categories cat1_ on this_.CONTENT_CATEGORY_= ID=3Dcat1_.ID where cat1_.name in ([...])
and this_.date_published<=3B= =3D'2014-05-26 12:23:31.557000 +02:00:00'
and (this_.PUBLICATION_STATUS = is null or this_.PUBLICATION_STATUS<=3B>=3B'DRAFT')
and (this_.moder= ation_status is null or this_.moderation_status<=3B>=3B'DANGEROUS')
= and exists(select * from content.content_visibilities cv where cv.content_i= d =3D this_.ID and cv.user_group_id in (1=2C2))=3B

Planner creates s= uch plan:
 =3B =3B =3B =3B =3B =3B =3B = =3B =3B =3B =3B =3B =3B =3B =3B =3B =3B=  =3B =3B =3B =3B =3B =3B =3B =3B =3B&nb= sp=3B =3B =3B =3B =3B =3B =3B =3B =3B = =3B =3B =3B =3B =3B =3B =3B =3B =3B =3B=  =3B =3B =3B =3B =3B =3B =3B =3B =3B&nb= sp=3B =3B =3B =3B =3B =3B =3B =3B =3B = =3B =3B =3B =3B =3B =3B =3B =3B =3B =3B=  =3B =3B =3B =3B =3B =3B =3B =3B =3B&nb= sp=3B =3B =3B =3B =3B =3B =3B =3B =3B = =3B =3B =3B =3B =3B =3B =3B =3B =3B =3B=  =3B =3B =3B =3B =3B =3B =3B =3B =3B&nb= sp=3B =3B =3B =3B =3B =3B =3B =3B =3B = =3B =3B =3B =3B =3B =3B =3B =3B =3B =3B= QUERY PLAN =3B =3B =3B =3B =3B =3B =3B =3B=  =3B =3B =3B =3B =3B =3B =3B =3B =3B&nb= sp=3B =3B =3B =3B =3B =3B =3B =3B =3B = =3B =3B =3B =3B =3B =3B =3B =3B =3B =3B=  =3B =3B =3B =3B =3B =3B =3B =3B =3B&nb= sp=3B =3B =3B =3B =3B =3B =3B =3B =3B = =3B =3B =3B =3B =3B =3B =3B =3B =3B =3B=  =3B =3B =3B =3B =3B =3B =3B =3B =3B&nb= sp=3B =3B =3B =3B =3B =3B =3B =3B =3B = =3B =3B =3B =3B =3B =3B =3B =3B =3B =3B=  =3B =3B =3B =3B =3B =3B =3B =3B =3B&nb= sp=3B =3B =3B =3B =3B =3B =3B =3B =3B = =3B =3B =3B =3B =3B =3B =3B =3B =3B =3B=  =3B =3B =3B =3B =3B =3B =3B =3B =3B -------------------------------------------------------------------------= ---------------------------------------------------------------------------= ---------------------------------------------------------------------------= -----------------------------------------------
 =3BHash Semi Join&n= bsp=3B (cost=3D31706.84..106020.81 rows=3D21871 width=3D2076) (actual time= =3D1197.658..6012.406 rows=3D430218 loops=3D1)
 =3B =3B Hash Con= d: (this_.id =3D cv.content_id)
 =3B =3B Buffers: shared hit=3D5= read=3D59031 written=3D3=2C temp read=3D47611 written=3D47549
 =3B&= nbsp=3B ->=3B =3B Hash Join =3B (cost=3D2.22..56618.11 rows=3D228= 81 width=3D2076) (actual time=3D0.163..1977.304 rows=3D430221 loops=3D1) =3B =3B =3B =3B =3B =3B =3B =3B Hash Cond= : (this_.content_category_id =3D cat1_.id)
 =3B =3B =3B = =3B =3B =3B =3B =3B Buffers: shared hit=3D1 read=3D46829 wr= itten=3D1
 =3B =3B =3B =3B =3B =3B =3B = =3B ->=3B =3B Seq Scan on contents this_ =3B (cost=3D0.00..54713.= 92 rows=3D446176 width=3D2030) (actual time=3D0.048..915.724 rows=3D450517 = loops=3D1)
 =3B =3B =3B =3B =3B =3B =3B = =3B =3B =3B =3B =3B =3B =3B Filter: ((date_publishe= d <=3B=3D '2014-05-26 12:23:31.557'::timestamp without time zone) AND ((p= ublication_status IS NULL) OR ((publication_status)::text <=3B>=3B 'DRA= FT'::text)) AND ((moderation_status IS NULL) OR ((moderation_status)::text = <=3B>=3B 'DANGEROUS'::text)))
 =3B =3B =3B =3B = =3B =3B =3B =3B =3B =3B =3B =3B =3B =3B= Rows Removed by Filter: 50
 =3B =3B =3B =3B =3B&nbs= p=3B =3B =3B =3B =3B =3B =3B =3B =3B Buffer= s: shared read=3D46829 written=3D1
 =3B =3B =3B =3B = =3B =3B =3B =3B ->=3B =3B Hash =3B (cost=3D2.17..2.17= rows=3D4 width=3D46) (actual time=3D0.089..0.089 rows=3D4 loops=3D1)
&n= bsp=3B =3B =3B =3B =3B =3B =3B =3B =3B = =3B =3B =3B =3B =3B Buckets: 1024 =3B Batches: 1 = =3B Memory Usage: 1kB
 =3B =3B =3B =3B =3B =3B&n= bsp=3B =3B =3B =3B =3B =3B =3B =3B Buffers: sha= red hit=3D1
 =3B =3B =3B =3B =3B =3B =3B&nbs= p=3B =3B =3B =3B =3B =3B =3B ->=3B =3B Seq Sc= an on content_categories cat1_ =3B (cost=3D0.00..2.17 rows=3D4 width=3D= 46) (actual time=3D0.053..0.076 rows=3D4 loops=3D1)
 =3B =3B&nbs= p=3B =3B =3B =3B =3B =3B =3B =3B =3B = =3B =3B =3B =3B =3B =3B =3B =3B =3B Filter:= ((name)::text =3D ANY ('{przeglad-prasy/rp=2Cprzeglad-prasy/parkiet=2Ckomu= nikat-z-rynku-pap-emitent=2Ckomunikat-z-rynku-pap-depesze}'::text[]))
&n= bsp=3B =3B =3B =3B =3B =3B =3B =3B =3B = =3B =3B =3B =3B =3B =3B =3B =3B =3B =3B=  =3B Rows Removed by Filter: 74
 =3B =3B =3B =3B&nbs= p=3B =3B =3B =3B =3B =3B =3B =3B =3B = =3B =3B =3B =3B =3B =3B =3B Buffers: shared hit=3D1=
 =3B =3B ->=3B =3B Hash =3B (cost=3D24435.09..24435.0= 9 rows=3D443083 width=3D8) (actual time=3D1197.146..1197.146 rows=3D447624 = loops=3D1)
 =3B =3B =3B =3B =3B =3B =3B = =3B Buckets: 4096 =3B Batches: 32 =3B Memory Usage: 560kB
 = =3B =3B =3B =3B =3B =3B =3B =3B Buffers: shared= hit=3D4 read=3D12202 written=3D2=2C temp written=3D1467
 =3B = =3B =3B =3B =3B =3B =3B =3B ->=3B =3B Bitmap = Heap Scan on content_visibilities cv =3B (cost=3D7614.55..24435.09 rows= =3D443083 width=3D8) (actual time=3D61.034..647.729 rows=3D447624 loops=3D1= )
 =3B =3B =3B =3B =3B =3B =3B =3B = =3B =3B =3B =3B =3B =3B Recheck Cond: (user_group_id = =3D ANY ('{1=2C2}'::bigint[]))
 =3B =3B =3B =3B =3B&= nbsp=3B =3B =3B =3B =3B =3B =3B =3B =3B Buf= fers: shared hit=3D4 read=3D12202 written=3D2
 =3B =3B =3B&n= bsp=3B =3B =3B =3B =3B =3B =3B =3B =3B = =3B =3B ->=3B =3B Bitmap Index Scan on content_visibilities_user_= group_id_idx =3B (cost=3D0.00..7503.78 rows=3D443083 width=3D0) (actual= time=3D58.680..58.680 rows=3D447626 loops=3D1)
 =3B =3B =3B=  =3B =3B =3B =3B =3B =3B =3B =3B =3B&nb= sp=3B =3B =3B =3B =3B =3B =3B =3B Index Cond: (= user_group_id =3D ANY ('{1=2C2}'::bigint[]))
 =3B =3B =3B&nb= sp=3B =3B =3B =3B =3B =3B =3B =3B =3B = =3B =3B =3B =3B =3B =3B =3B =3B Buffers: shared= hit=3D3 read=3D1226
 =3BTotal runtime: 6364.689 ms
(27 wierszy)<= br>
The suspicious part is:
 =3B =3B =3B =3B =3B&= nbsp=3B =3B =3B ->=3B =3B Seq Scan on contents this_ =3B = (cost=3D0.00..54713.92 =0A= rows=3D446176 width=3D2030) (actual time=3D0.048..915.724 rows=3D450517 loo= ps=3D1)
 =3B =3B =3B =3B =3B =3B =3B =3B=  =3B =3B =3B =3B =3B =3B=0A= Filter: ((date_published <=3B=3D '2014-05-26 12:23:31.557'::timestamp = =0A= without time zone) AND ((publication_status IS NULL) OR =0A= ((publication_status)::text <=3B>=3B 'DRAFT'::text)) AND =0A= ((moderation_status IS NULL) OR ((moderation_status)::text <=3B>=3B =0A= 'DANGEROUS'::text)))

I don't understand why planner doesn't use inde= xes. The problem is there are about 0.5M rows satisfying condition (almost = every row in the table). Could you please explain this behavior?

I'm= using PostgreSQL 9.2.8 on Ubuntu 12.04 LTS x86_64

Best regards=2CGrzegorz Olszewski
= --_779d6fd2-cb94-4e4e-8485-bfe14ad9be86_--