[rt-users] Postgresql 4.4.1 slow queries?

Joel Bergmark joel.bergmark at t3.se
Wed Sep 28 10:57:30 EDT 2016


Hahaha, i used mysql syntax first "use rt4;" of course that messed it up :)

Below is the output of EXPLAIN ANALYSE, but I need some help to interpret the relevant information in this :)

                                  QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Unique  (cost=311.85..311.93 rows=1 width=411) (actual time=371.738..371.809 rows=49 loops=1)
   ->  Sort  (cost=311.85..311.86 rows=1 width=411) (actual time=371.736..371.739 rows=94 loops=1)
         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.smimecertificate, main.creator, main.created, main.lastupdatedby, main.lastupdated
         Sort Method: quicksort  Memory: 59kB
         ->  Nested Loop  (cost=1.82..311.84 rows=1 width=411) (actual time=0.321..370.336 rows=94 loops=1)
               ->  Nested Loop  (cost=1.55..309.32 rows=2 width=415) (actual time=0.076..22.220 rows=21011 loops=1)
                     Join Filter: (principals_1.id = cachedgroupmembers_4.memberid)
                     ->  Nested Loop  (cost=1.12..306.10 rows=1 width=419) (actual time=0.067..0.937 rows=57 loops=1)
                           ->  Nested Loop  (cost=0.70..299.02 rows=4 width=415) (actual time=0.060..0.554 rows=57 loops=1)
                                 ->  Index Only Scan using disgroumem on cachedgroupmembers cachedgroupmembers_2  (cost=0.42..80.08 rows=35 width=4) (actual time=0.052..0.122 rows=58 loops=1)
                                       Index Cond: ((groupid = 4) AND (disabled = 0))
                                       Heap Fetches: 57
                                 ->  Index Scan using users_pkey on users main  (cost=0.28..6.25 rows=1 width=411) (actual time=0.005..0.006 rows=1 loops=58)
                                       Index Cond: (id = cachedgroupmembers_2.memberid)
                           ->  Index Scan using principals_pkey on principals principals_1  (cost=0.42..1.76 rows=1 width=4) (actual time=0.005..0.006 rows=1 loops=57)
                                 Index Cond: (id = main.id)
                                 Filter: ((id <> 1) AND (disabled = 0) AND ((principaltype)::text = 'User'::text))
                     ->  Index Scan using cachedgroupmembers3 on cachedgroupmembers cachedgroupmembers_4  (cost=0.42..3.15 rows=6 width=8) (actual time=0.006..0.291 rows=369 loops=57)
                           Index Cond: (memberid = main.id)
                           Filter: (disabled = 0)
                           Rows Removed by Filter: 0
               ->  Index Only Scan using acl1 on acl acl_3  (cost=0.28..1.25 rows=1 width=4) (actual time=0.016..0.016 rows=0 loops=21011)
                     Index Cond: ((rightname = 'OwnTicket'::text) AND (principaltype = 'Group'::text) AND (principalid = cachedgroupmembers_4.groupid))
                     Filter: ((((objecttype)::text = 'RT::Queue'::text) AND (objectid = 56)) OR (((objecttype)::text = 'RT::System'::text) AND (objectid = 1)))
                     Rows Removed by Filter: 0
                     Heap Fetches: 1615
Total runtime: 371.982 ms
(27 rows)

Regards, Joel

Från: rt-users [mailto:rt-users-bounces at lists.bestpractical.com] För Joel Bergmark
Skickat: den 27 september 2016 09:53
Till: rt-users at lists.bestpractical.com
Ämne: [rt-users] Postgresql 4.4.1 slow queries?

Hi,

After upgrading to version 4.4.1 i have noticed that the SQL-queries takes significant longer time to produce a result, on average on my system, running Ubuntu 14.04 LTS, Postgres 9.3, Apache with perlmod. 8 gigram and plenty of CPU in a vmware cluster on SSD:s (likely not a hardware issue). We did not experience RT to have been this slow on 4.4.0.

Each query takes about 350ms to give a result, occasionally up to 4000ms have been seen, not a big problem but somethings that needs to be fixed.

Postgres have access to shared buffers = 2048 and effective_cache_size = 4096MB that was modified yesterday but queries still are same speed.

I have read plenty on postgres optimizing but not much seem to make a difference, and the https://rt-wiki.bestpractical.com/wiki/PerformanceTuning seems a bit out of date.

Example of problem:

192.168.2.65 - - [27/Sep/2016:09:06:49 +0200] "GET /Search/Build.html?NewQuery=1 HTTP/1.1" 200 12072 Mozilla/5.0 (Windows NT 10.0; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/53.0.2785.101 Safari/537.36"
09:06:52 CEST LOG:  duration: 3362.432 ms  execute dbdpg_p2242_1745: 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
I'm looking for any suggestions about this, and I'm not an expert on postgresql, but guess that this could have something to do with RT:s "($UseSQLForACLChecks, 1);" or modperl via Apache or simply some index in postgres?

Appreciate any feedback :-)

Regards, Joel

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.bestpractical.com/pipermail/rt-users/attachments/20160928/9359dc58/attachment.htm>


More information about the rt-users mailing list