Extremely Slow Load

I have a ticket with say a dozen attachments, totallying ~300k. To
refers to three other tickets. It has perhaps 60 entries on it of
correspondance back and forth about an issue, including Dell machine
quites, network topology (cisco configs) etc. Here is the output from
MasonX:;Profiler

=Mason= 12.177.133.32 - /Ticket/Elements/ShowHistory }}} 37.3351

=Mason= 12.177.133.32 - /autohandler }}} 44.7194
=Mason= 12.177.133.32 - /Ticket/Display.html }}} ENDS

Does 44 seconds to load this ticket seem completely out there? This is
a 2.2 gig P4, 512mb ram, MySQL innodb with a modified mysql-large
config, deticated apache 1.3 install w/ mod_perl…

It helps if you can tell us things about the system’s memory usage, as
well as what versions of RT, SearchBuilder, MySQL, etc you’re running.
There’s a nice listing of most of this stuff in the Configuration →
Tools menu.On Sun, Nov 28, 2004 at 01:46:10PM -0500, Stan wrote:

I have a ticket with say a dozen attachments, totallying ~300k. To
refers to three other tickets. It has perhaps 60 entries on it of
correspondance back and forth about an issue, including Dell machine
quites, network topology (cisco configs) etc. Here is the output from
MasonX:;Profiler

=Mason= 12.177.133.32 - /Ticket/Elements/ShowHistory }}} 37.3351

=Mason= 12.177.133.32 - /autohandler }}} 44.7194
=Mason= 12.177.133.32 - /Ticket/Display.html }}} ENDS

Does 44 seconds to load this ticket seem completely out there? This is
a 2.2 gig P4, 512mb ram, MySQL innodb with a modified mysql-large
config, deticated apache 1.3 install w/ mod_perl…


The rt-users Archives

Be sure to check out the RT wiki at http://wiki.bestpractical.com

Jesse,

Perl v5.8.5 under linux
Apache v1.27;
Apache::Connection v1.00;
Apache::Constants v1.09;
Apache::DBI v0.94;
Apache::Server v1.01;
Apache::Session v1.6;
Apache::Session::Generate::MD5 v2.1;
Apache::Session::lock::MySQL v1.00;
Apache::Session::MySQL v1.01;
Apache::Session::Serialize::Storable v1.00;
Apache::Session::Store::DBI v1.02;
Apache::Session::Store::MySQL v1.04;
Apache::Status v2.03;
Apache::Symbol v1.31;
Apache::Table v0.01;
AutoLoader v5.60;
B v1.02;
base v2.06;
Benchmark v1.06;
bytes v1.01;
Cache::Simple::TimedExpiry v0.21;
Carp v1.03;
CGI v3.05;
CGI::Cookie v1.24;
CGI::Util v1.5;
Class::Container v0.11;
Class::Data::Inheritable v0.02;
Class::ReturnValue v0.52;
constant v1.04;
Cwd v2.19;
Data::Dumper v2.121;
DBD::mysql v2.9004;
DBI v1.43;
DBIx::SearchBuilder v1.11;
Devel::StackTrace v1.11;
Devel::StackTraceFrame v0.6;
Devel::Symdump v2.03;
Digest::base v1.00;
Digest::MD5 v2.33;
DynaLoader v1.05;
Encode v2.01;
Encode::Alias v2.00;
Encode::Config v2.00;
Encode::Encoding v2.00;
Errno v1.09;
Exception::Class v1.19;
Exception::Class::Base v1.2;
Exporter v5.58;
Exporter::Heavy v5.58;
Fcntl v1.05;
fields v2.03;
File::Basename v2.73;
File::Glob v1.03;
File::Path v1.06;
File::Spec v0.87;
File::Spec::Unix v1.5;
File::Temp v0.14;
FileHandle v2.01;
HTML::Entities v1.27;
HTML::Mason v1.26;
HTML::Mason::ApacheHandler v1.69;
HTML::Mason::Exception v1.1;
HTML::Mason::Exception::Abort v1.1;
HTML::Mason::Exception::Compilation v1.1;
HTML::Mason::Exception::Compilation::IncompatibleCompiler v1.1;
HTML::Mason::Exception::Compiler v1.1;
HTML::Mason::Exception::Decline v1.1;
HTML::Mason::Exception::Params v1.1;
HTML::Mason::Exception::Syntax v1.1;
HTML::Mason::Exception::System v1.1;
HTML::Mason::Exception::TopLevelNotFound v1.1;
HTML::Mason::Exception::VirtualMethod v1.1;
HTML::Mason::Exceptions v1.43;
HTML::Parser v3.36;
HTML::Scrubber v0.08;
I18N::LangTags v0.33;
I18N::LangTags::Detect v1.03;
integer v1.00;
IO v1.21;
IO::File v1.10;
IO::Handle v1.24;
IO::InnerFile v2.102 ;
IO::Lines v2.103 ;
IO::Scalar v2.105 ;
IO::ScalarArray v2.103 ;
IO::Seekable v1.09;
IO::Wrap v2.102 ;
IO::WrapTie v2.102 ;
IPC::Open2 v1.01;
IPC::Open3 v1.0106;
lib v0.5565;
List::Util v1.14;
locale v1.00;
Locale::Maketext v1.09;
Locale::Maketext::Fuzzy v0.02;
Locale::Maketext::Lexicon v0.38;
Locale::Maketext::Lexicon::Gettext v0.11;
Log::Dispatch v2.10;
Log::Dispatch::Base v1.09;
Log::Dispatch::File v1.22;
Log::Dispatch::Output v1.26;
Log::Dispatch::Screen v1.17;
Log::Dispatch::Syslog v1.18;
Mail::Address v1.62;
Mail::Field v1.62;
Mail::Field::AddrList v1.62;
Mail::Header v1.62;
Mail::Internet v1.62;
MIME::Base64 v3.01;
MIME::Body v5.403 ;
MIME::Decoder v5.403 ;
MIME::Entity v5.404 ;
MIME::Field::ContDisp v5.403 ;
MIME::Field::ConTraEnc v5.403 ;
MIME::Field::ContType v5.403 ;
MIME::Field::ParamVal v5.403 ;
MIME::Head v5.403 ;
MIME::Parser v5.406 ;
MIME::QuotedPrint v3.01;
MIME::Tools v5.411 ;
MIME::Words v5.404 ;
mod_perl v1.29;
Module::Versions::Report v1.02;
overload v1.01;
Params::Validate v0.74;
POSIX v1.08;
re v0.04;
Regexp::Common v2.117;
Regexp::Common::delimited v2.103;
RT v3.2.2;
Scalar::Util v1.14;
SelectSaver v1.00;
Socket v1.77;
Storable v2.13;
strict v1.03;
Symbol v1.05;
Sys::Hostname v1.11;
Sys::Syslog v0.05;
Text::Autoformat v1.12;
Text::Quoted v1.8;
Text::Reform v1.11;
Text::Tabs v98.112801;
Text::Template v1.44;
Text::WikiFormat v0.72;
Text::Wrapper v1.000;
Time::HiRes v1.59;
Time::JulianDay v2003.1125;
Time::Local v1.1;
Time::ParseDate v2003.1126;
Time::Timezone v2003.0211;
URI v1.31;
URI::Escape v3.26;
utf8 v1.04;
vars v1.01;
warnings v1.03;
warnings::register v1.00;
XSLoader v0.02;

RT Variables

RT::AmbiguousDayInPast 1
RT::BasePath /home/rt/rt
RT::CORE_CONFIG_FILE /home/rt/rt//etc/RT_Config.pm
RT::CanonicalizeEmailAddressMatch subdomain.example.com$
RT::CanonicalizeEmailAddressReplace example.com
RT::CommentAddress RT_CommentAddressNotSet
RT::CorrespondAddress RT_CorrespondAddressNotSet
RT::DatabaseHost localhost
RT::DatabaseName rt3
RT::DatabasePassword /Password not printed/
RT::DatabaseRTHost localhost
RT::DatabaseType mysql
RT::DatabaseUser rt_user
RT::DateDayBeforeMonth 1
RT::DefaultSearchResultFormat ‘id/TITLE:#’, ‘Subject/TITLE:Subject’,
Status, QueueName, OwnerName, Priority, ‘NEWLINE’, ‘’,
Requestors’, ‘CreatedRelative’,
ToldRelative’,
LastUpdatedRelative’, ‘TimeLeft
RT::EmailOutputEncoding utf-8
RT::EtcPath /home/rt/rt//etc
RT::FriendlyFromLineFormat “%s” <%s>
RT::FriendlyToLineFormat “%s of s Ticket #%s”:;
RT::LocalEtcPath /home/rt/rt//local/etc
RT::LocalLexiconPath /home/rt/rt//local/po
RT::LocalPath /home/rt/rt//local
RT::LogDir /home/rt/rt//var/log
RT::LogToFile debug
RT::LogToFileNamed rt.log
RT::LogToScreen error
RT::LogToSyslog error
RT::LogoURL http://support.domain.com:8000/NoAuth/images/rt.jpg
RT::LoopsToRTOwner 1
RT::MailCommand sendmailpipe
RT::MasonComponentRoot /home/rt/rt//share/html
RT::MasonDataDir /home/rt/rt//var/mason_data
RT::MasonLocalComponentRoot /home/rt/rt//local/html
RT::MasonSessionDir /home/rt/rt//var/session_data
RT::MaxAttachmentSize 10000000
RT::MaxInlineBody 128
RT::MessageBoxWidth 72
RT::MessageBoxWrap HARD
RT::MinimumPasswordLength /Password not printed/
RT::MyRequestsLength 10
RT::MyTicketsLength 10
RT::Organization support.domain.com
RT::OwnerEmail root
RT::RTAddressRegexp ^rt@support.domain.com$
RT::RecordOutgoingEmail 1
RT::SITE_CONFIG_FILE /home/rt/rt//etc/RT_SiteConfig.pm
RT::SendmailArguments -oi -t
RT::SendmailPath /usr/sbin/sendmail
RT::Timezone US/Eastern
RT::UseFriendlyFromLine 1
RT::VERSION 3.2.2
RT::VarPath /home/rt/rt//var
RT::WebBaseURL http://support.domain.com:8000
RT::WebImagesURL http://support.domain.com:8000/NoAuth/images/
RT::WebURL http://support.domain.com:8000/
RT::rtname s

Perl configuration

Summary of my perl5 (revision 5 version 8 subversion 5) configuration:
Platform:
osname=linux, osvers=2.4.24, archname=i686-linux
uname=‘linux pattern 2.4.24 #1 tue jan 6 20:20:35 est 2004 i686 intel(r) pentium(r) 4 cpu 2.40ghz genuineintel gnulinux ’
config_args=’’
hint=recommended, useposix=true, d_sigaction=define
usethreads=undef use5005threads=undef useithreads=undef usemultiplicity=undef
useperlio=define d_sfio=undef uselargefiles=define usesocks=undef
use64bitint=undef use64bitall=undef uselongdouble=undef
usemymalloc=n, bincompat5005=undef
Compiler:
cc=‘cc’, ccflags =‘-fno-strict-aliasing -pipe -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64’,
optimize=‘-O2’,
cppflags=‘-fno-strict-aliasing -pipe’
ccversion=‘’, gccversion=‘3.3.3 20040412 (Gentoo Linux 3.3.3-r6, ssp-3.3.2-2, pie-8.7.6)’, gccosandvers=‘’
intsize=4, longsize=4, ptrsize=4, doublesize=8, byteorder=1234
d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=12
ivtype=‘long’, ivsize=4, nvtype=‘double’, nvsize=8, Off_t=‘off_t’, lseeksize=8
alignbytes=4, prototype=define
Linker and Libraries:
ld=‘cc’, ldflags =‘-L/home/rt/local-perl/lib’
libpth=/home/rt/local-perl/lib /usr/local/lib /lib /usr/lib
libs=-lnsl -lndbm -lgdbm -ldb -ldl -lm -lcrypt -lutil -lc
perllibs=-lnsl -ldl -lm -lcrypt -lutil -lc
libc=/lib/libc-2.3.3.so, so=so, useshrplib=false, libperl=libperl.a
gnulibc_version=‘2.3.3’
Dynamic Linking:
dlsrc=dl_dlopen.xs, dlext=so, d_dlsymun=undef, ccdlflags=‘-Wl,-E’
cccdlflags=‘-fpic’, lddlflags=‘-shared -L/home/rt/local-perl/lib’

Jesse Vincent wrote:

Stan,

And memory usage on the box?
I’d be curious to know whether upgrading to a current dbix::searchbuilder improves things.

Jesse

stan@pattern stan $ cat /proc/meminfo
total: used: free: shared: buffers: cached:
Mem: 926334976 801812480 124522496 0 224817152 403955712
Swap: 518152192 307228672 210923520
MemTotal: 904624 kB
MemFree: 121604 kB
MemShared: 0 kB
Buffers: 219548 kB
Cached: 178384 kB
SwapCached: 216104 kB
Active: 449756 kB
Inactive: 266160 kB
HighTotal: 0 kB
HighFree: 0 kB
LowTotal: 904624 kB
LowFree: 121604 kB
SwapTotal: 506008 kB
SwapFree: 205980 kB

I have DBI Search Builder 1.11

I just installed

CPAN.pm: Going to build J/JE/JESSE/DBIx-SearchBuilder-1.15.tar.gz

=Mason= 12.177.133.32 - /Ticket/Display.html }}} 53.6131
=Mason= 12.177.133.32 - /Elements/Footer {{{
=Mason= 12.177.133.32 - /Elements/Callback {{{
=Mason= 12.177.133.32 - /Elements/Callback }}} 0.0027
=Mason= 12.177.133.32 - /Elements/Footer }}} 0.0127
=Mason= 12.177.133.32 - /Elements/SetupSessionCookie }}} 43.6643
=Mason= 12.177.133.32 - /Elements/Callback {{{
=Mason= 12.177.133.32 - /Elements/Callback }}} 0.0022
=Mason= 12.177.133.32 - /Elements/Callback {{{
=Mason= 12.177.133.32 - /Callbacks/RTFM/autohandler/Default {{{
=Mason= 12.177.133.32 - /Callbacks/RTFM/autohandler/Default
}}} 0.0023
=Mason= 12.177.133.32 - /Elements/Callback }}} 0.0051
=Mason= 12.177.133.32 - /Ticket/Attachment/dhandler {{{
=Mason= 12.177.133.32 - /Ticket/Attachment/dhandler }}} 0.0696
=Mason= 12.177.133.32 - /autohandler }}} 43.7508
=Mason= 12.177.133.32 - /Ticket/Attachment/1402/1244/ }}} ENDS
=Mason= 12.177.133.32 - /autohandler }}} 53.7351
=Mason= 12.177.133.32 - /Ticket/Display.html }}} ENDS

Still takes forever to load…

Stan

Jesse Vincent wrote:

CPAN.pm: Going to build J/JE/JESSE/DBIx-SearchBuilder-1.15.tar.gz

=Mason= 12.177.133.32 - /Elements/SetupSessionCookie }}} 43.6643

So. 43 seconds to do a single database fetch (presumably because of a
lock ktiming out). Then 10 seconds to load the long page.

That’s where you should start debugging.

Jesse Vincent wrote:

CPAN.pm: Going to build J/JE/JESSE/DBIx-SearchBuilder-1.15.tar.gz

=Mason= 12.177.133.32 - /Elements/SetupSessionCookie }}} 43.6643

So. 43 seconds to do a single database fetch (presumably because of a
lock ktiming out). Then 10 seconds to load the long page.

That’s where you should start debugging.

In my /etc/mysql/my.cnf file I have:

[mysqld]
skip-locking

Where else should I look for such locking issues, and how would I debug
them?

Stan