Derek Cunningham wrote, On 3/10/09 10:54 AM: > Hi > If I have gone about posting my question the wrong way please let me know. > Should I add my RT_SiteConfig.pm file in addition to these logs? The > autoreply goes out right away, but I'm getting a lengthy delay on only the > admincc messages, and only sometimes when a user submits a new request by > email. It doesn't seem to matter who the user is. If anybody sees anything > helpful in my log entries please tell me. If I should be including info > from another log, please tell me. I would have suspected a postfix config > problem, but I'm suspecting my RT config because this only happens during > the condition that a user submits a new request via email.
It's not primarily RT, it's primarily Postfix. > I am using RT 3.8.1 on Mac OSX (10.4), postfix/sendmail to relay to our main > email server with SMTP. RT is working great except for these email delays. The mail subsystem for MacOS X 10.4 in its default configuration has a tendency to have this sort of trouble, particularly when connectivity is intermittent or mail is being sent to systems that use "greylisting" for spam control. Messages that are not delivered on the first try will typically sit around until the next new mail submission, and in some cases will not be tried immediately because of how Postfix compartmentalizes operations. This can be fixed in your Postfix config, which presumably you've already adjusted somewhat to make the system accept mail. Look at the pickup, qmgr, and flush lines in master.cf and give them reasonable wakeup times. You also could set up a scheduled queue run via cron or launchd if you are not comfortable adjusting the Postfix config. > Another recent sample: > From /var/log/mail.log I'll comment a bit in the hope that it will be enlightening... > Mar 10 07:45:45 rt3-curis-com postfix/smtpd[215]: connect from > [mailserver].curis.com[10.2.0.20] > Mar 10 07:45:47 rt3-curis-com postfix/smtpd[215]: 1C89B8436A: > client=[mailserver].curis.com[10.2.0.20] > Mar 10 07:45:47 rt3-curis-com postfix/cleanup[218]: 1C89B8436A: > message-id=<c5dbcb27.111a%[request...@curis.com> > Mar 10 07:45:47 rt3-curis-com postfix/smtpd[215]: disconnect from > [mailserver].curis.com[10.2.0.20] > Mar 10 07:45:47 rt3-curis-com postfix/qmgr[219]: 1C89B8436A: > from=<[request...@curis.com>, size=896, nrcpt=1 (queue active) So, message 1C89B8436A comes in and gets queued. But it doesn't get delivered until 9 seconds later when an outgoing message wakes up Postfix: > Mar 10 07:45:54 rt3-curis-com postfix/pickup[214]: 2A4DE8438B: uid=70 > from=<www> > Mar 10 07:45:54 rt3-curis-com postfix/cleanup[218]: 2A4DE8438B: > message-id=<rt-3.8.1-212-1236685553-588.30085-...@curis.com> > Mar 10 07:45:54 rt3-curis-com postfix/qmgr[219]: 2A4DE8438B: > from=<w...@rt3.curis.com>, size=1655, nrcpt=1 (queue active) > Mar 10 07:45:54 rt3-curis-com postfix/smtp[225]: 2A4DE8438B: > to=<[request...@curis.com>, relay=[mailserver].curis.com[10.2.0.20], > delay=0, status=sent (250 2.0.0 49b652f2-000b3322 Message accepted for > delivery) > Mar 10 07:45:54 rt3-curis-com postfix/qmgr[219]: 2A4DE8438B: removed Message 2A4DE8438B makes it out immediately > Mar 10 07:45:54 rt3-curis-com postfix/local[220]: 1C89B8436A: > to=<facilit...@rt3.curis.com>, relay=local, delay=9, status=sent (delivered > to command: /opt/rt3/bin/rt-mailgate --queue facilities --action correspond > --url http://localhost/rt) > Mar 10 07:45:54 rt3-curis-com postfix/qmgr[219]: 1C89B8436A: removed And finally 1C89B8436A gets delivered locally, because the outbound mail woke up Postfix, which found it waiting for its first delivery attempt. Now the bad case: > Mar 10 08:56:51 rt3-curis-com postfix/pickup[214]: 6D778843F4: uid=70 > from=<www> > Mar 10 08:56:51 rt3-curis-com postfix/cleanup[231]: 6D778843F4: > message-id=<rt-3.8.1-228-1236689811-14.30085-...@curis.com> > Mar 10 08:56:51 rt3-curis-com postfix/qmgr[219]: 6D778843F4: > from=<w...@rt3.curis.com>, size=998, nrcpt=1 (queue active) > Mar 10 08:56:51 rt3-curis-com postfix/pickup[214]: 7C66B843F5: uid=70 > from=<www> > Mar 10 08:56:51 rt3-curis-com postfix/cleanup[231]: 7C66B843F5: > message-id=<rt-3.8.1-212-1236685553-104.30085-...@curis.com> > Mar 10 08:56:51 rt3-curis-com postfix/qmgr[219]: 7C66B843F5: > from=<w...@rt3.curis.com>, size=1232, nrcpt=3 (queue active) > Mar 10 08:56:51 rt3-curis-com postfix/smtp[234]: 6D778843F4: > to=<d...@curis.com>, relay=[mailserver].curis.com[10.2.0.20], delay=0, > status=sent (250 2.0.0 49b66393-000b34c3 Message accepted for delivery) > Mar 10 08:56:51 rt3-curis-com postfix/smtp[235]: 7C66B843F5: > to=<d...@curis.com>, relay=[mailserver].curis.com[10.2.0.20], delay=4257, > status=sent (250 2.0.0 49b66393-000b34c4 Message accepted for delivery) > Mar 10 08:56:51 rt3-curis-com postfix/smtp[235]: 7C66B843F5: > to=<de...@curis.com>, relay=[mailserver].curis.com[10.2.0.20], delay=4257, > status=sent (250 2.0.0 49b66393-000b34c4 Message accepted for delivery) > Mar 10 08:56:51 rt3-curis-com postfix/smtp[235]: 7C66B843F5: > to=<rcur...@curis.com>, relay=[mailserver].curis.com[10.2.0.20], delay=4257, > status=sent (250 2.0.0 49b66393-000b34c4 Message accepted for delivery) > Mar 10 08:56:51 rt3-curis-com postfix/qmgr[219]: 6D778843F4: removed > Mar 10 08:56:51 rt3-curis-com postfix/qmgr[219]: 7C66B843F5: removed Here, 6D778843F4 wakes up Postfix to the presence of 7C66B843F5, whose message-id and delay value point at it having been submitted 71 minutes earlier with 2A4DE8438B. > And from /var/log/httpd/error.log Which seems to be 4 hours ahead... UTC vs EDT? I wouldn't expect to see that discrepancy on MacOS X... > [Tue Mar 10 11:45:54 2009] [info]: > <rt-3.8.1-212-1236685553-588.30085-...@curis.com> #30085/1657 - Scrip 3 On > Create Autoreply To Requestors > (/opt/rt3/bin/../lib/RT/Action/SendEmail.pm:302) > [Tue Mar 10 11:45:54 2009] [info]: > <rt-3.8.1-212-1236685553-588.30085-...@curis.com> sent To: mbo...@curis.com > (/opt/rt3/bin/../lib/RT/Action/SendEmail.pm:333) > [Tue Mar 10 11:45:54 2009] [info]: > <rt-3.8.1-212-1236685553-104.30085-...@curis.com> #30085/1657 - Scrip 4 On > Create Notify AdminCcs (/opt/rt3/bin/../lib/RT/Action/SendEmail.pm:302) > [Tue Mar 10 11:45:54 2009] [info]: > <rt-3.8.1-212-1236685553-104.30085-...@curis.com> sent Bcc: d...@curis.com, > de...@curis.com, rcur...@curis.com > (/opt/rt3/bin/../lib/RT/Action/SendEmail.pm:333) And that answers the "why?" question. RT is sending that message with Bcc's (normal) which resulted in it not being ready for pickup back when 2A4DE8438B went out. > [Tue Mar 10 11:45:54 2009] [info]: Ticket 30085 created in queue > 'Facilities' by mbo...@curis.com > (/opt/rt3/bin/../lib/RT/Ticket_Overlay.pm:659) > [Tue Mar 10 12:56:13 2009] [info]: Successful login for dens from 10.2.2.9 > (/opt/rt3/share/html/autohandler:273) > [Tue Mar 10 12:56:51 2009] [info]: > <rt-3.8.1-228-1236689811-14.30085-...@curis.com> #30085/1660 - Scrip 2 On > Owner Change Notify Owner (/opt/rt3/bin/../lib/RT/Action/SendEmail.pm:302) > [Tue Mar 10 12:56:51 2009] [info]: > <rt-3.8.1-228-1236689811-14.30085-...@curis.com> sent To: d...@curis.com > (/opt/rt3/bin/../lib/RT/Action/SendEmail.pm:333) > > > My RT_SiteConfig.PM > > Set($rtname, "curis.com"); > Set($Organization, "curis.com"); > Set($WebBaseURL, "http://rt3.curis.com"); > Set($OwnerEmail , 'de...@curis.com'); > Set($CanonicalizeEmailAddressMatch , '@rt3\.curis\.com$'); > Set($CanonicalizeEmailAddressReplace , '@curis.com'); > Set($WebPath, "/rt"); > Set($CorrespondAddress, 'corresp...@curis.com'); > Set($CommentAddress , 'comm...@curis.com'); > Set($SendmailPath, "/usr/sbin/sendmail"); > Set($MessageBoxWrap, "SOFT"); > Set($UseFriendlyToLine, 0); > Set($NotifyActor, 1); > Set($MessageBoxRichText, 0); > Set($SMTPDebug, 1); > Set($MyTicketsLength, 30); > Set($DefaultSummaryRows, 30); > You *MIGHT* be able to get better behavior by adjusting the mail parameters that RT is using. The defaults are reasonable for Real Sendmail and for the sendmail compatibility interface of Postfix as Postfix is commonly configured on many Linux and *BSD systems, but it is really not suited for the modified (and somewhat old) Postfix that Apple ships on MacOS X with a desktop-oriented configuration. You might find that using 'sendmail' instead of 'sendmailpipe' for $MailCommand and adjusting $SendmailArguments (no -t) makes the whole issue vanish. _______________________________________________ http://lists.bestpractical.com/cgi-bin/mailman/listinfo/rt-users Community help: http://wiki.bestpractical.com Commercial support: sa...@bestpractical.com Discover RT's hidden secrets with RT Essentials from O'Reilly Media. Buy a copy at http://rtbook.bestpractical.com