Thread: Increasing pattern index query speed
Both queries return same result (19) and return same data.
Pattern query is a much slower (93 sec) than equality check (13 sec).
How to fix this ?
Using 8.1.4, utf-8 encoding, et-EE locale.
Andrus.
SELECT sum(1)
FROM dok JOIN rid USING (dokumnr)
JOIN toode USING (toode)
WHERE rid.toode = '99000010' AND dok.kuupaev BETWEEN '2008-11-21' AND
'2008-11-21'
AND dok.yksus LIKE 'ORISSAARE%'
"Aggregate (cost=43.09..43.10 rows=1 width=0) (actual
time=12674.675..12674.679 rows=1 loops=1)"
" -> Nested Loop (cost=29.57..43.08 rows=1 width=0) (actual
time=2002.045..12673.645 rows=19 loops=1)"
" -> Nested Loop (cost=29.57..37.06 rows=1 width=24) (actual
time=2001.922..12672.344 rows=19 loops=1)"
" -> Index Scan using dok_kuupaev_idx on dok (cost=0.00..3.47
rows=1 width=4) (actual time=342.812..9810.627 rows=319 loops=1)"
" Index Cond: ((kuupaev >= '2008-11-21'::date) AND
(kuupaev <= '2008-11-21'::date))"
" Filter: (yksus ~~ 'ORISSAARE%'::text)"
" -> Bitmap Heap Scan on rid (cost=29.57..33.58 rows=1
width=28) (actual time=8.948..8.949 rows=0 loops=319)"
" Recheck Cond: (("outer".dokumnr = rid.dokumnr) AND
(rid.toode = '99000010'::bpchar))"
" -> BitmapAnd (cost=29.57..29.57 rows=1 width=0)
(actual time=8.930..8.930 rows=0 loops=319)"
" -> Bitmap Index Scan on rid_dokumnr_idx
(cost=0.00..2.52 rows=149 width=0) (actual time=0.273..0.273 rows=2
loops=319)"
" Index Cond: ("outer".dokumnr =
rid.dokumnr)"
" -> Bitmap Index Scan on rid_toode_idx
(cost=0.00..26.79 rows=1941 width=0) (actual time=8.596..8.596 rows=15236
loops=319)"
" Index Cond: (toode = '99000010'::bpchar)"
" -> Index Scan using toode_pkey on toode (cost=0.00..6.01 rows=1
width=24) (actual time=0.043..0.048 rows=1 loops=19)"
" Index Cond: ('99000010'::bpchar = toode)"
"Total runtime: 12675.191 ms"
explain analyze SELECT sum(1)
FROM dok JOIN rid USING (dokumnr)
JOIN toode USING (toode)
WHERE rid.toode like '99000010%' AND dok.kuupaev BETWEEN '2008-11-21' AND
'2008-11-21'
AND dok.yksus LIKE 'ORISSAARE%'
"Aggregate (cost=15.52..15.53 rows=1 width=0) (actual
time=92966.501..92966.505 rows=1 loops=1)"
" -> Nested Loop (cost=0.00..15.52 rows=1 width=0) (actual
time=24082.032..92966.366 rows=19 loops=1)"
" -> Nested Loop (cost=0.00..9.50 rows=1 width=24) (actual
time=24081.919..92965.116 rows=19 loops=1)"
" Join Filter: ("outer".dokumnr = "inner".dokumnr)"
" -> Index Scan using dok_kuupaev_idx on dok (cost=0.00..3.47
rows=1 width=4) (actual time=0.203..13924.324 rows=319 loops=1)"
" Index Cond: ((kuupaev >= '2008-11-21'::date) AND
(kuupaev <= '2008-11-21'::date))"
" Filter: (yksus ~~ 'ORISSAARE%'::text)"
" -> Index Scan using rid_toode_pattern_idx on rid
(cost=0.00..6.01 rows=1 width=28) (actual time=0.592..166.778 rows=15235
loops=319)"
" Index Cond: ((toode ~>=~ '99000010'::bpchar) AND (toode
~<~ '99000011'::bpchar))"
" Filter: (toode ~~ '99000010%'::text)"
" -> Index Scan using toode_pkey on toode (cost=0.00..6.01 rows=1
width=24) (actual time=0.041..0.046 rows=1 loops=19)"
" Index Cond: ("outer".toode = toode.toode)"
"Total runtime: 92967.512 ms"
Andrus wrote: > Both queries return same result (19) and return same data. > Pattern query is a much slower (93 sec) than equality check (13 sec). > How to fix this ? > Using 8.1.4, utf-8 encoding, et-EE locale They're different queries. The fact that they return the same results is a coincidence. This > WHERE rid.toode = '99000010' Is a different condition to this > WHERE rid.toode like '99000010%' You aren't going to get the same plans. Anyway, I think the problem is in the dok JOIN rid bit look: > "Aggregate (cost=43.09..43.10 rows=1 width=0) (actual > time=12674.675..12674.679 rows=1 loops=1)" > " -> Nested Loop (cost=29.57..43.08 rows=1 width=0) (actual > time=2002.045..12673.645 rows=19 loops=1)" > " -> Nested Loop (cost=29.57..37.06 rows=1 width=24) (actual > time=2001.922..12672.344 rows=19 loops=1)" > "Aggregate (cost=15.52..15.53 rows=1 width=0) (actual > time=92966.501..92966.505 rows=1 loops=1)" > " -> Nested Loop (cost=0.00..15.52 rows=1 width=0) (actual > time=24082.032..92966.366 rows=19 loops=1)" > " -> Nested Loop (cost=0.00..9.50 rows=1 width=24) (actual > time=24081.919..92965.116 rows=19 loops=1)" These are the same but the times are different. I'd be very surprised if you can reproduce these times reliably. Can I give you some wider-ranging suggestions Andrus? 1. Fix the vacuuming issue in your hash-join question. 2. Monitor the system to make sure you know if/when disk activity is high. 3. *Then* start to profile individual queries and look into their plans. Change the queries one at a time and monitor again. Otherwise, it's very difficult to figure out whether changes you make are effective. HTH -- Richard Huxton Archonet Ltd
Richard,
> These are the same but the times are different. I'd be very surprised if
> you can reproduce these times reliably.
I re-tried today again and got same results: in production database pattern
query is many times slower that equality query.
toode and rid base contain only single product starting with 99000010
So both queries should scan exactly same numbers of rows.
> Can I give you some wider-ranging suggestions Andrus?
> 1. Fix the vacuuming issue in your hash-join question.
I have ran VACUUM FULL VERBOSE ANALYSE and set max_fsm_pages=150000
So issue is fixed before those tests.
> 2. Monitor the system to make sure you know if/when disk activity is high.
I optimized this system. Now there are short (some seconds) sales queries
about after every 5 - 300 seconds which cause few disk activity and add few
new rows to some tables.
I havent seen that this activity affects to this test result.
> 3. *Then* start to profile individual queries and look into their plans.
> Change the queries one at a time and monitor again.
How to change pattern matching query to faster ?
Andrus.
Btw.
I tried to reproduce this big difference in test server in 8.3 using sample
data script below and got big difference but in opposite direction.
explain analyze SELECT sum(1)
FROM orders
JOIN orders_products USING (order_id)
JOIN products USING (product_id)
WHERE orders.order_date>'2006-01-01' and ...
different where clauses produce different results:
AND orders_products.product_id = '3370000000000000' -- 880 .. 926 ms
AND orders_products.product_id like '3370000000000000%' -- 41 ..98 ms
So patter index is 10 .. 20 times (!) faster always.
No idea why.
Test data creation script:
begin;
CREATE OR REPLACE FUNCTION Counter() RETURNS int IMMUTABLE AS
$_$
SELECT 3500000;
$_$ LANGUAGE SQL;
CREATE TEMP TABLE orders (order_id INTEGER NOT NULL, order_date DATE NOT
NULL);
CREATE TEMP TABLE products (product_id CHAR(20) NOT NULL, product_name
char(70) NOT NULL, quantity numeric(12,2) default 1);
CREATE TEMP TABLE orders_products (order_id INTEGER NOT NULL, product_id
CHAR(20),
id serial, price numeric(12,2) default 1 );
INSERT INTO products SELECT (n*power( 10,13))::INT8::CHAR(20),
'product number ' || n::TEXT FROM generate_series(0,13410) AS n;
INSERT INTO orders
SELECT n,'2005-01-01'::date + (4000.0 * n/Counter() * '1 DAY'::interval)
FROM generate_series(0, Counter()/3 ) AS n;
SET work_mem TO 2097151;
INSERT INTO orders_products SELECT
generate_series/3 as order_id,
( (1+ (generate_series % 13410))*power( 10,13))::INT8::CHAR(20) AS
product_id
FROM generate_series(1, Counter());
ALTER TABLE orders ADD PRIMARY KEY (order_id);
ALTER TABLE products ADD PRIMARY KEY (product_id);
ALTER TABLE orders_products ADD PRIMARY KEY (id);
ALTER TABLE orders_products ADD FOREIGN KEY (product_id) REFERENCES
products(product_id);
ALTER TABLE orders_products ADD FOREIGN KEY (order_id) REFERENCES
orders(order_id) ON DELETE CASCADE;
CREATE INDEX orders_date ON orders( order_date );
CREATE INDEX order_product_pattern_idx ON orders_products( product_id
bpchar_pattern_ops );
COMMIT;
SET work_mem TO DEFAULT;
ANALYZE;
Andrus,
My first thought on the query where a pattern being faster than the query with an exact value is that the planner does
nothave good enough statistics on that column. Without looking at the explain plans further, I would suggest trying
somethingsimple. The fact that it is fasster on 8.3 but slower on 8.1 may have to do with changes between versions, or
maysimply be due to luck in the statistics sampling.
See if increasing the statistics target on that column significantly does anything:
EXPLAIN (your query);
ALTER TABLE orders_products ALTER COLUMN product_id SET STATISTICS 2000;
ANALYZE orders_products;
EXPLAIN (your query);
2000 is simply a guess of mine for a value much larger than the default. This will generally make query planning
slowerbut the system will have a lot more data about that column and the distribution of data in it. This should help
stabilizethe query performance.
If this has an effect, the query plans will change.
Your question below really boils down to something more simple:
--Why is the most optimal query plan not chosen? This is usually due to either insufficient statistics or quirks in
howthe query planner works on a specific data set or with certain configuration options.
-----Original Message-----
From: pgsql-performance-owner@postgresql.org [mailto:pgsql-performance-owner@postgresql.org] On Behalf Of Andrus
Sent: Monday, November 24, 2008 12:34 PM
To: Richard Huxton
Cc: pgsql-performance@postgresql.org
Subject: Re: [PERFORM] Increasing pattern index query speed
Richard,
> These are the same but the times are different. I'd be very surprised if
> you can reproduce these times reliably.
I re-tried today again and got same results: in production database pattern
query is many times slower that equality query.
toode and rid base contain only single product starting with 99000010
So both queries should scan exactly same numbers of rows.
> Can I give you some wider-ranging suggestions Andrus?
> 1. Fix the vacuuming issue in your hash-join question.
I have ran VACUUM FULL VERBOSE ANALYSE and set max_fsm_pages=150000
So issue is fixed before those tests.
> 2. Monitor the system to make sure you know if/when disk activity is high.
I optimized this system. Now there are short (some seconds) sales queries
about after every 5 - 300 seconds which cause few disk activity and add few
new rows to some tables.
I havent seen that this activity affects to this test result.
> 3. *Then* start to profile individual queries and look into their plans.
> Change the queries one at a time and monitor again.
How to change pattern matching query to faster ?
Andrus.
Btw.
I tried to reproduce this big difference in test server in 8.3 using sample
data script below and got big difference but in opposite direction.
explain analyze SELECT sum(1)
FROM orders
JOIN orders_products USING (order_id)
JOIN products USING (product_id)
WHERE orders.order_date>'2006-01-01' and ...
different where clauses produce different results:
AND orders_products.product_id = '3370000000000000' -- 880 .. 926 ms
AND orders_products.product_id like '3370000000000000%' -- 41 ..98 ms
So patter index is 10 .. 20 times (!) faster always.
No idea why.
Test data creation script:
begin;
CREATE OR REPLACE FUNCTION Counter() RETURNS int IMMUTABLE AS
$_$
SELECT 3500000;
$_$ LANGUAGE SQL;
CREATE TEMP TABLE orders (order_id INTEGER NOT NULL, order_date DATE NOT
NULL);
CREATE TEMP TABLE products (product_id CHAR(20) NOT NULL, product_name
char(70) NOT NULL, quantity numeric(12,2) default 1);
CREATE TEMP TABLE orders_products (order_id INTEGER NOT NULL, product_id
CHAR(20),
id serial, price numeric(12,2) default 1 );
INSERT INTO products SELECT (n*power( 10,13))::INT8::CHAR(20),
'product number ' || n::TEXT FROM generate_series(0,13410) AS n;
INSERT INTO orders
SELECT n,'2005-01-01'::date + (4000.0 * n/Counter() * '1 DAY'::interval)
FROM generate_series(0, Counter()/3 ) AS n;
SET work_mem TO 2097151;
INSERT INTO orders_products SELECT
generate_series/3 as order_id,
( (1+ (generate_series % 13410))*power( 10,13))::INT8::CHAR(20) AS
product_id
FROM generate_series(1, Counter());
ALTER TABLE orders ADD PRIMARY KEY (order_id);
ALTER TABLE products ADD PRIMARY KEY (product_id);
ALTER TABLE orders_products ADD PRIMARY KEY (id);
ALTER TABLE orders_products ADD FOREIGN KEY (product_id) REFERENCES
products(product_id);
ALTER TABLE orders_products ADD FOREIGN KEY (order_id) REFERENCES
orders(order_id) ON DELETE CASCADE;
CREATE INDEX orders_date ON orders( order_date );
CREATE INDEX order_product_pattern_idx ON orders_products( product_id
bpchar_pattern_ops );
COMMIT;
SET work_mem TO DEFAULT;
ANALYZE;
--
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
Andrus wrote:
>
> So patter index is 10 .. 20 times (!) faster always.
> No idea why.
Because you don't have a normal index on the product_id column? You
can't use xxx_pattern_ops indexes for non-pattern tests.
> Test data creation script:
The only change to the script was the obvious char(nn) => varchar(nn)
and I didn't use TEMP tables (so I could see what I was doing). Then, I
created the "standard" index on order_products.product_id.
EXPLAIN ANALYSE from my slow dev box are listed below. Database is in
LATIN9 encoding with locale=C.
QUERY PLAN
------------------------------------------------------------------------------------------------------------------------------------------------------------
Aggregate (cost=2993.69..2993.70 rows=1 width=0) (actual
time=2.960..2.960 rows=1 loops=1)
-> Nested Loop (cost=10.81..2993.23 rows=182 width=0) (actual
time=0.972..2.901 rows=189 loops=1)
-> Index Scan using products_pkey on products
(cost=0.00..8.27 rows=1 width=18) (actual time=0.017..0.019 rows=1 loops=1)
Index Cond: ((product_id)::text = '3370000000000000'::text)
-> Nested Loop (cost=10.81..2983.14 rows=182 width=18)
(actual time=0.951..2.785 rows=189 loops=1)
-> Bitmap Heap Scan on orders_products
(cost=10.81..942.50 rows=251 width=22) (actual time=0.296..0.771
rows=261 loops=1)
Recheck Cond: ((product_id)::text =
'3370000000000000'::text)
-> Bitmap Index Scan on
order_product_pattern_eq_idx (cost=0.00..10.75 rows=251 width=0)
(actual time=0.230..0.230 rows=261 loops=1)
Index Cond: ((product_id)::text =
'3370000000000000'::text)
-> Index Scan using orders_pkey on orders
(cost=0.00..8.12 rows=1 width=4) (actual time=0.006..0.007 rows=1 loops=261)
Index Cond: (orders.order_id =
orders_products.order_id)
Filter: (orders.order_date > '2006-01-01'::date)
Total runtime: 3.051 ms
(13 rows)
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------------------------
Aggregate (cost=25.56..25.57 rows=1 width=0) (actual time=8.244..8.245
rows=1 loops=1)
-> Nested Loop (cost=0.00..25.55 rows=1 width=0) (actual
time=1.170..8.119 rows=378 loops=1)
-> Nested Loop (cost=0.00..17.17 rows=1 width=4) (actual
time=0.043..4.167 rows=522 loops=1)
-> Index Scan using order_product_pattern_eq_idx on
orders_products (cost=0.00..8.88 rows=1 width=22) (actual
time=0.029..1.247 rows=522 loops=1)
Index Cond: (((product_id)::text >=
'3370000000000000'::text) AND ((product_id)::text <
'3370000000000001'::text))
Filter: ((product_id)::text ~~
'3370000000000000%'::text)
-> Index Scan using products_pkey on products
(cost=0.00..8.27 rows=1 width=18) (actual time=0.004..0.004 rows=1
loops=522)
Index Cond: ((products.product_id)::text =
(orders_products.product_id)::text)
-> Index Scan using orders_pkey on orders (cost=0.00..8.37
rows=1 width=4) (actual time=0.006..0.006 rows=1 loops=522)
Index Cond: (orders.order_id = orders_products.order_id)
Filter: (orders.order_date > '2006-01-01'::date)
Total runtime: 8.335 ms
(12 rows)
--
Richard Huxton
Archonet Ltd
Andrus schrieb:
> Richard,
>
>> These are the same but the times are different. I'd be very surprised if
>> you can reproduce these times reliably.
>
> I re-tried today again and got same results: in production database
> pattern query is many times slower that equality query.
> toode and rid base contain only single product starting with 99000010
> So both queries should scan exactly same numbers of rows.
>
>> Can I give you some wider-ranging suggestions Andrus?
>> 1. Fix the vacuuming issue in your hash-join question.
>
> I have ran VACUUM FULL VERBOSE ANALYSE and set max_fsm_pages=150000
> So issue is fixed before those tests.
>
>> 2. Monitor the system to make sure you know if/when disk activity is
>> high.
>
> I optimized this system. Now there are short (some seconds) sales
> queries about after every 5 - 300 seconds which cause few disk
> activity and add few new rows to some tables.
> I havent seen that this activity affects to this test result.
>
>> 3. *Then* start to profile individual queries and look into their plans.
>> Change the queries one at a time and monitor again.
>
> How to change pattern matching query to faster ?
>
> Andrus.
>
> Btw.
>
> I tried to reproduce this big difference in test server in 8.3 using
> sample data script below and got big difference but in opposite
> direction.
>
> explain analyze SELECT sum(1)
> FROM orders
> JOIN orders_products USING (order_id)
> JOIN products USING (product_id)
> WHERE orders.order_date>'2006-01-01' and ...
>
> different where clauses produce different results:
>
> AND orders_products.product_id = '3370000000000000' -- 880 .. 926 ms
> AND orders_products.product_id like '3370000000000000%' -- 41 ..98 ms
>
> So patter index is 10 .. 20 times (!) faster always.
> No idea why.
>
> Test data creation script:
>
> begin;
> CREATE OR REPLACE FUNCTION Counter() RETURNS int IMMUTABLE AS
> $_$
> SELECT 3500000;
> $_$ LANGUAGE SQL;
>
> CREATE TEMP TABLE orders (order_id INTEGER NOT NULL, order_date DATE
> NOT NULL);
> CREATE TEMP TABLE products (product_id CHAR(20) NOT NULL, product_name
> char(70) NOT NULL, quantity numeric(12,2) default 1);
> CREATE TEMP TABLE orders_products (order_id INTEGER NOT NULL,
> product_id CHAR(20),
> id serial, price numeric(12,2) default 1 );
>
> INSERT INTO products SELECT (n*power( 10,13))::INT8::CHAR(20),
> 'product number ' || n::TEXT FROM generate_series(0,13410) AS n;
>
> INSERT INTO orders
> SELECT n,'2005-01-01'::date + (4000.0 * n/Counter() * '1 DAY'::interval)
> FROM generate_series(0, Counter()/3 ) AS n;
>
> SET work_mem TO 2097151;
>
> INSERT INTO orders_products SELECT
> generate_series/3 as order_id,
> ( (1+ (generate_series % 13410))*power( 10,13))::INT8::CHAR(20) AS
> product_id
> FROM generate_series(1, Counter());
>
> ALTER TABLE orders ADD PRIMARY KEY (order_id);
> ALTER TABLE products ADD PRIMARY KEY (product_id);
> ALTER TABLE orders_products ADD PRIMARY KEY (id);
>
> ALTER TABLE orders_products ADD FOREIGN KEY (product_id) REFERENCES
> products(product_id);
> ALTER TABLE orders_products ADD FOREIGN KEY (order_id) REFERENCES
> orders(order_id) ON DELETE CASCADE;
>
> CREATE INDEX orders_date ON orders( order_date );
> CREATE INDEX order_product_pattern_idx ON orders_products( product_id
> bpchar_pattern_ops );
>
> COMMIT;
> SET work_mem TO DEFAULT;
> ANALYZE;
>
No wonder that = compares bad, you created the index this way:
CREATE INDEX order_product_pattern_idx ON orders_products( product_id
bpchar_pattern_ops );
why not:
CREATE INDEX order_product_pattern_idx ON orders_products( product_id);
explain analyze SELECT sum(1)
FROM orders
JOIN orders_products USING (order_id)
JOIN products USING (product_id)
WHERE orders.order_date>'2006-01-01'
AND orders_products.product_id = '3370000000000000';
QUERY
PLAN
-------------------------------------------------------------------------------------------------------------------------------------------
Aggregate (cost=3013.68..3013.69 rows=1 width=0) (actual
time=8.206..8.207 rows=1 loops=1)
-> Nested Loop (cost=10.83..3013.21 rows=185 width=0) (actual
time=2.095..7.962 rows=189 loops=1)
-> Index Scan using products_pkey on products
(cost=0.00..8.27 rows=1 width=18) (actual time=0.036..0.038 rows=1 loops=1)
Index Cond: ((product_id)::text = '3370000000000000'::text)
-> Nested Loop (cost=10.83..3003.09 rows=185 width=18)
(actual time=2.052..7.474 rows=189 loops=1)
-> Bitmap Heap Scan on orders_products
(cost=10.83..949.68 rows=253 width=22) (actual time=0.161..0.817
rows=261 loops=1)
Recheck Cond: ((product_id)::text =
'3370000000000000'::text)
-> Bitmap Index Scan on foo (cost=0.00..10.76
rows=253 width=0) (actual time=0.116..0.116 rows=261 loops=1)
Index Cond: ((product_id)::text =
'3370000000000000'::text)
-> Index Scan using orders_pkey on orders
(cost=0.00..8.10 rows=1 width=4) (actual time=0.020..0.021 rows=1 loops=261)
Index Cond: (orders.order_id =
orders_products.order_id)
Filter: (orders.order_date > '2006-01-01'::date)
Total runtime: 8.268 ms
Richard and Mario,
> You can't use xxx_pattern_ops indexes for non-pattern tests.
I missed regular index. Sorry for that. Now issue with testcase is solved.
Thank you very much.
I researched issue in live 8.1.4 db a bit more.
Performed vacuum and whole db reindex.
Tried several times to run two same pattern queries in quiet db.
additonal condition
AND dok.kuupaev BETWEEN date'2008-11-21' AND date'2008-11-21'
takes 239 seconds to run.
additonal condition
AND dok.kuupaev = date'2008-11-21'
takes 1 seconds.
Both query conditions are logically the same.
How to make BETWEEN query fast (real queries are running as between queries
over some date range)?
P.S. VACUUM issues warning that free space map 150000 is not sufficient,
160000 nodes reqired.
Two days ago after vacuum full there were 60000 used enties in FSM. No idea
why this occurs.
Andrus.
set search_path to firma2,public;
explain analyze SELECT sum(1)
FROM dok JOIN rid USING (dokumnr)
JOIN toode USING (toode)
WHERE rid.toode like '99000010%'
AND dok.kuupaev BETWEEN date'2008-11-21' AND date'2008-11-21'
"Aggregate (cost=17.86..17.87 rows=1 width=0) (actual
time=239346.647..239346.651 rows=1 loops=1)"
" -> Nested Loop (cost=0.00..17.85 rows=1 width=0) (actual
time=3429.715..239345.923 rows=108 loops=1)"
" -> Nested Loop (cost=0.00..11.84 rows=1 width=24) (actual
time=3429.666..239339.687 rows=108 loops=1)"
" Join Filter: ("outer".dokumnr = "inner".dokumnr)"
" -> Index Scan using dok_kuupaev_idx on dok (cost=0.00..5.81
rows=1 width=4) (actual time=0.028..13.341 rows=1678 loops=1)"
" Index Cond: ((kuupaev >= '2008-11-21'::date) AND
(kuupaev <= '2008-11-21'::date))"
" -> Index Scan using rid_toode_pattern_idx on rid
(cost=0.00..6.01 rows=1 width=28) (actual time=0.025..86.156 rows=15402
loops=1678)"
" Index Cond: ((toode ~>=~ '99000010'::bpchar) AND (toode
~<~ '99000011'::bpchar))"
" Filter: (toode ~~ '99000010%'::text)"
" -> Index Scan using toode_pkey on toode (cost=0.00..6.00 rows=1
width=24) (actual time=0.032..0.037 rows=1 loops=108)"
" Index Cond: ("outer".toode = toode.toode)"
"Total runtime: 239347.132 ms"
explain analyze SELECT sum(1)
FROM dok JOIN rid USING (dokumnr)
JOIN toode USING (toode)
WHERE rid.toode like '99000010%'
AND dok.kuupaev = date'2008-11-21'
"Aggregate (cost=17.86..17.87 rows=1 width=0) (actual time=707.028..707.032
rows=1 loops=1)"
" -> Nested Loop (cost=0.00..17.85 rows=1 width=0) (actual
time=60.890..706.460 rows=108 loops=1)"
" -> Nested Loop (cost=0.00..11.84 rows=1 width=24) (actual
time=60.848..701.908 rows=108 loops=1)"
" -> Index Scan using rid_toode_pattern_idx on rid
(cost=0.00..6.01 rows=1 width=28) (actual time=0.120..247.636 rows=15402
loops=1)"
" Index Cond: ((toode ~>=~ '99000010'::bpchar) AND (toode
~<~ '99000011'::bpchar))"
" Filter: (toode ~~ '99000010%'::text)"
" -> Index Scan using dok_dokumnr_idx on dok (cost=0.00..5.81
rows=1 width=4) (actual time=0.021..0.021 rows=0 loops=15402)"
" Index Cond: (dok.dokumnr = "outer".dokumnr)"
" Filter: (kuupaev = '2008-11-21'::date)"
" -> Index Scan using toode_pkey on toode (cost=0.00..6.00 rows=1
width=24) (actual time=0.021..0.026 rows=1 loops=108)"
" Index Cond: ("outer".toode = toode.toode)"
"Total runtime: 707.250 ms"
vmstat 5 output during running slower query:
procs -----------memory---------- ---swap-- -----io---- --system-- ----cpu----
r b swpd free buff cache si so bi bo in cs us sy id
wa
2 0 332 738552 0 1264832 0 0 4 1 1 11 6 1 83
10
1 0 332 738520 0 1264832 0 0 0 135 259 34 24 76 0
0
1 0 332 738488 0 1264832 0 0 0 112 263 42 24 76 0
0
1 0 332 738504 0 1264832 0 0 0 13 252 19 23 77 0
0
1 0 332 738528 0 1264832 0 0 0 31 255 26 26 74 0
0
1 0 332 738528 0 1264832 0 0 0 6 251 18 27 73 0
0
1 0 332 738544 0 1264856 0 0 5 22 254 25 27 73 0
0
1 0 332 737908 0 1264856 0 0 0 13 252 22 27 73 0
0
1 0 332 737932 0 1264856 0 0 0 2 251 18 23 77 0
0
1 0 332 737932 0 1264856 0 0 0 2 251 17 25 75 0
0
1 0 332 737932 0 1264856 0 0 0 4 252 19 25 75 0
0
1 0 332 737932 0 1264856 0 0 0 0 250 16 26 74 0
0
1 0 332 737932 0 1264856 0 0 0 8 252 19 26 74 0
0
1 0 332 737924 0 1264856 0 0 0 67 252 19 24 76 0
0
1 0 332 737900 0 1264856 0 0 0 13 258 37 25 75 0
0
1 0 332 737916 0 1264856 0 0 0 0 251 16 26 74 0
0
1 0 332 737932 0 1264856 0 0 0 2 251 18 26 74 0
0
1 1 332 736740 0 1264864 0 0 2 0 258 26 25 75 0
0
1 0 332 737716 0 1265040 0 0 10 91 267 60 28 72 0
0
1 0 332 737724 0 1265040 0 0 0 2 251 17 24 76 0
0
1 0 332 737732 0 1265044 0 0 1 219 288 128 24 76 0
0
r b swpd free buff cache si so bi bo in cs us sy id
wa
2 0 332 737732 0 1265044 0 0 0 20 255 25 23 77 0
0
1 0 332 737748 0 1265044 0 0 0 11 252 22 24 76 0
0
1 0 332 737748 0 1265044 0 0 0 0 250 16 24 76 0
0
1 0 332 737748 0 1265044 0 0 0 20 254 24 24 76 0
0
1 0 332 737740 0 1265044 0 0 0 87 252 20 26 74 0
0
1 0 332 737748 0 1265044 0 0 0 28 254 24 25 75 0
0
1 0 332 737748 0 1265052 0 0 2 6 251 18 27 73 0
0
1 0 332 737748 0 1265052 0 0 0 0 250 17 23 77 0
0
1 0 332 737748 0 1265052 0 0 0 2 251 17 26 74 0
0
1 0 332 737732 0 1265052 0 0 0 0 251 19 26 74 0
0
1 0 332 737732 0 1265052 0 0 0 1 251 17 25 75 0
0
1 0 332 737740 0 1265052 0 0 0 0 250 17 23 77 0
0
1 0 332 737748 0 1265052 0 0 0 0 250 16 24 76 0
0
1 0 332 737748 0 1265052 0 0 0 4 252 19 26 74 0
0
0 0 332 737740 0 1265052 0 0 0 0 252 20 12 37 51
0
0 0 332 737740 0 1265052 0 0 0 1 252 17 0 0
100 0 <-- query ends here probably
0 0 332 737740 0 1265052 0 0 0 4 251 18 0 0
100 0
0 0 332 734812 0 1265452 0 0 11 18 270 39 3 0 96
1
0 0 332 737172 0 1265632 0 0 18 153 261 35 1 0 98
1
0 0 332 737180 0 1265632 0 0 0 0 250 17 0 0
100 0
0 0 332 737188 0 1265632 0 0 0 0 251 16 0 0
100 0
Andrus wrote: > Richard and Mario, > >> You can't use xxx_pattern_ops indexes for non-pattern tests. > > I missed regular index. Sorry for that. Now issue with testcase is > solved. Thank you very much. > > I researched issue in live 8.1.4 db a bit more. > Performed vacuum and whole db reindex. > Tried several times to run two same pattern queries in quiet db. And the results were? > additonal condition One problem at a time. Let's get the pattern-matching speed problems on your live server sorted, then we can look at different queries. -- Richard Huxton Archonet Ltd
Scott,
>My first thought on the query where a pattern being faster than the query
>with an exact value is that the planner does not have good enough
>statistics on that column. Without looking at the explain plans further, I
>would suggest trying something simple. The fact that it is fasster on 8.3
>but slower on 8.1 may have to do with changes between versions, or may
>simply be due to luck in the statistics sampling.
>See if increasing the statistics target on that column significantly does
>anything:
>EXPLAIN (your query);
ALTER TABLE orders_products ALTER COLUMN product_id SET STATISTICS 2000;
ANALYZE orders_products;
EXPLAIN (your query);
>2000 is simply a guess of mine for a value much larger than the default.
>This will generally make query planning slower but the system will have a
>lot more data about that column and the distribution of data in it. This
>should help stabilize the query performance.
>If this has an effect, the query plans will change.
>Your question below really boils down to something more simple:
> --Why is the most optimal query plan not chosen? This is usually due to
> either insufficient statistics or quirks in how the query planner works on
> a specific data >set or with certain configuration options.
Thank you very much.
I found that AND dok.kuupaev = date'2008-11-21' runs fast but
AND dok.kuupaev BETWEEN date'2008-11-21' AND date'2008-11-21' runs very
slow.
explain SELECT sum(1)
FROM dok JOIN rid USING (dokumnr)
JOIN toode USING (toode)
WHERE rid.toode like '99000010%'
plan with default statistics:
"Aggregate (cost=17.86..17.87 rows=1 width=0)"
" -> Nested Loop (cost=0.00..17.85 rows=1 width=0)"
" -> Nested Loop (cost=0.00..11.84 rows=1 width=24)"
" Join Filter: ("outer".dokumnr = "inner".dokumnr)"
" -> Index Scan using dok_kuupaev_idx on dok (cost=0.00..5.81
rows=1 width=4)"
" Index Cond: ((kuupaev >= '2008-11-21'::date) AND
(kuupaev <= '2008-11-21'::date))"
" -> Index Scan using rid_toode_pattern_idx on rid
(cost=0.00..6.01 rows=1 width=28)"
" Index Cond: ((toode ~>=~ '99000010'::bpchar) AND (toode
~<~ '99000011'::bpchar))"
" Filter: (toode ~~ '99000010%'::text)"
" -> Index Scan using toode_pkey on toode (cost=0.00..6.00 rows=1
width=24)"
" Index Cond: ("outer".toode = toode.toode)"
after statistics is changed query runs fast ( 70 ... 1000 ms)
ALTER TABLE rid ALTER COLUMN toode SET STATISTICS 1000;
analyze rid;
explain analyze SELECT sum(1)
FROM dok JOIN rid USING (dokumnr)
JOIN toode USING (toode)
WHERE rid.toode like '99000010%'
AND dok.kuupaev BETWEEN date'2008-11-21' AND date'2008-11-21'
"Aggregate (cost=27.04..27.05 rows=1 width=0) (actual time=44.830..44.834
rows=1 loops=1)"
" -> Nested Loop (cost=0.00..27.04 rows=1 width=0) (actual
time=0.727..44.370 rows=108 loops=1)"
" -> Nested Loop (cost=0.00..21.02 rows=1 width=24) (actual
time=0.688..40.519 rows=108 loops=1)"
" -> Index Scan using dok_kuupaev_idx on dok (cost=0.00..5.81
rows=1 width=4) (actual time=0.027..8.094 rows=1678 loops=1)"
" Index Cond: ((kuupaev >= '2008-11-21'::date) AND
(kuupaev <= '2008-11-21'::date))"
" -> Index Scan using rid_dokumnr_idx on rid
(cost=0.00..15.20 rows=1 width=28) (actual time=0.011..0.011 rows=0
loops=1678)"
" Index Cond: ("outer".dokumnr = rid.dokumnr)"
" Filter: (toode ~~ '99000010%'::text)"
" -> Index Scan using toode_pkey on toode (cost=0.00..6.00 rows=1
width=24) (actual time=0.016..0.020 rows=1 loops=108)"
" Index Cond: ("outer".toode = toode.toode)"
"Total runtime: 45.050 ms"
It seems that you are genius.
I used 1000 since doc wrote that max value is 1000
Rid table contains 3.5millions rows, will increase 1 millions of rows per
year and is updated frequently, mostly by adding.
Is it OK to leave
SET STATISTICS 1000;
setting for this table this column or should I try to decrease it ?
Andrus.
Richard, > And the results were? Results are provided in bottom of the message to which you replied. > One problem at a time. Let's get the pattern-matching speed problems on > your live server sorted, then we can look at different queries. First message in this thread described the issue with query having additional condition AND dok.kuupaev BETWEEN '2008-11-21' AND '2008-11-21' It seems that this problem occurs when pattern matching and BETWEEN conditions are used in same query. According to Scott Garey great recommendation I added ALTER TABLE rid ALTER COLUMN toode SET STATISTICS 1000; This fixes testcase in live server, see my other message. Is it OK to run ALTER TABLE rid ALTER COLUMN toode SET STATISTICS 1000 in prod database or should I try to decrease 1000 to smaller value ? rid is big increasing table and is changed frequently, mostly by adding rows. Andrus.
Andrus wrote: > Richard, > >> And the results were? > > Results are provided in bottom of the message to which you replied. No - the explains there were contrasting a date test BETWEEN versus =. >> One problem at a time. Let's get the pattern-matching speed problems on >> your live server sorted, then we can look at different queries. > > First message in this thread described the issue with query having > additional condition > > AND dok.kuupaev BETWEEN '2008-11-21' AND '2008-11-21' Ah, I think I understand. The test case was *missing* this clause. > It seems that this problem occurs when pattern matching and BETWEEN > conditions are used in same query. > > According to Scott Garey great recommendation I added > > ALTER TABLE rid ALTER COLUMN toode SET STATISTICS 1000; > > This fixes testcase in live server, see my other message. > Is it OK to run > > ALTER TABLE rid ALTER COLUMN toode SET STATISTICS 1000 > > in prod database or should I try to decrease 1000 to smaller value ? > rid is big increasing table and is changed frequently, mostly by adding > rows. This will try to track the 1000 most-common values of "toode", whereas the default is to try to track the most common 10 values. Tracking more values means the planner has more accurate information but makes ANALYSE take longer to run, and also makes planning each query take slightly longer. Try 100, 200, 500 and see if they work *for a range of queries* - there's no point in having it much higher than it needs to be. -- Richard Huxton Archonet Ltd
> Is it OK to run > > ALTER TABLE rid ALTER COLUMN toode SET STATISTICS 1000 > > in prod database or should I try to decrease 1000 to smaller value ? > rid is big increasing table and is changed frequently, mostly by adding > rows. pgAdmin shows default_statistic_target value has its default value 10 in postgresql.conf file Andrus.
Richard, >> Results are provided in bottom of the message to which you replied. > > No - the explains there were contrasting a date test BETWEEN versus =. I changed rid.toode statitics target to 100: ALTER TABLE firma2.rid ALTER COLUMN toode SET STATISTICS 100; analyze firma2.rid; Analyze takes 3 seconds and testcase rans fast. I'm planning to monitor results by looking log file for queries which take longer than 10 seconds. Do you still need results ? If yes, which query and how many times should I run? > Ah, I think I understand. The test case was *missing* this clause. I added this clause to testcase. Also added char(70) colums containing padding characters to all three tables. Cannot still reproduce this issue in testcase in fast devel 8.3 notebook. In testcase order_products contains product_id values in a very regular order, maybe this affects the results. No idea how to use random() to generate random products for every order. Andrus.
Andrus wrote: > Richard, > >>> Results are provided in bottom of the message to which you replied. >> >> No - the explains there were contrasting a date test BETWEEN versus =. > > I changed rid.toode statitics target to 100: > > ALTER TABLE firma2.rid ALTER COLUMN toode SET STATISTICS 100; > analyze firma2.rid; > > Analyze takes 3 seconds and testcase rans fast. > I'm planning to monitor results by looking log file for queries which > take longer than 10 seconds. Sensible. I don't know if 10 seconds is the right value for your database, but there will be a point that filters out most of your traffic but still gives enough to find problems. > Do you still need results ? > If yes, which query and how many times should I run? If changing the statistics seems to help, you're not going to want to go back just to repeat tests. >> Ah, I think I understand. The test case was *missing* this clause. > > I added this clause to testcase. Also added char(70) colums containing > padding characters to all three tables. Cannot still reproduce this issue > in testcase in fast devel 8.3 notebook. > In testcase order_products contains product_id values in a very regular > order, maybe this affects the results. No idea how to use random() to > generate random > products for every order. Ideally you don't even want random products. You want a distribution of products that matches the same "shape" as you have in your production database. -- Richard Huxton Archonet Ltd
> I used 1000 since doc wrote that max value is 1000 > Rid table contains 3.5millions rows, will increase 1 millions of rows per > year and is updated frequently, mostly by adding. > Is it OK to leave > SET STATISTICS 1000; > setting for this table this column or should I try to decrease it ? > Andrus. If you expect millions of rows, and this is one of your most important use cases, leaving that column's statistics targetat 1000 is probably fine. You will incur a small cost on most queries that use this column (query planning is moreexpensive as it may have to scan all 1000 items for a match), but the risk of a bad query plan and a very slow queryis a lot less. It is probably worth the small constant cost to prevent bad queries in your case, and since the table will be growing. Largertables need larger statistics common values buckets in general. Leave this at 1000, focus on your other issues first. After all the other major issues are done you can come back and seeif a smaller value is worth trying or not. You may also end up setting higher statistics targets on some other columns to fix other issues. You may want to set thevalue in the configuration file higher than the default 10 -- I'd recommend starting with 40 and re-analyzing the tables. Going from 10 to 40 has a minor cost but can help the planner create significantly better queries if you have skeweddata distributions. -Scott
Scott,
>You may also end up setting higher statistics targets on some other columns
to fix other issues. You may want to set the value in the configuration
file higher than the default 10 -- I'd recommend starting with 40 and
re-analyzing the tables.
Thank you.
I set rid.toode statistics target to 1000. analyze rid now takes 40 seconds.
More queries run less than 10 seconds after this change.
I set default_statistic target to 40 and ran ANALYZE.
However there are still queries which take more than 10 seconds.
set search_path to firma2,public;
ALTER TABLE dok ALTER COLUMN kuupaev SET STATISTICS 1000;
analyze dok; -- 86 seconds
explain analyze select sum(1)
FROM dok JOIN rid USING (dokumnr)
JOIN toode USING (toode)
WHERE dok.kuupaev>='2008-10-01'
AND
( (
dok.doktyyp IN
('V','G','Y','K','I','T','D','N','H','M','E','B','A','R','C','F','J','Q')
AND CASE WHEN NOT dok.objrealt OR dok.doktyyp='I' THEN dok.yksus
ELSE rid.kuluobjekt END LIKE 'RIISIPERE%'
)
OR
( dok.doktyyp IN ('O','S','I','U','D','P')
AND CASE WHEN dok.objrealt THEN rid.kuluobjekt ELSE dok.sihtyksus
END LIKE 'RIISIPERE%'
)
)
ALTER TABLE dok ALTER COLUMN kuupaev SET STATISTICS -1;
analyze dok; -- 3 seconds
"Aggregate (cost=302381.83..302381.84 rows=1 width=0) (actual
time=32795.966..32795.970 rows=1 loops=1)"
" -> Merge Join (cost=302298.07..302379.45 rows=951 width=0) (actual
time=31478.319..32614.691 rows=47646 loops=1)"
" Merge Cond: ("outer".toode = "inner".toode)"
" -> Sort (cost=300522.54..300524.92 rows=954 width=24) (actual
time=31254.424..31429.436 rows=47701 loops=1)"
" Sort Key: rid.toode"
" -> Hash Join (cost=73766.03..300475.32 rows=954 width=24)
(actual time=920.122..30418.627 rows=47701 loops=1)"
" Hash Cond: ("outer".dokumnr = "inner".dokumnr)"
" Join Filter: (((("inner".doktyyp = 'V'::bpchar) OR
("inner".doktyyp = 'G'::bpchar) OR ("inner".doktyyp = 'Y'::bpchar) OR
("inner".doktyyp = 'K'::bpchar) OR ("inner".doktyyp = 'I'::bpchar) OR
("inner".doktyyp = 'T'::bpchar) OR ("inner".doktyyp = 'D'::bpchar) OR
("inner".doktyyp = 'N'::bpchar) OR ("inner".doktyyp = 'H'::bpchar) OR
("inner".doktyyp = 'M'::bpchar) OR ("inner".doktyyp = 'E'::bpchar) OR
("inner".doktyyp = 'B'::bpchar) OR ("inner".doktyyp = 'A'::bpchar) OR
("inner".doktyyp = 'R'::bpchar) OR ("inner".doktyyp = 'C'::bpchar) OR
("inner".doktyyp = 'F'::bpchar) OR ("inner".doktyyp = 'J'::bpchar) OR
("inner".doktyyp = 'Q'::bpchar)) AND (CASE WHEN ((NOT
("inner".objrealt)::boolean) OR ("inner".doktyyp = 'I'::bpchar)) THEN
"inner".yksus ELSE "outer".kuluobjekt END ~~ 'RIISIPERE%'::text)) OR
((("inner".doktyyp = 'O'::bpchar) OR ("inner".doktyyp = 'S'::bpchar) OR
("inner".doktyyp = 'I'::bpchar) OR ("inner".doktyyp = 'U'::bpchar) OR
("inner".doktyyp = 'D'::bpchar) OR ("inner".doktyyp = 'P'::bpchar)) AND
(CASE WHEN ("inner".objrealt)::boolean THEN "outer".kuluobjekt ELSE
"inner".sihtyksus END ~~ 'RIISIPERE%'::text)))"
" -> Seq Scan on rid (cost=0.00..129635.37 rows=3305337
width=42) (actual time=0.040..14458.666 rows=3293574 loops=1)"
" -> Hash (cost=73590.93..73590.93 rows=70042 width=38)
(actual time=916.812..916.812 rows=72439 loops=1)"
" -> Bitmap Heap Scan on dok
(cost=414.75..73590.93 rows=70042 width=38) (actual time=28.704..589.116
rows=72439 loops=1)"
" Recheck Cond: (kuupaev >=
'2008-10-01'::date)"
" Filter: ((doktyyp = 'V'::bpchar) OR
(doktyyp = 'G'::bpchar) OR (doktyyp = 'Y'::bpchar) OR (doktyyp =
'K'::bpchar) OR (doktyyp = 'I'::bpchar) OR (doktyyp = 'T'::bpchar) OR
(doktyyp = 'D'::bpchar) OR (doktyyp = 'N'::bpchar) OR (doktyyp =
'H'::bpchar) OR (doktyyp = 'M'::bpchar) OR (doktyyp = 'E'::bpchar) OR
(doktyyp = 'B'::bpchar) OR (doktyyp = 'A'::bpchar) OR (doktyyp =
'R'::bpchar) OR (doktyyp = 'C'::bpchar) OR (doktyyp = 'F'::bpchar) OR
(doktyyp = 'J'::bpchar) OR (doktyyp = 'Q'::bpchar) OR (doktyyp =
'O'::bpchar) OR (doktyyp = 'S'::bpchar) OR (doktyyp = 'I'::bpchar) OR
(doktyyp = 'U'::bpchar) OR (doktyyp = 'D'::bpchar) OR (doktyyp =
'P'::bpchar))"
" -> Bitmap Index Scan on dok_kuupaev_idx
(cost=0.00..414.75 rows=72500 width=0) (actual time=20.049..20.049
rows=72664 loops=1)"
" Index Cond: (kuupaev >=
'2008-10-01'::date)"
" -> Sort (cost=1775.54..1809.10 rows=13423 width=24) (actual
time=223.235..457.888 rows=59876 loops=1)"
" Sort Key: toode.toode"
" -> Seq Scan on toode (cost=0.00..855.23 rows=13423
width=24) (actual time=0.046..63.783 rows=13427 loops=1)"
"Total runtime: 32807.767 ms"
How to speed this up ?
'RIISIPERE%' is shop group code. Using this condition can limit scan to 6
times less documentes since there are 6 shops.
Mayber is it possible to create indexes or other way to force index search
for condition
dok.doktyyp IN
('V','G','Y','K','I','T','D','N','H','M','E','B','A','R','C','F','J','Q')
AND CASE WHEN NOT dok.objrealt OR dok.doktyyp='I' THEN dok.yksus
ELSE rid.kuluobjekt END LIKE 'RIISIPERE%'
)
OR
( dok.doktyyp IN ('O','S','I','U','D','P')
AND CASE WHEN dok.objrealt THEN rid.kuluobjekt ELSE dok.sihtyksus
END LIKE 'RIISIPERE%'
)
or is it possible to re-write this condition so that it uses existing
pattern indexes
CREATE INDEX dok_sihtyksus_pattern_idx ON firma2.dok (sihtyksus
bpchar_pattern_ops);
CREATE INDEX dok_yksus_pattern_idx ON firma2.dok (yksus
bpchar_pattern_ops);
without changing tables structureˇ?
Andrus.