[rt-users] Slow Response Time when Email involved
Kevin Falcone
falcone at bestpractical.com
Fri Nov 4 18:04:30 EDT 2011
On Fri, Nov 04, 2011 at 04:56:49PM -0400, Kevin Squire wrote:
> Sorry to reply to my own... but since it was after work hours, I
> commented out the section that I thought was slowing things down:
This isn't RT being slow, this is the command you pipe mail to being
slow. It may be doing DNS lookups incredibly slowly or if you're
using sendmail it may be trying to relay the mail before finishing.
We document a solution for this for sendmail in the configuration that
ships with RT. For non-sendmail mailers, it's usually DNS.
-kevin
> # unless ( close $mail ) {
> # die "close pipe failed: $!" if $!; # system error
> # sendmail exit statuses mostly errors with data not software
> # TODO: status parsing: core dump, exit on signal or EX_*
> # my $msg = "$msgid: `$path $args` exitted with code ". ($?>>8);
> # $msg = ", interrupted by signal ". ($?&127) if $?&127;
> # $RT::Logger->error( $msg );
> # }
>
> Well all that did was move the perceived slowdown. Now it seems to be
> between 11-0-4 and 11-1 (but only thing there is a } ) ... So I am
> even more confused now what the problem might be.
>
>
>
>
>
> On Fri, 4 Nov 2011 16:36:46 -0400
> Kevin Squire <gentgeen at wikiak.org> wrote:
>
> > We have been using RT for a long time now (3 or 4 years?) and have had
> > great success. Starting sometime in Aug, we found that there was a
> > LARGE delay when ever updating a ticket in ANY way that would include
> > sending emails. Since it was also that start of the school year, we
> > just assumed 'beginning of year' load issues. Well the problem is
> > still there.
> >
> > Anytime an email has to go out, there is exactly a 12 second delay in
> > the logs. This then causes the page load to be greater then 12
> > seconds. It does not seem to matter what time of day, or if the email
> > includes attachments, etc.
> >
> > So I went through the code, pretty much line by line, adding comments
> > to try and narrow down WHERE the delay is, but now I am stuck.
> >
> > I have edited both
> > $RT_INSTALL/lib/RT/Action/SendEmail.pm and
> > $RT_INSTALL/lib/RT/Interface/Email.pm
> >
> > SendEmail.pm now has "Ticker #" and Email.pm has "Ticker 1#"
> >
> > Here are my logs:
> > Nov 4 16:09:16 outrigger RT:
> > <rt-3.8.8-14121-1320437356-1460.35109-6-0 at pavcs.org> KDS Ticker 0 .
> > (/usr/share/request-tracker3.8/lib/RT/Action/SendEmail.pm:306) Nov 4
> > 16:09:16 outrigger RT: KDS Ticker 10
> > (/usr/share/request-tracker3.8/lib/RT/Interface/Email.pm:396) Nov 4
> > 16:09:16 outrigger RT: KDS Ticker 11
> > (/usr/share/request-tracker3.8/lib/RT/Interface/Email.pm:402) Nov 4
> > 16:09:16 outrigger RT: KDS Ticker 11-0
> > (/usr/share/request-tracker3.8/lib/RT/Interface/Email.pm:445) Nov 4
> > 16:09:16 outrigger RT: KDS Ticker 11-0-1
> > (/usr/share/request-tracker3.8/lib/RT/Interface/Email.pm:449) Nov 4
> > 16:09:16 outrigger RT: KDS Ticker 11-0-2
> > (/usr/share/request-tracker3.8/lib/RT/Interface/Email.pm:451) Nov 4
> > 16:09:16 outrigger RT: KDS Ticker 11-0-3
> > (/usr/share/request-tracker3.8/lib/RT/Interface/Email.pm:455) Nov 4
> > 16:09:28 outrigger RT: KDS Ticker 11-0-4
> > (/usr/share/request-tracker3.8/lib/RT/Interface/Email.pm:464) Nov 4
> > 16:09:28 outrigger RT: KDS Ticker 11-1
> > (/usr/share/request-tracker3.8/lib/RT/Interface/Email.pm:466) Nov 4
> > 16:09:28 outrigger RT:
> > <rt-3.8.8-14121-1320437356-1460.35109-6-0 at pavcs.org> sent To:
> > gentgeen at wikiak.org
> > (/usr/share/request-tracker3.8/lib/RT/Action/SendEmail.pm:331)
> >
> >
> > The 12 Second delay is between 11-0-3 and 11-0-4
> >
> > Here is my modified code (Email.pm):
> >
> >
> > $RT::Logger->info( " KDS Ticker 11-0 " );
> > eval {
> > # don't ignore CHLD signal to get proper exit code
> > local $SIG{'CHLD'} = 'DEFAULT';
> > $RT::Logger->info( " KDS Ticker 11-0-1 " );
> > open my $mail, "|$path $args" or die "couldn't execute
> > program: $!"; $RT::Logger->info( " KDS Ticker 11-0-2 " );
> > # if something wrong with $mail->print we will get PIPE
> > signal, handle it local $SIG{'PIPE'} = sub { die "program unexpectedly
> > closed pipe" }; $args{'Entity'}->print($mail);
> > $RT::Logger->info( " KDS Ticker 11-0-3 " );
> > unless ( close $mail ) {
> > die "close pipe failed: $!" if $!; # system error
> > # sendmail exit statuses mostly errors with data not
> > software # TODO: status parsing: core dump, exit on signal or EX_*
> > my $msg = "$msgid: `$path $args` exitted with code ".
> > ($?>>8); $msg = ", interrupted by signal ". ($?&127) if $?&127;
> > $RT::Logger->error( $msg );
> > }
> > $RT::Logger->info( " KDS Ticker 11-0-4 " );
> > };
> > $RT::Logger->info( " KDS Ticker 11-1 " );
> >
> >
> > Can anyone PLEASE help me narrow this down ... I am just at a lost
> > now. I just don't know enough Perl to understand what is going on or
> > why the large delay right at:
> >
> > unless ( close $mail ) {
> > die "close pipe failed: $!" if $!; # system error
> > # sendmail exit statuses mostly errors with data not software
> > # TODO: status parsing: core dump, exit on signal or EX_*
> > my $msg = "$msgid: `$path $args` exitted with code ". ($?>>8);
> > $msg = ", interrupted by signal ". ($?&127) if $?&127;
> > $RT::Logger->error( $msg );
> > }
> >
> >
>
>
> --
> http://www.wikiak.org
>
> #############################################################
> Associate yourself with men of good quality if you esteem
> your own reputation; for 'tis better to be alone then in bad
> company. - George Washington, Rules of Civility
> --------
> RT Training Sessions (http://bestpractical.com/services/training.html)
> * Barcelona, Spain November 28 & 29, 2011
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 195 bytes
Desc: not available
URL: <http://lists.bestpractical.com/pipermail/rt-users/attachments/20111104/13fba581/attachment.sig>
More information about the rt-users
mailing list