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 1kEK4A-00065c-1K for pgsql-performance@arkaria.postgresql.org; Fri, 04 Sep 2020 22:20:18 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.92) (envelope-from ) id 1kEK48-0001X1-PH for pgsql-performance@arkaria.postgresql.org; Fri, 04 Sep 2020 22:20:16 +0000 Received: from magus.postgresql.org ([2a02:c0:301:0:ffff::29]) by malur.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1kEK48-0001Wt-7s for pgsql-performance@lists.postgresql.org; Fri, 04 Sep 2020 22:20:16 +0000 Received: from sonic307-10.consmr.mail.ne1.yahoo.com ([66.163.190.33]) by magus.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_128_GCM_SHA256:128) (Exim 4.92) (envelope-from ) id 1kEK43-00008i-A3 for pgsql-performance@lists.postgresql.org; Fri, 04 Sep 2020 22:20:15 +0000 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=yahoo.com; s=s2048; t=1599258008; bh=x34PVijTyBotRAST1sr6eI22snwl+YHsD7mjM1ZC6IY=; h=Date:From:To:Cc:In-Reply-To:References:Subject:From:Subject; b=DG1Jb5USiv1Xwp9L/n5Y8E7ZvKEQ0OnXe6MWNFNuvWYWypWK9EVYvlU55YbQSi8TwhqhC/pKlLVZoS7HBgwFVDVc/K9pZNxP2jpiUzqthqUyVLreAUi4+AHkIxpyJiI1II7vpE0+duvSS7kNLIarCoMissC+CIgn123XlVx7CSl4BMpUxL05p1vG7fqM8wjD/uUJq5+xISVEVvVfkEiZEi/L8MUOudpOps6mRHpKD3oqNF8VfbJCjrwVWJyzL37P6dPcBdFiICrA/xLHICSVZJLkxpZ/R4ugdh4KpnzR9lwMlBsGTjjq9j8SIYZGvHDVn11wIOKBF8KofBVStiDtig== X-YMail-OSG: lDMCpasVM1loTlt11iolSnCRU_8Ve8Hy9dxT6BX2Azsoqeci9UqDrlFEEGC1gVz mD5Sn56coYTibQjvk1dH_S7fp1Egl1cEsws6mJ1N7tZGegM3KBttP5yeuDEdxRJdpG2cS95.A1Vm 6oSJpCjEZpAazbnaIW4dOSDNg4GzvfujrH3gs9GNMxMmHOoess1v1OfBNElUksZYtKdaWC0IrPd1 Nl75vx0oqTCEAIlqBCzHaiMmVOpBPtDFdwcjPWEmhlncr0XGz0FZ2mSU6yRLN2t9A0YE7SEzX6.o IsXgVSzUj_c_zae.gXKDONnUX6XrmhAe6Bjwf32P3lqRkKgw9dZzlMDd0p3tPEbcTcD.gPOm5VR2 ttlhb335FSRiAG32ZUZ0BTZdRnXTC1XW1tHwFycCh53NEcBFNQG.aZuk4t88e07VXF0EDAmFjjCt Lr3Hy4IdsLhdTUoeptQTjGz4LzJXyNXXbbsTE3aHAurYbI1gl8eMHUcF4xC8GiJgDxIKdmXJviNr m4.aAW3mTC4z4JLCcc0_WxiYPDSzU3TrHxdSFRqXGtzB2pBpySYEQde2NfmLFVA0q.Jr70UEOUZP Jl1SbeQueoAvT2dmFmGoNFe1NcAX9KY6KLGCGa4NWz98BFmWOrHK6FbqwnDpJyKaqDD5oDs3eKZH uyBlFPPHK21v8ZKX2umyK7edKkgIZPRD_kjfIjwd_ghea3CTnZTZn5IDi6fIywDJNFACyLJPRjDY QnyjAt5If_UjKHzCmW0ET4.zvxJEKXqgOxrtM7PyEuH0CIrIUu_Arj0LfnliXhq62XEO38Jo5f7p h.VkQ8f2Npb51wmgfBtXr9zSMZAh.8bV_tAOlLmozhbvBOMemy3jAW_SGXXGKb6UaAKoIPEAx3d6 sk5Dvog8klMELfRnnd3P5t4ZqlXiV2zDHUwh4MokMUFfF64mMGucWzdlISjd0PKuMjEHRtVydMiY Cnmoj1I8HU52276s.ICAwILlP1b0Pf.QwsHISe2qz6AOCJLDNyu5lvlTaoiJvrPfi5Z4iWToFxqz 5Z6B49yKs0Ya0M2R2U2lgeVW9O9GBS5UrYByi3zZIB1GeltRAcF0lATYFaO4BcgJBjGsc_ytvEij 4gnQgoWT2GmIWt1ppXv_ArJEf8.7P5abFYpGszuYzW0YRaV7xs8W9u0DSGkQJF0dNLJL_XNNB4oG HXNhvYhtdSvZpd5kLdzmZqnzqlGzttl2gUDmq_OW6Ol6XtGfcKlKFmdmGnrAXdalDk3fA2EoPGP5 1h_rcOXycfuSwyAt76C95jum0sic6qYBVjnvmmusjBXXBFTqJg5tWAIcdPP5ls0K5JGcdtHCX0bl yc6kGyGgcmKxrq6nU9.r_nMbM1m4p23ZOXvFanQdJQMg4vU8S9b1T9WTayqX5asA9THT2bp.Gc.E cPQyK5gSeD0qAYIe53gMyALL4tElR7jsgtI8uUrvDqVDYaThLzd8INnpuERT2gZ48YdVBDuNx6BA 3NrWJpF1dBP92U1N7TAPhClE- Received: from sonic.gate.mail.ne1.yahoo.com by sonic307.consmr.mail.ne1.yahoo.com with HTTP; Fri, 4 Sep 2020 22:20:08 +0000 Date: Fri, 4 Sep 2020 22:20:06 +0000 (UTC) From: Nagaraj Raj To: Michael Lewis Cc: Thomas Kellerer , Pgsql Performance Message-ID: <1574190552.3418086.1599258006641@mail.yahoo.com> In-Reply-To: References: <975305787.3395625.1599254321500.ref@mail.yahoo.com> <975305787.3395625.1599254321500@mail.yahoo.com> <499793818.3392649.1599254645140@mail.yahoo.com> <2010108831.405412.1599255854719@mail.yahoo.com> Subject: Re: Query performance issue MIME-Version: 1.0 Content-Type: multipart/alternative; boundary="----=_Part_3418085_1646267997.1599258006638" X-Mailer: WebService/1.1.16565 YMailNorrin Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.83 Safari/537.36 Content-Length: 16906 List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Precedence: bulk ------=_Part_3418085_1646267997.1599258006638 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Hi Mechel, I added the index as you suggested and the planner going through the bitmap= =C2=A0index scan,heap and the new planner is,HaOx | explain.depesz.com |=20 |=20 | |=20 HaOx | explain.depesz.com | | | Mem config:=C2=A0 Aurora PostgreSQL 11.7 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 4.9.3,= 64-bit vCPU =3D 64RAM =3D 512show shared_buffers =3D 355 GBshow work_mem =3D 214 M= B show maintenance_work_mem =3D 8363MBshow effective_cache_size =3D 355 GB Thanks,Rj On Friday, September 4, 2020, 02:55:50 PM PDT, Michael Lewis wrote: =20 =20 "Subquery Scan on rec (cost=3D1628601.89..1676580.92 rows=3D7381 width=3D4= 1) (actual time=3D22171.986..23549.079 rows=3D1236042 loops=3D1)"" Filter: = (rec.mpos =3D 1)"" Rows Removed by Filter: 228737"" Buffers: shared hit=3D4= 5 read=3D1166951"" I/O Timings: read=3D29.530"" -> WindowAgg (cost=3D162860= 1.89..1658127.45 rows=3D1476278 width=3D49) (actual time=3D22171.983..23379= .219 rows=3D1464779 loops=3D1)"" Buffers: shared hit=3D45 read=3D1166951"" = I/O Timings: read=3D29.530"" -> Sort (cost=3D1628601.89..1632292.58 rows=3D= 1476278 width=3D41) (actual time=3D22171.963..22484.044 rows=3D1464779 loop= s=3D1)"" Sort Key: receiving_item_delivered_received.serial_no, receiving_i= tem_delivered_received.eventtime DESC"" Sort Method: quicksort Memory: 1635= 89kB"" Buffers: shared hit=3D45 read=3D1166951"" I/O Timings: read=3D29.530= "" -> Gather (cost=3D1000.00..1477331.13 rows=3D1476278 width=3D41) (actual= time=3D1.296..10428.060 rows=3D1464779 loops=3D1)"" Workers Planned: 2"" W= orkers Launched: 2"" Buffers: shared hit=3D39 read=3D1166951"" I/O Timings:= read=3D29.530"" -> Parallel Seq Scan on receiving_item_delivered_received = (cost=3D0.00..1328703.33 rows=3D615116 width=3D41) (actual time=3D1.262..10= 150.325 rows=3D488260 loops=3D3)"" Filter: (((COALESCE(serial_no, ''::chara= cter varying))::text <> ''::text) AND ((eventtype)::text =3D 'LineItemdetai= lsReceived'::text) AND ((replenishmenttype)::text =3D 'DC2SWARRANTY'::text)= )"" Rows Removed by Filter: 6906258"" Buffers: shared hit=3D39 read=3D11669= 51"" I/O Timings: read=3D29.530""Planning Time: 0.375 ms""Execution Time: 2= 3617.348 ms" That is doing a lot of reading from disk. What do you have shared_buffers s= et to? I'd expect better cache hits unless it is quite low or this is a que= ry that differs greatly from the typical work. Also, did you try adding the index I suggested? That lowest node has 488k r= ows coming out of it after throwing away 6.9 million. I would expect an ind= ex on only=C2=A0eventtype,=C2=A0replenishmenttype=C2=A0to be quite helpful.= I don't assume you have tons of rows where serial_no is null. =20 ------=_Part_3418085_1646267997.1599258006638 Content-Type: text/html; charset=UTF-8 Content-Transfer-Encoding: quoted-printable
Hi Mechel,

I added the index as you sug= gested and the planner going through the bitmap index scan,heap and the new planner is,=

<= /table>

Mem config: 
Aurora PostgreSQL 11.7 on x86_64-pc-linux-gnu, compil= ed by gcc (GCC) 4.9.3, 64-bit
vCPU =3D 64
RA= M =3D 512
show shared_buffers =3D 355 GB
show work_mem =3D 214 MB
sho= w maintenance_work_mem =3D 8363MB
show effective_cache_size =3D 3= 55 GB


Thanks,
Rj

=20
=20
On Friday, September 4, 2020, 02:55:50 PM PDT, Michael = Lewis <mlewis@entrata.com> wrote:


"Subquery Scan on rec (cost=3D16286= 01.89..1676580.92 rows=3D7381 width=3D41) (actual time=3D22171.986..23549.0= 79 rows=3D1236042 loops=3D1)" " Filter: (rec.mpos =3D 1)" " Rows Removed by Filter: 228737" " Buffers: shared hit=3D45 read=3D1166951" " I/O Timings: read=3D29.530" " -> WindowAgg (cost=3D1628601.89..1658127.45 rows=3D1476278 width= =3D49) (actual time=3D22171.983..23379.219 rows=3D1464779 loops=3D1)" " Buffers: shared hit=3D45 read=3D1166951" " I/O Timings: read=3D29.530" " -> Sort (cost=3D1628601.89..1632292.58 rows=3D1476278 width= =3D41) (actual time=3D22171.963..22484.044 rows=3D1464779 loops=3D1)" " Sort Key: receiving_item_delivered_received.serial_no, rece= iving_item_delivered_received.eventtime DESC" " Sort Method: quicksort Memory: 163589kB" " Buffers: shared hit=3D45 read=3D1166951" " I/O Timings: read=3D29.530" " -> Gather (cost=3D1000.00..1477331.13 rows=3D1476278 w= idth=3D41) (actual time=3D1.296..10428.060 rows=3D1464779 loops=3D1)" " Workers Planned: 2" " Workers Launched: 2" " Buffers: shared hit=3D39 read=3D1166951" " I/O Timings: read=3D29.530" " -> Parallel Seq Scan on receiving_item_delivered_= received (cost=3D0.00..1328703.33 rows=3D615116 width=3D41) (actual time= =3D1.262..10150.325 rows=3D488260 loops=3D3)" " Filter: (((COALESCE(serial_no, ''::character va= rying))::text <> ''::text) AND ((eventtype)::text =3D 'LineItemdetail= sReceived'::text) AND ((replenishmenttype)::text =3D 'DC2SWARRANTY'::text))= " " Rows Removed by Filter: 6906258" " Buffers: shared hit=3D39 read=3D1166951"= " I/O Timings: read=3D29.530" "Planning Time: 0.375 ms" "Execution Time: 23617.348 ms"


That is doing a lot of reading from disk. What do you have shared_buff= ers set to? I'd expect better cache hits unless it is quite low or this is = a query that differs greatly from the typical work.

=
Also, did you try adding the index I suggested? That lowest node= has 488k rows coming out of it after throwing away 6.9 million. I would ex= pect an index on only eventtype, replenishmenttype to be qui= te helpful. I don't assume you have tons of rows where serial_no is null.
------=_Part_3418085_1646267997.1599258006638--
=

HaOx | explain.depesz.co= m

=