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=<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) 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 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 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 And from /var/log/httpd/error.log [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) [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); On 3/5/09 5:13 PM, "Derek Cunningham" <[email protected]> wrote: > 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=<c5d58b2c.9f31%[email protected]> > Mar 5 13:59:11 rt3-ourcompany-com postfix/qmgr[239]: 63F9B83254: > from=<[email protected]>, 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=<www> > Mar 5 13:59:14 rt3-ourcompany-com postfix/cleanup[432]: 2D92F83275: > message-id=<[email protected]> > Mar 5 13:59:14 rt3-ourcompany-com postfix/qmgr[239]: 2D92F83275: > from=<[email protected]>, size=1814, nrcpt=1 (queue active) > Mar 5 13:59:14 rt3-ourcompany-com postfix/smtp[437]: 2D92F83275: > to=<[email protected]>, 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=<[email protected]>, 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=<www> > Mar 5 15:36:36 rt3-ourcompany-com postfix/cleanup[492]: ECAAF833A0: > message-id=<[email protected]> > Mar 5 15:36:36 rt3-ourcompany-com postfix/qmgr[239]: ECAAF833A0: > from=<[email protected]>, size=2284, nrcpt=3 (queue active) > Mar 5 15:36:36 rt3-ourcompany-com postfix/smtp[494]: ECAAF833A0: > to=<[email protected]>, 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=<www> > Mar 5 15:36:55 rt3-ourcompany-com postfix/cleanup[492]: AA81C833AB: > message-id=<[email protected]> > Mar 5 15:36:55 rt3-ourcompany-com postfix/qmgr[239]: AA81C833AB: > from=<[email protected]>, size=1003, nrcpt=1 (queue active) > Mar 5 15:36:55 rt3-ourcompany-com postfix/smtp[494]: AA81C833AB: > to=<[email protected]>, 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]: > <[email protected]> #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]: > <[email protected]> sent To: > [email protected] (/opt/rt3/bin/../lib/RT/Action/SendEmail.pm:333) > [Thu Mar 5 18:59:14 2009] [info]: > <[email protected]> #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]: > <[email protected]> sent Bcc: > [email protected], [email protected], [email protected] > (/opt/rt3/bin/../lib/RT/Action/SendEmail.pm:333) > [Thu Mar 5 18:59:14 2009] [info]: Ticket 30082 created in queue > 'Facilities' by [email protected] > (/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 > [email protected] > > > _______________________________________________ > 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 _______________________________________________ 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
