RT search slow after update

Lovrenc_Avsenek · October 15, 2024, 8:31am

Hi.
I have recently updated RT from 5.0.1 to 5.0.7.
After updating I noticed a severe slowdown of the search function.
When using search I get immediate header saying something like " Found 29 tickets", but it takes a couple of minutes before the actual result is listed.
I checked the database and I can see a query running for a long time:
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 = $1) OR (ACL_3.ObjectType = $2 AND ACL_3.ObjectId = $3)) AND (ACL_3.PrincipalId = CachedGroupMembers_4.GroupId) AND (ACL_3.PrincipalType = $4) AND (ACL_3.RightName IN ($5, $6)) AND (CachedGroupMembers_2.Disabled = $7) AND (CachedGroupMembers_2.GroupId = $8) AND (CachedGroupMembers_4.Disabled = $9) AND (Principals_1.Disabled = $10) AND (Principals_1.PrincipalType = $11) AND (Principals_1.id != $12) ORDER BY main.Name ASC

I am running RT 5.0.7 on Ubuntu 22.04.
The database is Postgresql 16.3 and is currently about 71GB with 250k tickets.
I have tried to run vacuum and analyze on the database after upgrade, but that didn’t help.

Has anyone run into similar problem or has any idea on how to approach this problem?

GreenJimll · October 16, 2024, 10:12am

We’ve seen similar, yesterday in fact. In our case it we “fixed” it by suggesting the users concerned used “=” rather than “LIKE” in their rather large Ticket SQL, as the LIKE appeared to be causing table scans over a large number of aliased table JOINs of CachedGroupMembers. But they’ve been using the same query fine on our production RT, so something must have changed in the real SQL it is generating. We’ve not dug in much deeper yet.

Lovrenc_Avsenek · October 21, 2024, 11:24am

I see. So the user was actually doing and SQL query himself.
Unfortunately, I don’t have the option here, since this is the query produced by the built-in search in RT.

G.Booth · October 21, 2024, 11:53am

The user was using the built in TicketSQL and the “Advanced” option. Do you not have access to this via the Search menu?

Lovrenc_Avsenek · October 21, 2024, 12:52pm

If you mean the query builder - yes I have access to it. Though opening it also takes considerable time.
The search I have been using was the simple search though.

Lovrenc_Avsenek · October 21, 2024, 12:53pm

Update: Yes, just opening advanced search also takes a while while. In fact, the same query occupies the database. I made an analysis of the query.

024-10-21 14:29:54 CEST [137134]: [1-1] user=rt5,db=rt5 LOG:  duration: 256964.463 ms  execute <unnamed>: 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 = $1) OR (ACL_3.ObjectType = $2 AND ACL_3.ObjectId   = $3)) AND (ACL_3.PrincipalId = CachedGroupMembers_4.GroupId) AND (ACL_3.PrincipalType = $4) AND (ACL_3.RightName IN ($5, $6)) AND (CachedGroupMembers_2.Disabled = $7) AND (CachedGroupMembers_2.GroupId = $8) AND (CachedGroupMembers_4.Disabled = $9) AND (Principals_1.Disabled = $10) AND (Principals_1.PrincipalType = $11) AND (Principals_1.id != $12)  ORDER BY main.Name ASC 
2024-10-21 14:29:54 CEST [137134]: [2-1] user=rt5,db=rt5 LOG:  duration: 256964.454 ms  plan:
        Query Text: 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 = $1) OR (ACL_3.ObjectType = $2 AND ACL_3.ObjectId   = $3)) AND (ACL_3.PrincipalId = CachedGroupMembers_4.GroupId) AND (ACL_3.PrincipalType = $4) AND (ACL_3.RightName IN ($5, $6)) AND (CachedGroupMembers_2.Disabled = $7) AND (CachedGroupMembers_2.GroupId = $8) AND (CachedGroupMembers_4.Disabled = $9) AND (Principals_1.Disabled = $10) AND (Principals_1.PrincipalType = $11) AND (Principals_1.id != $12)  ORDER BY main.Name ASC 
        Query Parameters: $1 = 'RT::Queue', $2 = 'RT::System', $3 = '1', $4 = 'Group', $5 = 'SuperUser', $6 = 'OwnTicket', $7 = '0', $8 = '4', $9 = '0', $10 = '0', $11 = 'User', $12 = '1'
        Unique  (cost=317.39..317.47 rows=1 width=308) (actual time=256625.761..256963.803 rows=333 loops=1)
          ->  Sort  (cost=317.39..317.40 rows=1 width=308) (actual time=256625.758..256659.524 rows=734773 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: 142109kB
                ->  Nested Loop  (cost=2.11..317.38 rows=1 width=308) (actual time=2.143..254991.840 rows=734773 loops=1)
                      ->  Nested Loop  (cost=1.69..130.95 rows=2 width=312) (actual time=0.161..218.114 rows=326712 loops=1)
                            ->  Nested Loop  (cost=1.27..128.52 rows=1 width=316) (actual time=0.079..5.210 rows=333 loops=1)
                                  ->  Merge Join  (cost=0.84..90.20 rows=17 width=312) (actual time=0.064..1.984 rows=647 loops=1)
                                        Merge Cond: (main.id = cachedgroupmembers_2.memberid)
                                        ->  Index Scan using users_pkey on users main  (cost=0.28..70.52 rows=1647 width=308) (actual time=0.020..0.822 rows=1648 loops=1)
                                        ->  Index Only Scan using disgroumem on cachedgroupmembers cachedgroupmembers_2  (cost=0.43..14.27 rows=470 width=4) (actual time=0.030..0.384 rows=648 loops=1)
                                              Index Cond: ((groupid = 4) AND (disabled = 0))
                                              Heap Fetches: 155
                                  ->  Index Scan using principals_pkey on principals principals_1  (cost=0.42..2.25 rows=1 width=4) (actual time=0.004..0.004 rows=1 loops=647)
                                        Index Cond: (id = main.id)
                                        Filter: ((id <> 1) AND (disabled = 0) AND ((principaltype)::text = 'User'::text))
                                        Rows Removed by Filter: 0
                            ->  Index Only Scan using cachedgroupmembers2 on cachedgroupmembers cachedgroupmembers_4  (cost=0.43..2.09 rows=34 width=8) (actual time=0.017..0.398 rows=981 loops=333)
                                  Index Cond: ((memberid = principals_1.id) AND (disabled = 0))
                                  Heap Fetches: 39601
                      ->  Index Only Scan using acl1 on acl acl_3  (cost=0.42..93.20 rows=2 width=4) (actual time=0.773..0.779 rows=2 loops=326712)
                            Index Cond: ((rightname = ANY ('{SuperUser,OwnTicket}'::text[])) AND (principaltype = 'Group'::text) AND (principalid = cachedgroupmembers_4.groupid))
                            Filter: (((objecttype)::text = 'RT::Queue'::text) OR (((objecttype)::text = 'RT::System'::text) AND (objectid = 1)))
                            Heap Fetches: 804

Gerald_Sedrati-Dinet · October 22, 2024, 8:46am

Since it seems to be related to CacheGroupMembers table, maybe you can improve perfs with: etc/upgrade/shrink-cgm-table?

GreenJimll · October 22, 2024, 11:02am

I’ve been doing a bit more digging into our slow TicketSQL query here. This is comparing the output of RT 5.0.1/DBIx::SearchBuilder 1.68 with RT 5.0.7/DBIx::SearchBuilder 1.82. Some things I’ve discovered so far:

The introduction of the MariaDB window functions into DBIx::SearchBuilder don’t appear to be the cause, as running the “inner” SQL that the window function OVER() is operating over is the slow bit.
Running the raw SQL extracted from the RT 5.0.1 server on the RT 5.0.7 server produces a fast response still, so its not an index missing/not working issue.

I’m guessing at the moment that the slow down is coming from some change in one of the DBIx::SearchBuilder versions between 1.68 (fast) and 1.82 (slow). I need to dig in more deeply though. I’ll also give the shrink-cgm-table a go once I know I don’t have test users trying to play with the server.

Lovrenc_Avsenek · October 22, 2024, 2:36pm

Thank you for the replies.
I tried the etc/upgrade/shrink-cgm-table followed by VACUUM and ANALYZE. Unfortunately, this didn’t help.
A couple of of further information I was able to get:

In the 5.0.1 opening advanced search was already slow - unless the user was an admin!?
In 5.0.7 the advanced search is slow to open even if you’re an admin(except for one user, but I have yet to notice a difference from my user - who is also an admin user).

This does seem to be a permission check issue. When searching the number of “hits” is displayed immediately, then it continues to process the aforementioned query. So I’ll try to search on in this direction.

GreenJimll · October 22, 2024, 4:44pm

I’ve also just run /opt/rt5/etc/upgrade/shrink-cgm-table on our test 5.0.7 server and then ran our degenerate TicketSQL query and… no difference. Search takes ages, then server returns an error, with mariadb database server pegged at 100% CPU.

Lovrenc_Avsenek · October 24, 2024, 10:17am

I’m out of ideas.
Should I file this as a bug report?

GreenJimll · October 24, 2024, 2:21pm

Probably worth doing as it means BP have visibility of it in their issue tracking system.

FWIW I’ve found I can “work round” our issue with a callback that turns LIKE into SHALLOW LIKE in the Search/Build.html. Need to do a bit of finessing over the next week or so, but that will at least stop existing saved searches our service desk folk have from blowing up 5.0.7.

Lovrenc_Avsenek · November 12, 2024, 5:12am

Update:
To quote Jim Brandt who handled the bug report " The slowness is from building the Owner dropdown when there are a large number of users with OwnTicket and a few other configurations."
This seems to be a known issue and can be handled with a configuration update.
For me, setting :

Set($AutocompleteOwnersForSearch, 1);

Fixed the issue.
Another setting which mr. Brandt suggested could help is “$AutocompleteOwners”.

This fixed both the slowness of the quick search(which was new for me after the update from 5.0.1 to v5.0.7) as well as the slowness when opening advanced search(noticed when updated from v3. to v5.0.1)