Re: Specific query taking time to process

--0000000000001ec68b0599787519
Content-Type: text/plain; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

On Wed, Dec 11, 2019 at 5:21 PM Fahiz Mohamed <[email protected]> wrote:

> There is a slight different in both instance=E2=80=99s data. Inastanbce 1=
 contains
> latest data and instance 2 consists of data which is 3 weeks older than
> instance 1.
>

In knowing where to look for differences in performance, there is a big
difference between them being identical, and being generally similar, but
not identical.


> I hope the above data difference can make a drastic difference. Please
> correct me if I am wrong.
>

They are similar in scale, but we know there is a big difference in
distribution of some values.  For example, we still know the slow plan has
4697 rows in aspect_1 where qname_id =3D 251, while the other plan has 85
rows in aspect_1 meeting that same criterion. That is a big difference, and
it is real difference in the data, not just a difference in planning or
estimation.  Is this difference driving the difference in plan choice?
Probably not (plan choice is driven by estimated rows, not actual, and
estimates are quite similar), but it does demonstrate the data is quite
different between the two systems when you look under the hood.  It is
likely that there are other, similar differences in the distribution of
particular values which is driving the difference in plans.  It is just
that we can't see those differences, because the EXPLAIN ANALYZE only
reports on the plan it ran, not other plans it could have ran but didn't.

Your query is now using the index named  idx_alf_node_tqn in a way which is
equally unproductive as the previous use of  idx_alf_node_mdq was.  It
looks like they have the same columns, just in a different order.  My
previous advice to try  "type_qname_id+0 =3D 240" should still apply.

If you can't get that to work, then another avenue is to run "explain
(analyze, buffers) select count(*) from alf_node where (type_qname_id =3D
240) AND (store_id =3D 6)" on both instances.




> I did execute vacuum manually and I noticed the below in the output
>
> "INFO: vacuuming "public.alf_node_aspects"
> INFO: "alf_node_aspects": found 0 removable, 150264654 nonremovable row
> versions in 812242 pages
> DETAIL: 0 dead row versions cannot be removed yet.
> CPU 13.53s/33.35u sec elapsed 77.88 sec.
>

I'm not really sure what that means.  I certainly would not have expected 0
removable. There should have been some prior output, something like:

INFO:  scanned index "fk_alf_nasp_qn" to remove 500000 row versions

It could be that autovacuum had already gotten around to vacuuming after
your initial email but before you did the above, meaning there was not much
for your manual to do.

But you can see that the vacuum did have an effect, by comparing these
lines (despite them finding about same number of rows)

Heap Blocks: exact=3D40765

Heap Blocks: exact=3D1774

It wasn't all that large of an effect in this case, but it is still
something worth fixing.

Cheers,

Jeff

--0000000000001ec68b0599787519
Content-Type: text/html; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

<div dir=3D"ltr"><div dir=3D"ltr">On Wed, Dec 11, 2019 at 5:21 PM Fahiz Moh=
amed &lt;<a href=3D"mailto:[email protected]">[email protected]</a>&gt; wro=
te:<br></div><div class=3D"gmail_quote"><blockquote class=3D"gmail_quote" s=
tyle=3D"margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);pad=
ding-left:1ex">



<div>
<div name=3D"messageBodySection">
<div dir=3D"auto">There is a slight different in both instance=E2=80=99s da=
ta. Inastanbce 1 contains latest data and instance 2 consists of data which=
 is 3 weeks older than instance 1.=C2=A0</div></div></div></blockquote><div=
><br></div><div>In knowing where to look for differences in performance, th=
ere is a big difference between them being identical, and being generally s=
imilar, but not identical.</div><div><br></div><blockquote class=3D"gmail_q=
uote" style=3D"margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,2=
04);padding-left:1ex"><div>
<div name=3D"messageSignatureSection"><br>
<div dir=3D"auto">I hope the above data difference can make a drastic diffe=
rence. Please correct me if I am wrong.</div></div></div></blockquote><div>=
<br></div><div>They are similar in scale, but we know there is a big differ=
ence in distribution of some values.=C2=A0 For example, we still know the s=
low plan has 4697 rows in aspect_1 where qname_id =3D 251, while the other =
plan has 85 rows in aspect_1 meeting that same criterion. That is a big dif=
ference, and it is real difference in the data, not just a difference in pl=
anning or estimation.=C2=A0 Is this difference=C2=A0driving the difference =
in plan choice?=C2=A0 Probably not (plan choice is driven by estimated rows=
, not actual, and estimates are quite similar), but it does demonstrate the=
 data is quite different between the two systems when you look under the ho=
od.=C2=A0 It is likely that there are other, similar differences in the dis=
tribution of particular values which is driving the difference in plans.=C2=
=A0 It is just that we can&#39;t see those differences, because the EXPLAIN=
 ANALYZE only reports on the plan it ran, not other plans it could have ran=
 but didn&#39;t.</div><div><br></div><div>Your query is now using the index=
 named=C2=A0<span style=3D"color:rgb(0,0,0)">=C2=A0</span><span style=3D"co=
lor:rgb(0,0,0)">idx_alf_node_tqn in a way which is equally unproductive as =
the previous use of=C2=A0</span><span style=3D"color:rgb(0,0,0)">=C2=A0idx_=
alf_node_mdq was.=C2=A0 It looks like they have the same columns, just in a=
 different order.=C2=A0 My previous advice to try=C2=A0</span><span style=
=3D"color:rgb(0,0,0)">=C2=A0</span><span style=3D"color:rgb(0,0,0)">&quot;t=
ype_qname_id+0 =3D 240&quot; should still apply.</span></div><div><span sty=
le=3D"color:rgb(0,0,0)"><br></span></div><div><span style=3D"color:rgb(0,0,=
0)">If you can&#39;t get that to work, then another avenue is to run &quot;=
explain (analyze, buffers) select count(*) from=C2=A0</span>alf_node where =
(type_qname_id =3D 240) AND (store_id =3D 6)&quot; on both instances.</div>=
<div><span style=3D"color:rgb(0,0,0)"><br></span></div><div><br></div><div>=
<br></div><blockquote class=3D"gmail_quote" style=3D"margin:0px 0px 0px 0.8=
ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div><div name=
=3D"messageSignatureSection"><div dir=3D"auto"><br></div>
<div dir=3D"auto">I did execute vacuum manually and I noticed the below in =
the output</div>
<div dir=3D"auto"><br></div>
<div dir=3D"auto">&quot;INFO: vacuuming &quot;public.alf_node_aspects&quot;=
</div>
<div dir=3D"auto">INFO: &quot;alf_node_aspects&quot;: found 0 removable, 15=
0264654 nonremovable row versions in 812242 pages</div>
<div dir=3D"auto">DETAIL: 0 dead row versions cannot be removed yet.</div>
<div dir=3D"auto">CPU 13.53s/33.35u sec elapsed 77.88 sec.</div></div></div=
></blockquote><div><br></div><div><span style=3D"color:rgb(0,0,0)">I&#39;m =
not really sure what that means.=C2=A0 I certainly would not have expected =
0 removable. There should have been some prior output, something like:</spa=
n></div><div><span style=3D"color:rgb(0,0,0)"><br></span></div><div>INFO: =
=C2=A0scanned index &quot;fk_alf_nasp_qn&quot; to remove 500000 row version=
s<span style=3D"color:rgb(0,0,0)"></span>=C2=A0=C2=A0<br></div><div>=C2=A0<=
/div><div>It could be that autovacuum had already gotten around to vacuumin=
g after your initial email but before you did the above, meaning there was =
not much for your manual to do.</div><div><br></div><div>But you can see th=
at the vacuum did have an effect, by comparing these lines (despite them fi=
nding about same number of rows)</div><div><br></div><div>Heap Blocks: exac=
t=3D40765<br></div><div><span style=3D"color:rgb(0,0,0)"><br></span></div><=
div><span style=3D"color:rgb(0,0,0)">Heap Blocks: exact=3D1774</span>=C2=A0=
<br></div><div><br></div><div>It wasn&#39;t all that large of an effect in =
this case, but it is still something worth fixing.</div><div><br></div><div=
>Cheers,</div><div><br></div><div>Jeff</div></div></div>

--0000000000001ec68b0599787519--