Please help - rt4 slow after upgrade

Not sure where to start here, but trying to diagnose why after an upgrade
from 3.8.8 to 4.0.0 things have slowed down tremendously. Doing even
pedestrian tasks such as loading the home screen or opening the ticket
search will about 30% of the time decide it wants to max out the cpu with
the apache2 process for roughly 20 - 30 seconds. Sometimes, loading things
happens almost instantaneously. Other times, there’s this weird delay. Not
sure where to start looking, are there any known issues that I might need to
be aware of?

I actually saw something about that in a message to the mailing list, and
already turned it off as well, as a precaution. After searching around
some and trying out some tests, it seems the delay happens after the GET
request to the apache server, and watching the logs, nothing appears in the
log until about 20 seconds after the request to say the user asked for it…
so there’s about 20 - 30 seconds of dead time from the GET to when the log
shows a request was made. On a forum recommendation, I enabled slow mysql
logging and noticed several entries in the log. Here is a sample:

User@Host: rt_user[rt_user] @ localhost []

Query_time: 3246 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-8a63b00ecb1829c65682fc75db1c05be’, 3600);

User@Host: rt_user[rt_user] @ localhost []

Query_time: 3204 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-8a63b00ecb1829c65682fc75db1c05be’, 3600);

User@Host: rt_user[rt_user] @ localhost []

Query_time: 2897 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-8a63b00ecb1829c65682fc75db1c05be’, 3600);

User@Host: rt_user[rt_user] @ localhost []

Query_time: 2885 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-8a63b00ecb1829c65682fc75db1c05be’, 3600);

Time: 110518 19:51:37

User@Host: rt_user[rt_user] @ localhost []

Query_time: 1660 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-8a63b00ecb1829c65682fc75db1c05be’, 3600);

Time: 110518 19:56:44

User@Host: rt_user[rt_user] @ localhost []

Query_time: 14 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-29fd7421a2e8981d99740258bbb9aea3’, 3600);

Dunno if they are of any help, but to me, it seems to indicate several
SELECT queries that are running long for… whatever reason. Do these logs
make sense to anybody?On Wed, May 18, 2011 at 6:33 PM, Jonah Hirsch jwh83@nau.edu wrote:

I was having this issue, same exact versions and problems with apache2. I
turned off mod_deflate and that helped a bit, but I’m still getting some
slowdowns, just not as much as before.

Jonah Hirsch

On Wed, May 18, 2011 at 11:31 AM, Chris Hall hiro24@gmail.com wrote:

Not sure where to start here, but trying to diagnose why after an upgrade
from 3.8.8 to 4.0.0 things have slowed down tremendously. Doing even
pedestrian tasks such as loading the home screen or opening the ticket
search will about 30% of the time decide it wants to max out the cpu with
the apache2 process for roughly 20 - 30 seconds. Sometimes, loading things
happens almost instantaneously. Other times, there’s this weird delay. Not
sure where to start looking, are there any known issues that I might need to
be aware of?

Well, resolved the below a bit by adding to RT_SiteConfig.pm:

Set($WebSessionClass, “Apache::Session::File”);

However, CPU usage still peaks out on apache2 processes, although it appears
to be not AS frequent. Anybody have any other suggestions on areas to look
into? Some are saying the slowdown seems to occur most frequently when
updating tickets.On Wed, May 18, 2011 at 8:36 PM, Chris Hall hiro24@gmail.com wrote:

I actually saw something about that in a message to the mailing list, and
already turned it off as well, as a precaution. After searching around
some and trying out some tests, it seems the delay happens after the GET
request to the apache server, and watching the logs, nothing appears in the
log until about 20 seconds after the request to say the user asked for it…
so there’s about 20 - 30 seconds of dead time from the GET to when the log
shows a request was made. On a forum recommendation, I enabled slow mysql
logging and noticed several entries in the log. Here is a sample:

User@Host: rt_user[rt_user] @ localhost []

Query_time: 3246 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-8a63b00ecb1829c65682fc75db1c05be’, 3600);

User@Host: rt_user[rt_user] @ localhost []

Query_time: 3204 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-8a63b00ecb1829c65682fc75db1c05be’, 3600);

User@Host: rt_user[rt_user] @ localhost []

Query_time: 2897 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-8a63b00ecb1829c65682fc75db1c05be’, 3600);

User@Host: rt_user[rt_user] @ localhost []

Query_time: 2885 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-8a63b00ecb1829c65682fc75db1c05be’, 3600);

Time: 110518 19:51:37

User@Host: rt_user[rt_user] @ localhost []

Query_time: 1660 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-8a63b00ecb1829c65682fc75db1c05be’, 3600);

Time: 110518 19:56:44

User@Host: rt_user[rt_user] @ localhost []

Query_time: 14 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-29fd7421a2e8981d99740258bbb9aea3’, 3600);

Dunno if they are of any help, but to me, it seems to indicate several
SELECT queries that are running long for… whatever reason. Do these logs
make sense to anybody?

On Wed, May 18, 2011 at 6:33 PM, Jonah Hirsch jwh83@nau.edu wrote:

I was having this issue, same exact versions and problems with apache2. I
turned off mod_deflate and that helped a bit, but I’m still getting some
slowdowns, just not as much as before.

Jonah Hirsch

On Wed, May 18, 2011 at 11:31 AM, Chris Hall hiro24@gmail.com wrote:

Not sure where to start here, but trying to diagnose why after an upgrade
from 3.8.8 to 4.0.0 things have slowed down tremendously. Doing even
pedestrian tasks such as loading the home screen or opening the ticket
search will about 30% of the time decide it wants to max out the cpu with
the apache2 process for roughly 20 - 30 seconds. Sometimes, loading things
happens almost instantaneously. Other times, there’s this weird delay. Not
sure where to start looking, are there any known issues that I might need to
be aware of?

Seems after watching a few days this is still an issue. It seems completely
random… some pages just… take awhile to load for some reason. 15 - 20
seconds, and then you can blast through a few pages instantly it seems…
completely random. I’ve checked the logs, no errors or anything that stands
out. Some of the pages that slow down don’t access replying via email, so
SMTP wouldn’t be the issue. I examined again my slow query logs for mysql
and yesterday got this:

Time: 110523 2:30:10

User@Host: rt_user[rt_user] @ localhost []

Query_time: 6 Lock_time: 0 Rows_sent: 70390 Rows_examined: 70390

use rt3;
SELECT /*!40001 SQL_NO_CACHE */ * FROM Attachments;

Time: 110523 2:30:17

User@Host: rt_user[rt_user] @ localhost []

Query_time: 4 Lock_time: 0 Rows_sent: 125353 Rows_examined: 125353

SELECT /*!40001 SQL_NO_CACHE */ * FROM Transactions;

Time: 110523 2:30:20

User@Host: rt_user[rt_user] @ localhost []

Query_time: 3 Lock_time: 0 Rows_sent: 10343 Rows_examined: 10343

SELECT /*!40001 SQL_NO_CACHE */ * FROM sessions;

However, that’s only 3 entries… it happens much more often than that. I’m
thinking I’ll see the CPU peg out maybe 5 - 8 times in a 5 min span, for
about 10 - 15 seconds each time watching top. My only thought is there’s
some type of a miscommunication between apache and mysql, but I have no idea
what. At this point, I’m open to any and all suggestions. Please, if
anybody has any suggestions on where to look, I’d appreciate it.On Thu, May 19, 2011 at 10:33 AM, Chris Hall hiro24@gmail.com wrote:

Well, resolved the below a bit by adding to RT_SiteConfig.pm:

Set($WebSessionClass, “Apache::Session::File”);

However, CPU usage still peaks out on apache2 processes, although it
appears to be not AS frequent. Anybody have any other suggestions on areas
to look into? Some are saying the slowdown seems to occur most frequently
when updating tickets.

On Wed, May 18, 2011 at 8:36 PM, Chris Hall hiro24@gmail.com wrote:

I actually saw something about that in a message to the mailing list, and
already turned it off as well, as a precaution. After searching around
some and trying out some tests, it seems the delay happens after the GET
request to the apache server, and watching the logs, nothing appears in the
log until about 20 seconds after the request to say the user asked for it…
so there’s about 20 - 30 seconds of dead time from the GET to when the log
shows a request was made. On a forum recommendation, I enabled slow mysql
logging and noticed several entries in the log. Here is a sample:

User@Host: rt_user[rt_user] @ localhost []

Query_time: 3246 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-8a63b00ecb1829c65682fc75db1c05be’, 3600);

User@Host: rt_user[rt_user] @ localhost []

Query_time: 3204 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-8a63b00ecb1829c65682fc75db1c05be’, 3600);

User@Host: rt_user[rt_user] @ localhost []

Query_time: 2897 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-8a63b00ecb1829c65682fc75db1c05be’, 3600);

User@Host: rt_user[rt_user] @ localhost []

Query_time: 2885 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-8a63b00ecb1829c65682fc75db1c05be’, 3600);

Time: 110518 19:51:37

User@Host: rt_user[rt_user] @ localhost []

Query_time: 1660 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-8a63b00ecb1829c65682fc75db1c05be’, 3600);

Time: 110518 19:56:44

User@Host: rt_user[rt_user] @ localhost []

Query_time: 14 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-29fd7421a2e8981d99740258bbb9aea3’, 3600);

Dunno if they are of any help, but to me, it seems to indicate several
SELECT queries that are running long for… whatever reason. Do these logs
make sense to anybody?

On Wed, May 18, 2011 at 6:33 PM, Jonah Hirsch jwh83@nau.edu wrote:

I was having this issue, same exact versions and problems with apache2. I
turned off mod_deflate and that helped a bit, but I’m still getting some
slowdowns, just not as much as before.

Jonah Hirsch

On Wed, May 18, 2011 at 11:31 AM, Chris Hall hiro24@gmail.com wrote:

Not sure where to start here, but trying to diagnose why after an
upgrade from 3.8.8 to 4.0.0 things have slowed down tremendously. Doing
even pedestrian tasks such as loading the home screen or opening the ticket
search will about 30% of the time decide it wants to max out the cpu with
the apache2 process for roughly 20 - 30 seconds. Sometimes, loading things
happens almost instantaneously. Other times, there’s this weird delay. Not
sure where to start looking, are there any known issues that I might need to
be aware of?

Seems after watching a few days this is still an issue. It seems completely
random… some pages just… take awhile to load for some reason. 15 - 20
seconds, and then you can blast through a few pages instantly it seems…
completely random. I’ve checked the logs, no errors or anything that stands
out. Some of the pages that slow down don’t access replying via email, so
SMTP wouldn’t be the issue. I examined again my slow query logs for mysql
and yesterday got this:

None of these queries look like something generated by RT. RT’s ORM
has some… signatures it leaves on the query.

Are you perhaps using some sort of backup or indexing tool, or an
extension developed in-house?

Time: 110523 2:30:10

User@Host: rt_user[rt_user] @ localhost []

Query_time: 6 Lock_time: 0 Rows_sent: 70390 Rows_examined: 70390

use rt3;
SELECT /*!40001 SQL_NO_CACHE */ * FROM Attachments;

Time: 110523 2:30:17

User@Host: rt_user[rt_user] @ localhost []

Query_time: 4 Lock_time: 0 Rows_sent: 125353 Rows_examined: 125353

SELECT /*!40001 SQL_NO_CACHE */ * FROM Transactions;

Time: 110523 2:30:20

User@Host: rt_user[rt_user] @ localhost []

Query_time: 3 Lock_time: 0 Rows_sent: 10343 Rows_examined: 10343

SELECT /*!40001 SQL_NO_CACHE */ * FROM sessions;

If you’d like to try and examine SQL problems on a particular page, you
can enable $StatementLog and examine the output from the Configuration
-> Tools page as a superuser.

-kevin

That -really- seemed to slow down… almost everything I did. Although when
I looked at the results, I was seeing not alot of time spent on the queries.

/index.html - 0.0208s Toggle 45 queries
/Ticket/Display.html - 0.1104s Toggle 65 queries
/Search/Results.html - 0.5969s Toggle 232 queries

The only extension I’m running is one called BriefHistory, which filters out
a lot of stuff we don’t want to sift through in the comments section of
tickets, but considering the slowdown can occur on the main page, search
pages (before criteria is even entered), etc… I don’t think that’s the
factor. Just to be sure, I restarted without it loaded, and saw similar
delays. Below is my current RT_SiteConfig.pm… does anything look wrong?

Set to try to stop the lag…

Set($WebSessionClass, “Apache::Session::File”);

Set( $rtname, ‘-CENSORED-’);
Set($Organization , “-CENSORED-”);
Set($CorrespondAddress , ‘-CENSORED-’);
Set($CommentAddress , ‘-CENSORED-’);
Set($MailCommand, ‘smtp’);
Set($SMTPServer, ‘-CENSORED-’);
Set($SMTPFrom , ‘-CENSORED-’);
Set($NotifyActor , ‘1’);
Set($OwnerEmail , ‘root’);
Set($MaxAttachmentSize , 10000000);
Set($DatabaseType, ‘mysql’);
Set($DatabaseUser , ‘rt_user’); Set($DatabasePassword , ‘-CENSORED-’);
Set($DatabaseName , ‘rt4’);
Set($WebPath , “”);
Set($WebBaseURL , “http://-CENSORED-”);
Set(@Plugins,qw(RT::Extension::BriefHistory));
1;On Mon, May 23, 2011 at 1:42 PM, Kevin Falcone falcone@bestpractical.comwrote:

On Mon, May 23, 2011 at 09:09:08AM -0400, Chris Hall wrote:

Seems after watching a few days this is still an issue. It seems
completely
random… some pages just… take awhile to load for some reason. 15 - 20
seconds, and then you can blast through a few pages instantly it seems…
completely random. I’ve checked the logs, no errors or anything that
stands
out. Some of the pages that slow down don’t access replying via email,
so
SMTP wouldn’t be the issue. I examined again my slow query logs for
mysql
and yesterday got this:

None of these queries look like something generated by RT. RT’s ORM
has some… signatures it leaves on the query.

Are you perhaps using some sort of backup or indexing tool, or an
extension developed in-house?

Time: 110523 2:30:10

User@Host: rt_user[rt_user] @ localhost []

Query_time: 6 Lock_time: 0 Rows_sent: 70390 Rows_examined: 70390

use rt3;
SELECT /*!40001 SQL_NO_CACHE */ * FROM Attachments;

Time: 110523 2:30:17

User@Host: rt_user[rt_user] @ localhost []

Query_time: 4 Lock_time: 0 Rows_sent: 125353 Rows_examined: 125353

SELECT /*!40001 SQL_NO_CACHE */ * FROM Transactions;

Time: 110523 2:30:20

User@Host: rt_user[rt_user] @ localhost []

Query_time: 3 Lock_time: 0 Rows_sent: 10343 Rows_examined: 10343

SELECT /*!40001 SQL_NO_CACHE */ * FROM sessions;

If you’d like to try and examine SQL problems on a particular page, you
can enable $StatementLog and examine the output from the Configuration
-> Tools page as a superuser.

-kevin

However, that’s only 3 entries… it happens much more often than that.
I’m
thinking I’ll see the CPU peg out maybe 5 - 8 times in a 5 min span, for
about 10 - 15 seconds each time watching top. My only thought is there’s
some type of a miscommunication between apache and mysql, but I have no
idea
what. At this point, I’m open to any and all suggestions. Please, if
anybody has any suggestions on where to look, I’d appreciate it.

On Thu, May 19, 2011 at 10:33 AM, Chris Hall hiro24@gmail.com wrote:

Well, resolved the below a bit by adding to RT_SiteConfig.pm:

Set($WebSessionClass, “Apache::Session::File”);

However, CPU usage still peaks out on apache2 processes, although it
appears to be not AS frequent. Anybody have any other suggestions on
areas

to look into? Some are saying the slowdown seems to occur most
frequently

when updating tickets.

On Wed, May 18, 2011 at 8:36 PM, Chris Hall hiro24@gmail.com wrote:

I actually saw something about that in a message to the mailing list,
and

already turned it off as well, as a precaution. After searching
around

some and trying out some tests, it seems the delay happens after the
GET

request to the apache server, and watching the logs, nothing appears
in the

log until about 20 seconds after the request to say the user asked for
it…

so there’s about 20 - 30 seconds of dead time from the GET to when the
log

shows a request was made. On a forum recommendation, I enabled slow
mysql

logging and noticed several entries in the log. Here is a sample:

User@Host: rt_user[rt_user] @ localhost []

Query_time: 3246 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-8a63b00ecb1829c65682fc75db1c05be’,
3600);

User@Host: rt_user[rt_user] @ localhost []

Query_time: 3204 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-8a63b00ecb1829c65682fc75db1c05be’,
3600);

User@Host: rt_user[rt_user] @ localhost []

Query_time: 2897 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-8a63b00ecb1829c65682fc75db1c05be’,
3600);

User@Host: rt_user[rt_user] @ localhost []

Query_time: 2885 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-8a63b00ecb1829c65682fc75db1c05be’,
3600);

Time: 110518 19:51:37

User@Host: rt_user[rt_user] @ localhost []

Query_time: 1660 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-8a63b00ecb1829c65682fc75db1c05be’,
3600);

Time: 110518 19:56:44

User@Host: rt_user[rt_user] @ localhost []

Query_time: 14 Lock_time: 0 Rows_sent: 1 Rows_examined: 0

SELECT GET_LOCK(‘Apache-Session-29fd7421a2e8981d99740258bbb9aea3’,
3600);

Dunno if they are of any help, but to me, it seems to indicate several
SELECT queries that are running long for… whatever reason. Do these
logs

make sense to anybody?

On Wed, May 18, 2011 at 6:33 PM, Jonah Hirsch jwh83@nau.edu wrote:

I was having this issue, same exact versions and problems with
apache2. I

turned off mod_deflate and that helped a bit, but I’m still getting
some

slowdowns, just not as much as before.

Jonah Hirsch

On Wed, May 18, 2011 at 11:31 AM, Chris Hall hiro24@gmail.com wrote:

Not sure where to start here, but trying to diagnose why after an
upgrade from 3.8.8 to 4.0.0 things have slowed down tremendously.
Doing

even pedestrian tasks such as loading the home screen or opening the
ticket

search will about 30% of the time decide it wants to max out the cpu
with

the apache2 process for roughly 20 - 30 seconds. Sometimes, loading
things

happens almost instantaneously. Other times, there’s this weird
delay. Not

sure where to start looking, are there any known issues that I might
need to

be aware of?

That -really- seemed to slow down… almost everything I did. Although when I looked at the
results, I was seeing not alot of time spent on the queries.
/index.html - 0.0208s Toggle 45 queries
/Ticket/Display.html - 0.1104s Toggle 65 queries
/Search/Results.html - 0.5969s Toggle 232 queries

Logging all the queries is going to add some load, but it doesn’t
appear that this is the RT frontend based on your findings.

I’d concentrate on finding out what software is issuing those full
stable scans.

-kevin