Thread: Performance problems with 9.2.15
Hello!
I am just about to upgrade from PostgreSQL 8.4.20 to 9.2.15, but I'v run
into some huge performance issues. Both databases are configured the
same way (shared_buffers = 2GB, temp_buffers = 32MB). I have increased
work_mem on the 9.2 from 4MB to 64MB, but to no avail.
Now, the query on 8.4:
rt4=# EXPLAIN ANALYZE VERBOSE SELECT DISTINCT main.* FROM Users main
CROSS JOIN ACL ACL_3 JOIN Principals Principals_1 ON ( Principals_1.id
= main.id ) JOIN CachedGroupMembers CachedGroupMembers_2 ON
( CachedGroupMembers_2.MemberId = Principals_1.id ) JOIN
CachedGroupMembers CachedGroupMembers_4 ON
( CachedGroupMembers_4.MemberId = Principals_1.id ) WHERE
((ACL_3.ObjectType = 'RT::Queue') OR (ACL_3.ObjectType = 'RT::System'
AND ACL_3.ObjectId = 1)) AND (ACL_3.PrincipalId =
CachedGroupMembers_4.GroupId) AND (ACL_3.PrincipalType = 'Group') AND
(ACL_3.RightName = 'OwnTicket' OR ACL_3.RightName = 'SuperUser') AND
(CachedGroupMembers_2.Disabled = '0') AND (CachedGroupMembers_2.GroupId
= '4') AND (CachedGroupMembers_4.Disabled = '0') AND
(Principals_1.Disabled = '0') AND (Principals_1.PrincipalType = 'User')
AND (Principals_1.id != '1') ORDER BY main.Name ASC;
QUERY
PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
--------------------
Unique (cost=19822.31..19843.46 rows=235 width=1084) (actual
time=6684.054..7118.015 rows=571 loops=1)
Output: main.id, main.name, main.password, main.authtoken,
main.comments, main.signature, main.emailaddress,
main.freeformcontactinfo, main.organization, main.realname,
main.nickname, main.lang, main.emailenc
oding, main.webencoding, main.externalcontactinfoid,
main.contactinfosystem, main.externalauthid, main.authsystem,
main.gecos, main.homephone, main.workphone, main.mobilephone,
main.pagerphone, main.address1, ma
in.address2, main.city, main.state, main.zip, main.country,
main.timezone, main.pgpkey, main.creator, main.created,
main.lastupdatedby, main.lastupdated
-> Sort (cost=19822.31..19822.90 rows=235 width=1084) (actual
time=6684.052..7085.835 rows=33310 loops=1)
Output: main.id, main.name, main.password, main.authtoken,
main.comments, main.signature, main.emailaddress,
main.freeformcontactinfo, main.organization, main.realname,
main.nickname, main.lang, main.em
ailencoding, main.webencoding, main.externalcontactinfoid,
main.contactinfosystem, main.externalauthid, main.authsystem,
main.gecos, main.homephone, main.workphone, main.mobilephone,
main.pagerphone, main.addres
s1, main.address2, main.city, main.state, main.zip, main.country,
main.timezone, main.pgpkey, main.creator, main.created,
main.lastupdatedby, main.lastupdated
Sort Key: main.name, main.id, main.password, main.authtoken,
main.comments, main.signature, main.emailaddress,
main.freeformcontactinfo, main.organization, main.realname,
main.nickname, main.lang, main.
emailencoding, main.webencoding, main.externalcontactinfoid,
main.contactinfosystem, main.externalauthid, main.authsystem,
main.gecos, main.homephone, main.workphone, main.mobilephone,
main.pagerphone, main.addr
ess1, main.address2, main.city, main.state, main.zip, main.country,
main.timezone, main.pgpkey, main.creator, main.created,
main.lastupdatedby, main.lastupdated
Sort Method: external merge Disk: 7408kB
-> Hash Join (cost=19659.66..19813.05 rows=235 width=1084)
(actual time=3362.897..4080.600 rows=33310 loops=1)
Output: main.id, main.name, main.password,
main.authtoken, main.comments, main.signature, main.emailaddress,
main.freeformcontactinfo, main.organization, main.realname,
main.nickname, main.lang, m
ain.emailencoding, main.webencoding, main.externalcontactinfoid,
main.contactinfosystem, main.externalauthid, main.authsystem,
main.gecos, main.homephone, main.workphone, main.mobilephone,
main.pagerphone, main.
address1, main.address2, main.city, main.state, main.zip, main.country,
main.timezone, main.pgpkey, main.creator, main.created,
main.lastupdatedby, main.lastupdated
Hash Cond: (acl_3.principalid =
cachedgroupmembers_4.groupid)
-> Bitmap Heap Scan on acl acl_3 (cost=30.04..145.27
rows=494 width=4) (actual time=0.339..1.790 rows=528 loops=1)
Output: acl_3.id, acl_3.principaltype,
acl_3.principalid, acl_3.rightname, acl_3.objecttype, acl_3.objectid,
acl_3.creator, acl_3.created, acl_3.lastupdatedby, acl_3.lastupdated
Recheck Cond: ((((rightname)::text =
'OwnTicket'::text) AND ((principaltype)::text = 'Group'::text)) OR
(((rightname)::text = 'SuperUser'::text) AND ((principaltype)::text =
'Group'::text)))
Filter: (((objecttype)::text = 'RT::Queue'::text)
OR (((objecttype)::text = 'RT::System'::text) AND (objectid = 1)))
-> BitmapOr (cost=30.04..30.04 rows=529 width=0)
(actual time=0.303..0.303 rows=0 loops=1)
-> Bitmap Index Scan on acl1
(cost=0.00..25.43 rows=518 width=0) (actual time=0.283..0.283 rows=524
loops=1)
Index Cond: (((rightname)::text =
'OwnTicket'::text) AND ((principaltype)::text = 'Group'::text))
-> Bitmap Index Scan on acl1
(cost=0.00..4.36 rows=11 width=0) (actual time=0.020..0.020 rows=4
loops=1)
Index Cond: (((rightname)::text =
'SuperUser'::text) AND ((principaltype)::text = 'Group'::text))
-> Hash (cost=19615.48..19615.48 rows=1131 width=1088)
(actual time=3301.001..3301.001 rows=949843 loops=1)
Output: main.id, main.name, main.password,
main.authtoken, main.comments, main.signature, main.emailaddress,
main.freeformcontactinfo, main.organization, main.realname,
main.nickname, main.l
ang, main.emailencoding, main.webencoding, main.externalcontactinfoid,
main.contactinfosystem, main.externalauthid, main.authsystem,
main.gecos, main.homephone, main.workphone, main.mobilephone,
main.pagerphone,
main.address1, main.address2, main.city, main.state, main.zip,
main.country, main.timezone, main.pgpkey, main.creator, main.created,
main.lastupdatedby, main.lastupdated, cachedgroupmembers_4.groupid
-> Nested Loop (cost=24.59..19615.48 rows=1131
width=1088) (actual time=0.540..1835.831 rows=949843 loops=1)
Output: main.id, main.name, main.password,
main.authtoken, main.comments, main.signature, main.emailaddress,
main.freeformcontactinfo, main.organization, main.realname,
main.nickname,
main.lang, main.emailencoding, main.webencoding,
main.externalcontactinfoid, main.contactinfosystem, main.externalauthid,
main.authsystem, main.gecos, main.homephone, main.workphone,
main.mobilephone, main.pager
phone, main.address1, main.address2, main.city, main.state, main.zip,
main.country, main.timezone, main.pgpkey, main.creator, main.created,
main.lastupdatedby, main.lastupdated, cachedgroupmembers_4.groupid
-> Nested Loop (cost=18.63..8795.62 rows=41
width=1092) (actual time=0.438..22.198 rows=674 loops=1)
Output: main.id, main.name,
main.password, main.authtoken, main.comments, main.signature,
main.emailaddress, main.freeformcontactinfo, main.organization,
main.realname, main.nick
name, main.lang, main.emailencoding, main.webencoding,
main.externalcontactinfoid, main.contactinfosystem, main.externalauthid,
main.authsystem, main.gecos, main.homephone, main.workphone,
main.mobilephone, main
.pagerphone, main.address1, main.address2, main.city, main.state,
main.zip, main.country, main.timezone, main.pgpkey, main.creator,
main.created, main.lastupdatedby, main.lastupdated,
cachedgroupmembers_2.member
id, principals_1.id
-> Nested Loop (cost=18.63..8459.04
rows=41 width=8) (actual time=0.381..13.384 rows=674 loops=1)
Output: principals_1.id,
cachedgroupmembers_2.memberid
-> Bitmap Heap Scan on
cachedgroupmembers cachedgroupmembers_2 (cost=18.63..2436.95 rows=669
width=4) (actual time=0.308..1.973 rows=675 loops=1)
Output:
cachedgroupmembers_2.id, cachedgroupmembers_2.groupid,
cachedgroupmembers_2.memberid, cachedgroupmembers_2.via,
cachedgroupmembers_2.immediateparentid, cached
groupmembers_2.disabled
Recheck Cond: (groupid = 4)
Filter: (disabled = 0)
-> Bitmap Index Scan on
cachedgroupmembers3 (cost=0.00..18.46 rows=669 width=0) (actual
time=0.223..0.223 rows=675 loops=1)
Index Cond: (groupid
= 4)
-> Index Scan using
principals_pkey on principals principals_1 (cost=0.00..8.99 rows=1
width=4) (actual time=0.015..0.016 rows=1 loops=675)
Output: principals_1.id,
principals_1.principaltype, principals_1.objectid, principals_1.disabled
Index Cond:
(principals_1.id = cachedgroupmembers_2.memberid)
Filter: ((principals_1.id
<> 1) AND (principals_1.disabled = 0) AND
((principals_1.principaltype)::text = 'User'::text))
-> Index Scan using users_pkey on
users main (cost=0.00..8.20 rows=1 width=1084) (actual
time=0.010..0.011 rows=1 loops=674)
Output: main.id, main.name,
main.password, main.authtoken, main.comments, main.signature,
main.emailaddress, main.freeformcontactinfo, main.organization,
main.realname, mai
n.nickname, main.lang, main.emailencoding, main.webencoding,
main.externalcontactinfoid, main.contactinfosystem, main.externalauthid,
main.authsystem, main.gecos, main.homephone, main.workphone,
main.mobilephone
, main.pagerphone, main.address1, main.address2, main.city, main.state,
main.zip, main.country, main.timezone, main.pgpkey, main.creator,
main.created, main.lastupdatedby, main.lastupdated
Index Cond: (main.id =
principals_1.id)
-> Bitmap Heap Scan on cachedgroupmembers
cachedgroupmembers_4 (cost=5.96..263.05 rows=68 width=8) (actual
time=0.464..2.233 rows=1409 loops=674)
Output: cachedgroupmembers_4.id,
cachedgroupmembers_4.groupid, cachedgroupmembers_4.memberid,
cachedgroupmembers_4.via, cachedgroupmembers_4.immediateparentid,
cachedgroupmembers
_4.disabled
Recheck Cond:
(cachedgroupmembers_4.memberid = main.id)
Filter: (cachedgroupmembers_4.disabled
= 0)
-> Bitmap Index Scan on
cachedgroupmembers2 (cost=0.00..5.95 rows=68 width=0) (actual
time=0.286..0.286 rows=1410 loops=674)
Index Cond:
(cachedgroupmembers_4.memberid = main.id)
Total runtime: 7120.012 ms
Same query on 9.2:
QUERY
PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
-----------------------------------------------------------------------------------------------------------------
Unique (cost=8922.03..8922.11 rows=1 width=348) (actual
time=259143.677..259180.526 rows=572 loops=1)
Output: main.id, main.name, main.password, main.authtoken,
main.comments, main.signature, main.emailaddress,
main.freeformcontactinfo, main.organization, main.realname,
main.nickname, main.lang, main.gecos, m
ain.homephone, main.workphone, main.mobilephone, main.pagerphone,
main.address1, main.address2, main.city, main.state, main.zip,
main.country, main.timezone, main.creator, main.created,
main.lastupdatedby, main.
lastupdated, main.smimecertificate
-> Sort (cost=8922.03..8922.04 rows=1 width=348) (actual
time=259143.674..259145.919 rows=33209 loops=1)
Output: main.id, main.name, main.password, main.authtoken,
main.comments, main.signature, main.emailaddress,
main.freeformcontactinfo, main.organization, main.realname,
main.nickname, main.lang, main.ge
cos, main.homephone, main.workphone, main.mobilephone, main.pagerphone,
main.address1, main.address2, main.city, main.state, main.zip,
main.country, main.timezone, main.creator, main.created,
main.lastupdatedby,
main.lastupdated, main.smimecertificate
Sort Key: main.name, main.id, main.password, main.authtoken,
main.comments, main.signature, main.emailaddress,
main.freeformcontactinfo, main.organization, main.realname,
main.nickname, main.lang, main.
gecos, main.homephone, main.workphone, main.mobilephone,
main.pagerphone, main.address1, main.address2, main.city, main.state,
main.zip, main.country, main.timezone, main.creator, main.created,
main.lastupdatedb
y, main.lastupdated, main.smimecertificate
Sort Method: quicksort Memory: 13143kB
-> Nested Loop (cost=47.83..8922.02 rows=1 width=348) (actual
time=388.225..258422.830 rows=33209 loops=1)
Output: main.id, main.name, main.password,
main.authtoken, main.comments, main.signature, main.emailaddress,
main.freeformcontactinfo, main.organization, main.realname,
main.nickname, main.lang, m
ain.gecos, main.homephone, main.workphone, main.mobilephone,
main.pagerphone, main.address1, main.address2, main.city, main.state,
main.zip, main.country, main.timezone, main.creator, main.created,
main.lastupda
tedby, main.lastupdated, main.smimecertificate
Join Filter: (cachedgroupmembers_4.groupid =
acl_3.principalid)
Rows Removed by Join Filter: 495425041
-> Bitmap Heap Scan on public.acl acl_3
(cost=30.07..144.35 rows=497 width=4) (actual time=0.305..9.489 rows=525
loops=1)
Output: acl_3.id, acl_3.principaltype,
acl_3.principalid, acl_3.rightname, acl_3.objecttype, acl_3.objectid,
acl_3.creator, acl_3.created, acl_3.lastupdatedby, acl_3.lastupdated
Recheck Cond: ((((acl_3.rightname)::text =
'OwnTicket'::text) AND ((acl_3.principaltype)::text = 'Group'::text)) OR
(((acl_3.rightname)::text = 'SuperUser'::text) AND
((acl_3.principaltype):
:text = 'Group'::text)))
Filter: (((acl_3.objecttype)::text =
'RT::Queue'::text) OR (((acl_3.objecttype)::text = 'RT::System'::text)
AND (acl_3.objectid = 1)))
-> BitmapOr (cost=30.07..30.07 rows=531 width=0)
(actual time=0.270..0.270 rows=0 loops=1)
-> Bitmap Index Scan on acl1
(cost=0.00..25.46 rows=521 width=0) (actual time=0.248..0.248 rows=521
loops=1)
Index Cond: (((acl_3.rightname)::text =
'OwnTicket'::text) AND ((acl_3.principaltype)::text = 'Group'::text))
-> Bitmap Index Scan on acl1
(cost=0.00..4.36 rows=11 width=0) (actual time=0.020..0.020 rows=4
loops=1)
Index Cond: (((acl_3.rightname)::text =
'SuperUser'::text) AND ((acl_3.principaltype)::text = 'Group'::text))
-> Materialize (cost=17.76..8740.41 rows=5 width=352)
(actual time=0.004..179.471 rows=943730 loops=525)
Output: main.id, main.name, main.password,
main.authtoken, main.comments, main.signature, main.emailaddress,
main.freeformcontactinfo, main.organization, main.realname,
main.nickname, main.l
ang, main.gecos, main.homephone, main.workphone, main.mobilephone,
main.pagerphone, main.address1, main.address2, main.city, main.state,
main.zip, main.country, main.timezone, main.creator, main.created,
main.la
stupdatedby, main.lastupdated, main.smimecertificate,
cachedgroupmembers_4.groupid
-> Nested Loop (cost=17.76..8740.38 rows=5
width=352) (actual time=0.436..1595.962 rows=943730 loops=1)
Output: main.id, main.name, main.password,
main.authtoken, main.comments, main.signature, main.emailaddress,
main.freeformcontactinfo, main.organization, main.realname,
main.nickname,
main.lang, main.gecos, main.homephone, main.workphone, main.mobilephone,
main.pagerphone, main.address1, main.address2, main.city, main.state,
main.zip, main.country, main.timezone, main.creator, main.created, m
ain.lastupdatedby, main.lastupdated, main.smimecertificate,
cachedgroupmembers_4.groupid
-> Nested Loop (cost=14.17..8325.31 rows=3
width=356) (actual time=0.392..27.201 rows=675 loops=1)
Output: main.id, main.name,
main.password, main.authtoken, main.comments, main.signature,
main.emailaddress, main.freeformcontactinfo, main.organization,
main.realname, main.nick
name, main.lang, main.gecos, main.homephone, main.workphone,
main.mobilephone, main.pagerphone, main.address1, main.address2,
main.city, main.state, main.zip, main.country, main.timezone,
main.creator, main.crea
ted, main.lastupdatedby, main.lastupdated, main.smimecertificate,
principals_1.id, cachedgroupmembers_2.memberid
-> Nested Loop (cost=14.17..8160.17
rows=43 width=8) (actual time=0.351..16.568 rows=675 loops=1)
Output: principals_1.id,
cachedgroupmembers_2.memberid
-> Bitmap Heap Scan on
public.cachedgroupmembers cachedgroupmembers_2 (cost=14.17..2431.45
rows=669 width=4) (actual time=0.303..2.098 rows=676 loops=1)
Output:
cachedgroupmembers_2.id, cachedgroupmembers_2.groupid,
cachedgroupmembers_2.memberid, cachedgroupmembers_2.via,
cachedgroupmembers_2.immediateparentid, cached
groupmembers_2.disabled
Recheck Cond:
(cachedgroupmembers_2.groupid = 4)
Filter:
(cachedgroupmembers_2.disabled = 0)
-> Bitmap Index Scan on
cachedgroupmembers2 (cost=0.00..14.00 rows=669 width=0) (actual
time=0.215..0.215 rows=676 loops=1)
Index Cond:
(cachedgroupmembers_2.groupid = 4)
-> Index Scan using
principals_pkey on public.principals principals_1 (cost=0.00..8.55
rows=1 width=4) (actual time=0.019..0.020 rows=1 loops=676)
Output: principals_1.id
Index Cond:
(principals_1.id = cachedgroupmembers_2.memberid)
Filter: ((principals_1.id
<> 1) AND (principals_1.disabled = 0) AND
((principals_1.principaltype)::text = 'User'::text))
Rows Removed by Filter: 0
-> Index Scan using users_pkey on
public.users main (cost=0.00..3.83 rows=1 width=348) (actual
time=0.014..0.015 rows=1 loops=675)
Output: main.id, main.name,
main.password, main.authtoken, main.comments, main.signature,
main.emailaddress, main.freeformcontactinfo, main.organization,
main.realname, mai
n.nickname, main.lang, main.gecos, main.homephone, main.workphone,
main.mobilephone, main.pagerphone, main.address1, main.address2,
main.city, main.state, main.zip, main.country, main.timezone,
main.creator, mai
n.created, main.lastupdatedby, main.lastupdated, main.smimecertificate
Index Cond: (main.id =
principals_1.id)
-> Bitmap Heap Scan on
public.cachedgroupmembers cachedgroupmembers_4 (cost=3.59..137.70
rows=66 width=8) (actual time=0.340..2.016 rows=1398 loops=675)
Output: cachedgroupmembers_4.id,
cachedgroupmembers_4.groupid, cachedgroupmembers_4.memberid,
cachedgroupmembers_4.via, cachedgroupmembers_4.immediateparentid,
cachedgroupmembers
_4.disabled
Recheck Cond:
(cachedgroupmembers_4.memberid = principals_1.id)
Filter: (cachedgroupmembers_4.disabled
= 0)
Rows Removed by Filter: 0
-> Bitmap Index Scan on
cachedgroupmembers1 (cost=0.00..3.58 rows=66 width=0) (actual
time=0.210..0.210 rows=1398 loops=675)
Index Cond:
(cachedgroupmembers_4.memberid = principals_1.id)
Total runtime: 259230.400 ms
The 9.2 chose "nesed loop" in stead of "hash join" with a massive
penalty of 250 seconds in stead of 7-8 seconds.
I have tried to set "enable_nestloop = off" and then this query is down
to 4-5 seconds, but all other queries are slower.
How can I make PostgreSQL 9.2 run this query just as fast as 8.4 did?
/ Eskil
Johan Fredriksson <eskil@kth.se> writes:
> I am just about to upgrade from PostgreSQL 8.4.20 to 9.2.15, but I'v run
> into some huge performance issues.
The rowcount estimates from 9.2 seem greatly different from the 8.4 plan.
Did you remember to ANALYZE all the tables after migrating? Maybe there
were some table-specific statistics targets that you forgot to transfer
over? In any case, the 9.2 plan looks like garbage-in-garbage-out to
me :-( ... without estimates at least a little closer to reality, the
planner is unlikely to do anything very sane.
(BTW, I wonder why you are moving only to 9.2 and not something more
recent.)
regards, tom lane
> The rowcount estimates from 9.2 seem greatly different from the 8.4 plan.
> Did you remember to ANALYZE all the tables after migrating? Maybe there
> were some table-specific statistics targets that you forgot to transfer
> over?
No, I did not. Honestly I though everything would be transfered with a
dump/restore procedure. Unfortunatly running ANALYZE VERBOSE on all
involved tables did not really improve anything.
> In any case, the 9.2 plan looks like garbage-in-garbage-out to
> me :-( ... without estimates at least a little closer to reality, the
> planner is unlikely to do anything very sane.
>
> (BTW, I wonder why you are moving only to 9.2 and not something more
> recent.)
Well, 9.2.15 is what comes bundled with RHEL 7, so I decided to go with
that to avoid dependency issues. But I could install a more fresh
version from scratch if that would solve my problem.
/ Eskil
...(BTW, I wonder why you are moving only to 9.2 and not something more
recent.)
Well, 9.2.15 is what comes bundled with RHEL 7, so I decided to go with that to avoid dependency issues. But I could install a more fresh version from scratch if that would solve my problem.
Generally my first step is to get the latest stable directly from the PostgreSQL Development Group, i.e.:
yum install https://download.postgresql.org/pub/repos/yum/9.5/redhat/rhel-7-x86_64/pgdg-redhat95-9.5-2.noarch.rpm
Then I know I'm starting with the latest and greatest and will get critical updates without worrying about any distribution packager delays.
Cheers,
Steve
> > I am just about to upgrade from PostgreSQL 8.4.20 to 9.2.15, but I'v run
> > into some huge performance issues.
>
> The rowcount estimates from 9.2 seem greatly different from the 8.4 plan.
> Did you remember to ANALYZE all the tables after migrating? Maybe there
> were some table-specific statistics targets that you forgot to transfer
> over? In any case, the 9.2 plan looks like garbage-in-garbage-out to
> me :-( ... without estimates at least a little closer to reality, the
> planner is unlikely to do anything very sane.
>
> (BTW, I wonder why you are moving only to 9.2 and not something more
> recent.)
You put me on the right track with your conclusion that the estimates
were off the chart. The quick-and-dirty fix "DELETE FROM pg_statistic;"
solved this problem. This database now have to build up sane estimates
from scratch.
/ Eskil
> > The rowcount estimates from 9.2 seem greatly different from the 8.4 plan.
> > Did you remember to ANALYZE all the tables after migrating? Maybe there
> > were some table-specific statistics targets that you forgot to transfer
> > over? In any case, the 9.2 plan looks like garbage-in-garbage-out to
> > me :-( ... without estimates at least a little closer to reality, the
> > planner is unlikely to do anything very sane.
> >
> > (BTW, I wonder why you are moving only to 9.2 and not something more
> > recent.)
>
> You put me on the right track with your conclusion that the estimates
> were off the chart. The quick-and-dirty fix "DELETE FROM pg_statistic;"
> solved this problem. This database now have to build up sane estimates
> from scratch.
Actually it took a VACUUM FULL; and DELETE FROM pg_statistic; followed
by ANALYZE on all tables to get it right.
Can someone please explain to me the difference between these two query
plans:
The bad one:
Unique (cost=6037.10..6037.18 rows=1 width=434) (actual
time=255608.588..255646.828 rows=572 loops=1)
-> Sort (cost=6037.10..6037.11 rows=1 width=434) (actual
time=255608.583..255611.632 rows=33209 loops=1)
Sort Method: quicksort Memory: 13143kB
-> Nested Loop (cost=42.51..6037.09 rows=1 width=434) (actual
time=152.818..254886.674 rows=33209 loops=1)
Join Filter: (cachedgroupmembers_4.groupid =
acl_3.principalid)
Rows Removed by Join Filter: 495425041
-> Bitmap Heap Scan on public.acl acl_3
(cost=30.07..144.35 rows=497 width=4) (actual time=0.284..8.184 rows=525
loops=1)
Recheck Cond: ((((acl_3.rightname)::text =
'OwnTicket'::text) AND ((acl_3.principaltype)::text = 'Group'::text)) OR
(((acl_3.rightname)::text = 'SuperUser'::text) AND
((acl_3.principaltype):
:text = 'Group'::text)))
Filter: (((acl_3.objecttype)::text =
'RT::Queue'::text) OR (((acl_3.objecttype)::text = 'RT::System'::text)
AND (acl_3.objectid = 1)))
-> BitmapOr (cost=30.07..30.07 rows=531 width=0)
(actual time=0.249..0.249 rows=0 loops=1)
-> Bitmap Index Scan on acl1
(cost=0.00..25.46 rows=521 width=0) (actual time=0.233..0.233 rows=521
loops=1)
Index Cond: (((acl_3.rightname)::text =
'OwnTicket'::text) AND ((acl_3.principaltype)::text = 'Group'::text))
-> Bitmap Index Scan on acl1
(cost=0.00..4.36 rows=11 width=0) (actual time=0.016..0.016 rows=4
loops=1)
Index Cond: (((acl_3.rightname)::text =
'SuperUser'::text) AND ((acl_3.principaltype)::text = 'Group'::text))
-> Materialize (cost=12.44..5870.39 rows=3 width=438)
(actual time=0.004..176.296 rows=943730 loops=525)
-> Nested Loop (cost=12.44..5870.37 rows=3
width=438) (actual time=0.351..1028.683 rows=943730 loops=1)
-> Nested Loop (cost=12.44..5601.49 rows=2
width=442) (actual time=0.326..15.591 rows=675 loops=1)
-> Nested Loop (cost=12.44..5502.26
rows=27 width=8) (actual time=0.303..9.744 rows=675 loops=1)
Output: principals_1.id,
cachedgroupmembers_2.memberid
-> Bitmap Heap Scan on
public.cachedgroupmembers cachedgroupmembers_2 (cost=12.44..1659.12
rows=446 width=4) (actual time=0.267..1.266 rows=676 loops=1)
Recheck Cond: (cachedgroupmembers_2.groupid = 4)
Filter:
(cachedgroupmembers_2.disabled = 0)
-> Bitmap Index Scan on
cachedgroupmembers2 (cost=0.00..12.33 rows=446 width=0) (actual
time=0.171..0.171 rows=676 loops=1)
Index Cond:
(cachedgroupmembers_2.groupid = 4)
-> Index Scan using
principals_pkey on public.principals principals_1 (cost=0.00..8.61
rows=1 width=4) (actual time=0.011..0.011 rows=1 loops=676)
Output: principals_1.id
Index Cond:
(principals_1.id = cachedgroupmembers_2.memberid)
Filter: ((principals_1.id
<> 1) AND (principals_1.disabled = 0) AND
((principals_1.principaltype)::text = 'User'::text))
Rows Removed by Filter: 0
-> Index Scan using users_pkey on
public.users main (cost=0.00..3.67 rows=1 width=434) (actual
time=0.007..0.008 rows=1
loops=675)
Index Cond: (main.id =
principals_1.id)
-> Index Scan using cachedgroupmembers1 on
public.cachedgroupmembers cachedgroupmembers_4 (cost=0.00..133.79
rows=65 width=8) (actual time=0.012..1.199 rows=1398 loops=675)
Index Cond:
(cachedgroupmembers_4.memberid = principals_1.id)
Filter: (cachedgroupmembers_4.disabled
= 0)
Rows Removed by Filter: 0
Total runtime: 255694.440 ms
(47 rows)
The good one:
Unique (cost=528.88..528.96 rows=1 width=522) (actual
time=5029.906..5068.395 rows=572 loops=1)
-> Sort (cost=528.88..528.89 rows=1 width=522) (actual
time=5029.889..5032.743 rows=33209 loops=1)
Sort Method: quicksort Memory: 13143kB
-> Nested Loop (cost=36.08..528.87 rows=1 width=522) (actual
time=0.410..4178.931 rows=33209 loops=1)
-> Nested Loop (cost=3.54..449.25 rows=2 width=526)
(actual time=0.139..1459.785 rows=943730 loops=1)
Join Filter: (principals_1.id =
cachedgroupmembers_4.memberid)
-> Nested Loop (cost=0.00..314.65 rows=1
width=530) (actual time=0.115..12.537 rows=675 loops=1)
-> Nested Loop (cost=0.00..310.98 rows=1
width=8) (actual time=0.106..7.203 rows=675 loops=1)
Output: principals_1.id,
cachedgroupmembers_2.memberid
-> Index Only Scan using disgroumem on
public.cachedgroupmembers cachedgroupmembers_2 (cost=0.00..101.59
rows=24 width=4) (actual time=0.071..1.046 rows=676 loops=1)
Output:
cachedgroupmembers_2.groupid, cachedgroupmembers_2.memberid,
cachedgroupmembers_2.disabled
Index Cond:
((cachedgroupmembers_2.groupid = 4) AND (cachedgroupmembers_2.disabled =
0))
Heap Fetches: 676
-> Index Scan using principals_pkey on
public.principals principals_1 (cost=0.00..8.71 rows=1 width=4) (actual
time=0.008..0.008 rows=1 loops=676)
Output: principals_1.id
Index Cond: (principals_1.id =
cachedgroupmembers_2.memberid)
Filter: ((principals_1.id <> 1)
AND (principals_1.disabled = 0) AND ((principals_1.principaltype)::text
= 'User'::text))
Rows Removed by Filter: 0
-> Index Scan using users_pkey on
public.users main (cost=0.00..3.67 rows=1 width=522) (actual
time=0.006..0.007 rows=1 loops=675)
Index Cond: (main.id = principals_1.id)
-> Bitmap Heap Scan on public.cachedgroupmembers
cachedgroupmembers_4 (cost=3.54..133.77 rows=66 width=8) (actual
time=0.309..1.752 rows=1398 loops=675)
Recheck Cond: (cachedgroupmembers_4.memberid
= main.id)
Filter: (cachedgroupmembers_4.disabled = 0)
Rows Removed by Filter: 0
-> Bitmap Index Scan on cachedgroupmembers1
(cost=0.00..3.52 rows=66 width=0) (actual time=0.185..0.185 rows=1398
loops=675)
Index Cond:
(cachedgroupmembers_4.memberid = main.id)
-> Bitmap Heap Scan on public.acl acl_3
(cost=32.54..39.78 rows=3 width=4) (actual time=0.002..0.002 rows=0
loops=943730)
Recheck Cond: ((acl_3.principalid =
cachedgroupmembers_4.groupid) AND ((((acl_3.rightname)::text =
'OwnTicket'::text) AND ((acl_3.principaltype)::text = 'Group'::text)) OR
(((acl_3.rightname
)::text = 'SuperUser'::text) AND ((acl_3.principaltype)::text =
'Group'::text))))
Filter: (((acl_3.objecttype)::text =
'RT::Queue'::text) OR (((acl_3.objecttype)::text = 'RT::System'::text)
AND (acl_3.objectid = 1)))
-> BitmapAnd (cost=32.54..32.54 rows=3 width=0)
(actual time=0.002..0.002 rows=0 loops=943730)
-> Bitmap Index Scan on acl3
(cost=0.00..2.22 rows=49 width=0) (actual time=0.001..0.001 rows=1
loops=943730)
Index Cond: (acl_3.principalid =
cachedgroupmembers_4.groupid)
-> BitmapOr (cost=30.07..30.07 rows=531
width=0) (actual time=0.110..0.110 rows=0 loops=4412)
-> Bitmap Index Scan on acl1
(cost=0.00..25.46 rows=521 width=0) (actual time=0.102..0.102 rows=521
loops=4412)
Index Cond:
(((acl_3.rightname)::text = 'OwnTicket'::text) AND
((acl_3.principaltype)::text = 'Group'::text))
-> Bitmap Index Scan on acl1
(cost=0.00..4.36 rows=11 width=0) (actual time=0.007..0.007 rows=4
loops=4412)
Index Cond:
(((acl_3.rightname)::text = 'SuperUser'::text) AND
((acl_3.principaltype)::text = 'Group'::text))
Total runtime: 5069.842 ms
(47 rows)
Why does PostgreSQL pick one before the other and how can I make sure
that it will keep using the "good" one instead of the "bad" one?
/ Eskil
> > > The rowcount estimates from 9.2 seem greatly different from the 8.4 plan.
> > > Did you remember to ANALYZE all the tables after migrating? Maybe there
> > > were some table-specific statistics targets that you forgot to transfer
> > > over? In any case, the 9.2 plan looks like garbage-in-garbage-out to
> > > me :-( ... without estimates at least a little closer to reality, the
> > > planner is unlikely to do anything very sane.
> > >
> > > (BTW, I wonder why you are moving only to 9.2 and not something more
> > > recent.)
> >
> > You put me on the right track with your conclusion that the estimates
> > were off the chart. The quick-and-dirty fix "DELETE FROM pg_statistic;"
> > solved this problem. This database now have to build up sane estimates
> > from scratch.
>
> Actually it took a VACUUM FULL; and DELETE FROM pg_statistic; followed
> by ANALYZE on all tables to get it right.
It worked last time, but this time it does not work. I have deleted all
data in the table pg_statistic and run ANALYZE on all tables but the
planner still make crappy optimizations. How can I adjust the estimates
to make the planner work better?
Last time it was in testing, this time it is in production, so urgent
help is needed, please!
This query now takes 90 seconds and it should not take more than 4-5
seconds.
EXPLAIN ANALYZE VERBOSE SELECT DISTINCT main.* FROM Users main CROSS
JOIN ACL ACL_3 JOIN Principals Principals_1 ON ( Principals_1.id =
main.id ) JOIN CachedGroupMembers CachedGroupMembers_2 ON
( CachedGroupMembers_2.MemberId = Principals_1.id ) JOIN
CachedGroupMembers CachedGroupMembers_4 ON
( CachedGroupMembers_4.MemberId = Principals_1.id ) WHERE
((ACL_3.ObjectType = 'RT::Queue' AND ACL_3.ObjectId = 85) OR
(ACL_3.ObjectType = 'RT::System' AND ACL_3.ObjectId = 1)) AND
(ACL_3.PrincipalId = CachedGroupMembers_4.GroupId) AND
(ACL_3.PrincipalType = 'Group') AND (ACL_3.RightName = 'OwnTicket') AND
(CachedGroupMembers_2.Disabled = '0') AND (CachedGroupMembers_2.GroupId
= '4') AND (CachedGroupMembers_4.Disabled = '0') AND
(Principals_1.Disabled = '0') AND (Principals_1.PrincipalType = 'User')
AND (Principals_1.id != '1') ORDER BY main.Name ASC;
QUERY
PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
-----------------------------------------------------------------------------------------------------------
Unique (cost=8907.68..8907.76 rows=1 width=336) (actual
time=92075.721..92076.336 rows=176 loops=1)
Output: main.id, main.name, main.password, main.authtoken,
main.comments, main.signature, main.emailaddress,
main.freeformcontactinfo, main.organization, main.realname,
main.nickname, main.lang, main.gecos, m
ain.homephone, main.workphone, main.mobilephone, main.pagerphone,
main.address1, main.address2, main.city, main.state, main.zip,
main.country, main.timezone, main.creator, main.created,
main.lastupdatedby, main.
lastupdated, main.smimecertificate
-> Sort (cost=8907.68..8907.69 rows=1 width=336) (actual
time=92075.720..92075.748 rows=607 loops=1)
Output: main.id, main.name, main.password, main.authtoken,
main.comments, main.signature, main.emailaddress,
main.freeformcontactinfo, main.organization, main.realname,
main.nickname, main.lang, main.ge
cos, main.homephone, main.workphone, main.mobilephone, main.pagerphone,
main.address1, main.address2, main.city, main.state, main.zip,
main.country, main.timezone, main.creator, main.created,
main.lastupdatedby,
main.lastupdated, main.smimecertificate
Sort Key: main.name, main.id, main.password, main.authtoken,
main.comments, main.signature, main.emailaddress,
main.freeformcontactinfo, main.organization, main.realname,
main.nickname, main.lang, main.
gecos, main.homephone, main.workphone, main.mobilephone,
main.pagerphone, main.address1, main.address2, main.city, main.state,
main.zip, main.country, main.timezone, main.creator, main.created,
main.lastupdatedb
y, main.lastupdated, main.smimecertificate
Sort Method: quicksort Memory: 243kB
-> Nested Loop (cost=20.37..8907.67 rows=1 width=336) (actual
time=540.971..92062.584 rows=607 loops=1)
Output: main.id, main.name, main.password,
main.authtoken, main.comments, main.signature, main.emailaddress,
main.freeformcontactinfo, main.organization, main.realname,
main.nickname, main.lang, m
ain.gecos, main.homephone, main.workphone, main.mobilephone,
main.pagerphone, main.address1, main.address2, main.city, main.state,
main.zip, main.country, main.timezone, main.creator, main.created,
main.lastupda
tedby, main.lastupdated, main.smimecertificate
-> Nested Loop (cost=20.37..8845.47 rows=3 width=340)
(actual time=0.188..1204.040 rows=972439 loops=1)
Output: main.id, main.name, main.password,
main.authtoken, main.comments, main.signature, main.emailaddress,
main.freeformcontactinfo, main.organization, main.realname,
main.nickname, main.l
ang, main.gecos, main.homephone, main.workphone, main.mobilephone,
main.pagerphone, main.address1, main.address2, main.city, main.state,
main.zip, main.country, main.timezone, main.creator, main.created,
main.la
stupdatedby, main.lastupdated, main.smimecertificate,
cachedgroupmembers_4.groupid
-> Nested Loop (cost=20.37..8568.24 rows=2
width=344) (actual time=0.179..11.075 rows=688 loops=1)
Output: main.id, main.name, main.password,
main.authtoken, main.comments, main.signature, main.emailaddress,
main.freeformcontactinfo, main.organization, main.realname,
main.nickname,
main.lang, main.gecos, main.homephone, main.workphone, main.mobilephone,
main.pagerphone, main.address1, main.address2, main.city, main.state,
main.zip, main.country, main.timezone, main.creator, main.created, m
ain.lastupdatedby, main.lastupdated, main.smimecertificate,
principals_1.id, cachedgroupmembers_2.memberid
-> Nested Loop (cost=20.37..8411.79 rows=41
width=8) (actual time=0.170..6.551 rows=688 loops=1)
Output: principals_1.id,
cachedgroupmembers_2.memberid
-> Bitmap Heap Scan on
public.cachedgroupmembers cachedgroupmembers_2 (cost=20.37..2510.57
rows=689 width=4) (actual time=0.156..1.362 rows=689 loops=1)
Output: cachedgroupmembers_2.id,
cachedgroupmembers_2.groupid, cachedgroupmembers_2.memberid,
cachedgroupmembers_2.via, cachedgroupmembers_2.immediateparentid,
cachedgroupm
embers_2.disabled
Recheck Cond:
((cachedgroupmembers_2.groupid = 4) AND (cachedgroupmembers_2.disabled =
0))
-> Bitmap Index Scan on
disgroumem (cost=0.00..20.20 rows=689 width=0) (actual
time=0.107..0.107 rows=689 loops=1)
Index Cond:
((cachedgroupmembers_2.groupid = 4) AND (cachedgroupmembers_2.disabled =
0))
-> Index Scan using principals_pkey on
public.principals principals_1 (cost=0.00..8.55 rows=1 width=4) (actual
time=0.006..0.007 rows=1 loops=689)
Output: principals_1.id
Index Cond: (principals_1.id =
cachedgroupmembers_2.memberid)
Filter: ((principals_1.id <> 1)
AND (principals_1.disabled = 0) AND ((principals_1.principaltype)::text
= 'User'::text))
Rows Removed by Filter: 0
-> Index Scan using users_pkey on
public.users main (cost=0.00..3.81 rows=1 width=336) (actual
time=0.005..0.006 rows=1 loops=688)
Output: main.id, main.name,
main.password, main.authtoken, main.comments, main.signature,
main.emailaddress, main.freeformcontactinfo, main.organization,
main.realname, main.nick
name, main.lang, main.gecos, main.homephone, main.workphone,
main.mobilephone, main.pagerphone, main.address1, main.address2,
main.city, main.state, main.zip, main.country, main.timezone,
main.creator, main.crea
ted, main.lastupdatedby, main.lastupdated, main.smimecertificate
Index Cond: (main.id = principals_1.id)
-> Index Scan using cachedgroupmembers1 on
public.cachedgroupmembers cachedgroupmembers_4 (cost=0.00..137.96
rows=65 width=8) (actual time=0.008..1.434 rows=1413 loops=688)
Output: cachedgroupmembers_4.id,
cachedgroupmembers_4.groupid, cachedgroupmembers_4.memberid,
cachedgroupmembers_4.via, cachedgroupmembers_4.immediateparentid,
cachedgroupmembers_4.dis
abled
Index Cond: (cachedgroupmembers_4.memberid =
principals_1.id)
Filter: (cachedgroupmembers_4.disabled = 0)
Rows Removed by Filter: 0
-> Index Only Scan using acl1 on public.acl acl_3
(cost=0.00..20.72 rows=1 width=4) (actual time=0.093..0.093 rows=0
loops=972439)
Output: acl_3.rightname, acl_3.objecttype,
acl_3.objectid, acl_3.principaltype, acl_3.principalid
Index Cond: ((acl_3.rightname = 'OwnTicket'::text)
AND (acl_3.principaltype = 'Group'::text) AND (acl_3.principalid =
cachedgroupmembers_4.groupid))
Filter: ((((acl_3.objecttype)::text =
'RT::Queue'::text) AND (acl_3.objectid = 85)) OR
(((acl_3.objecttype)::text = 'RT::System'::text) AND (acl_3.objectid =
1)))
Rows Removed by Filter: 0
Heap Fetches: 33532
Total runtime: 92076.507 ms
(39 rows)
/ Eskil
On Thu, Jul 21, 2016 at 11:48 AM, Johan Fredriksson <eskil@kth.se> wrote: > EXPLAIN ANALYZE VERBOSE SELECT DISTINCT main.* FROM Users main CROSS > JOIN ACL ACL_3 JOIN Principals Principals_1 ON ( Principals_1.id = > main.id ) JOIN CachedGroupMembers CachedGroupMembers_2 ON > ( CachedGroupMembers_2.MemberId = Principals_1.id ) JOIN > CachedGroupMembers CachedGroupMembers_4 ON > ( CachedGroupMembers_4.MemberId = Principals_1.id ) WHERE > ((ACL_3.ObjectType = 'RT::Queue' AND ACL_3.ObjectId = 85) OR > (ACL_3.ObjectType = 'RT::System' AND ACL_3.ObjectId = 1)) AND > (ACL_3.PrincipalId = CachedGroupMembers_4.GroupId) AND > (ACL_3.PrincipalType = 'Group') AND (ACL_3.RightName = 'OwnTicket') AND > (CachedGroupMembers_2.Disabled = '0') AND (CachedGroupMembers_2.GroupId > = '4') AND (CachedGroupMembers_4.Disabled = '0') AND > (Principals_1.Disabled = '0') AND (Principals_1.PrincipalType = 'User') > AND (Principals_1.id != '1') ORDER BY main.Name ASC; That cross join doesn't look right. It has no join condition.
That cross join doesn't look right. It has no join condition.
That is that the definition of a "CROSS JOIN"...
David J.
On Thu, Jul 21, 2016 at 3:29 PM, David G. Johnston <david.g.johnston@gmail.com> wrote: > On Thu, Jul 21, 2016 at 2:24 PM, Claudio Freire <klaussfreire@gmail.com> > wrote: >> >> That cross join doesn't look right. It has no join condition. > > > That is that the definition of a "CROSS JOIN"... > > David J. Well, maybe it shouldn't be. A cross join I mean. I see the query and a cross join there doesn't make much sense. There's no filtering of the output rows on the where clause either AFAICT, and it's producing a lot of intermediate rows that don't seem to be necessary. That was my point.
I can add that setting enable_nestloop = 0 cuts the runtime for this query down to about 4 seconds.
Disabling nested loops globaly does however impacts performance of a lot of other queries.
/ Eskil
And by the way, I have also tried to upgrade to Postgresql 9.4.8 (the latest version in postgresl.org's own repository)
withoutimprovment.
/ Eskil
On 22/07/16 13:07, Johan Fredriksson wrote: > And by the way, I have also tried to upgrade to Postgresql 9.4.8 (the latest version in postgresl.org's own repository)without improvment. > Not sure what repo you are using, but 9.5.3 and 9.6 Beta are the *actual* latest versions. Now I'm not sure they will actually help your particular query, but are probably worth a try out! regards Mark
fre 2016-07-22 klockan 19:08 +1200 skrev Mark Kirkwood: > On 22/07/16 13:07, Johan Fredriksson wrote: > > And by the way, I have also tried to upgrade to Postgresql 9.4.8 (the latest version in postgresl.org's own repository)without improvment. > > > > Not sure what repo you are using, but 9.5.3 and 9.6 Beta are the > *actual* latest versions. Now I'm not sure they will actually help your > particular query, but are probably worth a try out! The one I found on https://www.postgresql.org/download/linux/redhat/ That page points out http://yum.postgresql.org/9.4/redhat/rhel-6-x86_64/pgdg-redhat94-9.4-1.noarch.rpm as the latest. Perhaps the download-pageneed to be updated? / Eskil