Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtp (Exim 4.84_2) (envelope-from ) id 1aqYj0-00076n-RR for pgsql-performance@arkaria.postgresql.org; Thu, 14 Apr 2016 04:17:51 +0000 Received: from localhost ([127.0.0.1] helo=postgresql.org) by malur.postgresql.org with smtp (Exim 4.84_2) (envelope-from ) id 1aqYj0-0006Fz-8P for pgsql-performance@arkaria.postgresql.org; Thu, 14 Apr 2016 04:17:50 +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_SHA384:256) (Exim 4.84_2) (envelope-from ) id 1aqYiz-0006FV-D6 for pgsql-performance@postgresql.org; Thu, 14 Apr 2016 04:17:49 +0000 Received: from mail-lf0-x22a.google.com ([2a00:1450:4010:c07::22a]) by magus.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA1:256) (Exim 4.84_2) (envelope-from ) id 1aqYit-0003AV-60 for pgsql-performance@postgresql.org; Thu, 14 Apr 2016 04:17:48 +0000 Received: by mail-lf0-x22a.google.com with SMTP id g184so94631043lfb.3 for ; Wed, 13 Apr 2016 21:17:43 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:in-reply-to:references:date:message-id:subject:from:to; bh=37PG4oXCTlB1PXX0SaTpgV9U0Zot2SCLTxyo0mjeV4w=; b=aCGGXQFIs79wZ64XCDIa6ZPCPKVdd52o4oItweqiodk/4C7xX6fVR8ypSfeT31KqLA mgy4atPztvop1RmW+uuTSOgKy0KCpEGhsBFJpxuR4XaQ/+GzsU4RwCOUUu5bgbaq/2J3 pl4kI6NzZ0snDOM7KsS1N9OdjpA36B+0J2ftrFBVGYWVQN3KiBWFibAYYN4bDicsZf0B yzSjYWMIqs5ZbqdtD1Ecq3rIhRnheXm6lxsVPxq0PNWZhxk3zitpp6QVfJ2kmz6iSvst 3MuE+oqSa2ho7v529FagpTJMCKKq3fElPcZfsY0xvkcAOXG+U2WKpInTULH0pqHiUo0T bL8w== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:mime-version:in-reply-to:references:date :message-id:subject:from:to; bh=37PG4oXCTlB1PXX0SaTpgV9U0Zot2SCLTxyo0mjeV4w=; b=i47wDFmD8r70C5G7y+ZqjshMTM//yp44dKqgf33bZIUY4g8fY23sZmMjUAcGeCyc9t Z1tgZCCP6PPkY7vYcz/SjBWLN44MsOez/npjSzRqG3rV3Ach0n1/bpiFj4Hirq/MW8DC OrF3wPlwTFoj3D5y2gN39BUeE8SWo4A5Vc686X4rrM6dnuBfM4Fyi1e96BzulhJTPO0f Nz1TQfEBLJ/A66PB+0n9d5u2XaW+aKvcLzVpQVrBfTAVTH+ZNDFZgup2tzOfe22q/05x 9NtDu/u6odkifgbdKi0n9CyGz/ayOVJFk+HHPCjC9oQhg+gN0l/sLXXPRSRpShKt0Fyx +GLQ== X-Gm-Message-State: AOPr4FXnmW3eAZB1IzXSGuPEm8X75yy8jo5g3aU+xZ8AuzzFvFVjbCkdw4hPG/9siNKV9RBlAbZzb2Z6MXCD2w== MIME-Version: 1.0 X-Received: by 10.112.227.71 with SMTP id ry7mr5445406lbc.78.1460607462683; Wed, 13 Apr 2016 21:17:42 -0700 (PDT) Received: by 10.25.207.74 with HTTP; Wed, 13 Apr 2016 21:17:42 -0700 (PDT) In-Reply-To: <5C918770-5BC7-43E2-90B1-9A90174370F6@gmail.com> References: <5C918770-5BC7-43E2-90B1-9A90174370F6@gmail.com> Date: Thu, 14 Apr 2016 00:17:42 -0400 Message-ID: Subject: Re: Slow update on column that is part of exclusion constraint From: Adam Brusselback To: pgsql-performance@postgresql.org Content-Type: multipart/mixed; boundary=001a11347e8ef8b79105306a2cf4 X-Pg-Spam-Score: -2.7 (--) 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 --001a11347e8ef8b79105306a2cf4 Content-Type: multipart/alternative; boundary=001a11347e8ef8b78b05306a2cf2 --001a11347e8ef8b78b05306a2cf2 Content-Type: text/plain; charset=UTF-8 So fair enough, it does seem to be related to the lookup rather than maintenance on the index. I was misguided in my initial assumption. Spent quite a bit of time trying to come up with a self contained test, and it seems like I can't make it choose the GiST index unless I remove the regular btree index in my test case, though the opposite is true for my table in production. Not really sure what that means as far as what I need to do though. I've tried a vacuum full, analyze, rebuild index, drop and re-add the constraint... It still uses that GiST index for this query. Hell, a sequential scan is a ton faster even. On Wed, Apr 13, 2016 at 2:54 PM, Evgeniy Shishkin wrote: > > > On 13 Apr 2016, at 20:14, Adam Brusselback > wrote: > > > > Sorry, brain stopped working and I forgot to include the normal info. > > > > Postgres version: 9.5.1 > > Hardware: 2 core, 4gb Digital Ocean virtual server > > OS: Debian > > > > explain analyze for an example update: > > 'Update on price_generated (cost=32.45..644.83 rows=1 width=157) > (actual time=29329.614..29329.614 rows=0 loops=1)' > > ' -> Nested Loop (cost=32.45..644.83 rows=1 width=157) (actual > time=29329.608..29329.608 rows=0 loops=1)' > > ' -> HashAggregate (cost=32.04..34.35 rows=231 width=52) > (actual time=1.137..2.090 rows=231 loops=1)' > > ' Group Key: pti.product_id, pti.company_id, pti.date_range' > > ' -> Seq Scan on _prices_to_insert pti (cost=0.00..30.31 > rows=231 width=52) (actual time=0.060..0.678 rows=231 loops=1)' > > ' -> Index Scan using > price_generated_company_product_date_active_excl on price_generated > (cost=0.41..2.63 rows=1 width=151) (actual time=126.949..126.949 rows=0 > loops=231)' > > ' Index Cond: (date_range = pti.date_range)' > > ' Filter: ((upper(active_range) IS NULL) AND > (pti.product_id = product_id) AND (pti.company_id = company_id))' > > ' Rows Removed by Filter: 29460' > > 'Planning time: 3.134 ms' > > 'Execution time: 29406.717 ms' > > Well, you see execution time of 30 seconds because there are 231 index > lookups, > each taking 126 ms. > > And that lookup is slow because of > Filter: ((upper(active_range) IS NULL) AND (pti.product_id = product_id) > AND (pti.company_id = company_id))' > > Can you provide self-containing example of update? > I don't see there (upper(active_range) IS NULL condition is coming from. --001a11347e8ef8b78b05306a2cf2 Content-Type: text/html; charset=UTF-8 Content-Transfer-Encoding: quoted-printable
So fair enough, it does seem to be related to the lookup r= ather than maintenance on the index. I was misguided in my initial assumpti= on. =C2=A0

Spent quite a bit of time trying to come up w= ith a self contained test, and it seems like I can't make it choose the= GiST index unless I remove the regular btree index in my test case, though= the opposite is true for my table in production.=C2=A0 Not really sure wha= t that means as far as what I need to do though. I've tried a vacuum fu= ll, analyze, rebuild index, drop and re-add the constraint... It still uses= that GiST index for this query.

Hell, a sequentia= l scan is a ton faster even.

On Wed, Apr 13, 2016 at 2:54 PM, Evgeniy Shishkin <itparanoia@gmail.com> wrote:

> On 13 Apr 2016, at 20:14, Adam Brusselback <adambrusselback@gmail.com> wrote:
>
> Sorry, brain stopped working and I forgot to include the normal info.<= br> >
> Postgres version: 9.5.1
> Hardware: 2 core, 4gb Digital Ocean virtual server
> OS: Debian
>
> explain analyze for an example update:
> 'Update on price_generated=C2=A0 (cost=3D32.45..644.83 rows=3D1 wi= dth=3D157) (actual time=3D29329.614..29329.614 rows=3D0 loops=3D1)'
> '=C2=A0 ->=C2=A0 Nested Loop=C2=A0 (cost=3D32.45..644.83 rows= =3D1 width=3D157) (actual time=3D29329.608..29329.608 rows=3D0 loops=3D1)&#= 39;
> '=C2=A0 =C2=A0 =C2=A0 =C2=A0 ->=C2=A0 HashAggregate=C2=A0 (cost= =3D32.04..34.35 rows=3D231 width=3D52) (actual time=3D1.137..2.090 rows=3D2= 31 loops=3D1)'
> '=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 Group Key: pti.p= roduct_id, pti.company_id, pti.date_range'
> '=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 ->=C2=A0 Seq = Scan on _prices_to_insert pti=C2=A0 (cost=3D0.00..30.31 rows=3D231 width=3D= 52) (actual time=3D0.060..0.678 rows=3D231 loops=3D1)'
> '=C2=A0 =C2=A0 =C2=A0 =C2=A0 ->=C2=A0 Index Scan using price_ge= nerated_company_product_date_active_excl on price_generated=C2=A0 (cost=3D0= .41..2.63 rows=3D1 width=3D151) (actual time=3D126.949..126.949 rows=3D0 lo= ops=3D231)'
> '=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 Index Cond: (dat= e_range =3D pti.date_range)'
> '=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 Filter: ((upper(= active_range) IS NULL) AND (pti.product_id =3D product_id) AND (pti.company= _id =3D company_id))'
> '=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 Rows Removed by = Filter: 29460'
> 'Planning time: 3.134 ms'
> 'Execution time: 29406.717 ms'

Well, you see execution time of 30 seconds because there are 23= 1 index lookups,
each taking 126 ms.

And that lookup is slow because of
Filter: ((upper(active_range) IS NULL) AND (pti.product_id= =3D product_id) AND (pti.company_id =3D company_id))'

Can you provide self-containing example of update?
I don't see there (upper(active_range) IS NULL condition is coming from= .

--001a11347e8ef8b78b05306a2cf2-- --001a11347e8ef8b79105306a2cf4 Content-Type: text/plain; charset=UTF-8; name="excl constraint test case.sql" Content-Disposition: attachment; filename="excl constraint test case.sql" Content-Transfer-Encoding: base64 X-Attachment-Id: f_imzrws6p0 77u/U0VUIHdvcmtfbWVtID0gJzUxMiBNQic7DQoNCkRST1AgVEFCTEUgSUYg RVhJU1RTIHByaWNlX2dlbmVyYXRlZF90ZXN0Ow0KRFJPUCBUQUJMRSBJRiBF WElTVFMgX3ByaWNlc190b19pbnNlcnQ7DQoNCkNSRUFURSBURU1QT1JBUlkg VEFCTEUgcHJpY2VfZ2VuZXJhdGVkX3Rlc3QNCigNCiAgcHJpY2VfZ2VuZXJh dGVkX2lkIHV1aWQgTk9UIE5VTEwgREVGQVVMVCBnZW5fcmFuZG9tX3V1aWQo KSwNCiAgcHJvZHVjdF9pZCB1dWlkIE5PVCBOVUxMLA0KICBjb21wYW55X2lk IHV1aWQgTk9UIE5VTEwsDQogIGRhdGVfcmFuZ2UgZGF0ZXJhbmdlIE5PVCBO VUxMLA0KICBhdmVyYWdlX3ByaWNlIG51bWVyaWMgTk9UIE5VTEwsDQogIGF2 ZXJhZ2VfcHJpY2VfZGVsaXZlcmVkIG51bWVyaWMgTk9UIE5VTEwsDQogIGxv d19wcmljZSBudW1lcmljIE5PVCBOVUxMLA0KICBsb3dfcHJpY2VfZGVsaXZl cmVkIG51bWVyaWMgTk9UIE5VTEwsDQogIGhpZ2hfcHJpY2UgbnVtZXJpYyBO T1QgTlVMTCwNCiAgaGlnaF9wcmljZV9kZWxpdmVyZWQgbnVtZXJpYyBOT1Qg TlVMTCwNCiAgdW9tX3R5cGVfaWQgdXVpZCBOT1QgTlVMTCwNCiAgYWN0aXZl X3JhbmdlIHRzdHpyYW5nZSBOT1QgTlVMTCBERUZBVUxUIHRzdHpyYW5nZShu b3coKSwgTlVMTDo6dGltZXN0YW1wIHdpdGggdGltZSB6b25lKSwNCiAgQ09O U1RSQUlOVCBwcmljZV9nZW5lcmF0ZWRfdGVzdF9wa2V5IFBSSU1BUlkgS0VZ IChwcmljZV9nZW5lcmF0ZWRfaWQpLA0KICBDT05TVFJBSU5UIHByaWNlX2dl bmVyYXRlZF90ZXN0X2NvbXBhbnlfcHJvZHVjdF9kYXRlX2FjdGl2ZV9leGNs IEVYQ0xVREUgDQogIFVTSU5HIGdpc3QgKGdvc2ltcGxlLmhleF90b19iaWdp bnQoY29tcGFueV9pZDo6dGV4dCkgV0lUSCA9LCBnb3NpbXBsZS5oZXhfdG9f YmlnaW50KHByb2R1Y3RfaWQ6OnRleHQpIFdJVEggPSwgZGF0ZV9yYW5nZSBX SVRIICYmLCBhY3RpdmVfcmFuZ2UgV0lUSCAmJikNCik7DQoNCkNSRUFURSBJ TkRFWCBpZHhfcHJpY2VfZ2VuZXJhdGVkX3Rlc3RfcHJvZF9jb21wX2RhdGUN CiAgT04gcHJpY2VfZ2VuZXJhdGVkX3Rlc3QNCiAgVVNJTkcgYnRyZWUNCiAg KHByb2R1Y3RfaWQsIGNvbXBhbnlfaWQsIGRhdGVfcmFuZ2UpOw0KDQoNCklO U0VSVCBJTlRPIHByaWNlX2dlbmVyYXRlZF90ZXN0IChwcm9kdWN0X2lkLCBj b21wYW55X2lkLCBkYXRlX3JhbmdlLCBhdmVyYWdlX3ByaWNlLCBhdmVyYWdl X3ByaWNlX2RlbGl2ZXJlZCwgbG93X3ByaWNlLCBsb3dfcHJpY2VfZGVsaXZl cmVkLCBoaWdoX3ByaWNlLCBoaWdoX3ByaWNlX2RlbGl2ZXJlZCwgdW9tX3R5 cGVfaWQsIGFjdGl2ZV9yYW5nZSkNClNFTEVDVCBwLnByb2R1Y3RfaWQsIGMu Y29tcGFueV9pZCwgZC5kYXRlX3JhbmdlLCBhdmcocHIucHJpY2UpLCBhdmco cHIucHJpY2UgKyBwci5kZWxpdmVyeSksIG1pbihwci5wcmljZSksIG1pbihw ci5wcmljZSArIHByLmRlbGl2ZXJ5KSwgbWF4KHByLnByaWNlKSwgbWF4KHBy LnByaWNlICsgcHIuZGVsaXZlcnkpLCB1LnVvbV90eXBlX2lkLCBhci5hY3Rp dmVfcmFuZ2UNCkZST00gKA0KCVNFTEVDVCBnZW5fcmFuZG9tX3V1aWQoKSBh cyBwcm9kdWN0X2lkDQoJRlJPTSBnZW5lcmF0ZV9zZXJpZXMoMSwgMjAwKQ0K KSBwDQpDUk9TUyBKT0lOICgNCglTRUxFQ1QgZ2VuX3JhbmRvbV91dWlkKCkg YXMgY29tcGFueV9pZA0KCUZST00gZ2VuZXJhdGVfc2VyaWVzKDEsIDYwKQ0K KSBjDQpDUk9TUyBKT0lOICgNCglTRUxFQ1QgZGF0ZXJhbmdlKChub3coKSAr IChnZW5lcmF0ZV9zZXJpZXMgfHwgJyBtb250aHMnKTo6aW50ZXJ2YWwpOjpk YXRlLCAobm93KCkgKyAoZ2VuZXJhdGVfc2VyaWVzICsgMSB8fCAnIG1vbnRo cycpOjppbnRlcnZhbCk6OmRhdGUpIGFzIGRhdGVfcmFuZ2UNCglGUk9NIGdl bmVyYXRlX3NlcmllcygxLCAyNCkNCikgZA0KQ1JPU1MgSk9JTiAoDQoJU0VM RUNUIGdlbl9yYW5kb21fdXVpZCgpIGFzIHVvbV90eXBlX2lkDQoJRlJPTSBn ZW5lcmF0ZV9zZXJpZXMoMSwgMSkNCikgdSANCkNST1NTIEpPSU4gKA0KCVNF TEVDVCByYW5kb20oKSAqIDE1IGFzIHByaWNlLCByYW5kb20oKSAqIDMgYXMg ZGVsaXZlcnkNCglGUk9NIGdlbmVyYXRlX3NlcmllcygxLCAxNSkNCikgcHIN CkNST1NTIEpPSU4gKA0KCVNFTEVDVCB0c3R6cmFuZ2Uobm93KCkgLSAoZ2Vu ZXJhdGVfc2VyaWVzIHx8ICcgZGF5cycpOjppbnRlcnZhbCwgQ0FTRSBXSEVO IG5vdygpIC0gKGdlbmVyYXRlX3NlcmllcyB8fCAnIGRheXMnKTo6aW50ZXJ2 YWwgPSBub3coKSBUSEVOIG51bGwgRUxTRSBub3coKSAtIChnZW5lcmF0ZV9z ZXJpZXMgfHwgJyBkYXlzJyk6OmludGVydmFsIEVORCwgJ1tdJykgYXMgYWN0 aXZlX3JhbmdlDQoJRlJPTSBnZW5lcmF0ZV9zZXJpZXMoMCwgMTAsIDEwKQ0K KSBhcg0KR1JPVVAgQlkgcC5wcm9kdWN0X2lkLCBjLmNvbXBhbnlfaWQsIGQu ZGF0ZV9yYW5nZSwgdS51b21fdHlwZV9pZCwgYXIuYWN0aXZlX3JhbmdlOw0K DQoNCkNSRUFURSBURU1QT1JBUlkgVEFCTEUgX3ByaWNlc190b19pbnNlcnQg QVMNClNFTEVDVCBwcm9kdWN0X2lkLCBjb21wYW55X2lkLCBkYXRlX3Jhbmdl LCBhdmVyYWdlX3ByaWNlICogcmFuZG9tKCkgKiAxLjUgYXZlcmFnZV9wcmlj ZSwgYXZlcmFnZV9wcmljZV9kZWxpdmVyZWQgKiByYW5kb20oKSAqIDEuNSBh dmVyYWdlX3ByaWNlX2RlbGl2ZXJlZCwgbG93X3ByaWNlLCBsb3dfcHJpY2Vf ZGVsaXZlcmVkLCBoaWdoX3ByaWNlLCBoaWdoX3ByaWNlX2RlbGl2ZXJlZCwg dW9tX3R5cGVfaWQNCkZST00gcHJpY2VfZ2VuZXJhdGVkX3Rlc3QNCldIRVJF IGFjdGl2ZV9yYW5nZSBAPiBub3coKQ0KT1JERVIgQlkgcmFuZG9tKCkNCkxJ TUlUIDIwMDsNCg0KDQoNCkJFR0lOOw0KLS0gSWYgdGhpcyBpbmRleCBleGlz dHMgdGhpcyB0ZXN0IGNhc2Ugd2lsbCB1c2UgaXQgZm9yIHRoZSB1cGRhdGUN CkRST1AgSU5ERVggaWR4X3ByaWNlX2dlbmVyYXRlZF90ZXN0X3Byb2RfY29t cF9kYXRlOw0KLS0gSWYgdGhpcyBpcyBlbmFibGVkIGl0IHdpbGwgY2hvb3Nl IGEgc2VxIHNjYW4gd2hlcmUgbXkgcmVndWxhciB0YWJsZSBzdGlsbCB3b24n dA0KU0VUIGVuYWJsZV9zZXFzY2FuID0gZmFsc2U7DQoNCg0KVVBEQVRFIHBy aWNlX2dlbmVyYXRlZF90ZXN0DQpTRVQgYWN0aXZlX3JhbmdlID0gdHN0enJh bmdlKGxvd2VyKGFjdGl2ZV9yYW5nZSksIG5vdygpKQ0KV0hFUkUgdXBwZXIo cHJpY2VfZ2VuZXJhdGVkX3Rlc3QuYWN0aXZlX3JhbmdlKSBJUyBOVUxMDQpB TkQgRVhJU1RTICgNCglTRUxFQ1QgMQ0KCUZST00gX3ByaWNlc190b19pbnNl cnQgcHRpDQoJV0hFUkUgcHJpY2VfZ2VuZXJhdGVkX3Rlc3QucHJvZHVjdF9p ZCA9IHB0aS5wcm9kdWN0X2lkDQoJQU5EIHByaWNlX2dlbmVyYXRlZF90ZXN0 LmNvbXBhbnlfaWQgPSBwdGkuY29tcGFueV9pZA0KCUFORCBwcmljZV9nZW5l cmF0ZWRfdGVzdC5kYXRlX3JhbmdlID0gcHRpLmRhdGVfcmFuZ2UpOw== --001a11347e8ef8b79105306a2cf4 Content-Type: text/plain Content-Disposition: inline Content-Transfer-Encoding: 8bit MIME-Version: 1.0 -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance --001a11347e8ef8b79105306a2cf4--