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 */ * FROMAttachments;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 */ * FROMAttachments;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