[rt-users] RT 4 Upgrade Slow Performance

[Ruslan Zakirov]

On Wed, May 30, 2012 at 1:42 AM, Darren Nickerson <darren at dazza.org> wrote:
>
> On May 29, 2012, at 4:54 PM, Darren Nickerson wrote:
>
>
> 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.