Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA1:256) (Exim 4.89) (envelope-from ) id 1ix6vz-0000Dl-3y for pgsql-performance@arkaria.postgresql.org; Thu, 30 Jan 2020 10:20:27 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.89) (envelope-from ) id 1ix6vw-0007dr-Gv for pgsql-performance@arkaria.postgresql.org; Thu, 30 Jan 2020 10:20:24 +0000 Received: from magus.postgresql.org ([2a02:c0:301:0:ffff::29]) by malur.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA1:256) (Exim 4.89) (envelope-from ) id 1ix6Nb-0005xI-QM for pgsql-performance@lists.postgresql.org; Thu, 30 Jan 2020 09:44:55 +0000 Received: from mail-wr1-x42a.google.com ([2a00:1450:4864:20::42a]) by magus.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_128_GCM_SHA256:128) (Exim 4.92) (envelope-from ) id 1ix6NU-0002NC-Jb for pgsql-performance@lists.postgresql.org; Thu, 30 Jan 2020 09:44:55 +0000 Received: by mail-wr1-x42a.google.com with SMTP id m16so3140703wrx.11 for ; Thu, 30 Jan 2020 01:44:48 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=netwidz-com.20150623.gappssmtp.com; s=20150623; h=date:from:to:cc:message-id:in-reply-to:references:subject :mime-version; bh=zYHwdlkUysx0umP7TXaxwHb1BN/XnDraFYR61zXxEQY=; b=BXtLFy2WADLdkfNJeDlcBilrii1RZEA/SRAu+8envekTy3npg7cnTMekSgJmYM4Uf9 4K/U56ewteGeqCu5vtif+aq+rNlv5izK4YKAaziQsGxcWeALWQiM73rfvBsUJHKUE9os YolBqugJoJEK7CkYBVAPqHboDE+NVFZS7oWD+fCt06xh9AxxTluI1u8w5kIwqAgbGzSG in2kUr2hhZ9ixwL0dLqIKIY9YUfQP0F3b2v/+QOgYrXnF2Qhod7NNC5BwzSJnikfGafl cBMdoAT6EV9dJJ8OLPNA/EGox5bG9IepegrVLU6Ds1XA7BxHNGUt7i/avUDU9GuY5A/a x2+w== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:date:from:to:cc:message-id:in-reply-to :references:subject:mime-version; bh=zYHwdlkUysx0umP7TXaxwHb1BN/XnDraFYR61zXxEQY=; b=QrQHO5QQZXMa9d9+Ho4SWm4Yf73K/zGvrcXJv3bjcsuPZzBDOhxmikpDMNdbKMW71z TuhlxmAZ29eVfEx5BIlwxuwI6o50WNpnv7EL70BGCt2lECL7ljVMI43B+l9FcbElN8gs 9Cpcl7SG9vW3hZNdNSgBkjwevhySJpqjKShDTl7K/ckwi6kUfAIb+BEN1lrBZl8wLGoB 0hl2b7cF44SuMwumt9olmPFLjParUubEuiYrpL+MPX/ok8nyMpKv+CFXm+HDRTH8Y2m1 V6hY1x0qRx/w6dLh5ZPf8ZI09hkPHxQRhT7sWCgTOHit4Alg11bGXmqzwmAbYPRx2QC0 85SA== X-Gm-Message-State: APjAAAV2zPyfofehrel6MULvVPrA6MkhOCAlBrf2Eh6cw9AKJRKwY8eY m4vNShGJktylv3Z9iN80jpIlbA== X-Google-Smtp-Source: APXvYqxdIVEJsdrG7kswhps1V/lc+OqoH3YQL/zzmUAb/L+FMKQJH59sPL769/C8Bx60C9UJp1e9zA== X-Received: by 2002:a5d:67c7:: with SMTP id n7mr4320303wrw.319.1580377487365; Thu, 30 Jan 2020 01:44:47 -0800 (PST) Received: from [192.168.9.23] ([217.33.148.210]) by smtp.gmail.com with ESMTPSA id c17sm6346069wrr.87.2020.01.30.01.44.46 (version=TLS1_2 cipher=ECDHE-RSA-AES128-GCM-SHA256 bits=128/128); Thu, 30 Jan 2020 01:44:46 -0800 (PST) Date: Thu, 30 Jan 2020 09:44:41 +0000 From: Fahiz Mohamed To: Jeff Janes , Duncan Whitham Cc: Michael Lewis , Pgsql Performance Message-ID: <53622ec9-bf97-4066-ac52-9b8e5698c3ea@Spark> In-Reply-To: References: <6bd9b9b7-f127-4e48-a456-b3bbcfb741ab@Spark> <10b65cf1-a079-4aa3-92f0-ca21375da683@Spark> <7cb455c5-dd6a-4f33-bdbe-92033f7986e2@Spark> Subject: Re: Specific query taking time to process X-Readdle-Message-ID: 53622ec9-bf97-4066-ac52-9b8e5698c3ea@Spark MIME-Version: 1.0 Content-Type: multipart/alternative; boundary="5e32a58e_71f32454_16c" List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Precedence: bulk --5e32a58e_71f32454_16c Content-Type: text/plain; charset="utf-8" Content-Transfer-Encoding: quoted-printable Content-Disposition: inline Hi Jeff, Thank you for your email, Sorry I couldn=E2=80=99t respond back to you. I= am not working on this project at the moment. I have copied one of my co= lleague who working on this. He has some progress on this, he will update= the email thread with those findings Appreciate your support. Thank you, =46ahiz On 12 Dec 2019, 02:25 +0000, Jeff Janes , wrote: > On Wed, Dec 11, 2019 at 5:21 PM =46ahiz Mohamed w= rote: > > > There is a slight different in both instance=E2=80=99s data. Inasta= nbce 1 contains latest data and instance 2 consists of data which is 3 we= eks older than instance 1. > > > > In knowing where to look for differences in performance, there is a b= ig difference between them being identical, and being generally similar, = but not identical. > > > > > > > > I hope the above data difference can make a drastic difference. Ple= ase correct me if I am wrong. > > > > They are similar in scale, but we know there is a big difference in d= istribution of some values.=C2=A0 =46or example, we still know the slow p= lan has 4697 rows in aspect=5F1 where qname=5Fid =3D 251, while the other= plan has 85 rows in aspect=5F1 meeting that same criterion. That is a bi= g difference, and it is real difference in the data, not just a differenc= e in planning or estimation.=C2=A0 Is this difference=C2=A0driving the di= fference in plan choice=3F=C2=A0 Probably not (plan choice is driven by e= stimated 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.=C2=A0 It is likely that there are other, similar dif= ferences in the distribution of particular values which is driving the di= fference in plans.=C2=A0 It is just that we can't see those differences, = because the EXPLAIN ANALYZE only reports on the plan it ran, not other pl= ans it could have ran but didn't. > > > > Your query is now using the index named=C2=A0=C2=A0idx=5Falf=5Fnode=5F= tqn in a way which is equally unproductive as the previous use of=C2=A0=C2= =A0idx=5Falf=5Fnode=5Fmdq was.=C2=A0 It looks like they have the same col= umns, just in a different order.=C2=A0 My previous advice to try=C2=A0=C2= =A0=22type=5Fqname=5Fid+0 =3D 240=22 should still apply. > > > > If you can't get that to work, then another avenue is to run =22expla= in (analyze, buffers) select count(*) from=C2=A0alf=5Fnode where (type=5F= qname=5Fid =3D 240) AND (store=5Fid =3D 6)=22 on both instances. > > > > > > > > > > > > I did execute vacuum manually and I noticed the below in the output= > > > > > > =22IN=46O: vacuuming =22public.alf=5Fnode=5Faspects=22 > > > IN=46O: =22alf=5Fnode=5Faspects=22: found 0 removable, 150264654 no= nremovable 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.=C2=A0 I certainly would not have= expected 0 removable. There should have been some prior output, somethin= g like: > > > > IN=46O: =C2=A0scanned index =22fk=5Falf=5Fnasp=5Fqn=22 to remove 5000= 00 row versions > > > > It could be that autovacuum had already gotten around to vacuuming af= ter your initial email but before you did the above, meaning there was no= t much for your manual to do. > > > > But you can see that the vacuum did have an effect, by comparing thes= e 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 s= omething worth fixing. > > > > Cheers, > > > > Jeff --5e32a58e_71f32454_16c Content-Type: text/html; charset="utf-8" Content-Transfer-Encoding: quoted-printable Content-Disposition: inline
Hi Jeff,&=23160;

Thank you for your email, Sorry I couldn=E2=80=99t = respond back to you. I am not working on this project at the moment. I ha= ve copied one of my colleague who working on this. He has some progress o= n this, he will update the email thread with those findings

Appreciate your support.

Thank you,
=46ahiz
On 12 Dec 2019, 02:25 +0000, Jeff J= anes <jeff.janes=40gmail.com>, wrote:
On Wed, Dec 11, 2019 at 5:21 PM =46ahiz Mohamed <= fahiz=40netwidz.com> wr= ote:
There is a slight different in both instance=E2=80=99= s data. Inastanbce 1 contains latest data and instance 2 consists of data= which is 3 weeks older than instance 1.&=23160;

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.&=23160; =46or example, we still know the slo= w plan has 4697 rows in aspect=5F1 where qname=5Fid =3D 251, while the ot= her plan has 85 rows in aspect=5F1 meeting that same criterion. That is a= big difference, and it is real difference in the data, not just a differ= ence in planning or estimation.&=23160; Is this difference&=23160;driving= the difference in plan choice=3F&=23160; Probably not (plan choice is dr= iven 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.&=23160; It is likely that there are other, = similar differences in the distribution of particular values which is dri= ving the difference in plans.&=23160; 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&=23160;&=23160;idx=5F= alf=5Fnode=5Ftqn in a way which is equally unproductive as the previous u= se of&=23160;&=23160;idx=5Fal= f=5Fnode=5Fmdq was.&=23160; It looks like they have the same columns, jus= t in a different order.&=23160; My previous advice to try&=23160;<= span style=3D=22color:rgb(0,0,0)=22>&=23160;=22type=5Fqname=5Fid+0 =3D 240=22 should still apply.

If you can't get that to work, = then another avenue is to run =22explain (analyze, buffers) select count(= *) from&=23160;alf=5Fnode where (type=5Fqname=5Fid =3D 240) AND (s= tore=5Fid =3D 6)=22 on both instances.




I did execute vacuum manually and I noticed the bel= ow in the output

=22IN=46O: vacuuming =22public.alf=5Fnode=5Faspects= =22
IN=46O: =22alf=5Fnode=5Faspects=22: found 0 removab= le, 150264654 nonremovable row versions in 812242 pages
DETAIL: 0 dead row versions cannot be removed yet.<= /div>
CPU 13.53s/33.35u sec elapsed 77.88 sec.

I'm not really sure what that m= eans.&=23160; I certainly would not have expected 0 removable. There shou= ld have been some prior output, something like:

IN=46O: &=23160;scanned index =22fk=5Falf=5Fnasp=5Fqn=22 to remove 5= 00000 row versions&=23160;&=23= 160;
&=23160;
It could be that autovacuum had already gotten around to vacuuming a= fter your initial email but before you did the above, meaning there was n= ot much for your manual to do.

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

Heap Blocks: exact=3D40765

Heap Blocks: exact=3D1774&=23160;

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

Cheers,

Jeff
--5e32a58e_71f32454_16c--