Re: [rt-users] Email delay on ticket creation - sending to "www" user?
Derek Cunningham wrote, On 3/20/09 10:45 AM: > I thought this was solved, but I was wrong - see below: > > On 3/11/09 2:02 PM, "Bill Cole" > wrote: > >> Now the bad case: >> >>> Mar 10 08:56:51 rt3-curis-com postfix/pickup[214]: 6D778843F4: uid=70 >>> from= >>> Mar 10 08:56:51 rt3-curis-com postfix/cleanup[231]: 6D778843F4: >>> message-id= >>> Mar 10 08:56:51 rt3-curis-com postfix/qmgr[219]: 6D778843F4: >>> from=, size=998, nrcpt=1 (queue active) >>> Mar 10 08:56:51 rt3-curis-com postfix/pickup[214]: 7C66B843F5: uid=70 >>> from= HINT! [big snip] > I figured out that it is trying to send email to the user "www", No, it isn't. > which is > the problem!!! No, it isn't. > So, where is RT making the decision to add www to the bcc > list? It isn't. > rt3:/etc/postfix root# mailq > -Queue ID- --Size-- Arrival Time -Sender/Recipient--- > D97C288D82 1416 Fri Mar 20 10:10:14 www > de...@curis.com > j...@curis.com > rcur...@curis.com > > -- 1 Kbytes in 1 Request. > > rt3:/etc/postfix root# sendmail -q > rt3:/etc/postfix root# mailq > -Queue ID- --Size-- Arrival Time -Sender/Recipient--- > D97C288D82 1416 Fri Mar 20 10:10:14 www > de...@curis.com > j...@curis.com > rcur...@curis.com > > -- 1 Kbytes in 1 Request. > rt3:/etc/postfix root# Look at the mail log, which should tell you what happened when you ran sendmail -q. Also 'man mailq' or consider what the header on the 4th column in the mailq output might mean about the content of the 4th column. You may want to configure RT so that it uses something other than 'www' but using that address is unlikely to be a cause for slow deliveries. ___ 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
Re: [rt-users] Email delay on ticket creation - sending to "www" user?
I thought this was solved, but I was wrong - see below: On 3/11/09 2:02 PM, "Bill Cole" wrote: > > Now the bad case: > >> Mar 10 08:56:51 rt3-curis-com postfix/pickup[214]: 6D778843F4: uid=70 >> from= >> Mar 10 08:56:51 rt3-curis-com postfix/cleanup[231]: 6D778843F4: >> message-id= >> Mar 10 08:56:51 rt3-curis-com postfix/qmgr[219]: 6D778843F4: >> from=, size=998, nrcpt=1 (queue active) >> Mar 10 08:56:51 rt3-curis-com postfix/pickup[214]: 7C66B843F5: uid=70 >> from= >> Mar 10 08:56:51 rt3-curis-com postfix/cleanup[231]: 7C66B843F5: >> message-id= >> Mar 10 08:56:51 rt3-curis-com postfix/qmgr[219]: 7C66B843F5: >> from=, size=1232, nrcpt=3 (queue active) >> Mar 10 08:56:51 rt3-curis-com postfix/smtp[234]: 6D778843F4: >> to=, 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=, 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=, 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=, 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]: >> #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]: >> sent To: mbo...@curis.com >> (/opt/rt3/bin/../lib/RT/Action/SendEmail.pm:333) >> [Tue Mar 10 11:45:54 2009] [info]: >> #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]: >> 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]: >> #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]: >> 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. > On 3/19/09 9:21 AM, "Derek Cunningham" wrote: > > > Sure enough, it was the postfix configuration. Thanks for suggesting it > Bill - I just put default Postfix (not Apple) times for wakeup on pickup, > qmgr and flush in the master.cf, Apple sets them to "-". I had already > enabled pickup, which had things partially working, but missed qmgr and > flush. > > -Derek > I figured out that it is trying to send email to the user "www", which is the problem!!! So, where is RT making the decision to ad
Re: [rt-users] Email delay on ticket creation - SOLVED
On 3/12/09 10:45 AM, "Bill Cole" wrote: > Derek Cunningham wrote, On 3/12/09 8:30 AM: >> Hi Bill, >> >> I really appreciate your time and helpful answers. They have certainly >> pointed me in the right direction, and I'll update the list when I have it >> solved. >> >> It's been a bit of a challenge to make this run on Mac OS X, all kinds of >> different preinstalled software points to that it 'should' work easily, but >> time and time again I find myself fighting against what should be simple >> config changes that have been harder to solve than I though it should be. > > It is useful to keep in mind that Apple acts strategically, even when it > looks like they are just being sloppy. MacOS X *Server* is a premium-priced > product and has very few truly secret differences from the standard version > of MacOS X that comes with a personal Mac, it is mostly a matter of > configuration; the desktop version of the system is aggressively configured > towards use as a personal computer that is almost exclusively used through > the GUI by one person at a time. The Postfix config is an example of this, > and if you want Postfix on a Mac to behave like a normal server instance of > Postfix, you should either replace it altogether or at least fix the lack of > wakeup settings in master.cf. That may also require you to watch out for > Apple regressing the change in future updates, but it won't break anything > that already works. > >> At least I have some much more focused searches to make about the postfix >> config. I will try changing RT's $MailCommand and $SendmailArguments first >> and see if that makes the difference. > > Well, despite my digression on that option I think that is a second-best > approach. It is something one might try if one does not have administrative > control of the mail subsystem or has some need to keep the no-wakeup model. > The 'sendmailpipe' option for $MailCommand is a much more efficient > approach, and I wouldn't suggest switching to 'sendmail' on a high-volume RT > machine. I'm not even sure that change will solve the queue delay problem > completely. My hypothesis is that it will avoid the problem by serializing > the queueing of messages for multiple recipients so that the Postfix > 'pickup' process can't win a parallel race with a 'sendmail -oi -t' process > that has to parse multiple recipients out of a Bcc header. Sure enough, it was the postfix configuration. Thanks for suggesting it Bill - I just put default Postfix (not Apple) times for wakeup on pickup, qmgr and flush in the master.cf, Apple sets them to "-". I had already enabled pickup, which had things partially working, but missed qmgr and flush. Thanks for the assist! I now happily have RT 3.8.1 running on Mac OS X 10.4 client. In all reality, most services needed to make it all happen were in place, but needed to be activated and slightly reconfigured. None of it was too difficult, but none of it was exactly 'out of the box' either... -Derek ___ 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
Re: [rt-users] Email delay on ticket creation
Derek Cunningham wrote, On 3/12/09 8:30 AM: > Hi Bill, > > I really appreciate your time and helpful answers. They have certainly > pointed me in the right direction, and I'll update the list when I have it > solved. > > It's been a bit of a challenge to make this run on Mac OS X, all kinds of > different preinstalled software points to that it 'should' work easily, but > time and time again I find myself fighting against what should be simple > config changes that have been harder to solve than I though it should be. It is useful to keep in mind that Apple acts strategically, even when it looks like they are just being sloppy. MacOS X *Server* is a premium-priced product and has very few truly secret differences from the standard version of MacOS X that comes with a personal Mac, it is mostly a matter of configuration; the desktop version of the system is aggressively configured towards use as a personal computer that is almost exclusively used through the GUI by one person at a time. The Postfix config is an example of this, and if you want Postfix on a Mac to behave like a normal server instance of Postfix, you should either replace it altogether or at least fix the lack of wakeup settings in master.cf. That may also require you to watch out for Apple regressing the change in future updates, but it won't break anything that already works. > At least I have some much more focused searches to make about the postfix > config. I will try changing RT's $MailCommand and $SendmailArguments first > and see if that makes the difference. Well, despite my digression on that option I think that is a second-best approach. It is something one might try if one does not have administrative control of the mail subsystem or has some need to keep the no-wakeup model. The 'sendmailpipe' option for $MailCommand is a much more efficient approach, and I wouldn't suggest switching to 'sendmail' on a high-volume RT machine. I'm not even sure that change will solve the queue delay problem completely. My hypothesis is that it will avoid the problem by serializing the queueing of messages for multiple recipients so that the Postfix 'pickup' process can't win a parallel race with a 'sendmail -oi -t' process that has to parse multiple recipients out of a Bcc header. ___ 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
Re: [rt-users] Email delay on ticket creation
Hi Bill, I really appreciate your time and helpful answers. They have certainly pointed me in the right direction, and I'll update the list when I have it solved. It's been a bit of a challenge to make this run on Mac OS X, all kinds of different preinstalled software points to that it 'should' work easily, but time and time again I find myself fighting against what should be simple config changes that have been harder to solve than I though it should be. At least I have some much more focused searches to make about the postfix config. I will try changing RT's $MailCommand and $SendmailArguments first and see if that makes the difference. Thanks again, -Derek Cunningham On 3/11/09 6:37 PM, "Bill Cole" wrote: > Kenneth Marshall wrote, On 3/11/09 2:27 PM: >> 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. > [...] >>> 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. > > The age is a tangential issue, but when working with Postfix on MacOS X it > is helpful to know that one is dealing with an Apple-modified 2.1.x rather > than Dr. Venema's 2.5.x and that the default configuration on MacOS X is an > afterthought for a personal desktop system that almost never uses it. One > can really fix that Postfix by replacing it with a standard modern version, > adapt it to more normal use by changing the config, or adjust things that > use it (like RT) to go around its flaws. I may be wrong, but I think that by > using 'sendmail' instead of 'sendmailpipe' in RT, the envelope splitting > task is done upstream in the Mail::Mailer part of a MIME::Entity object > rather than being handed off to the sendmail binary called with a '-t' > argument. That should prevent the circumstance where messages end up sitting > in the queue waiting for the next external event to trigger pickup. > ___ > 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 ___ 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
Re: [rt-users] Email delay on ticket creation
Kenneth Marshall wrote, On 3/11/09 2:27 PM: > 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. [...] >> 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. The age is a tangential issue, but when working with Postfix on MacOS X it is helpful to know that one is dealing with an Apple-modified 2.1.x rather than Dr. Venema's 2.5.x and that the default configuration on MacOS X is an afterthought for a personal desktop system that almost never uses it. One can really fix that Postfix by replacing it with a standard modern version, adapt it to more normal use by changing the config, or adjust things that use it (like RT) to go around its flaws. I may be wrong, but I think that by using 'sendmail' instead of 'sendmailpipe' in RT, the envelope splitting task is done upstream in the Mail::Mailer part of a MIME::Entity object rather than being handed off to the sendmail binary called with a '-t' argument. That should prevent the circumstance where messages end up sitting in the queue waiting for the next external event to trigger pickup. ___ 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
Re: [rt-users] Email delay on ticket creation
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= > > 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= > > Mar 10 07:45:54 rt3-curis-com postfix/cleanup[218]: 2A4DE8438B: > > message-id= > > Mar 10 07:45:54 rt3-curis-com postfix/qmgr[219]: 2A4DE8438B: > > from=, 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=, 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= > > Mar 10 08:56:51 rt3-curis-com postfix/cleanup[231]: 6D778843F4: > > message-id= > > Mar 10 08:56:51 rt3-curis-com postfix/qmgr[219]: 6D778843F4: > > from=, size=998, nrcpt=1 (queue active) > > Mar 10 08:56:51 rt3-curis-com postfix/pickup[214]: 7C66B843F5: uid=70 > > from= > > Mar 10 08:56:51 rt3-curis-com postfix/cleanup[231]: 7C66B843F5: > > message-id= > > Mar 10 08:56:51 rt3-curis-com postfix/qmgr[219]: 7C66B843F5: > > from=, size=1232, nrcpt=3 (queue active) > > Mar 10 08:56:51 rt3-curis-com postfix/smtp[234]: 6D778843F4: > > to=, 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=, 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=, 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]: 7C66B843
Re: [rt-users] Email delay on ticket creation
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= > 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= > Mar 10 07:45:54 rt3-curis-com postfix/cleanup[218]: 2A4DE8438B: > message-id= > Mar 10 07:45:54 rt3-curis-com postfix/qmgr[219]: 2A4DE8438B: > from=, 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=, 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= > Mar 10 08:56:51 rt3-curis-com postfix/cleanup[231]: 6D778843F4: > message-id= > Mar 10 08:56:51 rt3-curis-com postfix/qmgr[219]: 6D778843F4: > from=, size=998, nrcpt=1 (queue active) > Mar 10 08:56:51 rt3-curis-com postfix/pickup[214]: 7C66B843F5: uid=70 > from= > Mar 10 08:56:51 rt3-curis-com postfix/cleanup[231]: 7C66B843F5: > message-id= > Mar 10 08:56:51 rt3-curis-com postfix/qmgr[219]: 7C66B843F5: > from=, size=1232, nrcpt=3 (queue active) > Mar 10 08:56:51 rt3-curis-com postfix/smtp[234]: 6D778843F4: > to=, 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=, 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=, 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=, 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[2
Re: [rt-users] Email delay on ticket creation
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. 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. Another recent sample: >From /var/log/mail.log 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= 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) Mar 10 07:45:54 rt3-curis-com postfix/pickup[214]: 2A4DE8438B: uid=70 from= Mar 10 07:45:54 rt3-curis-com postfix/cleanup[218]: 2A4DE8438B: message-id= Mar 10 07:45:54 rt3-curis-com postfix/qmgr[219]: 2A4DE8438B: from=, 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 Mar 10 07:45:54 rt3-curis-com postfix/local[220]: 1C89B8436A: to=, 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 Mar 10 08:56:51 rt3-curis-com postfix/pickup[214]: 6D778843F4: uid=70 from= Mar 10 08:56:51 rt3-curis-com postfix/cleanup[231]: 6D778843F4: message-id= Mar 10 08:56:51 rt3-curis-com postfix/qmgr[219]: 6D778843F4: from=, size=998, nrcpt=1 (queue active) Mar 10 08:56:51 rt3-curis-com postfix/pickup[214]: 7C66B843F5: uid=70 from= Mar 10 08:56:51 rt3-curis-com postfix/cleanup[231]: 7C66B843F5: message-id= Mar 10 08:56:51 rt3-curis-com postfix/qmgr[219]: 7C66B843F5: from=, size=1232, nrcpt=3 (queue active) Mar 10 08:56:51 rt3-curis-com postfix/smtp[234]: 6D778843F4: to=, 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=, 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=, 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=, 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 And from /var/log/httpd/error.log [Tue Mar 10 11:45:54 2009] [info]: #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]: sent To: mbo...@curis.com (/opt/rt3/bin/../lib/RT/Action/SendEmail.pm:333) [Tue Mar 10 11:45:54 2009] [info]: #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]: sent Bcc: d...@curis.com, de...@curis.com, rcur...@curis.com (/opt/rt3/bin/../lib/RT/Action/SendEmail.pm:333) [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]: #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]: 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
[rt-users] Email delay on ticket creation
Hi all, I have not posted to this list in a long time. I was quite stumped for a long time trying to get sendmail configured properly on Mac OS X (client) and I finally did... So, I have a new install of RT 3.8.1 on FreeBSD (Mac OS X). I'm having trouble with what seems to be random delays in the email notifications to admincc's when a user emails in a new request. I am having a great deal of trouble figuring out where the delay is coming from, I have googled and searched RT's wiki, and I'm not coming up with anything, so I'm turning to the list for help. Most actions that generate email, the email is delivered immediately. When a user submits an email to RT that is creating a new ticket, their autoreply email is sent immediately, but then the notice to us (the admincc's) has a 'delay=5235' or other random high number in it. Performing another action in RT that generates another email makes both the new email and the as-yet-undelivered email be delivered immediately. I captured all the info I could from mail.log and httpd/system.log, and there wasn't anything related in system.log. I'm open to any ideas. In this case the delay time was set to 5842. I have seen it set to other times, usually in the thousands. If we aren't paying close attention to RT a new ticket can go unnoticed for sometimes 40 minutes, sometimes well over 2 hours... from /var/log/mail.log Mar 5 13:59:11 rt3-ourcompany-com postfix/smtpd[429]: connect from mailserver.ourcompany.com[10.2.0.20] Mar 5 13:59:11 rt3-ourcompany-com postfix/smtpd[429]: 63F9B83254: client=mailserver.ourcompany.com[10.2.0.20] Mar 5 13:59:11 rt3-ourcompany-com postfix/cleanup[432]: 63F9B83254: message-id= Mar 5 13:59:11 rt3-ourcompany-com postfix/qmgr[239]: 63F9B83254: from=, size=1980, nrcpt=1 (queue active) Mar 5 13:59:11 rt3-ourcompany-com postfix/smtpd[429]: disconnect from mailserver.ourcompany.com[10.2.0.20] Mar 5 13:59:14 rt3-ourcompany-com postfix/pickup[422]: 2D92F83275: uid=70 from= Mar 5 13:59:14 rt3-ourcompany-com postfix/cleanup[432]: 2D92F83275: message-id= Mar 5 13:59:14 rt3-ourcompany-com postfix/qmgr[239]: 2D92F83275: from=, size=1814, nrcpt=1 (queue active) Mar 5 13:59:14 rt3-ourcompany-com postfix/smtp[437]: 2D92F83275: to=, relay=mailserver.ourcompany.com[10.2.0.20], delay=0, status=sent (250 2.0.0 49b02102-000ac917 Message accepted for delivery) Mar 5 13:59:14 rt3-ourcompany-com postfix/qmgr[239]: 2D92F83275: removed Mar 5 13:59:15 rt3-ourcompany-com postfix/local[433]: 63F9B83254: to=, relay=local, delay=4, status=sent (delivered to command: /opt/rt3/bin/rt-mailgate --queue facilities --action correspond --url http://localhost/rt) Mar 5 13:59:15 rt3-ourcompany-com postfix/qmgr[239]: 63F9B83254: removed >> Above is the user submitting the request Mar 5 15:36:35 rt3-ourcompany-com postfix/pickup[491]: ECAAF833A0: uid=70 from= Mar 5 15:36:36 rt3-ourcompany-com postfix/cleanup[492]: ECAAF833A0: message-id= Mar 5 15:36:36 rt3-ourcompany-com postfix/qmgr[239]: ECAAF833A0: from=, size=2284, nrcpt=3 (queue active) Mar 5 15:36:36 rt3-ourcompany-com postfix/smtp[494]: ECAAF833A0: to=, relay=mailserver.ourcompany.com[10.2.0.20], delay=5842, status=sent (250 2.0.0 49b037d4-000acb38 Message accepted for delivery) Mar 5 15:36:36 rt3-ourcompany-com postfix/qmgr[239]: ECAAF833A0: removed >>Above is the user's request being relayed to us admincc's Mar 5 15:36:55 rt3-ourcompany-com postfix/pickup[491]: AA81C833AB: uid=70 from= Mar 5 15:36:55 rt3-ourcompany-com postfix/cleanup[492]: AA81C833AB: message-id= Mar 5 15:36:55 rt3-ourcompany-com postfix/qmgr[239]: AA81C833AB: from=, size=1003, nrcpt=1 (queue active) Mar 5 15:36:55 rt3-ourcompany-com postfix/smtp[494]: AA81C833AB: to=, relay=mailserver.ourcompany.com[10.2.0.20], delay=0, status=sent (250 2.0.0 49b037e7-000acb39 Message accepted for delivery) Mar 5 15:36:55 rt3-ourcompany-com postfix/qmgr[239]: AA81C833AB: removed >>Above is my taking the ticket, generating an email to me, what I think 'pushed' the other message on it's way. from /var/log/httpd/error.log (times in GMT, so -5:00) [Thu Mar 5 18:59:14 2009] [info]: #30082/1590 - Scrip 3 On Create Autoreply To Requestors (/opt/rt3/bin/../lib/RT/Action/SendEmail.pm:302) [Thu Mar 5 18:59:14 2009] [info]: sent To: theu...@ourcompany.com (/opt/rt3/bin/../lib/RT/Action/SendEmail.pm:333) [Thu Mar 5 18:59:14 2009] [info]: #30082/1590 - Scrip 4 On Create Notify AdminCcs (/opt/rt3/bin/../lib/RT/Action/SendEmail.pm:302) [Thu Mar 5 18:59:14 2009] [info]: sent Bcc: d...@ourcompany.com, de...@ourcompany.com, rcur...@ourcompany.com (/opt/rt3/bin/../lib/RT/Action/SendEmail.pm:333) [Thu Mar 5 18:59:14 2009] [info]: Ticket 30082 created in queue 'Facilities' by theu...@ourcompany.com (/opt/rt3/bin/../lib/RT/Ticket_Overlay.pm:659) >> Above is user's request being created in httpd log Other messages have delay=0 or delay=1. Where do I go looking next? Thanks -Derek Cunningham de...@curis.com ___
