On Wed, Mar 11, 2009 at 02:02:15PM -0400, Bill Cole wrote: > 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%[[email protected]> > > 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=<[[email protected]>, 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=<[email protected]> > > Mar 10 07:45:54 rt3-curis-com postfix/qmgr[219]: 2A4DE8438B: > > from=<[email protected]>, size=1655, nrcpt=1 (queue active) > > Mar 10 07:45:54 rt3-curis-com postfix/smtp[225]: 2A4DE8438B: > > to=<[[email protected]>, 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=<[email protected]>, 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=<[email protected]> > > Mar 10 08:56:51 rt3-curis-com postfix/qmgr[219]: 6D778843F4: > > from=<[email protected]>, 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=<[email protected]> > > Mar 10 08:56:51 rt3-curis-com postfix/qmgr[219]: 7C66B843F5: > > from=<[email protected]>, size=1232, nrcpt=3 (queue active) > > Mar 10 08:56:51 rt3-curis-com postfix/smtp[234]: 6D778843F4: > > to=<[email protected]>, 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=<[email protected]>, 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=<[email protected]>, 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=<[email protected]>, 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]: > > <[email protected]> #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]: > > <[email protected]> sent To: [email protected] > > (/opt/rt3/bin/../lib/RT/Action/SendEmail.pm:333) > > [Tue Mar 10 11:45:54 2009] [info]: > > <[email protected]> #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]: > > <[email protected]> sent Bcc: [email protected], > > [email protected], [email protected] > > (/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 [email protected] > > (/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]: > > <[email protected]> #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]: > > <[email protected]> sent To: [email protected] > > (/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 , '[email protected]'); > > Set($CanonicalizeEmailAddressMatch , '@rt3\.curis\.com$'); > > Set($CanonicalizeEmailAddressReplace , '@curis.com'); > > Set($WebPath, "/rt"); > > Set($CorrespondAddress, '[email protected]'); > > Set($CommentAddress , '[email protected]'); > > 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. > We have been using RT since 3.2 with postfix versions 1.x and later and this sort of problem speaks to a misconfiguration of the postfix system, not a problem with the age of the release. The sendmail compatibility even in the earliest postfix releases has no problem with the way RT submits E-mail. I would recommend checking your postfix configurations. Good luck.
Cheers, Ken _______________________________________________ http://lists.bestpractical.com/cgi-bin/mailman/listinfo/rt-users Community help: http://wiki.bestpractical.com Commercial support: [email protected] Discover RT's hidden secrets with RT Essentials from O'Reilly Media. Buy a copy at http://rtbook.bestpractical.com
