Mail fetching is sometimes delayed

[robcar]

Hello,
OTRS 5.0.3 here.
I scheduled mail fetching under:

Daemon::SchedulerCronTaskManager::Task###MailAccountFetch

and I set it to:

*/5 * * * *

In this way most of the mails are fetched correctly every 5 minutes, but not all. In some cases (which can occur roughly once every 10 mail/tickets) I got delays of more than 10 minutes, like 11 or 18 minutes.

What can be the cause of this delays?

thanks
--
rob

[robcar]

Another case this morning.

In the OTRS mailbox arrive 2 mails:

10.41 Nagios recovery notification
10.58 Mail request from user1


But OTRS stays quiet until 11.10. The Nagios recovery notification should have closed the previous ticket and user1 should have received the mail before (Nagios notifications don't generate replies; I've filtered them by using X-OTRS-Loop).

Code: Select all

# tail /var/log/syslog

Jun  8 10:25:06 otrshost postfix/qmgr[2140]: 21B2E80064: removed
Jun  8 10:30:01 otrshost CRON[22699]: (otrs) CMD ($HOME/bin/otrs.Daemon.pl start >> /dev/null)
Jun  8 10:35:01 otrshost CRON[22739]: (otrs) CMD ($HOME/bin/otrs.Daemon.pl start >> /dev/null)
Jun  8 10:39:01 otrshost CRON[22777]: (root) CMD (  [ -x /usr/lib/php5/maxlifetime ] && [ -x /usr/lib/php5/sessionclean ] && [ -d /var/lib/php5 ] && /usr/lib/php5/sessionclean /var/lib/php5 $(/usr/lib/php5/maxlifetime))
Jun  8 10:55:01 otrshost CRON[22906]: (otrs) CMD ($HOME/bin/otrs.Daemon.pl start >> /dev/null)
Jun  8 11:09:01 otrshost CRON[23018]: (root) CMD (  [ -x /usr/lib/php5/maxlifetime ] && [ -x /usr/lib/php5/sessionclean ] && [ -d /var/lib/php5 ] && /usr/lib/php5/sessionclean /var/lib/php5 $(/usr/lib/php5/maxlifetime))
Jun  8 11:10:07 otrshost postfix/pickup[22668]: 9807A80064: uid=1001 from=<>
Jun  8 11:10:07 otrshost postfix/cleanup[23039]: 9807A80064: message-id=<1465377007.21585.2371177825.1867.1@otrshost.example.com>
Jun  8 11:10:07 otrshost postfix/qmgr[2140]: 9807A80064: from=<>, size=3589, nrcpt=1 (queue active)
Jun  8 11:10:07 otrshost postfix/smtp[23041]: 9807A80064: to=<user1@example.com>, relay=ex01faiv.example.com[10.10.10.130]:25, delay=0.17, delays=0.01/0.01/0.01/0.13, dsn=2.6.0, status=sent (250 2.6.0 <1465377007.21585.2371177825.1867.1@otrshost.example.com> [InternalId=14336600834297, Hostname=EX02FAIV.example.com] Queued mail for delivery)
Jun  8 11:10:07 otrshost postfix/qmgr[2140]: 9807A80064: removed
Jun  8 11:15:01 otrshost CRON[23076]: (otrs) CMD ($HOME/bin/otrs.Daemon.pl start >> /dev/null)
Jun  8 11:17:01 otrshost CRON[23083]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Jun  8 11:20:01 otrshost CRON[23117]: (otrs) CMD ($HOME/bin/otrs.Daemon.pl start >> /dev/null)

[robcar]

Another case; mail from the user at 14.31 (I checked in the otrs mailbox and it was there at that time) and then:

Code: Select all

Jun  8 14:30:01 otrshost CRON[24704]: (otrs) CMD ($HOME/bin/otrs.Daemon.pl start >> /dev/null)
Jun  8 14:35:01 otrshost CRON[24742]: (otrs) CMD ($HOME/bin/otrs.Daemon.pl start >> /dev/null)
Jun  8 14:39:01 otrshost CRON[24781]: (root) CMD (  [ -x /usr/lib/php5/maxlifetime ] && [ -x /usr/lib/php5/sessionclean ] && [ -d /var/lib/php5 ] && /usr/lib/php5/sessionclean /var/lib/php5 $(/usr/lib/php5/maxlifetime))
Jun  8 14:40:01 otrshost CRON[24794]: (otrs) CMD ($HOME/bin/otrs.Daemon.pl start >> /dev/null)
May 28 20:35:01 otrshost CRON[24832]: (otrs) CMD ($HOME/bin/otrs.Daemon.pl start >> /dev/null)
Jun  8 14:45:01 otrshost CRON[24833]: (otrs) CMD ($HOME/bin/otrs.Daemon.pl start >> /dev/null)
Jun  8 14:45:14 otrshost postfix/pickup[24308]: BA35E80064: uid=1001 from=<>
Jun  8 14:45:14 otrshost postfix/cleanup[24841]: BA35E80064: message-id=<1465389914.554714.021717102.1872.1@otrshost.example.com>
Jun  8 14:45:14 otrshost postfix/qmgr[2140]: BA35E80064: from=<>, size=3508, nrcpt=1 (queue active)
Jun  8 14:45:14 otrshost postfix/smtp[24843]: BA35E80064: to=<user2@example.com>, relay=ex01faiv.example.com[10.10.10.130]:25, delay=0.14, delays=0.01/0.01/0/0.12, dsn=2.6.0, status=sent (250 2.6.0 <1465389914.554714.021717102.1872.1@otrshost.example.com> [InternalId=14349485736968, Hostname=EX02FAIV.example.com] Queued mail for delivery)
Jun  8 14:45:14 otrshost postfix/qmgr[2140]: BA35E80064: removed

Why did it realize only at 14:45 that there was a mail to pickup?

[robcar]

The problem is still present.
I see $HOME/bin/otrs.Daemon.pl starting at every 5 minutes, but sometimes mails are not fetched.
In those cases I can see that they are present in the mailbox and I can manually fetch them by going to Mail Account Management.

What can be the cause of the deferrals of mails automatically fetched?

[robcar]

I can see that:

Daemon::SchedulerCronTaskManager::Task###FetchMail
Daemon::SchedulerCronTaskManager::Task###FetchMailSSL

are not enabled, while the following is enabled:

Daemon::SchedulerCronTaskManager::Task###MailAccountFetch

[schulmann]

What can be the cause of the deferrals of mails automatically fetched?

There are several possibilities:

• Network problems
• DNS problems
• Overloaded Mailserver (i. e. all possible connections are used)
• Overloaded OTRS server (i. e. process table full)
• ...

I'd try to analyze the network traffic with tcpdump or wireshark.