Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtp (Exim 4.80) (envelope-from ) id 1Yo8f2-0003Xh-PR for pgsql-performance@arkaria.postgresql.org; Fri, 01 May 2015 10:59:13 +0000 Received: from localhost ([127.0.0.1] helo=postgresql.org) by malur.postgresql.org with smtp (Exim 4.80) (envelope-from ) id 1Yo8f1-0007uD-QA for pgsql-performance@arkaria.postgresql.org; Fri, 01 May 2015 10:59:11 +0000 Received: from magus.postgresql.org ([2a02:c0:301:0:ffff::29]) by malur.postgresql.org with esmtps (TLS1.2:RSA_AES_256_CBC_SHA256:256) (Exim 4.80) (envelope-from ) id 1Yo8f1-0007u7-0D for pgsql-performance@postgresql.org; Fri, 01 May 2015 10:59:11 +0000 Received: from mail-lb0-x244.google.com ([2a00:1450:4010:c04::244]) by magus.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA1:256) (Exim 4.84) (envelope-from ) id 1Yo8ex-00011h-I0 for pgsql-performance@postgresql.org; Fri, 01 May 2015 10:59:10 +0000 Received: by lbiv13 with SMTP id v13so3662170lbi.3 for ; Fri, 01 May 2015 03:59:04 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=content-type:mime-version:subject:from:in-reply-to:date:cc :content-transfer-encoding:message-id:references:to; bh=9UPcSVGv6ScnXKMI25C5u53mh8sheBIZY4KY3tDZwTE=; b=wwRw6XXty5HhmntapDFUt92O/NASi5gRGtUsiQXa9JU5J2g2j6xrh7acPnJUAQHZW+ MjGnSqYAUTRMlBrAfSXmUNfrGk25e0Vs2S2elX8dyLElvftPepmaHxcBy8wL7Tjvkxa/ 59vSwJvqdVnvwC8uiRGa1YVUDc1E2ozey/J1lPio9yBoyxMzCd2gKbj94h7YWlOvXBGI P5QI0Lj6faYHjoQCp/XRNf07crrfUJoClIQoXYmprOykYQgcFFh4+dJ1eYuBw62Bb/kp JZAKLEYh2v9TjF7euOKMWZo/6nav5zLUNtKgFjqr4FOrt5Pw6MiROMZuWr01y9bQ3W17 mtoA== X-Received: by 10.112.211.167 with SMTP id nd7mr7837480lbc.62.1430477944727; Fri, 01 May 2015 03:59:04 -0700 (PDT) Received: from [192.168.1.2] ([37.44.94.145]) by mx.google.com with ESMTPSA id w10sm1260798laz.6.2015.05.01.03.59.02 (version=TLSv1 cipher=ECDHE-RSA-RC4-SHA bits=128/128); Fri, 01 May 2015 03:59:03 -0700 (PDT) Content-Type: text/plain; charset=us-ascii Mime-Version: 1.0 (Mac OS X Mail 8.2 \(2098\)) Subject: Re: Index Scan Backward Slow From: Evgeniy Shishkin In-Reply-To: Date: Fri, 1 May 2015 13:59:02 +0300 Cc: pgsql-performance@postgresql.org Content-Transfer-Encoding: quoted-printable Message-Id: References: To: David Osborne X-Mailer: Apple Mail (2.2098) 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 > On 01 May 2015, at 13:54, David Osborne wrote: >=20 > Hi, >=20 > We have a query which finds the latest row_id for a particular code. >=20 > We've found a backwards index scan is much slower than a forward one, to = the extent that disabling indexscan altogether actually improves the query = time. >=20 > Can anyone suggest why this might be, and what's best to do to improve th= e query time? >=20 >=20 >=20 > dev=3D> \d table > Table "public.table" > Column | Type | Modifiers=20 > --------------+--------------------------------+----------- > row_id | integer |=20 > code | character(2) |=20 > Indexes: > "table_code_idx" btree (code) > "table_row_idx" btree (row_id) >=20 > dev=3D> select count(*) from table; > count=20=20 > --------- > 6090254 > (1 row) >=20 > dev=3D> select count(distinct(row_id)) from table; > count=20=20 > --------- > 5421022 > (1 row) >=20 > dev=3D> select n_distinct from pg_stats where tablename=3D'table' and att= name=3D'row_id'; > n_distinct=20 > ------------ > -0.762951 > (1 row) >=20 > dev=3D> show work_mem; > work_mem=20=20 > ----------- > 1249105kB > (1 row) >=20 > dev=3D> select version(); > version=20=20=20=20=20= =20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20= =20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20 > -------------------------------------------------------------------------= ------------------------------------- > PostgreSQL 9.3.6 on x86_64-unknown-linux-gnu, compiled by gcc (GCC) 4.6.= 3 20120306 (Red Hat 4.6.3-2), 64-bit > (1 row) >=20 >=20 > The query in question: >=20 > dev=3D> explain (analyse,buffers) select row_id as last_row_id from tabl= e where code=3D'XX' order by row_id desc limit 1; > = QUERY PLAN=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20= =20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20= =20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20= =20=20=20 > -------------------------------------------------------------------------= ---------------------------------------------------------------------------= ---------- > Limit (cost=3D0.43..1.67 rows=3D1 width=3D4) (actual time=3D835.281..83= 5.282 rows=3D1 loops=3D1) > Buffers: shared hit=3D187961 > -> Index Scan Backward using table_row_idx on table (cost=3D0.43..34= 3741.98 rows=3D278731 width=3D4) (actual time=3D835.278..835.278 rows=3D1 l= oops=3D1) > Filter: (code =3D 'XX'::bpchar) > Rows Removed by Filter: 4050971 > Buffers: shared hit=3D187961 > Total runtime: 835.315 ms > (7 rows) >=20 > http://explain.depesz.com/s/uGC >=20 >=20 > So we can see it's doing a backwards index scan. Out of curiosity I tried= a forward scan and it was MUCH quicker: >=20 > dev=3D> explain (analyse,buffers) select row_id as first_row_id from tab= le where code=3D'XX' order by row_id asc limit 1; > QUERY= PLAN=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20= =20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20= =20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20 > -------------------------------------------------------------------------= -------------------------------------------------------------------------- > Limit (cost=3D0.43..1.67 rows=3D1 width=3D4) (actual time=3D19.473..19.= 474 rows=3D1 loops=3D1) > Buffers: shared hit=3D26730 > -> Index Scan using table_row_idx on table (cost=3D0.43..343741.98 r= ows=3D278731 width=3D4) (actual time=3D19.470..19.470 rows=3D1 loops=3D1) > Filter: (code =3D 'XX'::bpchar) > Rows Removed by Filter: 62786 > Buffers: shared hit=3D26730 > Total runtime: 19.509 ms > (7 rows) >=20 > http://explain.depesz.com/s/ASxD >=20 >=20 > I thought adding a index on row_id desc might be the answer but it has li= ttle effect: >=20 > dev=3D> create index row_id_desc_idx on table(row_id desc); > CREATE INDEX > Time: 5293.812 ms >=20 > dev=3D> explain (analyse,buffers) select row_id as last_row_id from tabl= e where code=3D'XX' order by row_id desc limit 1; > = QUERY PLAN=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20= =20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20= =20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20= =20=20 > -------------------------------------------------------------------------= ---------------------------------------------------------------------------= -------- > Limit (cost=3D0.43..1.66 rows=3D1 width=3D4) (actual time=3D944.666..94= 4.667 rows=3D1 loops=3D1) > Buffers: shared hit=3D176711 read=3D11071 > -> Index Scan using row_id_desc_idx on table (cost=3D0.43..342101.98= rows=3D278731 width=3D4) (actual time=3D944.663..944.663 rows=3D1 loops=3D= 1) > Filter: (code =3D 'XX'::bpchar) > Rows Removed by Filter: 4050971 > Buffers: shared hit=3D176711 read=3D11071 > Total runtime: 944.699 ms > (7 rows) >=20 > http://explain.depesz.com/s/JStM >=20 > In fact, disabling the index scan completely improves matters considerabl= y: >=20 > dev=3D> drop index row_id_desc_idx; > DROP INDEX > dev=3D> set enable_indexscan to off; > SET=20=20=20 >=20 > dev=3D> explain (analyse,buffers) select row_id as last_row_id from tabl= e where code=3D'XX' order by row_id desc limit 1; > QU= ERY PLAN=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20= =20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20= =20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20 > -------------------------------------------------------------------------= ---------------------------------------------------------------------------= ---- > Limit (cost=3D74006.39..74006.39 rows=3D1 width=3D4) (actual time=3D183= .997..183.998 rows=3D1 loops=3D1) > Buffers: shared hit=3D14723 > -> Sort (cost=3D74006.39..74703.22 rows=3D278731 width=3D4) (actual = time=3D183.995..183.995 rows=3D1 loops=3D1) > Sort Key: row_id > Sort Method: top-N heapsort Memory: 25kB > Buffers: shared hit=3D14723 > -> Bitmap Heap Scan on table (cost=3D5276.60..72612.74 rows=3D= 278731 width=3D4) (actual time=3D25.533..119.320 rows=3D275909 loops=3D1) > Recheck Cond: (code =3D 'XX'::bpchar) > Buffers: shared hit=3D14723 > -> Bitmap Index Scan on table_code_idx (cost=3D0.00..520= 6.91 rows=3D278731 width=3D0) (actual time=3D23.298..23.298 rows=3D275909 l= oops=3D1) > Index Cond: (code =3D 'XX'::bpchar) > Buffers: shared hit=3D765 > Total runtime: 184.043 ms > (13 rows) >=20 > http://explain.depesz.com/s/E9VE Your queries are slow not because of backward scan. They are slow because of Rows Removed by Filter: 4050971 Try creating index on (code, row_id). >=20 > Thanks in advance for any help. >=20 > Regards, > --=20 > David Osborne > Qcode Software Limited > http://www.qcode.co.uk >=20 --=20 Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance