RT 4 Upgrade Slow Performance

Nathan_Baker · May 29, 2012, 8:32pm

Hello Everyone,

We’ve upgraded from RT 3.8.8 with MySQL to RT 4.0.5 (debian package) with
Postgresql, and are having some performance issues with the web interface.
I’ve searched the list archives and Google, and haven’t been able to find
the issue. I’m hoping someone can help point me in the right direction.
Basically, the first time I visit any page (Home, Display, etc.) it takes
3-5 seconds to load, and sometimes 10-15 seconds. If I keep clicking on
other links as soon as the pages load, it’s fast and loads pages in 0.2 -
0.3 seconds. If I wait for about 15-30 seconds and then click a link
again, it takes 3-5 seconds to load again. Updating tickets seems to
consistently take 3-5 seconds.

Here’s some info about our installation:

About 6,000 tickets, 5 active users
Increased memory to 2GB, running on VMWare
Increased Postgresql shared_buffers and effective_cache_size (
Tuning Your PostgreSQL Server - PostgreSQL wiki)
Changed JS Minifier to jsmin as suggested here:
Carbon60: Cloud Consulting - Services and Solutions

Our config seems fairly basic compared so some examples I’ve seen, I can
post it if necessary though. We are using FullTextSearch and
CommandByMail, although I’ve tried disabling them both. I turned on
debugging to a log file, and I don’t see anything unusual. I also turned
on the SQL statement log, and didn’t see any queries taking a long time.
The longest was 0.12 seconds. I tried disabling the Javascript Minifier
in JS.pm like I’ve seen in other posts, and that didn’t seem to make a
difference.

Any help would be greatly appreciated.

Thanks,
Nate

Ruslan_Zakirov1 · May 29, 2012, 8:59pm

Hi,

Probably next step would be Mason profiler. It’s described in
RT_Config.pm. Once you know where WebUI is slow return back.On Wed, May 30, 2012 at 12:32 AM, Nathan Baker bakern@gmail.com wrote:

Hello Everyone,

We’ve upgraded from RT 3.8.8 with MySQL to RT 4.0.5 (debian package) with
Postgresql, and are having some performance issues with the web interface.
I’ve searched the list archives and Google, and haven’t been able to find
the issue. I’m hoping someone can help point me in the right direction.
Basically, the first time I visit any page (Home, Display, etc.) it takes
3-5 seconds to load, and sometimes 10-15 seconds. If I keep clicking on
other links as soon as the pages load, it’s fast and loads pages in 0.2 -
0.3 seconds. If I wait for about 15-30 seconds and then click a link again,
it takes 3-5 seconds to load again. Updating tickets seems to consistently
take 3-5 seconds.

Here’s some info about our installation:

About 6,000 tickets, 5 active users

Increased memory to 2GB, running on VMWare

Increased Postgresql shared_buffers and effective_cache_size
(Tuning Your PostgreSQL Server - PostgreSQL wiki)

Changed JS Minifier to jsmin as suggested
here: Carbon60: Managed Cloud Services

Our config seems fairly basic compared so some examples I’ve seen, I can
post it if necessary though. We are using FullTextSearch and CommandByMail,
although I’ve tried disabling them both. I turned on debugging to a log
file, and I don’t see anything unusual. I also turned on the SQL statement
log, and didn’t see any queries taking a long time. The longest was 0.12
seconds. I tried disabling the Javascript Minifier in JS.pm like I’ve seen
in other posts, and that didn’t seem to make a difference.

Any help would be greatly appreciated.

Thanks,
Nate

Best regards, Ruslan.

Darren_Nickerson3 · May 29, 2012, 8:54pm

Hello Everyone,

We’ve upgraded from RT 3.8.8 with MySQL to RT 4.0.5 (debian package) with Postgresql, and are having some performance issues with the web interface. I’ve searched the list archives and Google, and haven’t been able to find the issue. I’m hoping someone can help point me in the right direction. Basically, the first time I visit any page (Home, Display, etc.) it takes 3-5 seconds to load, and sometimes 10-15 seconds. If I keep clicking on other links as soon as the pages load, it’s fast and loads pages in 0.2 - 0.3 seconds. If I wait for about 15-30 seconds and then click a link again, it takes 3-5 seconds to load again. Updating tickets seems to consistently take 3-5 seconds.

We’re seeing similar performance regression after an upgrade from 4.0.0rc5 to 4.0.5. I just loaded a very short ticket for the first time, it took 16 seconds. I did a reload on the page, and it took less than 2 seconds. I also went to Tickets → New Search, and it took a full 20 seconds to load. Subsequent reloads of that page were essentially immediate. Within 10 minutes of not using RT much, opening a few tickets etc but then letting it sit idle for 10 minutes, going back to Tickets->New Search once again took 20 seconds to load, and was fast on subsequent loads

Have I misconfigured or broken some cache mechanism?

Our support staff have complained of a variety of long hangs/pauses like this and I still haven’t pinned it down enough much more than I outline above. Our setup is very vanilla, MySQL with very little customization of RT … if there’s instructions anywhere on how to figure out what’s consuming all the time I’d be happy to dig into it and report back here. I’ve been meaning to try some of the other ways to invoke RT, we’re using apache+FastCGI right now, but there just hasn’t been time. Perhaps the next time I’m waiting for query builder to load …

-d

Darren_Nickerson3 · May 29, 2012, 9:42pm

We’re seeing similar performance regression after an upgrade from 4.0.0rc5 to 4.0.5. I just loaded a very short ticket for the first time, it took 16 seconds. I did a reload on the page, and it took less than 2 seconds. I also went to Tickets → New Search, and it took a full 20 seconds to load. Subsequent reloads of that page were essentially immediate. Within 10 minutes of not using RT much, opening a few tickets etc but then letting it sit idle for 10 minutes, going back to Tickets->New Search once again took 20 seconds to load, and was fast on subsequent loads

Have I misconfigured or broken some cache mechanism?

Our support staff have complained of a variety of long hangs/pauses like this and I still haven’t pinned it down enough much more than I outline above. Our setup is very vanilla, MySQL with very little customization of RT … if there’s instructions anywhere on how to figure out what’s consuming all the time I’d be happy to dig into it and report back here. I’ve been meaning to try some of the other ways to invoke RT, we’re using apache+FastCGI right now, but there just hasn’t been time. Perhaps the next time I’m waiting for query builder to load …

I enabled the profiler per Ruslan’s advice, and loaded the new search page. It took over 20 seconds. It generated a lot of output, should I include it all here? I think the relevant bit might be:

=Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - =Mason= localhost - /Elements/SelectOwnerDropdown {{{
/Elements/ShowUser {{{
/Elements/ShowUserVerbose {{{
/Elements/ShowUserVerbose }}} 0.0021
/Elements/ShowUser }}} 0.0045
/Elements/ShowUser {{{
/Elements/ShowUserVerbose {{{
/Elements/ShowUserVerbose }}} 0.0020
/Elements/ShowUser }}} 0.0042
/Elements/ShowUser {{{
/Elements/ShowUserVerbose {{{
/Elements/ShowUserVerbose }}} 0.0018
/Elements/ShowUser }}} 0.0038
/Elements/ShowUser {{{
/Elements/ShowUserVerbose {{{
/Elements/ShowUserVerbose }}} 0.0018
/Elements/ShowUser }}} 0.0037
/Elements/ShowUser {{{
/Elements/ShowUserVerbose {{{
/Elements/ShowUserVerbose }}} 0.0019
/Elements/ShowUser }}} 0.0038
/Elements/ShowUser {{{
/Elements/ShowUserVerbose {{{
/Elements/ShowUserVerbose }}} 0.0019
/Elements/ShowUser }}} 0.0038
/Elements/ShowUser {{{
/Elements/ShowUserVerbose {{{
/Elements/ShowUserVerbose }}} 0.0019
/Elements/ShowUser }}} 0.0038
/Elements/ShowUser {{{
/Elements/ShowUserVerbose {{{
/Elements/ShowUserVerbose }}} 0.0019
/Elements/ShowUser }}} 0.0038
/Elements/ShowUser {{{
/Elements/ShowUserVerbose {{{
/Elements/ShowUserVerbose }}} 0.0019
/Elements/ShowUser }}} 0.0038
/Elements/ShowUser {{{
/Elements/ShowUserVerbose {{{
/Elements/ShowUserVerbose }}} 0.0019
/Elements/ShowUser }}} 0.0042
/Elements/SelectOwnerDropdown }}} 20.9869

I’m not sure how we get from all those small values to 20 seconds, but it does seem to represent the lion’s share of the slow-down. The last few lines look like:

=Mason= localhost - /Search/Build.html }}} 21.7671
=Mason= localhost - /Elements/Footer {{{
=Mason= localhost - /Elements/Footer }}} 0.0030
=Mason= localhost - /autohandler }}} 21.7901
=Mason= localhost - /Search/Build.html }}} ENDS

So it would seem the SelectOwnerDropdown timer of 20.9869 represents most of the delay …

-Darren

Ruslan_Zakirov1 · May 29, 2012, 9:56pm

We’re seeing similar performance regression after an upgrade from 4.0.0rc5
to 4.0.5. I just loaded a very short ticket for the first time, it took 16
seconds. I did a reload on the page, and it took less than 2 seconds. I also
went to Tickets → New Search, and it took a full 20 seconds to load.
Subsequent reloads of that page were essentially immediate. Within 10
minutes of not using RT much, opening a few tickets etc but then letting it
sit idle for 10 minutes, going back to Tickets->New Search once again took
20 seconds to load, and was fast on subsequent loads

Have I misconfigured or broken some cache mechanism?

Our support staff have complained of a variety of long hangs/pauses like
this and I still haven’t pinned it down enough much more than I outline
above. Our setup is very vanilla, MySQL with very little customization of RT
… if there’s instructions anywhere on how to figure out what’s consuming
all the time I’d be happy to dig into it and report back here. I’ve been
meaning to try some of the other ways to invoke RT, we’re using
apache+FastCGI right now, but there just hasn’t been time. Perhaps the next
time I’m waiting for query builder to load …

I enabled the profiler per Ruslan’s advice, and loaded the new search page.
It took over 20 seconds. It generated a lot of output, should I include it
all here? I think the relevant bit might be:

=Mason= localhost -
/Elements/SelectOwnerDropdown {{{
=Mason= localhost - /Elements/ShowUser
{{{
=Mason= localhost -
/Elements/ShowUserVerbose {{{
=Mason= localhost -
/Elements/ShowUserVerbose }}} 0.0021
=Mason= localhost - /Elements/ShowUser
}}} 0.0045
=Mason= localhost - /Elements/ShowUser
{{{
=Mason= localhost -
/Elements/ShowUserVerbose {{{
=Mason= localhost -
/Elements/ShowUserVerbose }}} 0.0020
=Mason= localhost - /Elements/ShowUser
}}} 0.0042
=Mason= localhost - /Elements/ShowUser
{{{
=Mason= localhost -
/Elements/ShowUserVerbose {{{
=Mason= localhost -
/Elements/ShowUserVerbose }}} 0.0018
=Mason= localhost - /Elements/ShowUser
}}} 0.0038
=Mason= localhost - /Elements/ShowUser
{{{
=Mason= localhost -
/Elements/ShowUserVerbose {{{
=Mason= localhost -
/Elements/ShowUserVerbose }}} 0.0018
=Mason= localhost - /Elements/ShowUser
}}} 0.0037
=Mason= localhost - /Elements/ShowUser
{{{
=Mason= localhost -
/Elements/ShowUserVerbose {{{
=Mason= localhost -
/Elements/ShowUserVerbose }}} 0.0019
=Mason= localhost - /Elements/ShowUser
}}} 0.0038
=Mason= localhost - /Elements/ShowUser
{{{
=Mason= localhost -
/Elements/ShowUserVerbose {{{
=Mason= localhost -
/Elements/ShowUserVerbose }}} 0.0019
=Mason= localhost - /Elements/ShowUser
}}} 0.0038
=Mason= localhost - /Elements/ShowUser
{{{
=Mason= localhost -
/Elements/ShowUserVerbose {{{
=Mason= localhost -
/Elements/ShowUserVerbose }}} 0.0019
=Mason= localhost - /Elements/ShowUser
}}} 0.0038
=Mason= localhost - /Elements/ShowUser
{{{
=Mason= localhost -
/Elements/ShowUserVerbose {{{
=Mason= localhost -
/Elements/ShowUserVerbose }}} 0.0019
=Mason= localhost - /Elements/ShowUser
}}} 0.0038
=Mason= localhost - /Elements/ShowUser
{{{
=Mason= localhost -
/Elements/ShowUserVerbose {{{
=Mason= localhost -
/Elements/ShowUserVerbose }}} 0.0019
=Mason= localhost - /Elements/ShowUser
}}} 0.0038
=Mason= localhost - /Elements/ShowUser
{{{
=Mason= localhost -
/Elements/ShowUserVerbose {{{
=Mason= localhost -
/Elements/ShowUserVerbose }}} 0.0019
=Mason= localhost - /Elements/ShowUser
}}} 0.0042
=Mason= localhost -
/Elements/SelectOwnerDropdown }}} 20.9869

I’m not sure how we get from all those small values to 20 seconds, but it
does seem to represent the lion’s share of the slow-down. The last few lines
look like:

=Mason= localhost - /Search/Build.html }}} 21.7671
=Mason= localhost - /Elements/Footer {{{
=Mason= localhost - /Elements/Footer }}} 0.0030
=Mason= localhost - /autohandler }}} 21.7901
=Mason= localhost - /Search/Build.html }}} ENDS

So it would seem the SelectOwnerDropdown timer of 20.9869 represents most of
the delay …

How many users do you have in the owner dropdown in search builder?
Can you write a script that sums numbers after ShowUserVerbose to make
sure problem in number of users and not something in
SelectOwnerDropdown?

-Darren

Best regards, Ruslan.

Darren_Nickerson3 · May 29, 2012, 10:01pm

How many users do you have in the owner dropdown in search builder?

Only 10. And the next time I load this page (and with each attempt immediately after) the number is much healthier:

=Mason= localhost - /Elements/SelectOwnerDropdown {{{
=Mason= localhost - /Elements/ShowUser {{{
=Mason= localhost - /Elements/ShowUserVerbose {{{
=Mason= localhost - /Elements/ShowUserVerbose }}} 0.0018
=Mason= localhost - /Elements/ShowUser }}} 0.0042
=Mason= localhost - /Elements/ShowUser {{{
=Mason= localhost - /Elements/ShowUserVerbose {{{
=Mason= localhost - /Elements/ShowUserVerbose }}} 0.0017
=Mason= localhost - /Elements/ShowUser }}} 0.0036
=Mason= localhost - /Elements/ShowUser {{{
=Mason= localhost - /Elements/ShowUserVerbose {{{
=Mason= localhost - /Elements/ShowUserVerbose }}} 0.0018
=Mason= localhost - /Elements/ShowUser }}} 0.0036
=Mason= localhost - /Elements/ShowUser {{{
=Mason= localhost - /Elements/ShowUserVerbose {{{
=Mason= localhost - /Elements/ShowUserVerbose }}} 0.0018
=Mason= localhost - /Elements/ShowUser }}} 0.0036
=Mason= localhost - /Elements/ShowUser {{{
=Mason= localhost - /Elements/ShowUserVerbose {{{
=Mason= localhost - /Elements/ShowUserVerbose }}} 0.0017
=Mason= localhost - /Elements/ShowUser }}} 0.0035
=Mason= localhost - /Elements/ShowUser {{{
=Mason= localhost - /Elements/ShowUserVerbose {{{
=Mason= localhost - /Elements/ShowUserVerbose }}} 0.0063
=Mason= localhost - /Elements/ShowUser }}} 0.0082
=Mason= localhost - /Elements/ShowUser {{{
=Mason= localhost - /Elements/ShowUserVerbose {{{
=Mason= localhost - /Elements/ShowUserVerbose }}} 0.0018
=Mason= localhost - /Elements/ShowUser }}} 0.0035
=Mason= localhost - /Elements/ShowUser {{{
=Mason= localhost - /Elements/ShowUserVerbose {{{
=Mason= localhost - /Elements/ShowUserVerbose }}} 0.0017
=Mason= localhost - /Elements/ShowUser }}} 0.0035
=Mason= localhost - /Elements/ShowUser {{{
=Mason= localhost - /Elements/ShowUserVerbose {{{
=Mason= localhost - /Elements/ShowUserVerbose }}} 0.0017
=Mason= localhost - /Elements/ShowUser }}} 0.0035
=Mason= localhost - /Elements/ShowUser {{{
=Mason= localhost - /Elements/ShowUserVerbose {{{
=Mason= localhost - /Elements/ShowUserVerbose }}} 0.0018
=Mason= localhost - /Elements/ShowUser }}} 0.0035
=Mason= localhost - /Elements/SelectOwnerDropdown }}} 0.0552

But if I wait a few minutes and try again, it will be slow again.

Can you write a script that sums numbers after ShowUserVerbose to make
sure problem in number of users and not something in
SelectOwnerDropdown?

I’m sorry, I’m having a hard time even understanding what you mean there … I therefore conclude it’s something I would NOT be able to do.

-d

Nathan_Baker · May 29, 2012, 10:11pm

Ruslan,

Thank you, that provided some great info. I’m wondering if my issue (or
one of them) is from our custom fields. There is one spot where it
consistently takes a couple seconds:

=Mason= localhost -
/Ticket/Elements/ShowCustomFields {{{
=Mason= localhost -
/Elements/ShowCustomFields {{{
=Mason= localhost -
/Elements/ShowCustomFields }}} 2.0221
=Mason= localhost -
/Ticket/Elements/ShowCustomFields }}} 2.0261
…
=Mason= localhost - /autohandler }}} 3.2073

We only have 1 or 2 custom fields (depending on the Queue), and there are
less than 20 options for each. Any ideas what could cause that, or is that
normal for custom fields?

Thanks,
NateOn Tue, May 29, 2012 at 4:59 PM, Ruslan Zakirov ruz@bestpractical.comwrote:

Hi,

Probably next step would be Mason profiler. It’s described in
RT_Config.pm. Once you know where WebUI is slow return back.

On Wed, May 30, 2012 at 12:32 AM, Nathan Baker bakern@gmail.com wrote:

Hello Everyone,

We’ve upgraded from RT 3.8.8 with MySQL to RT 4.0.5 (debian package) with
Postgresql, and are having some performance issues with the web
interface.
I’ve searched the list archives and Google, and haven’t been able to
find
the issue. I’m hoping someone can help point me in the right direction.
Basically, the first time I visit any page (Home, Display, etc.) it
takes
3-5 seconds to load, and sometimes 10-15 seconds. If I keep clicking on
other links as soon as the pages load, it’s fast and loads pages in 0.2 -
0.3 seconds. If I wait for about 15-30 seconds and then click a link
again,
it takes 3-5 seconds to load again. Updating tickets seems to
consistently
take 3-5 seconds.

Here’s some info about our installation:

About 6,000 tickets, 5 active users

Increased memory to 2GB, running on VMWare

Increased Postgresql shared_buffers and effective_cache_size
(Tuning Your PostgreSQL Server - PostgreSQL wiki)

Changed JS Minifier to jsmin as suggested
here: Carbon60: Managed Cloud Services

Our config seems fairly basic compared so some examples I’ve seen, I can
post it if necessary though. We are using FullTextSearch and
CommandByMail,
although I’ve tried disabling them both. I turned on debugging to a log
file, and I don’t see anything unusual. I also turned on the SQL
statement
log, and didn’t see any queries taking a long time. The longest was 0.12
seconds. I tried disabling the Javascript Minifier in JS.pm like I’ve
seen
in other posts, and that didn’t seem to make a difference.

Any help would be greatly appreciated.

Thanks,
Nate

–
Best regards, Ruslan.

Ruslan_Zakirov1 · May 29, 2012, 10:31pm

How many users do you have in the owner dropdown in search builder?

Only 10. And the next time I load this page (and with each attempt
immediately after) the number is much healthier:

=Mason= localhost -
/Elements/SelectOwnerDropdown {{{

[snip]

But if I wait a few minutes and try again, it will be slow again.

Can you write a script that sums numbers after ShowUserVerbose to make
sure problem in number of users and not something in
SelectOwnerDropdown?

I’m sorry, I’m having a hard time even understanding what you mean there …
I therefore conclude it’s something I would NOT be able to do.

Hi Daren,

No need to write anything. I’ve misread the cut from the log.

In your case I suspect slow query. Enable SQL logging in RT, wait
until it’s slow, go to Build.html page, get slow SQL from logs and
send EXPLAIN to the list in different conversation thread. As
alternative just enable logging of slow queries in mysql.

-d

Best regards, Ruslan.

Tim_Cutts · May 30, 2012, 8:56am

I saw this too. Since it seems to be SelectOwner that’s slow (it was for me too - I have several hundred privileged users on our RT) the thing I did to fix it was to set the appropriate option in RT_SiteConfig to use a text box with the new autocomplete rather than the drop down. It’s both much faster to load, and a lot quicker to actually use as well.

Set($AutocompleteOwnersForSearch, 1);

Regards,

Tim

The Wellcome Trust Sanger Institute is operated by Genome Research
Limited, a charity registered in England with number 1021457 and a
company registered in England with number 2742969, whose registered
office is 215 Euston Road, London, NW1 2BE.