[rt-users] RT 4 Upgrade Slow Performance - CustomFields?

Nathan Baker bakern at gmail.com
Wed May 30 16:25:15 EDT 2012


Ruslan,

I guess what I was getting at is I don't think the SQL queries are the
problem here.  The sum (by using your perl code) was 0.324813 seconds, much
less than 4 seconds.

I'm still trying different Apache settings, Postgresql settings, etc., but
here's a different way to explain the issue:

I can click on Home, then click on a ticket, then Home, then a ticket,
etc., for as long as I want and it is very fast (page load time is about
0.2-0.3 seconds).

If I wait for about 5 seconds, I can continue this without any change.

If I wait for even 10 seconds, or 30 seconds, or anything longer, when I
click on either Home or a ticket, the page takes about 2-4 seconds to load.
This will happen for both the Home page and a ticket Display page the first
time they are each displayed, and after that they are very fast again.
 This is why it seems to me it has to be an Apache or Mason cache/timeout
issue.  It's almost like it's compiling or building something again, which
is why I originally was drawn to the Javascript minifier suggestion.

I really appreciate your advice on this.

-Nate

On Wed, May 30, 2012 at 3:49 PM, Ruslan Zakirov <ruz at bestpractical.com>wrote:

> On Wed, May 30, 2012 at 10:15 PM, Nathan Baker <bakern at gmail.com> wrote:
> > Ruslan,
> >
> > I wasn't aware that sessions had to be cleared, but now that you
> mentioned
> > it I looked and there were almost 10k sessions in our table.  I cleared
> that
> > out and it does not seem to be slow in that section anymore.  I've also
> > added that command to crontab to run daily.
> >
> > It seems much better after doing that, I don't see any pages taking over
> 3-4
> > seconds to load anymore.  I do still see some taking about 2-3 seconds to
> > load.  That is more usable, although I would like to get it better if
> > possible.  I turned on logging of SQL statements in RT only for now, I'm
> not
> > as familiar with Postgresql as I am with MySQL, but I could look into
> > logging in there if necessary.
> >
> > We only have about 5 staff using the RT web interface.  The longest
> queries
> > I see are still fairly quick I think, but here are a couple examples of
> the
> > longer ones for Display.html:
> >
> > [Wed May 30 17:52:44 2012] [debug]: SQL(0.136027s): SELECT  * FROM Groups
> > WHERE LOWER(Domain) = LOWER(?) AND LOWER(Type) = LOWER(?);  [ bound
> values:
> > 'SystemInternal' 'Privileged' ]
> > (/usr/share/request-tracker4/lib/RT/Interface/Web.pm:1115)
>
> This one is sort of "known issue". We have code paths where LOWER is
> used and is not used, but indexes for Pg on Groups table don't account
> this. Proper way would be to collect as many queries as possible that
> select or join Groups table, do analysis and come up with set of
> indexes for the table. I would love to take a look at such log.
>
> For this particular query index on LOWER(Domain) would be enough or
> (LOWER(Domain), LOWER(Type)) pair.
>
> > [Wed May 30 17:49:20 2012] [debug]: SQL(0.387888s): SELECT DISTINCT
> main.*
> > FROM Users main JOIN Principals Principals_1  ON ( Principals_1.id =
> main.id
> > ) JOIN CachedGroupMembers CachedGroupMembers_2  ON (
> > CachedGroupMembers_2.MemberId = Principals_1.id )  WHERE
> > (Principals_1.Disabled = '0') AND (CachedGroupMembers_2.GroupId =
> '25472')
> > AND (CachedGroupMembers_2.Disabled = '0') AND
> > (LOWER(Principals_1.PrincipalType) = 'user')  ORDER BY main.Name ASC ;
> > (/usr/share/request-tracker4/lib/RT/Interface/Web.pm:1115)
>
> Hard to tell anything without EXPLAIN ANALYZE... This query selects
> users who are not disabled and recursive members of a group. Select
> from Groups by id to see how important this query is.
>
> > Here is an example summary of a page load (with SQL logging on and Mason
> > profiling off) for Display.html:
> > 48 Queries
> > 4.1 Seconds page load
> > Longest query:
> > [Wed May 30 17:56:19 2012] [debug]: SQL(0.118095s): SELECT  * FROM Groups
> > WHERE LOWER(Domain) = LOWER(?) AND LOWER(Type) = LOWER(?);  [ bound
> values:
> > 'SystemInternal' 'Unprivileged' ]
> > (/usr/share/request-tracker4/lib/RT/Interface/Web.pm:1115)
> >
> > All other queries < 0.1 seconds, most are < 0.01 seconds
>
> Use the following command to calculate how much time all 48 queries took:
>
> cat part.of.rt.log | perl -ne '$res += (/SQL\(([0-9.]+s)\)/)[0] || 0;
> END { print "$res\n"}'
>
> Question is how close the sum to 4 seconds.
>
> > Thanks,
> > Nate
>
> --
> Best regards, Ruslan.
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.bestpractical.com/pipermail/rt-users/attachments/20120530/61cc8d76/attachment.htm>


More information about the rt-users mailing list