Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1ngs6B-0005I3-3w for pgsql-admin@arkaria.postgresql.org; Tue, 19 Apr 2022 17:57:11 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.92) (envelope-from ) id 1ngs6A-0004wi-0Z for pgsql-admin@arkaria.postgresql.org; Tue, 19 Apr 2022 17:57:10 +0000 Received: from makus.postgresql.org ([2001:4800:3e1:1::229]) by malur.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1ngs69-0004wB-Ar for pgsql-admin@lists.postgresql.org; Tue, 19 Apr 2022 17:57:09 +0000 Received: from mail-vs1-xe36.google.com ([2607:f8b0:4864:20::e36]) by makus.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_128_GCM_SHA256:128) (Exim 4.92) (envelope-from ) id 1ngs66-0007jj-H1 for pgsql-admin@lists.postgresql.org; Tue, 19 Apr 2022 17:57:08 +0000 Received: by mail-vs1-xe36.google.com with SMTP id i186so16391466vsc.9 for ; Tue, 19 Apr 2022 10:57:06 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20210112; h=mime-version:references:in-reply-to:from:date:message-id:subject:to :cc; bh=nVt3ZbfA5+qnJuXIFjm+ycBAB5tTIKxalYWEL/HRZ14=; b=BDKQdtyGm1n9eNbvsenrOJKNZ2TRGKnJl7uPQHc/Ex+r8w0NBfRgSdcpdqoyP0rw4Z yr0u/5MWwIgRzBt5in8/5X/zxQlEo9mxur7UpY8KiHJavrRnDXV77brhbFRKZsrpZl7c wV9fRHFanULVPxIH2vW1GsY/p1nLjTVpJtIWf7vhKSly0tDjHWlZHQCM/xWZPNIhmZVz bmER7KRgNxgKuvbJHHS+gvSBV74lqHKR7gsObq+ZOCA7f0o+QUh6FdEUH1IAJu081agL I/HxRzJbAfhP9frghPU4dKoccJpTM7ODi9lIK1VWxuk0aEswBg57grExUWRvX4W7tsTH uQHA== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=x-gm-message-state:mime-version:references:in-reply-to:from:date :message-id:subject:to:cc; bh=nVt3ZbfA5+qnJuXIFjm+ycBAB5tTIKxalYWEL/HRZ14=; b=KwjxEl0vqc2HaIccPd5W1m2TFdUNAbs8edwztjaTGd1D53Qrc+r7odzd9GQGBEvT+4 yVxwZDLDn6v9qu0qVjvxqH1igtA3Cazn87VZdPuGpRYpHF902POxGqctsfJO5VJZbu6I F15siJigsvmjR/hM0gBRL5+puRpBFpDSHNVtXEJ2f/1vsrWnOqBxiep7/zH4TWtni4Wm i0bbIQ85ydUt5FRMc4pQ2Mk4fBJgw/9gnIy1GJoHlE5iva1tvFnjxTfNCxACR2S9caBm WsFRFvIwlikiPD0l4usJ3Sus9q7YcDSC+39cY66WtHbu4xxSYe4cXGBcUzeKu1iNjceq Bi7g== X-Gm-Message-State: AOAM533UuLGcVKRFBGu0Pu083ZE//cHq5zX6g4gTJQOTFJMqEKMYlkmD Jy1vQa7T968+0qA3xJytFYDI6UeI/BoG7qfANv8= X-Google-Smtp-Source: ABdhPJzH/TkWPBkFQKgWmMGPuaqEmxtZf9+bN3cLuU7HohLTumUvIeuVjQO8G0LPtgVcZXqTSW6n44ia0HoSuWQmv5A= X-Received: by 2002:a67:f4d5:0:b0:32a:39b4:c483 with SMTP id s21-20020a67f4d5000000b0032a39b4c483mr4731942vsn.50.1650391025614; Tue, 19 Apr 2022 10:57:05 -0700 (PDT) MIME-Version: 1.0 References: In-Reply-To: From: Kenny Bachman Date: Tue, 19 Apr 2022 20:56:54 +0300 Message-ID: Subject: Re: PG Query Planner To: Gaurav Anand Cc: pgsql-admin@lists.postgresql.org Content-Type: multipart/alternative; boundary="000000000000d2849e05dd059a79" List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk --000000000000d2849e05dd059a79 Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable Hello, My query is : SELECT subs.id AS id1_109, scriber_id AS subs_109 FROM subscription subs LEFT OUTER JOIN offer offer1 ON subs.offer_id =3D offer1.id WHERE offer1.is_external_lifecycle_management =3D FALSE AND subs.job_next_process_time < '2022-04-19 09:25:25.535' AND subs.job_in_progress =3D FALSE ORDER BY subs.id ASC LIMIT 1 ; Gaurav Anand , 19 Nis 2022 Sal, 20:45 tarihinde =C5=9Funu yazd=C4=B1: > Looks like your Index has gone wrong, instead of 92355 records it is > scanning 8021769 rows which is why it is taking 6s. > > Share the sql too > > On Tue, 19 Apr 2022 at 11:07 PM, Kenny Bachman > wrote: > >> Hello, >> >> I wonder how the query planner works in postgresql. So, I have a query >> that takes 6 seconds with an index scan. However, the same query takes >> 0.1ms when I set disable index scan parameter. >> >> How do I get the planner to make the right decision? Also, I ran ANALYZE >> command many times. >> >> And I have an index on job_next_process_time column but did not use it >> by the planner. >> >> Limit (cost=3D0.56..29.04 rows=3D1 width=3D695) (actual >> time=3D6386.751..6386.753 rows=3D0 loops=3D1) >> -> Nested Loop (cost=3D0.56..692987.46 rows=3D24331 width=3D695) (a= ctual >> time=3D6386.749..6386.751 rows=3D0 loops=3D1) >> Join Filter: (subs.offer_id =3D offer1.id) >> -> Index Scan using subs_pkey on subscription subs >> (cost=3D0.56..572151.65 rows=3D8053633 width=3D695) (actual time=3D0.00= 8..5554.872 >> rows=3D8021769 loops=3D1) >> Filter: ((NOT job_in_progress) AND (job_next_process_time >> < '2022-04-19 09:25:25.535'::timestamp without time zone)) >> Rows Removed by Filter: 72039 >> -> Materialize (cost=3D0.00..31.31 rows=3D1 width=3D8) (actua= l >> time=3D0.000..0.000 rows=3D0 loops=3D8021769) >> -> Seq Scan on offer offer1 (cost=3D0.00..31.31 rows=3D= 1 >> width=3D8) (actual time=3D0.087..0.088 rows=3D0 loops=3D1) >> Filter: (NOT is_external_lifecycle_management) >> Rows Removed by Filter: 334 >> Planning Time: 1.335 ms >> Execution Time: 6386.792 ms >> >> *SET enable_indexscan =3D OFF;* >> >> Limit (cost=3D84760.55..84760.55 rows=3D1 width=3D695) (actual >> time=3D0.092..0.093 rows=3D0 loops=3D1) >> -> Sort (cost=3D84760.55..84822.63 rows=3D24832 width=3D695) (actua= l >> time=3D0.092..0.092 rows=3D0 loops=3D1) >> Sort Key: subs.id >> Sort Method: quicksort Memory: 25kB >> -> Nested Loop (cost=3D955.54..84636.39 rows=3D24832 width=3D= 695) >> (actual time=3D0.090..0.090 rows=3D0 loops=3D1) >> -> Seq Scan on offer offer1 (cost=3D0.00..31.31 rows=3D= 1 >> width=3D8) (actual time=3D0.089..0.089 rows=3D0 loops=3D1) >> Filter: (NOT is_external_lifecycle_management) >> Rows Removed by Filter: 334 >> -> Bitmap Heap Scan on subscription subs >> (cost=3D955.54..83681.53 rows=3D92355 width=3D695) (never executed) >> Recheck Cond: (offer_id =3D offer1.id) >> Filter: ((NOT job_in_progress) AND >> (job_next_process_time < '2022-04-19 09:25:25.535'::timestamp without ti= me >> zone)) >> -> Bitmap Index Scan on i_fk_subscription_offer >> (cost=3D0.00..932.45 rows=3D93029 width=3D0) (never executed) >> Index Cond: (offer_id =3D offer1.id) >> Planning Time: 0.266 ms >> Execution Time: 0.126 ms >> > -- > > Thanks. > > Regards, > Gaurav Anand > > [image: logo] > > This communication is confidential and subject to and governed by Saama= =E2=80=99s Electronic > Communications Disclaimer. > > > > --000000000000d2849e05dd059a79 Content-Type: text/html; charset="UTF-8" Content-Transfer-Encoding: quoted-printable
Hello,

My query is :

SELECT subs.id AS id1_109,
scribe= r_id AS subs_109
FROM subscription subs
LEFT OUTER JOIN offer offer1=
ON subs.offer_id =3D offer1.id
WH= ERE offer1.is_external_lifecycle_management =3D FALSE
AND subs.job_next= _process_time < '2022-04-19 09:25:25.535'
AND subs.job_in_pr= ogress =3D FALSE
ORDER BY subs.id ASC LIM= IT 1 ;


Gaurav Anand <gaurav.anand@saama.com>, 19 Nis 2022 Sal, 20:45 tarih= inde =C5=9Funu yazd=C4=B1:
Looks like your Index has g= one wrong, instead of 92355 records it is scanning =C2=A0=C2=A0 =C2=A08021769 rows which is why it is t= aking 6s.

Share the sql too

On Tue, 19 Apr 2022 at 11:07 PM, Kenny Bachman <= kenny.bachma= n17@gmail.com> wrote:
Hello,

I wonder how the qu= ery planner works in postgresql. So, I have a query that takes 6 seconds wi= th an index scan. However, the same query takes 0.1ms when I set disable in= dex scan parameter.

How do I get the=C2=A0planner = to make the right decision? Also, I ran ANALYZE command many times.

And I have an index on job_next_process_time=C2=A0 column= but did not use it by the planner.

Limit =C2=A0(c= ost=3D0.56..29.04 rows=3D1 width=3D695) (actual time=3D6386.751..6386.753 r= ows=3D0 loops=3D1)
=C2=A0 =C2=A0-> =C2=A0Nested Loop =C2=A0(cost=3D0.= 56..692987.46 rows=3D24331 width=3D695) (actual time=3D6386.749..6386.751 r= ows=3D0 loops=3D1)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0Join Filter: (subs.= offer_id =3D offer1.id)<= br>=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0-> =C2=A0Index Scan using subs_pkey= on subscription subs =C2=A0(cost=3D0.56..572151.65 rows=3D8053633 width=3D= 695) (actual time=3D0.008..5554.872 rows=3D8021769 loops=3D1)
=C2=A0 =C2= =A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0Filter: ((NOT job_in_progress)= AND (job_next_process_time < '2022-04-19 09:25:25.535'::timesta= mp without time zone))
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 = =C2=A0Rows Removed by Filter: 72039
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0-&= gt; =C2=A0Materialize =C2=A0(cost=3D0.00..31.31 rows=3D1 width=3D8) (actual= time=3D0.000..0.000 rows=3D0 loops=3D8021769)
=C2=A0 =C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0-> =C2=A0Seq Scan on offer offer1 =C2=A0(= cost=3D0.00..31.31 rows=3D1 width=3D8) (actual time=3D0.087..0.088 rows=3D0= loops=3D1)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A0Filter: (NOT is_external_lifecycle_management)
=C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0Rows R= emoved by Filter: 334
=C2=A0Planning Time: 1.335 ms
=C2=A0Execution T= ime: 6386.792 ms

SET enable_indexscan =3D O= FF;

=C2=A0 Limit =C2=A0(cost=3D84760.55..84760= .55 rows=3D1 width=3D695) (actual time=3D0.092..0.093 rows=3D0 loops=3D1)=C2=A0 =C2=A0-> =C2=A0Sort =C2=A0(cost=3D84760.55..84822.63 rows=3D248= 32 width=3D695) (actual time=3D0.092..0.092 rows=3D0 loops=3D1)
=C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0Sort Key: subs.id
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0Sort Method: quicks= ort =C2=A0Memory: 25kB
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0-> =C2=A0Nes= ted Loop =C2=A0(cost=3D955.54..84636.39 rows=3D24832 width=3D695) (actual t= ime=3D0.090..0.090 rows=3D0 loops=3D1)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A0 =C2=A0-> =C2=A0Seq Scan on offer offer1 =C2=A0(cost=3D= 0.00..31.31 rows=3D1 width=3D8) (actual time=3D0.089..0.089 rows=3D0 loops= =3D1)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2= =A0 =C2=A0Filter: (NOT is_external_lifecycle_management)
=C2=A0 =C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0Rows Removed = by Filter: 334
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0-&= gt; =C2=A0Bitmap Heap Scan on subscription subs =C2=A0(cost=3D955.54..83681= .53 rows=3D92355 width=3D695) (never executed)
=C2=A0 =C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0Recheck Cond: (offer_id= =3D offer1.id)
=C2= =A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0Fi= lter: ((NOT job_in_progress) AND (job_next_process_time < '2022-04-1= 9 09:25:25.535'::timestamp without time zone))
=C2=A0 =C2=A0 =C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0-> =C2=A0Bitmap I= ndex Scan on i_fk_subscription_offer =C2=A0(cost=3D0.00..932.45 rows=3D9302= 9 width=3D0) (never executed)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0Index Cond: (offer_i= d =3D offer1.id)
=C2= =A0Planning Time: 0.266 ms
=C2=A0Execution Time: 0.126 ms
--

Thanks.
Regards,
Gaurav Anand
<= /div>
3D"logo"

This communication is confidential and subject to and governed by=C2=A0Saama=E2=80=99s=C2=A0Electronic Communications Disclaimer.

=C2=A0

--000000000000d2849e05dd059a79--