Re: Greatly increased query time after update to 4.2.9

Did some more digging on this issue today, and discovered the following difference between our production RT 4.0.8 environment and the underperforming test instance of RT 4.2.9: an extra join to CachedGroupMembers in a query that creates the SelectOwnerDropdown element under 4.2.9 produces a query that runs for 18 seconds (the one previously mentioned), as compared with 0.0023 seconds under 4.0.8.

4.2.9:
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 = 3) 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

Stack:
  [/opt/rt-4.2.9/app/sbin/../lib/RT/Handle.pm:1711]
  [/opt/rt-4.2.9/perl/perls/perl-5.20.1-RT/lib/site_perl/5.20.1/DBIx/SearchBuilder/Handle.pm:588]
  [/opt/rt-4.2.9/perl/perls/perl-5.20.1-RT/lib/site_perl/5.20.1/DBIx/SearchBuilder.pm:239]
  [/opt/rt-4.2.9/app/sbin/../lib/RT/SearchBuilder.pm:985]
  [/opt/rt-4.2.9/perl/perls/perl-5.20.1-RT/lib/site_perl/5.20.1/DBIx/SearchBuilder.pm:507]
  [/opt/rt-4.2.9/perl/perls/perl-5.20.1-RT/lib/site_perl/5.20.1/DBIx/SearchBuilder/Union.pm:112]
  [/opt/rt-4.2.9/app/share/html/Elements/SelectOwnerDropdown:78]
  [/opt/rt-4.2.9/app/share/html/Elements/SelectOwner:48]
  [/opt/rt-4.2.9/app/share/html/Ticket/Elements/Reminders:138]
  [/opt/rt-4.2.9/app/share/html/Ticket/Elements/Reminders:120]
  [/opt/rt-4.2.9/app/share/html/Ticket/Elements/ShowSummary:80]
  [/opt/rt-4.2.9/app/share/html/Widgets/TitleBox:56]
  [/opt/rt-4.2.9/app/share/html/Ticket/Elements/ShowSummary:83]
  [/opt/rt-4.2.9/app/share/html/Ticket/Display.html:62]
  [/opt/rt-4.2.9/app/share/html/Widgets/TitleBox:56]
  [/opt/rt-4.2.9/app/share/html/Ticket/Display.html:63]
  [/opt/rt-4.2.9/app/share/html/Ticket/autohandler:66]
  [/opt/rt-4.2.9/app/sbin/../lib/RT/Interface/Web.pm:681]
  [/opt/rt-4.2.9/app/sbin/../lib/RT/Interface/Web.pm:369]
  [/opt/rt-4.2.9/app/share/html/autohandler:53]

--

4.0.8:
SELECT DISTINCT main.* FROM Users main CROSS JOIN ACL ACL_2 JOIN Principals Principals_1 ON ( Principals_1.id = main.id ) JOIN CachedGroupMembers CachedGroupMembers_3 ON ( CachedGroupMembers_3.MemberId = Principals_1.id ) WHERE (Principals_1.Disabled = '0') AND (ACL_2.PrincipalId = CachedGroupMembers_3.GroupId) AND (Principals_1.id != '1') AND (ACL_2.PrincipalType = 'Group') AND (Principals_1.PrincipalType = 'User') AND (ACL_2.RightName = 'OwnTicket' OR ACL_2.RightName = 'SuperUser') AND (CachedGroupMembers_3.Disabled = '0') AND ((ACL_2.ObjectType = 'RT::Queue' AND ACL_2.ObjectId = 3) OR (ACL_2.ObjectType = 'RT::System') OR (ACL_2.ObjectType = 'RT::Queue' AND ACL_2.ObjectId = 3) OR (ACL_2.ObjectType = 'RT::System')) ORDER BY main.Name ASC

Stack:
  [/opt/rt4/sbin/../lib/RT/Handle.pm:1190]
  [/opt/rt_perl/lib/perl5/DBIx/SearchBuilder/Handle.pm:511]
  [/opt/rt_perl/lib/perl5/DBIx/SearchBuilder.pm:235]
  [/opt/rt4/sbin/../lib/RT/SearchBuilder.pm:343]
  [/opt/rt_perl/lib/perl5/DBIx/SearchBuilder.pm:503]
  [/opt/rt_perl/lib/perl5/DBIx/SearchBuilder/Union.pm:112]
  [/opt/rt4/share/html/Elements/SelectOwnerDropdown:80]
  [/opt/rt4/share/html/Elements/SelectOwner:48]
  [/opt/rt4/share/html/Ticket/Elements/Reminders:128]
  [/opt/rt4/share/html/Ticket/Elements/Reminders:116]
  [/opt/rt4/share/html/Ticket/Elements/ShowSummary:79]
  [/opt/rt4/share/html/Widgets/TitleBox:56]
  [/opt/rt4/share/html/Ticket/Elements/ShowSummary:83]
  [/opt/rt4/share/html/Ticket/Display.html:61]
  [/opt/rt4/share/html/Widgets/TitleBox:56]
  [/opt/rt4/share/html/Ticket/Display.html:62]
  [/opt/rt4/share/html/Ticket/autohandler:19]
  [/opt/rt4/sbin/../lib/RT/Interface/Web.pm:621]
  [/opt/rt4/sbin/../lib/RT/Interface/Web.pm:326]
  [/opt/rt4/share/html/autohandler:53]

I've glanced at the code, and at the commit history, but it's not apparent to me what's changed in the building of the query that leads to this extra join; nevertheless, this is certainly the problem. RT devs, should I be raising this as a bug against 4.2.9?

Cheers,
Jeff

-----Original Message-----
From: rt-devel [mailto:[email protected]] On Behalf Of Jeff Albert
Sent: Thursday, November 27, 2014 9:57 AM
To: Christian Loos; [email protected]
Subject: Re: [rt-devel] Greatly increased query time after update to 4.2.9

Hi Chris,
Sadly a restart didn't help; the first query after the restart was even worse as the cache got repopulated, and performance has since returned to where I found it immediately after the upgrade. Thanks for the suggestion, though! Has anybody else seen this with 4.2.9 installs?

Cheers,
Jeff

-----Original Message-----
From: Christian Loos [mailto:[email protected]]
Sent: Wednesday, November 26, 2014 10:52 PM
To: Jeff Albert; [email protected]
Subject: Re: Greatly increased query time after update to 4.2.9

Hi,

have you tried a mysql restart?
This fixed it for me (I didn't dig deeper what exactly was the problem).

Chris

Am 27.11.2014 um 02:11 schrieb Jeff Albert:
> I've just updated the development instance of our RT service, which 
> had been running at 4.0.8, to the latest 4.2.9 in preparation for a 
> planned production update to follow. Unfortunately, we've hit a 
> significant
> snag: the UI is now hugely slow in some views that were relatively 
> snappy before the update. The slow query log identifies a likely culprit: