[PERFORM] Performance issue after upgrading from 9.4 to 9.6
We are having some performance issues after we upgraded to newest version of PostgreSQL, before it everything was fast and smooth. Upgrade was done by pg_upgrade from 9.4 directly do 9.6.1. Now we upgraded to 9.6.2 with no improvement. Some information about our setup: Freebsd, Solaris (SmartOS), simple master-slave using streaming replication. Problem: Very high system CPU when master is streaming replication data, CPU goes up to 77%. Only one process is generating this load, it's a postgresql startup process. When I attached a truss to this process I saw a lot o read calls with almost the same number of errors (EAGAIN). root@d8:~ # truss -c -p 38091 ^Csyscall seconds calls errors semop 0.001611782 198 0 write 0.74404 2 0 read2.281535100 17266 12375 openat 0.000683532 48 0 lseek 0.177612479 20443 0 close 0.000395549 48 0 - --- --- 2.461912846 38005 12375 read(6,0x7fffa0c7,1) ERR#35 'Resource temporarily unavailable' lseek(444,0x0,SEEK_END) = 32571392 (0x1f1) read(6,0x7fffa0c7,1) ERR#35 'Resource temporarily unavailable' lseek(444,0x0,SEEK_END) = 32571392 (0x1f1) read(6,0x7fffa0c7,1) ERR#35 'Resource temporarily unavailable' lseek(7,0x0,SEEK_END) = 164487168 (0x9cde000) lseek(778,0x0,SEEK_END) = 57344 (0xe000) read(6,0x7fffa0c7,1) ERR#35 'Resource temporarily unavailable' lseek(894,0x0,SEEK_END) = 139296768 (0x84d8000) lseek(894,0x4b7e000,SEEK_SET) = 79159296 (0x4b7e000) read(894," ~\0\08\a\M--m\0\0\^A\0\M^T\"...,8192) = 8192 (0x2000) lseek(3,0xfa6000,SEEK_SET) = 16408576 (0xfa6000) read(3,"\M^S\M-P\^E\0\^A\0\0\0\0`\M-z"...,8192) = 8192 (0x2000) read(6,0x7fffa0c7,1) ERR#35 'Resource temporarily unavailable' lseek(894,0x0,SEEK_END) = 139296768 (0x84d8000) lseek(894,0x0,SEEK_END) = 139296768 (0x84d8000) lseek(894,0x449c000,SEEK_SET) = 71942144 (0x449c000) read(894,"\^_~\0\0\M-H\M-H\M-B\M-b\0\0\^E"...,8192) = 8192 (0x2000) lseek(818,0x0,SEEK_END) = 57344 (0xe000) read(6,0x7fffa0c7,1) ERR#35 'Resource temporarily unavailable' lseek(442,0x0,SEEK_END) = 10174464 (0x9b4000) lseek(442,0x4c4000,SEEK_SET) = 4997120 (0x4c4000) read(442,"\^_~\0\0\M-P\M-+\M-1\M-b\0\0\0\0"...,8192) = 8192 (0x2000) read(6,0x7fffa0c7,1) ERR#35 'Resource temporarily unavailable' Descriptor 6 is a pipe Read call try to read one byte over and over, I looked up to source code and I think this file is responsible for this behavior src/backend/storage/ipc/latch.c. There was no such file in 9.4. -- Piotr Gasidło -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
[PERFORM] Wrong index selection
) (actual
time=0.224..0.225 rows=8 loops=1)
Sort Key: co2ta.co2ta_ta_id, co2ta.co2ta_co_id
Sort Method: quicksort Memory: 25kB
- Index Scan using cookies2tags_co_id_key2 on
cookies2tags co2ta (cost=0.58..45.24 rows=1 width=57) (actual
time=0.031..0.215 rows=8 loops=1)
Index Cond: ((co2ta_co_id = ANY
('{123567429,123872617,123929118,123930244,123935996,123937156,123944495,123944999,123945469}'::integer[]))
AND (co2ta_cl_id = 97))
Filter: (co2ta_ta_id = ANY ('{142}'::integer[]))
Rows Removed by Filter: 187
- CTE Scan on s (cost=0.00..0.02 rows=1 width=36) (actual
time=0.232..0.244 rows=8 loops=1)
- HashAggregate (cost=0.03..0.04 rows=1 width=12) (actual
time=0.007..0.009 rows=8 loops=1)
- CTE Scan on s s_1 (cost=0.00..0.02 rows=1 width=12) (actual
time=0.001..0.001 rows=8 loops=1)
Total runtime: 0.321 ms
This plan is much faster. I notice that if I put more co2ta_co_id values in
query than some threshold PostgreSQL creates unoptimal plan.
I wonder what should I tune, to get PostgreSQL use other index for queries
with more co2ta_co_id values in query?
Currently as hotfix I split input values, to execute more queries with less
co2ta_co_id values.
--
Piotr Gasidło
[PERFORM] Big difference in time returned by EXPLAIN ANALYZE SELECT ... AND SELECT ...
[] | | extended | oc_h_id | integer | | plain| oc_hg_id | integer | | plain| oc_hg_category| numeric(2,1)| | main | oc_r_id | integer | | plain| oc_date_from | date| | plain| oc_date_to| date| | plain| oc_duration | integer | | plain| oc_transport | integer | | plain| oc_price_min | numeric | | main | oc_price_max | numeric | | main | oc_rc_ids | integer[] | | extended | oc_orc_ids| integer[] | | extended | oc_fc_ids | integer[] | | extended | oc_ofc_id_1 | integer | | plain| oc_ap_ids_from1 | integer[] | | extended | oc_bc_ids_from| integer[] | | extended | oc_obc_ids_from | integer[] | | extended | oc_o_ids | integer[] | | extended | oc_price_avg | numeric | | main | oc_o_date_updated_min | timestamp without time zone | | plain| oc_o_date_updated_max | timestamp without time zone | | plain| Indexes: ocache_2010_12_oc_ap_ids_from1_key gist (oc_ap_ids_from1) ocache_2010_12_oc_h_id_key btree (oc_h_id) ocache_2010_12_oc_hg_id_key btree (oc_hg_id) ocache_2010_12_oc_obc_ids_from_key gist (oc_obc_ids_from) ocache_2010_12_oc_r_id_key btree (oc_r_id) ocache_2010_12_oc_to_id_key btree (oc_to_id) Check constraints: ocache_2010_12_oc_date_from_check CHECK (oc_date_from = '2010-12-01'::date AND oc_date_from = '2011-01-01'::date) Inherits: ocache Has OIDs: no Options: fillfactor=80 -- Piotr Gasidło -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
[PERFORM] Re: Big difference in time returned by EXPLAIN ANALYZE SELECT ... AND SELECT ...
W dniu 26 lipca 2010 10:35 użytkownik Piotr Gasidło qua...@barbara.eu.org napisał: \d+ ocache_2010_12 Table public.ocache_2010_12 Indexes: (...) Missed index in listing: ocache_2010_12_ukey UNIQUE, btree (oc_date_from, oc_date_to, oc_h_id, oc_transport, oc_ofc_id_1) WITH (fillfactor=80) -- Piotr Gasidło -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] Big difference in time returned by EXPLAIN ANALYZE SELECT ... AND SELECT ...
2010/7/26 Vitalii Tymchyshyn tiv...@gmail.com:
26.07.10 12:15, Craig Ringer написав(ла):
(...)
Piotr: You can try preparing your statement and then analyzing execute time
to check if this is planning time.
You are right.
I've done simple PREPARE (without params, etc).
REPARE query as select oc_h_id,oc_duration,SUM(oc_count) FROM ocache WHERE
oc_date_from = '2010-07-22'::date AND oc_date_from = '2010-07-24'::date AND
oc_h_id =
ANY('{32842,3095,27929,2229,22769,3098,33433,22559,226,2130,226,2130,2229,3095,3098,22559,22769,27929,32842,33433}'::int[])
GROUP BY oc_h_id, oc_duration;
PREPARE
Time: 19,873 ms
EXPLAIN ANALYZE EXECUTE query;
...
Total runtime: 3.237 ms
Time: 5,118 ms
EXECUTE query;
oc_h_id | oc_duration | sum
-+-+--
27929 | 7 | 546
3098 | 7 | 552
27929 | 14 | 512
3098 | 14 | 444
22769 | 14 | 984
32842 | 14 | 444
27929 | 22 |4
27929 | 15 | 44
32842 | 7 | 552
22769 | 7 | 1356
2229 | 7 | 496
226 | 14 | 536
2130 | 7 | 536
2130 | 14 | 448
226 | 7 | 584
2229 | 14 | 400
33433 | 14 | 444
3095 | 7 | 552
33433 | 7 | 552
3095 | 14 | 444
27929 | 8 | 40
(21 rows)
Time: 3,494 ms
The time matches EXPLAIN ANALYZE runtime.
Compared to not prepared query, its big difference!
select oc_h_id,oc_duration,SUM(oc_count) FROM ocache WHERE oc_date_from =
'2010-07-22'::date AND oc_date_from = '2010-07-24'::date AND oc_h_id =
ANY('{32842,3095,27929,2229,22769,3098,33433,22559,226,2130,226,2130,2229,3095,3098,22559,22769,27929,32842,33433}'::int[])
GROUP BY oc_h_id, oc_duration;
oc_h_id | oc_duration | sum
-+-+--
27929 | 7 | 546
3098 | 7 | 552
27929 | 14 | 512
3098 | 14 | 444
22769 | 14 | 984
32842 | 14 | 444
27929 | 22 |4
27929 | 15 | 44
32842 | 7 | 552
22769 | 7 | 1356
2229 | 7 | 496
226 | 14 | 536
2130 | 7 | 536
2130 | 14 | 448
226 | 7 | 584
2229 | 14 | 400
33433 | 14 | 444
3095 | 7 | 552
33433 | 7 | 552
3095 | 14 | 444
27929 | 8 | 40
(21 rows)
Time: 22,571 ms
Ok. Is there any way to tune postgresql, to shorten planning time for
such queries?
--
Piotr Gasidło
--
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] Index on VARCHAR with text_pattern_ops inside PL/PGSQL procedure.
2007/12/10, Piotr Gasidło [EMAIL PROTECTED]: Why PL/PGSQL is unable to proper utilize users_user_name_unique_text_pattern_ops? I found solution, that satisfies me (EXECUTE is a bit ugly for me). I've replaced LIKE operator with ~=~ operator. Now PL/PGSQL function properly uses index on SELECT. ---(end of broadcast)--- TIP 4: Have you searched our list archives? http://archives.postgresql.org
[PERFORM] Index on VARCHAR with text_pattern_ops inside PL/PGSQL procedure.
Hello,
I've created table:
quaker= \d users
Table public.users
Column | Type| Modifiers
---+---+
id| integer | not null default
nextval('users_id_seq'::regclass)
user_name | character varying | not null
extra | integer |
Indexes:
users_pkey PRIMARY KEY, btree (id)
users_user_name_unique_text_ops UNIQUE, btree (user_name text_ops)
users_user_name_unique_text_pattern_ops btree (user_name
text_pattern_ops)
Filled with random data (100k records).
I do simple queries using above indexes (asking for existing record).
explain analyze select id from users where user_name = 'quaker';
QUERY
PLAN
---
Index Scan using users_user_name_unique_text_ops on users
(cost=0.00..8.28 rows=1 width=4) (actual time=0.040..0.043 rows=1 loops=1)
Index Cond: ((user_name)::text = 'quaker'::text)
Total runtime: 0.084 ms
(3 rows)
explain analyze select id from users where user_name like 'quaker';
QUERY
PLAN
---
Index Scan using users_user_name_unique_text_pattern_ops on users
(cost=0.00..8.28 rows=1 width=4) (actual time=0.022..0.024 rows=1 loops=1)
Index Cond: ((user_name)::text ~=~ 'quaker'::text)
Filter: ((user_name)::text ~~ 'quaker'::text)
Total runtime: 0.050 ms
(4 rows)
Everything looks fine.
Now, I've created PL/PGSQL function:
create or replace function user_login(
_v_user_name varchar
) returns integer as $$
declare
_i_user_id integer;
begin
select id into _i_user_id from users where user_name = _v_user_name
limit 1;
if found then
return _i_user_id;
end if;
return -1;
end;
$$ language plpgsql security definer;
As shown above, I use = operator, which should use
users_user_name_unique_text_ops index:
explain analyze select user_login('quaker');
QUERY PLAN
Result (cost=0.00..0.01 rows=1 width=0) (actual time=0.320..0.322
rows=1 loops=1)
Total runtime: 0.340 ms
(2 rows)
Some performance loss, but OK. Now I've changed = into LIKE to use
users_user_name_unique_text_pattern_ops index and rerun query:
explain analyze select user_login('quaker');
QUERY PLAN
--
Result (cost=0.00..0.01 rows=1 width=0) (actual time=41.606..41.608
rows=1 loops=1)
Total runtime: 41.629 ms
(2 rows)
Second run give 61.061 ms. So no improvements.
Why PL/PGSQL is unable to proper utilize
users_user_name_unique_text_pattern_ops?
quaker= select version();
version
--
PostgreSQL 8.2.5 on i486-pc-linux-gnu, compiled by GCC cc (GCC) 4.1.3
20070831 (prerelease) (Ubuntu 4.1.2-16ubuntu1)
(1 row)
---(end of broadcast)---
TIP 1: if posting/reading through Usenet, please send an appropriate
subscribe-nomail command to [EMAIL PROTECTED] so that your
message can get through to the mailing list cleanly
[PERFORM] Trouble with LEFT JOIN using VIEWS.
Hello,
I've just hit problem, that is unusual for me.
quaker= \d sites
Table public.sites
Column | Type| Modifiers
---+---+
id| integer | not null default
nextval('sites_id_seq'::regclass)
site_name | character varying | not null
user_id | integer | not null
extra | integer |
Indexes:
sites_pkey PRIMARY KEY, btree (id)
sites_site_name_key_unique UNIQUE, btree (site_name text_pattern_ops)
sites_user_id_key btree (user_id)
quaker= \d users
Table public.users
Column | Type| Modifiers
---+---+
id| integer | not null default
nextval('users_id_seq'::regclass)
user_name | character varying | not null
extra | integer |
Indexes:
users_pkey PRIMARY KEY, btree (id)
Both tables filled with 100k records of random data. In users id is in
range from 1..100k, same in sites. In sites user_id is random, range
from 1..150k.
I've created views:
quaker= \d users_secure
View public.users_secure
Column | Type| Modifiers
---+---+---
id| integer |
user_name | character varying |
View definition:
SELECT users.id, users.user_name
FROM users;
quaker= \d users_secure_with_has_extra
View public.users_secure_with_has_extra
Column | Type| Modifiers
---+---+---
id| integer |
user_name | character varying |
has_extra | boolean |
View definition:
SELECT users.id, users.user_name, users.extra IS NOT NULL AS has_extra
FROM users;
Now, when I do simple query to find all data for sites matching
site_name like 'H3bh%' (there are at least one record in sites matching
this condition).
quaker= explain analyze select s.site_name,u.user_name from
sites_secure s left join users_secure_with_has_extra u on u.id =
s.user_id where site_name like 'H3bh%' order by site_name limit 10;
QUERY PLAN
-
Limit (cost=3897.02..3897.03 rows=2 width=44) (actual
time=430.326..430.331 rows=1 loops=1)
- Sort (cost=3897.02..3897.03 rows=2 width=44) (actual
time=430.321..430.323 rows=1 loops=1)
Sort Key: sites.site_name
- Nested Loop Left Join (cost=0.00..3897.01 rows=2
width=44) (actual time=290.103..430.301 rows=1 loops=1)
Join Filter: (inner.id = outer.user_id)
- Index Scan using sites_site_name_key_unique on sites
(cost=0.00..6.01 rows=1 width=16) (actual time=0.044..0.054 rows=1
loops=1)
Index Cond: (((site_name)::text ~=~ 'H3bh'::text)
AND ((site_name)::text ~~ 'H3bi'::text))
Filter: ((site_name)::text ~~ 'H3bh%'::text)
- Seq Scan on users (cost=0.00..1641.00 rows=10
width=20) (actual time=0.007..245.406 rows=10 loops=1)
Total runtime: 430.432 ms
(10 rows)
When I resign from LEFT JOIN users_secure_with_has_extra, and put JOIN
instead I've got:
quaker= explain analyze select s.site_name,u.user_name from
sites_secure s join users_secure_with_has_extra u on u.id = s.user_id
where site_name like 'H3bh%' order by site_name limit 10;
QUERY PLAN
-
Limit (cost=9.05..9.06 rows=1 width=24) (actual time=0.112..0.118
rows=1 loops=1)
- Sort (cost=9.05..9.06 rows=1 width=24) (actual
time=0.106..0.108 rows=1 loops=1)
Sort Key: sites.site_name
- Nested Loop (cost=0.00..9.04 rows=1 width=24) (actual
time=0.073..0.088 rows=1 loops=1)
- Index Scan using sites_site_name_key_unique on sites
(cost=0.00..6.01 rows=1 width=16) (actual time=0.044..0.050 rows=1
loops=1)
Index Cond: (((site_name)::text ~=~ 'H3bh'::text)
AND ((site_name)::text ~~ 'H3bi'::text))
Filter: ((site_name)::text ~~ 'H3bh%'::text)
- Index Scan using users_pkey on users
(cost=0.00..3.02 rows=1 width=16) (actual time=0.019..0.023 rows=1 loops=1)
Index Cond: (users.id = outer.user_id)
Total runtime: 0.216 ms
(10 rows)
As explain shows PostgreSQL is using index scan on users, instead of seq
scan like in example above.
Now. When I use view with no has_extra field (important: field is a
simple function on extra field) I get expectable results. Both using
indexes.
quaker= explain analyze select s.site_name,u.user_name from
sites_secure s left join users_secure u on u.id
