pg.ddx.io  pgsql-performance@postgresql.org mailing list archive  
help / color / mirror / Atom feed
Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3
15+ messages / 6 participants
[nested] [flat]

* Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3
@ 2011-03-15 18:23 Timothy Garnett <tgarnett@panjiva.com>
  2011-03-15 18:39 ` Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Timothy Garnett <tgarnett@panjiva.com>
  2011-03-16 17:05 ` Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Shaun Thomas <sthomas@peak6.com>
  0 siblings, 2 replies; 15+ messages in thread

From: Timothy Garnett @ 2011-03-15 18:23 UTC (permalink / raw)
  To: pgsql-performance

Hi all,

We added an index to a table (to support some different functionality) then
ran into cases where the new index (on month, bl_number in the schema below)
made performance of some existing queries ~20,000 times worse.  While we do
have a workaround (using a CTE to force the proper index to be used) that
gets us down to ~twice the original performance (i.e. without the new
index), I'm wondering if there's a better workaround that can get us closer
to the original performance. It also seems like kind of a strange case so
I'm wondering if there's something weird going on in the optimizer.  The #
of rows estimates are pretty accurate so it's guessing that about right, but
the planner seems to be putting way too much weight on using a sorted index
vs. looking up. This is all after an analyze.

Near as I can guess the planner seems to be weighting scanning what should
be an expected 100k rows (though in practice it will have to do about 35
million, because the assumption of independence between columns is
incorrect) given an expected selectivity of 48K rows out of 45 million over
scanning ~48k rows (using the index) and doing a top-n 100 sort on them
(actual row count is 43k so pretty close on that).  Even giving the
optimizer the benefit of column independence I don't see how that first plan
could possibly come out ahead.  It would really help if explain would print
out the number of rows it expects to scan and analyze would print out the
number of rows it actually scanned (instead of just the number that matched
the filter/limit), see the expensive query explain analyze output below.

At the bottom I have some info on the contents and probability.


## The original Query:

explain analyze
SELECT customs_records.* FROM "customs_records" WHERE (((buyer_id IS NOT
NULL AND buyer_id IN
(1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585))))
ORDER BY month DESC LIMIT 100 OFFSET 0;
-----------------------------------
 Limit  (cost=184626.64..184626.89 rows=100 width=908) (actual
time=102.630..102.777 rows=100 loops=1)
   ->  Sort  (cost=184626.64..184748.19 rows=48623 width=908) (actual
time=102.628..102.683 rows=100 loops=1)
         Sort Key: month
         Sort Method:  top-N heapsort  Memory: 132kB
         ->  Bitmap Heap Scan on customs_records  (cost=1054.22..182768.30
rows=48623 width=908) (actual time=5.809..44.832 rows=43352 loops=1)
               Recheck Cond: ((buyer_id IS NOT NULL) AND (buyer_id = ANY
('{1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585}'::integer[])))
               ->  Bitmap Index Scan on index_customs_records_on_buyer_id
(cost=0.00..1042.07 rows=48623 width=0) (actual time=4.588..4.588 rows=43352
loops=1)
                     Index Cond: ((buyer_id IS NOT NULL) AND (buyer_id = ANY
('{1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585}'::integer[])))
 Total runtime: 102.919 ms


## Same query after adding the new index
### NOTE - it would be very useful here if explain would print out the
number of rows it expects to scan in the index and analyze dumped out the
number of rows actually scanned.  Instead analyze is printing the rows
actually outputed and explain appears to be outputting the number of rows
expected to match the filter ignoring the limit... (it exactly matches the
row count in the query above)
##

explain analyze
SELECT customs_records.* FROM "customs_records" WHERE (((buyer_id IS NOT
NULL AND buyer_id IN
(1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585))))
ORDER BY month DESC LIMIT 100 OFFSET 0;
--------------------------------------------
 Limit  (cost=0.00..161295.58 rows=100 width=908) (actual
time=171344.185..3858893.743 rows=100 loops=1)
   ->  Index Scan Backward using
index_customs_records_on_month_and_bl_number on customs_records
(cost=0.00..78426750.74 rows=48623 width=908) (actual
time=171344.182..3858893.588 rows=100 loops=1)
         Filter: ((buyer_id IS NOT NULL) AND (buyer_id = ANY
('{1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585}'::integer[])))
 Total runtime: 3858893.908 ms


############################################################
My workaround is to use a CTE query to force the planner to not use the
month index for sorting (using a subselect is not enough since the planner
is too smart for that). However this is still twice as slow as the original
query...
############################################################

explain analyze
with foo as (select customs_records.* FROM "customs_records" WHERE
(((buyer_id IS NOT NULL AND buyer_id IN
(1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585)))))
select * from foo order by month desc limit 100 ;
-----------------------------------------------------------
 Limit  (cost=185599.10..185599.35 rows=100 width=5325) (actual
time=196.968..197.105 rows=100 loops=1)
   CTE foo
     ->  Bitmap Heap Scan on customs_records  (cost=1054.22..182768.30
rows=48623 width=908) (actual time=5.765..43.489 rows=43352 loops=1)
           Recheck Cond: ((buyer_id IS NOT NULL) AND (buyer_id = ANY
('{1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585}'::integer[])))
           ->  Bitmap Index Scan on index_customs_records_on_buyer_id
(cost=0.00..1042.07 rows=48623 width=0) (actual time=4.544..4.544 rows=43352
loops=1)
                 Index Cond: ((buyer_id IS NOT NULL) AND (buyer_id = ANY
('{1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585}'::integer[])))
   ->  Sort  (cost=2830.80..2952.35 rows=48623 width=5325) (actual
time=196.966..197.029 rows=100 loops=1)
         Sort Key: foo.month
         Sort Method:  top-N heapsort  Memory: 132kB
         ->  CTE Scan on foo  (cost=0.00..972.46 rows=48623 width=5325)
(actual time=5.770..153.322 rows=43352 loops=1)
 Total runtime: 207.282 ms


#### Table information

Table information - the schema is the table below (with some columns removed
for succinctness).  There are ~45 million rows, the rows are also fairly
wide about 80 columns total. buyer_id is null ~30% of the time (as is
supplier_id). A given buyer id maps to between 1 and ~100,000 records (in a
decreasing distribution, about 1 million unique buyer id values).
Supplier_id is similar.  Note buyer_id and month columns are not always
independent (for some buyer_ids there is a strong correlation as in this
case where the buyer_ids are associated with only older months, though for
others there isn't), though even so I'm still not clear on why it would pick
the plan that it does. We can consider these table never updated or inserted
into (updates are done in a new db offline that is periodically swapped in).

                                          Table "public.customs_records"
          Column          |          Type
|                          Modifiers
--------------------------+------------------------+--------------------------------------------------------------
 id                       | integer                | not null default
nextval('customs_records_id_seq'::regclass)
....
 bl_number                | character varying(16)  |
....
 month                    | date                   |
....
 buyer_id                 | integer                |
...
 supplier_id              | integer                |
...
Indexes:
    "customs_records_pkey" PRIMARY KEY, btree (id) WITH (fillfactor=100)
    "index_customs_records_on_month_and_bl_number" UNIQUE, btree (month,
bl_number) WITH (fillfactor=100)
    "index_customs_records_on_buyer_id" btree (buyer_id) WITH
(fillfactor=100) WHERE buyer_id IS NOT NULL
    "index_customs_records_on_supplier_id_and_buyer_id" btree (supplier_id,
buyer_id) WITH (fillfactor=100) CLUSTER


db version =>
 PostgreSQL 9.0.3 on x86_64-unknown-linux-gnu, compiled by GCC gcc (GCC)
4.1.2 20080704 (Red Hat 4.1.2-46), 64-bit
 (enterprise db build)
ubuntu 8.04 LTS is the host

^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3
  2011-03-15 18:23 Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Timothy Garnett <tgarnett@panjiva.com>
@ 2011-03-15 18:39 ` Timothy Garnett <tgarnett@panjiva.com>
  2011-03-15 18:42   ` Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Timothy Garnett <tgarnett@panjiva.com>
  1 sibling, 1 reply; 15+ messages in thread

From: Timothy Garnett @ 2011-03-15 18:39 UTC (permalink / raw)
  To: pgsql-performance

Forgot to include our non-default config settings and server info, not that
it probably makes a difference for this.

from pg_settings:
 name                         | current_setting
 version                      | PostgreSQL 9.0.3 on
x86_64-unknown-linux-gnu, compiled by GCC gcc (GCC) 4.1.2 20080704 (Red Hat
4.1.2-46), 64-bit
 bytea_output                 | escape
 checkpoint_completion_target | 0.9
 checkpoint_segments          | 24
 effective_cache_size         | 24GB
 effective_io_concurrency     | 2
 lc_collate                   | en_US.utf8
 lc_ctype                     | en_US.utf8
 listen_addresses             | *
 log_checkpoints              | on
 log_connections              | on
 log_disconnections           | on
 log_hostname                 | on
 log_line_prefix              | %t
 logging_collector            | on
 maintenance_work_mem         | 256MB
 max_connections              | 120
 max_stack_depth              | 2MB
 port                         | 5432
 server_encoding              | UTF8
 shared_buffers               | 4GB
 synchronous_commit           | off
 tcp_keepalives_idle          | 180
 TimeZone                     | US/Eastern
 track_activity_query_size    | 8192
 wal_buffers                  | 16MB
 wal_writer_delay             | 330ms
 work_mem                     | 512MB

This is a dual dual-core 64bit intel machine (hyperthreaded so 8 logical
cpus) with 24GB of memory running basically just the db against a raid 5
diskarray.

Tim

On Tue, Mar 15, 2011 at 2:23 PM, Timothy Garnett <tgarnett@panjiva.com>wrote:

> Hi all,
>
> We added an index to a table (to support some different functionality) then
> ran into cases where the new index (on month, bl_number in the schema below)
> made performance of some existing queries ~20,000 times worse.  While we do
> have a workaround (using a CTE to force the proper index to be used) that
> gets us down to ~twice the original performance (i.e. without the new
> index), I'm wondering if there's a better workaround that can get us closer
> to the original performance. It also seems like kind of a strange case so
> I'm wondering if there's something weird going on in the optimizer.  The #
> of rows estimates are pretty accurate so it's guessing that about right, but
> the planner seems to be putting way too much weight on using a sorted index
> vs. looking up. This is all after an analyze.
>
> Near as I can guess the planner seems to be weighting scanning what should
> be an expected 100k rows (though in practice it will have to do about 35
> million, because the assumption of independence between columns is
> incorrect) given an expected selectivity of 48K rows out of 45 million over
> scanning ~48k rows (using the index) and doing a top-n 100 sort on them
> (actual row count is 43k so pretty close on that).  Even giving the
> optimizer the benefit of column independence I don't see how that first plan
> could possibly come out ahead.  It would really help if explain would print
> out the number of rows it expects to scan and analyze would print out the
> number of rows it actually scanned (instead of just the number that matched
> the filter/limit), see the expensive query explain analyze output below.
>
> At the bottom I have some info on the contents and probability.
>
>
> ## The original Query:
>
> explain analyze
> SELECT customs_records.* FROM "customs_records" WHERE (((buyer_id IS NOT
> NULL AND buyer_id IN
> (1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585))))
> ORDER BY month DESC LIMIT 100 OFFSET 0;
> -----------------------------------
>  Limit  (cost=184626.64..184626.89 rows=100 width=908) (actual
> time=102.630..102.777 rows=100 loops=1)
>    ->  Sort  (cost=184626.64..184748.19 rows=48623 width=908) (actual
> time=102.628..102.683 rows=100 loops=1)
>          Sort Key: month
>          Sort Method:  top-N heapsort  Memory: 132kB
>          ->  Bitmap Heap Scan on customs_records  (cost=1054.22..182768.30
> rows=48623 width=908) (actual time=5.809..44.832 rows=43352 loops=1)
>                Recheck Cond: ((buyer_id IS NOT NULL) AND (buyer_id = ANY
> ('{1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585}'::integer[])))
>                ->  Bitmap Index Scan on index_customs_records_on_buyer_id
> (cost=0.00..1042.07 rows=48623 width=0) (actual time=4.588..4.588 rows=43352
> loops=1)
>                      Index Cond: ((buyer_id IS NOT NULL) AND (buyer_id =
> ANY
> ('{1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585}'::integer[])))
>  Total runtime: 102.919 ms
>
>
> ## Same query after adding the new index
> ### NOTE - it would be very useful here if explain would print out the
> number of rows it expects to scan in the index and analyze dumped out the
> number of rows actually scanned.  Instead analyze is printing the rows
> actually outputed and explain appears to be outputting the number of rows
> expected to match the filter ignoring the limit... (it exactly matches the
> row count in the query above)
> ##
>
> explain analyze
> SELECT customs_records.* FROM "customs_records" WHERE (((buyer_id IS NOT
> NULL AND buyer_id IN
> (1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585))))
> ORDER BY month DESC LIMIT 100 OFFSET 0;
> --------------------------------------------
>  Limit  (cost=0.00..161295.58 rows=100 width=908) (actual
> time=171344.185..3858893.743 rows=100 loops=1)
>    ->  Index Scan Backward using
> index_customs_records_on_month_and_bl_number on customs_records
> (cost=0.00..78426750.74 rows=48623 width=908) (actual
> time=171344.182..3858893.588 rows=100 loops=1)
>          Filter: ((buyer_id IS NOT NULL) AND (buyer_id = ANY
> ('{1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585}'::integer[])))
>  Total runtime: 3858893.908 ms
>
>
> ############################################################
> My workaround is to use a CTE query to force the planner to not use the
> month index for sorting (using a subselect is not enough since the planner
> is too smart for that). However this is still twice as slow as the original
> query...
> ############################################################
>
> explain analyze
> with foo as (select customs_records.* FROM "customs_records" WHERE
> (((buyer_id IS NOT NULL AND buyer_id IN
> (1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585)))))
> select * from foo order by month desc limit 100 ;
> -----------------------------------------------------------
>  Limit  (cost=185599.10..185599.35 rows=100 width=5325) (actual
> time=196.968..197.105 rows=100 loops=1)
>    CTE foo
>      ->  Bitmap Heap Scan on customs_records  (cost=1054.22..182768.30
> rows=48623 width=908) (actual time=5.765..43.489 rows=43352 loops=1)
>            Recheck Cond: ((buyer_id IS NOT NULL) AND (buyer_id = ANY
> ('{1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585}'::integer[])))
>            ->  Bitmap Index Scan on index_customs_records_on_buyer_id
> (cost=0.00..1042.07 rows=48623 width=0) (actual time=4.544..4.544 rows=43352
> loops=1)
>                  Index Cond: ((buyer_id IS NOT NULL) AND (buyer_id = ANY
> ('{1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585}'::integer[])))
>    ->  Sort  (cost=2830.80..2952.35 rows=48623 width=5325) (actual
> time=196.966..197.029 rows=100 loops=1)
>          Sort Key: foo.month
>          Sort Method:  top-N heapsort  Memory: 132kB
>          ->  CTE Scan on foo  (cost=0.00..972.46 rows=48623 width=5325)
> (actual time=5.770..153.322 rows=43352 loops=1)
>  Total runtime: 207.282 ms
>
>
> #### Table information
>
> Table information - the schema is the table below (with some columns
> removed for succinctness).  There are ~45 million rows, the rows are also
> fairly wide about 80 columns total. buyer_id is null ~30% of the time (as is
> supplier_id). A given buyer id maps to between 1 and ~100,000 records (in a
> decreasing distribution, about 1 million unique buyer id values).
> Supplier_id is similar.  Note buyer_id and month columns are not always
> independent (for some buyer_ids there is a strong correlation as in this
> case where the buyer_ids are associated with only older months, though for
> others there isn't), though even so I'm still not clear on why it would pick
> the plan that it does. We can consider these table never updated or inserted
> into (updates are done in a new db offline that is periodically swapped in).
>
>                                           Table "public.customs_records"
>           Column          |          Type
> |                          Modifiers
>
> --------------------------+------------------------+--------------------------------------------------------------
>  id                       | integer                | not null default
> nextval('customs_records_id_seq'::regclass)
> ....
>  bl_number                | character varying(16)  |
> ....
>  month                    | date                   |
> ....
>  buyer_id                 | integer                |
> ...
>  supplier_id              | integer                |
> ...
> Indexes:
>     "customs_records_pkey" PRIMARY KEY, btree (id) WITH (fillfactor=100)
>     "index_customs_records_on_month_and_bl_number" UNIQUE, btree (month,
> bl_number) WITH (fillfactor=100)
>     "index_customs_records_on_buyer_id" btree (buyer_id) WITH
> (fillfactor=100) WHERE buyer_id IS NOT NULL
>     "index_customs_records_on_supplier_id_and_buyer_id" btree (supplier_id,
> buyer_id) WITH (fillfactor=100) CLUSTER
>
>
> db version =>
>  PostgreSQL 9.0.3 on x86_64-unknown-linux-gnu, compiled by GCC gcc (GCC)
> 4.1.2 20080704 (Red Hat 4.1.2-46), 64-bit
>  (enterprise db build)
> ubuntu 8.04 LTS is the host
>
>

^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3
  2011-03-15 18:23 Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Timothy Garnett <tgarnett@panjiva.com>
  2011-03-15 18:39 ` Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Timothy Garnett <tgarnett@panjiva.com>
@ 2011-03-15 18:42   ` Timothy Garnett <tgarnett@panjiva.com>
  2011-03-16 16:40     ` Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Kevin Grittner <Kevin.Grittner@wicourts.gov>
  0 siblings, 1 reply; 15+ messages in thread

From: Timothy Garnett @ 2011-03-15 18:42 UTC (permalink / raw)
  To: pgsql-performance

Sorry meant with 32GB of memory.

Tim

On Tue, Mar 15, 2011 at 2:39 PM, Timothy Garnett <tgarnett@panjiva.com>wrote:

> Forgot to include our non-default config settings and server info, not that
> it probably makes a difference for this.
>
> from pg_settings:
>  name                         | current_setting
>
>  version                      | PostgreSQL 9.0.3 on
> x86_64-unknown-linux-gnu, compiled by GCC gcc (GCC) 4.1.2 20080704 (Red Hat
> 4.1.2-46), 64-bit
>  bytea_output                 | escape
>  checkpoint_completion_target | 0.9
>  checkpoint_segments          | 24
>  effective_cache_size         | 24GB
>  effective_io_concurrency     | 2
>  lc_collate                   | en_US.utf8
>  lc_ctype                     | en_US.utf8
>  listen_addresses             | *
>  log_checkpoints              | on
>  log_connections              | on
>  log_disconnections           | on
>  log_hostname                 | on
>  log_line_prefix              | %t
>  logging_collector            | on
>  maintenance_work_mem         | 256MB
>  max_connections              | 120
>  max_stack_depth              | 2MB
>  port                         | 5432
>  server_encoding              | UTF8
>  shared_buffers               | 4GB
>  synchronous_commit           | off
>  tcp_keepalives_idle          | 180
>  TimeZone                     | US/Eastern
>  track_activity_query_size    | 8192
>  wal_buffers                  | 16MB
>  wal_writer_delay             | 330ms
>  work_mem                     | 512MB
>
> This is a dual dual-core 64bit intel machine (hyperthreaded so 8 logical
> cpus) with 24GB of memory running basically just the db against a raid 5
> diskarray.
>
> Tim
>
>
> On Tue, Mar 15, 2011 at 2:23 PM, Timothy Garnett <tgarnett@panjiva.com>wrote:
>
>> Hi all,
>>
>> We added an index to a table (to support some different functionality)
>> then ran into cases where the new index (on month, bl_number in the schema
>> below) made performance of some existing queries ~20,000 times worse.  While
>> we do have a workaround (using a CTE to force the proper index to be used)
>> that gets us down to ~twice the original performance (i.e. without the new
>> index), I'm wondering if there's a better workaround that can get us closer
>> to the original performance. It also seems like kind of a strange case so
>> I'm wondering if there's something weird going on in the optimizer.  The #
>> of rows estimates are pretty accurate so it's guessing that about right, but
>> the planner seems to be putting way too much weight on using a sorted index
>> vs. looking up. This is all after an analyze.
>>
>> Near as I can guess the planner seems to be weighting scanning what should
>> be an expected 100k rows (though in practice it will have to do about 35
>> million, because the assumption of independence between columns is
>> incorrect) given an expected selectivity of 48K rows out of 45 million over
>> scanning ~48k rows (using the index) and doing a top-n 100 sort on them
>> (actual row count is 43k so pretty close on that).  Even giving the
>> optimizer the benefit of column independence I don't see how that first plan
>> could possibly come out ahead.  It would really help if explain would print
>> out the number of rows it expects to scan and analyze would print out the
>> number of rows it actually scanned (instead of just the number that matched
>> the filter/limit), see the expensive query explain analyze output below.
>>
>> At the bottom I have some info on the contents and probability.
>>
>>
>> ## The original Query:
>>
>> explain analyze
>> SELECT customs_records.* FROM "customs_records" WHERE (((buyer_id IS NOT
>> NULL AND buyer_id IN
>> (1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585))))
>> ORDER BY month DESC LIMIT 100 OFFSET 0;
>> -----------------------------------
>>  Limit  (cost=184626.64..184626.89 rows=100 width=908) (actual
>> time=102.630..102.777 rows=100 loops=1)
>>    ->  Sort  (cost=184626.64..184748.19 rows=48623 width=908) (actual
>> time=102.628..102.683 rows=100 loops=1)
>>          Sort Key: month
>>          Sort Method:  top-N heapsort  Memory: 132kB
>>          ->  Bitmap Heap Scan on customs_records  (cost=1054.22..182768.30
>> rows=48623 width=908) (actual time=5.809..44.832 rows=43352 loops=1)
>>                Recheck Cond: ((buyer_id IS NOT NULL) AND (buyer_id = ANY
>> ('{1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585}'::integer[])))
>>                ->  Bitmap Index Scan on index_customs_records_on_buyer_id
>> (cost=0.00..1042.07 rows=48623 width=0) (actual time=4.588..4.588 rows=43352
>> loops=1)
>>                      Index Cond: ((buyer_id IS NOT NULL) AND (buyer_id =
>> ANY
>> ('{1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585}'::integer[])))
>>  Total runtime: 102.919 ms
>>
>>
>> ## Same query after adding the new index
>> ### NOTE - it would be very useful here if explain would print out the
>> number of rows it expects to scan in the index and analyze dumped out the
>> number of rows actually scanned.  Instead analyze is printing the rows
>> actually outputed and explain appears to be outputting the number of rows
>> expected to match the filter ignoring the limit... (it exactly matches the
>> row count in the query above)
>> ##
>>
>> explain analyze
>> SELECT customs_records.* FROM "customs_records" WHERE (((buyer_id IS NOT
>> NULL AND buyer_id IN
>> (1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585))))
>> ORDER BY month DESC LIMIT 100 OFFSET 0;
>> --------------------------------------------
>>  Limit  (cost=0.00..161295.58 rows=100 width=908) (actual
>> time=171344.185..3858893.743 rows=100 loops=1)
>>    ->  Index Scan Backward using
>> index_customs_records_on_month_and_bl_number on customs_records
>> (cost=0.00..78426750.74 rows=48623 width=908) (actual
>> time=171344.182..3858893.588 rows=100 loops=1)
>>          Filter: ((buyer_id IS NOT NULL) AND (buyer_id = ANY
>> ('{1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585}'::integer[])))
>>  Total runtime: 3858893.908 ms
>>
>>
>> ############################################################
>> My workaround is to use a CTE query to force the planner to not use the
>> month index for sorting (using a subselect is not enough since the planner
>> is too smart for that). However this is still twice as slow as the original
>> query...
>> ############################################################
>>
>> explain analyze
>> with foo as (select customs_records.* FROM "customs_records" WHERE
>> (((buyer_id IS NOT NULL AND buyer_id IN
>> (1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585)))))
>> select * from foo order by month desc limit 100 ;
>> -----------------------------------------------------------
>>  Limit  (cost=185599.10..185599.35 rows=100 width=5325) (actual
>> time=196.968..197.105 rows=100 loops=1)
>>    CTE foo
>>      ->  Bitmap Heap Scan on customs_records  (cost=1054.22..182768.30
>> rows=48623 width=908) (actual time=5.765..43.489 rows=43352 loops=1)
>>            Recheck Cond: ((buyer_id IS NOT NULL) AND (buyer_id = ANY
>> ('{1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585}'::integer[])))
>>            ->  Bitmap Index Scan on index_customs_records_on_buyer_id
>> (cost=0.00..1042.07 rows=48623 width=0) (actual time=4.544..4.544 rows=43352
>> loops=1)
>>                  Index Cond: ((buyer_id IS NOT NULL) AND (buyer_id = ANY
>> ('{1172672,1570888,1336461,1336464,1336471,1189285,1336463,1336460,1654709,1000155646,1191114,1336480,1336479,1000384928,1161787,1811495,1507188,1159339,1980765,1200258,1980770,1980768,1980767,1980769,1980766,1980772,1000350850,1000265917,1980764,1980761,1170019,1980762,1184356,1985585}'::integer[])))
>>    ->  Sort  (cost=2830.80..2952.35 rows=48623 width=5325) (actual
>> time=196.966..197.029 rows=100 loops=1)
>>          Sort Key: foo.month
>>          Sort Method:  top-N heapsort  Memory: 132kB
>>          ->  CTE Scan on foo  (cost=0.00..972.46 rows=48623 width=5325)
>> (actual time=5.770..153.322 rows=43352 loops=1)
>>  Total runtime: 207.282 ms
>>
>>
>> #### Table information
>>
>> Table information - the schema is the table below (with some columns
>> removed for succinctness).  There are ~45 million rows, the rows are also
>> fairly wide about 80 columns total. buyer_id is null ~30% of the time (as is
>> supplier_id). A given buyer id maps to between 1 and ~100,000 records (in a
>> decreasing distribution, about 1 million unique buyer id values).
>> Supplier_id is similar.  Note buyer_id and month columns are not always
>> independent (for some buyer_ids there is a strong correlation as in this
>> case where the buyer_ids are associated with only older months, though for
>> others there isn't), though even so I'm still not clear on why it would pick
>> the plan that it does. We can consider these table never updated or inserted
>> into (updates are done in a new db offline that is periodically swapped in).
>>
>>                                           Table "public.customs_records"
>>           Column          |          Type
>> |                          Modifiers
>>
>> --------------------------+------------------------+--------------------------------------------------------------
>>  id                       | integer                | not null default
>> nextval('customs_records_id_seq'::regclass)
>> ....
>>  bl_number                | character varying(16)  |
>> ....
>>  month                    | date                   |
>> ....
>>  buyer_id                 | integer                |
>> ...
>>  supplier_id              | integer                |
>> ...
>> Indexes:
>>     "customs_records_pkey" PRIMARY KEY, btree (id) WITH (fillfactor=100)
>>     "index_customs_records_on_month_and_bl_number" UNIQUE, btree (month,
>> bl_number) WITH (fillfactor=100)
>>     "index_customs_records_on_buyer_id" btree (buyer_id) WITH
>> (fillfactor=100) WHERE buyer_id IS NOT NULL
>>     "index_customs_records_on_supplier_id_and_buyer_id" btree
>> (supplier_id, buyer_id) WITH (fillfactor=100) CLUSTER
>>
>>
>> db version =>
>>  PostgreSQL 9.0.3 on x86_64-unknown-linux-gnu, compiled by GCC gcc (GCC)
>> 4.1.2 20080704 (Red Hat 4.1.2-46), 64-bit
>>  (enterprise db build)
>> ubuntu 8.04 LTS is the host
>>
>>
>

^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3
  2011-03-15 18:23 Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Timothy Garnett <tgarnett@panjiva.com>
  2011-03-15 18:39 ` Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Timothy Garnett <tgarnett@panjiva.com>
  2011-03-15 18:42   ` Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Timothy Garnett <tgarnett@panjiva.com>
@ 2011-03-16 16:40     ` Kevin Grittner <Kevin.Grittner@wicourts.gov>
  2011-03-16 17:01       ` Re: Re: Adding additional index causes 20, 000x slowdown for certain select queries - postgres 9.0.3 Tom Lane <tgl@sss.pgh.pa.us>
  0 siblings, 1 reply; 15+ messages in thread

From: Kevin Grittner @ 2011-03-16 16:40 UTC (permalink / raw)
  To: Timothy Garnett <tgarnett@panjiva.com>; pgsql-performance

Timothy Garnett <tgarnett@panjiva.com> wrote:
 
>>>    ->  Index Scan Backward using
>>> index_customs_records_on_month_and_bl_number on customs_records
>>> (cost=0.00..78426750.74 rows=48623 width=908) (actual
>>> time=171344.182..3858893.588 rows=100 loops=1)
 
We've seen a lot of those lately -- Index Scan Backward performing
far worse than alternatives.  One part of it is that disk sectors
are arranged for optimal performance on forward scans; but I don't
think we've properly accounted for the higher cost of moving
backward through our btree indexes, either.  To quote from the
README for the btree AM:
 
| A backwards scan has one additional bit of complexity: after
| following the left-link we must account for the possibility that
| the left sibling page got split before we could read it.  So, we
| have to move right until we find a page whose right-link matches
| the page we came from.  (Actually, it's even harder than that; see
| deletion discussion below.)
 
I'm wondering whether the planner should have some multiplier or
other adjustment to attempt to approximate the known higher cost of
backward scans.
 
-Kevin



^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: Re: Adding additional index causes 20, 000x slowdown for certain select queries - postgres 9.0.3
  2011-03-15 18:23 Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Timothy Garnett <tgarnett@panjiva.com>
  2011-03-15 18:39 ` Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Timothy Garnett <tgarnett@panjiva.com>
  2011-03-15 18:42   ` Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Timothy Garnett <tgarnett@panjiva.com>
  2011-03-16 16:40     ` Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Kevin Grittner <Kevin.Grittner@wicourts.gov>
@ 2011-03-16 17:01       ` Tom Lane <tgl@sss.pgh.pa.us>
  0 siblings, 0 replies; 15+ messages in thread

From: Tom Lane @ 2011-03-16 17:01 UTC (permalink / raw)
  To: Kevin Grittner <Kevin.Grittner@wicourts.gov>; +Cc: Timothy Garnett <tgarnett@panjiva.com>; pgsql-performance

"Kevin Grittner" <Kevin.Grittner@wicourts.gov> writes:
> Timothy Garnett <tgarnett@panjiva.com> wrote:
> ->  Index Scan Backward using
> index_customs_records_on_month_and_bl_number on customs_records
> (cost=0.00..78426750.74 rows=48623 width=908) (actual
> time=171344.182..3858893.588 rows=100 loops=1)
 
> We've seen a lot of those lately -- Index Scan Backward performing
> far worse than alternatives.

It's not clear to me that that has anything to do with Tim's problem.
It certainly wouldn't be 20000x faster if it were a forward scan.

> One part of it is that disk sectors
> are arranged for optimal performance on forward scans; but I don't
> think we've properly accounted for the higher cost of moving
> backward through our btree indexes, either.  To quote from the
> README for the btree AM:
 
> | A backwards scan has one additional bit of complexity: after
> | following the left-link we must account for the possibility that
> | the left sibling page got split before we could read it.  So, we
> | have to move right until we find a page whose right-link matches
> | the page we came from.  (Actually, it's even harder than that; see
> | deletion discussion below.)

That's complicated, but it's not slow, except in the extremely
infrequent case where there actually was an index page split while your
scan was in flight to the page.  The normal code path will only spend
one extra comparison to verify that no such split happened, and then it
goes on about its business.

The point about disk page layout is valid, so I could believe that in
a recently-built index there might be a significant difference in
forward vs backward scan speed, if none of the index were in memory.
The differential would degrade pretty rapidly due to page splits though
...

			regards, tom lane



^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3
  2011-03-15 18:23 Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Timothy Garnett <tgarnett@panjiva.com>
@ 2011-03-16 17:05 ` Shaun Thomas <sthomas@peak6.com>
  2011-03-16 17:38   ` Re: Adding additional index causes 20, 000x slowdown for certain select queries - postgres 9.0.3 Tom Lane <tgl@sss.pgh.pa.us>
  2011-03-17 16:55   ` Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Timothy Garnett <tgarnett@panjiva.com>
  1 sibling, 2 replies; 15+ messages in thread

From: Shaun Thomas @ 2011-03-16 17:05 UTC (permalink / raw)
  To: Timothy Garnett <tgarnett@panjiva.com>; +Cc: pgsql-performance

On 03/15/2011 01:23 PM, Timothy Garnett wrote:

>           Column          |          Type
> --------------------------+------------------------+
>  id                       | integer                |
>  bl_number                | character varying(16)  |
>  month                    | date                   |
>  buyer_id                 | integer                |
>  supplier_id              | integer                |

Ok. In your table description, you don't really talk about the 
distribution of bl_number. But this part of your query:

ORDER BY month DESC LIMIT 100 OFFSET 0

Is probably tricking the planner into using that index. But there's the 
fun thing about dates: we almost always want them in order of most 
recent to least recent. So you might want to try again with your 
index_customs_records_on_month_and_bl_number declared like this instead:

CREATE INDEX index_customs_records_on_month_and_bl_number
     ON customs_records (month DESC, bl_number);

Or, if bl_number is more selective anyway, but you need both columns for 
other queries and you want this one to ignore it:

CREATE INDEX index_customs_records_on_month_and_bl_number
     ON customs_records (bl_number, month DESC);

Either way, I bet you'll find that your other queries that use this 
index are also doing a backwards index scan, which will always be slower 
by about two orders of magnitude, since backwards reads act basically 
like random reads.

The effect you're getting is clearly exaggerated, and I've run into it 
on occasion for effectively the entire history of PostgreSQL. Normally 
increasing the statistics on the affected columns and re-analyzing fixes 
it, but on a composite index, that won't necessarily be the case.

-- 
Shaun Thomas
OptionsHouse | 141 W. Jackson Blvd. | Suite 800 | Chicago IL, 60604
312-676-8870
sthomas@peak6.com

______________________________________________

See  http://www.peak6.com/email_disclaimer.php
for terms and conditions related to this email



^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: Adding additional index causes 20, 000x slowdown for certain select queries - postgres 9.0.3
  2011-03-15 18:23 Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Timothy Garnett <tgarnett@panjiva.com>
  2011-03-16 17:05 ` Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Shaun Thomas <sthomas@peak6.com>
@ 2011-03-16 17:38   ` Tom Lane <tgl@sss.pgh.pa.us>
  2011-04-18 16:51     ` Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Robert Haas <robertmhaas@gmail.com>
  1 sibling, 1 reply; 15+ messages in thread

From: Tom Lane @ 2011-03-16 17:38 UTC (permalink / raw)
  To: sthomas@peak6.com; +Cc: Timothy Garnett <tgarnett@panjiva.com>; pgsql-performance

Shaun Thomas <sthomas@peak6.com> writes:
> Ok. In your table description, you don't really talk about the 
> distribution of bl_number. But this part of your query:

> ORDER BY month DESC LIMIT 100 OFFSET 0

> Is probably tricking the planner into using that index. But there's the 
> fun thing about dates: we almost always want them in order of most 
> recent to least recent. So you might want to try again with your 
> index_customs_records_on_month_and_bl_number declared like this instead:

> CREATE INDEX index_customs_records_on_month_and_bl_number
>      ON customs_records (month DESC, bl_number);

That isn't going to dissuade the planner from using that index for this
query.  It would result in the scan being a forward indexscan instead of
backwards.  Now it'd be worth trying that, to see if you and Kevin are
right that it's the backwards aspect that's hurting.  I'm not convinced
though.  I suspect the issue is that the planner is expecting the target
records (the ones selected by the filter condition) to be approximately
equally distributed in the month ordering, but really there is a
correlation which causes them to be much much further back in the index
than it expects.  So a lot more of the index has to be scanned than it's
expecting.

> Or, if bl_number is more selective anyway, but you need both columns for 
> other queries and you want this one to ignore it:

> CREATE INDEX index_customs_records_on_month_and_bl_number
>      ON customs_records (bl_number, month DESC);

Flipping bl_number around to the front would prevent this index from
being used in this way, but it might also destroy the usefulness of the
index for its intended purpose.  Tim didn't show us the queries he
wanted this index for, so it's hard to say if he can fix it by
redefining the index or not.

			regards, tom lane



^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3
  2011-03-15 18:23 Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Timothy Garnett <tgarnett@panjiva.com>
  2011-03-16 17:05 ` Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Shaun Thomas <sthomas@peak6.com>
  2011-03-16 17:38   ` Re: Adding additional index causes 20, 000x slowdown for certain select queries - postgres 9.0.3 Tom Lane <tgl@sss.pgh.pa.us>
@ 2011-04-18 16:51     ` Robert Haas <robertmhaas@gmail.com>
  0 siblings, 0 replies; 15+ messages in thread

From: Robert Haas @ 2011-04-18 16:51 UTC (permalink / raw)
  To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: sthomas@peak6.com, Timothy Garnett <tgarnett@panjiva.com>; pgsql-performance

On Wed, Mar 16, 2011 at 1:38 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> That isn't going to dissuade the planner from using that index for this
> query.  It would result in the scan being a forward indexscan instead of
> backwards.  Now it'd be worth trying that, to see if you and Kevin are
> right that it's the backwards aspect that's hurting.  I'm not convinced
> though.  I suspect the issue is that the planner is expecting the target
> records (the ones selected by the filter condition) to be approximately
> equally distributed in the month ordering, but really there is a
> correlation which causes them to be much much further back in the index
> than it expects.  So a lot more of the index has to be scanned than it's
> expecting.

This has got to be one of the five most frequently reported planner
problems, and it's nearly always with a *backward* index scan.  So I
agree with Kevin that we probably ought to have a Todo to make
backward index scans look more expensive than forward index scans,
maybe related in some way to the correlation estimates for the
relevant columns.

But I don't really think that's the root of the problem.  When
confronted with this type of query, you can either filter-then-sort,
or index-scan-in-desired-order-then-filter.  I think the heart of the
problem is that we're able to estimate the cost of the first plan much
more accurately than the cost of the second one.  In many cases, the
filter is done using a sequential scan, which is easy to cost, and
even if it's done using a bitmap index scan the cost of that is also
pretty simple to estimate, as long as our selectivity estimate is
somewhere in the ballpark.  The cost of the sort depends primarily on
how many rows we need to sort, and if the qual is something like an
equality condition, as in this case, then we'll know that pretty
accurately as well.  So we're good.

On the other hand, when we use an index scan to get the rows in order,
and then apply the filter condition to them, the cost of the index
scan is heavily dependent on how far we have to scan through the
index, and that depends on the distribution of values in the qual
column relative to the distribution of values in the index column.  We
have no data that allow us to estimate that, so we are basically
shooting in the dark.  This is a multi-column statistics problem, but
I think it's actually harder than what we usually mean by multi-column
statistics, where we only need to estimate selectivity.  A system that
can perfectly estimate the selectivity of state = $1 and zipcode = $2
might still be unable to tell us much about how many zipcodes we'd
have to read in ascending order to find a given number in some
particular state.

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company



^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3
  2011-03-15 18:23 Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Timothy Garnett <tgarnett@panjiva.com>
  2011-03-16 17:05 ` Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Shaun Thomas <sthomas@peak6.com>
@ 2011-03-17 16:55   ` Timothy Garnett <tgarnett@panjiva.com>
  2011-03-17 18:13     ` Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Kevin Grittner <Kevin.Grittner@wicourts.gov>
  1 sibling, 1 reply; 15+ messages in thread

From: Timothy Garnett @ 2011-03-17 16:55 UTC (permalink / raw)
  To: sthomas@peak6.com; +Cc: pgsql-performance

Hi all,

The bl_number is nearly a unique value per a row (some small portion are
duplicated on a handful or rows).

We need the unique on pair of bl_number and month, but evaluating current
usage we don't make use of selecting on just month currently (though we
expect to have usage scenarios that do that in the not too distant future,
i.e. pulling out all the records that match a given month date).  But for
the time being we've gone with the suggestion here of flipping the order of
the index columns to (bl_number, month) which rescues the original
performance (since the new index can no longer be used with the query).

We'd still be interested in other suggestions for convincing the query
planner not to pick the bad plan in this case (since we'll eventually need
an index on month) without having to use the slower CTE form.  To me the
problem seems two fold,
 (1) planner doesn't know there's a correlation between month and particular
buyer_ids (some are randomly distributed across month)
 (2) even in cases where there isn't a correlation (not all of our buyer
id's are correlated with month) it still seems really surprising to me the
planner thought this plan would be faster, the estimated selectivity of the
buyer fields is 48k / 45million ~ 1/1000 so for limit 100 it should expect
to backward index scan ~100K rows, vs. looking up the expected 48k rows and
doing a top-100 sort on them, I'd expect the latter plan to be faster in
almost all situations (unless we're clustered on month perhaps, but we're
actually clustered on supplier_id, buyer_id which would favor the latter
plan as well I'd think).

(an aside) there's also likely some benefit from clustering in the original
plan before the new index, since we cluster on supplier_id, buyer_id and a
given buyer_id while having up to 100k rows will generally only have a few
supplier ids

Tim

On Wed, Mar 16, 2011 at 1:05 PM, Shaun Thomas <sthomas@peak6.com> wrote:

> On 03/15/2011 01:23 PM, Timothy Garnett wrote:
>
>           Column          |          Type
>> --------------------------+------------------------+
>>  id                       | integer                |
>>
>>  bl_number                | character varying(16)  |
>>  month                    | date                   |
>>  buyer_id                 | integer                |
>>  supplier_id              | integer                |
>>
>
> Ok. In your table description, you don't really talk about the distribution
> of bl_number. But this part of your query:
>
>
> ORDER BY month DESC LIMIT 100 OFFSET 0
>
> Is probably tricking the planner into using that index. But there's the fun
> thing about dates: we almost always want them in order of most recent to
> least recent. So you might want to try again with your
> index_customs_records_on_month_and_bl_number declared like this instead:
>
> CREATE INDEX index_customs_records_on_month_and_bl_number
>    ON customs_records (month DESC, bl_number);
>
> Or, if bl_number is more selective anyway, but you need both columns for
> other queries and you want this one to ignore it:
>
> CREATE INDEX index_customs_records_on_month_and_bl_number
>    ON customs_records (bl_number, month DESC);
>
> Either way, I bet you'll find that your other queries that use this index
> are also doing a backwards index scan, which will always be slower by about
> two orders of magnitude, since backwards reads act basically like random
> reads.
>
> The effect you're getting is clearly exaggerated, and I've run into it on
> occasion for effectively the entire history of PostgreSQL. Normally
> increasing the statistics on the affected columns and re-analyzing fixes it,
> but on a composite index, that won't necessarily be the case.
>
> --
> Shaun Thomas
> OptionsHouse | 141 W. Jackson Blvd. | Suite 800 | Chicago IL, 60604
> 312-676-8870
> sthomas@peak6.com
>
> ______________________________________________
>
> See  http://www.peak6.com/email_disclaimer.php
> for terms and conditions related to this email
>

^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3
  2011-03-15 18:23 Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Timothy Garnett <tgarnett@panjiva.com>
  2011-03-16 17:05 ` Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Shaun Thomas <sthomas@peak6.com>
  2011-03-17 16:55   ` Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Timothy Garnett <tgarnett@panjiva.com>
@ 2011-03-17 18:13     ` Kevin Grittner <Kevin.Grittner@wicourts.gov>
  2011-03-17 20:33       ` Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Timothy Garnett <tgarnett@panjiva.com>
  0 siblings, 1 reply; 15+ messages in thread

From: Kevin Grittner @ 2011-03-17 18:13 UTC (permalink / raw)
  To: Timothy Garnett <tgarnett@panjiva.com>; sthomas@peak6.com; +Cc: pgsql-performance

Timothy Garnett <tgarnett@panjiva.com> wrote:
 
> We'd still be interested in other suggestions for convincing the
> query planner not to pick the bad plan in this case
 
You could try boosting cpu_tuple_cost.  I've seen some evidence that
the default number is a bit low in general, so it wouldn't
necessarily be bad to try your whole load with a higher setting.  If
that doesn't work you could set it for the one query.  If that
setting alone doesn't do it, you could either decrease both page
cost numbers or multiply all the cpu numbers (again, probably
boosting cpu_tuple_cost relative to the others).
 
-Kevin



^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3
  2011-03-15 18:23 Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Timothy Garnett <tgarnett@panjiva.com>
  2011-03-16 17:05 ` Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Shaun Thomas <sthomas@peak6.com>
  2011-03-17 16:55   ` Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Timothy Garnett <tgarnett@panjiva.com>
  2011-03-17 18:13     ` Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Kevin Grittner <Kevin.Grittner@wicourts.gov>
@ 2011-03-17 20:33       ` Timothy Garnett <tgarnett@panjiva.com>
  0 siblings, 0 replies; 15+ messages in thread

From: Timothy Garnett @ 2011-03-17 20:33 UTC (permalink / raw)
  To: Kevin Grittner <Kevin.Grittner@wicourts.gov>; +Cc: pgsql-performance

Thanks, we'll give these a try.

Tim

On Thu, Mar 17, 2011 at 2:13 PM, Kevin Grittner <Kevin.Grittner@wicourts.gov
> wrote:

> Timothy Garnett <tgarnett@panjiva.com> wrote:
>
> > We'd still be interested in other suggestions for convincing the
> > query planner not to pick the bad plan in this case
>
> You could try boosting cpu_tuple_cost.  I've seen some evidence that
> the default number is a bit low in general, so it wouldn't
> necessarily be bad to try your whole load with a higher setting.  If
> that doesn't work you could set it for the one query.  If that
> setting alone doesn't do it, you could either decrease both page
> cost numbers or multiply all the cpu numbers (again, probably
> boosting cpu_tuple_cost relative to the others).
>
> -Kevin
>

^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3
@ 2011-03-16 17:44 Kevin Grittner <Kevin.Grittner@wicourts.gov>
  2011-03-16 18:34 ` Re: Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Shaun Thomas <sthomas@peak6.com>
  0 siblings, 1 reply; 15+ messages in thread

From: Kevin Grittner @ 2011-03-16 17:44 UTC (permalink / raw)
  To: tgl@sss.pgh.pa.us; +Cc: tgarnett@panjiva.com; pgsql-performance

Tom Lane <tgl@sss.pgh.pa.us> wrote:
> "Kevin Grittner" <Kevin.Grittner@wicourts.gov> writes:
 
>> We've seen a lot of those lately -- Index Scan Backward
>> performing far worse than alternatives.
> 
> It's not clear to me that that has anything to do with Tim's
> problem.  It certainly wouldn't be 20000x faster if it were a
> forward scan.
 
Well, that's one way of looking at it.  Another would be that the
slower plan with the backward scan was only estimated to be 14.5%
less expensive than the fast plan, so a pretty moderate modifier
would have avoided this particular problem.  The fact that the
backward scan mis-estimate may be combining multiplicatively with
other mis-estimates doesn't make it less important.
 
-Kevin




^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3
  2011-03-16 17:44 Re: Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Kevin Grittner <Kevin.Grittner@wicourts.gov>
@ 2011-03-16 18:34 ` Shaun Thomas <sthomas@peak6.com>
  2011-03-16 18:39   ` Re: Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Claudio Freire <klaussfreire@gmail.com>
  0 siblings, 1 reply; 15+ messages in thread

From: Shaun Thomas @ 2011-03-16 18:34 UTC (permalink / raw)
  To: Kevin Grittner <Kevin.Grittner@wicourts.gov>; +Cc: tgl@sss.pgh.pa.us <tgl@sss.pgh.pa.us>; tgarnett@panjiva.com <tgarnett@panjiva.com>; pgsql-performance

On 03/16/2011 12:44 PM, Kevin Grittner wrote:

> Well, that's one way of looking at it.  Another would be that the
> slower plan with the backward scan was only estimated to be 14.5%
> less expensive than the fast plan, so a pretty moderate modifier
> would have avoided this particular problem.

I was wondering about that myself. Considering any backwards scan would 
necessarily be 10-100x slower than a forward scan unless the data was on 
an SSD, I assumed the planner was already using a multiplier to 
discourage its use.

If not, it seems like a valid configurable. We set our random_page_cost 
to 1.5 once the DB was backed by NVRAM. I could see that somehow 
influencing precedence of a backwards index scan. But even then, SSDs 
and their ilk react more like RAM than even a large RAID... so should 
there be a setting that passes such useful info to the planner?

Maybe a good attribute to associate with the tablespace, if nothing else.

-- 
Shaun Thomas
OptionsHouse | 141 W. Jackson Blvd. | Suite 800 | Chicago IL, 60604
312-676-8870
sthomas@peak6.com

______________________________________________

See  http://www.peak6.com/email_disclaimer.php
for terms and conditions related to this email



^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3
  2011-03-16 17:44 Re: Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Kevin Grittner <Kevin.Grittner@wicourts.gov>
  2011-03-16 18:34 ` Re: Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Shaun Thomas <sthomas@peak6.com>
@ 2011-03-16 18:39   ` Claudio Freire <klaussfreire@gmail.com>
  2011-03-16 19:42     ` Re: Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Kevin Grittner <Kevin.Grittner@wicourts.gov>
  0 siblings, 1 reply; 15+ messages in thread

From: Claudio Freire @ 2011-03-16 18:39 UTC (permalink / raw)
  To: pgsql-performance

On Wed, Mar 16, 2011 at 3:34 PM, Shaun Thomas <sthomas@peak6.com> wrote:
> If not, it seems like a valid configurable. We set our random_page_cost to
> 1.5 once the DB was backed by NVRAM. I could see that somehow influencing
> precedence of a backwards index scan. But even then, SSDs and their ilk
> react more like RAM than even a large RAID... so should there be a setting
> that passes such useful info to the planner?

Forgive the naive question...
but...

Aren't all index scans, forward or backward, random IO?



^ permalink  raw  reply  [nested|flat] 15+ messages in thread

* Re: Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3
  2011-03-16 17:44 Re: Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Kevin Grittner <Kevin.Grittner@wicourts.gov>
  2011-03-16 18:34 ` Re: Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Shaun Thomas <sthomas@peak6.com>
  2011-03-16 18:39   ` Re: Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Claudio Freire <klaussfreire@gmail.com>
@ 2011-03-16 19:42     ` Kevin Grittner <Kevin.Grittner@wicourts.gov>
  0 siblings, 0 replies; 15+ messages in thread

From: Kevin Grittner @ 2011-03-16 19:42 UTC (permalink / raw)
  To: Claudio Freire <klaussfreire@gmail.com>; pgsql-performance

Claudio Freire <klaussfreire@gmail.com> wrote:
 
> Forgive the naive question...
> but...
> 
> Aren't all index scans, forward or backward, random IO?
 
No.  Some could approach that; but, for example, an index scan
immediately following a CLUSTER on the index would be totally
sequential on the heap file access and would tend to be fairly close
to sequential on the index itself.  It would certainly trigger OS
level read-ahead for the heap, and quite possibly for the index.  So
for a lot of pages, the difference might be between copying a page
from the OS cache to the database cache versus a random disk seek.
 
To a lesser degree than CLUSTER you could get some degree of
sequencing from a bulk load or even from normal data insert
patterns.  Consider a primary key which is sequentially assigned, or
a timestamp column, or receipt numbers, etc.
 
As Tom points out, some usage patterns may scramble this natural
order pretty quickly.  Some won't.
 
-Kevin



^ permalink  raw  reply  [nested|flat] 15+ messages in thread


end of thread, other threads:[~2011-04-18 16:51 UTC | newest]

Thread overview: 15+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2011-03-15 18:23 Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Timothy Garnett <tgarnett@panjiva.com>
2011-03-15 18:39 ` Timothy Garnett <tgarnett@panjiva.com>
2011-03-15 18:42   ` Timothy Garnett <tgarnett@panjiva.com>
2011-03-16 16:40     ` Kevin Grittner <Kevin.Grittner@wicourts.gov>
2011-03-16 17:01       ` Re: Re: Adding additional index causes 20, 000x slowdown for certain select queries - postgres 9.0.3 Tom Lane <tgl@sss.pgh.pa.us>
2011-03-16 17:05 ` Shaun Thomas <sthomas@peak6.com>
2011-03-16 17:38   ` Re: Adding additional index causes 20, 000x slowdown for certain select queries - postgres 9.0.3 Tom Lane <tgl@sss.pgh.pa.us>
2011-04-18 16:51     ` Robert Haas <robertmhaas@gmail.com>
2011-03-17 16:55   ` Timothy Garnett <tgarnett@panjiva.com>
2011-03-17 18:13     ` Kevin Grittner <Kevin.Grittner@wicourts.gov>
2011-03-17 20:33       ` Timothy Garnett <tgarnett@panjiva.com>
2011-03-16 17:44 Re: Re: Adding additional index causes 20,000x slowdown for certain select queries - postgres 9.0.3 Kevin Grittner <Kevin.Grittner@wicourts.gov>
2011-03-16 18:34 ` Shaun Thomas <sthomas@peak6.com>
2011-03-16 18:39   ` Claudio Freire <klaussfreire@gmail.com>
2011-03-16 19:42     ` Kevin Grittner <Kevin.Grittner@wicourts.gov>

This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox