On Wed, May 30, 2012 at 1:42 AM, Darren Nickerson <dar...@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.