Exim seems to ignore retry configuration shows "retry time not reached for any host" every 15 minutes
According to Exim configuration (WHM > Service Configuration > Exim Configuration Manager) on my VPS, the outgoing mail rules are:
it means: retries every 15 minutes for 2 hours, then increasing retry intervals, starting at 1 hour and increasing each time by a factor of 1.5, up to 16 hours, then retries every 8 hours until 4 days have passed since the first failed delivery Hence I would expect the retry intervel to be 15 minutes for the first 2 hours, then the retry interval should be at least 1 hour, but when I look at the log of a message that was sent to a not existing/working email address, it seems it goes on retrying very 15 minutes forever. See Exim log below, where sending mail to joe.blow@somedomain.com fails, the message is sent at 14:55 for the 1st time, but after 2 hours, Exim is still retyring every 15 minutes at 18:01, 18:14, 18:29 instead of retrying with an interval of 1 hour. o_O
+secondarymx * F,4h,5m; G,16h,1h,1.5; F,4d,8h
* * F,2h,15m; G,16h,1h,1.5; F,4d,8hit means: retries every 15 minutes for 2 hours, then increasing retry intervals, starting at 1 hour and increasing each time by a factor of 1.5, up to 16 hours, then retries every 8 hours until 4 days have passed since the first failed delivery Hence I would expect the retry intervel to be 15 minutes for the first 2 hours, then the retry interval should be at least 1 hour, but when I look at the log of a message that was sent to a not existing/working email address, it seems it goes on retrying very 15 minutes forever. See Exim log below, where sending mail to joe.blow@somedomain.com fails, the message is sent at 14:55 for the 1st time, but after 2 hours, Exim is still retyring every 15 minutes at 18:01, 18:14, 18:29 instead of retrying with an interval of 1 hour. o_O
root@myhost [~]# exigrep "1iuGTy-00026o-A7" /var/log/exim_mainlog
2020-01-22 14:55:46 cwd=/var/spool/exim 3 args: /usr/sbin/exim -Mc 1iuGTy-00026o-A7
+++ 1iuGTy-00026o-A7 has not completed +++
2020-01-22 14:55:46 1iuGTy-00026o-A7 <= info@mydomain.it U=me P=local S=1487 id=932b8078cbd5e576dee8f3f24e97237f@clienti.mydomain.it T="confermato" for mailbox1@virgilio.it joe.blow@somedomain.com mailbox2@gmail.com mailbox3@mydomain.it
2020-01-22 14:55:46 1iuGTy-00026o-A7 Sender identification U=me D=mydomain.it S=info@mydomain.it
2020-01-22 14:55:46 1iuGTy-00026o-A7 SMTP connection outbound 1579701346 1iuGTy-00026o-A7 mydomain.it mailbox3@mydomain.it
2020-01-22 14:55:46 1iuGTy-00026o-A7 Sender identification U=me D=mydomain.it S=info@mydomain.it
2020-01-22 14:55:46 1iuGTy-00026o-A7 SMTP connection outbound 1579701346 1iuGTy-00026o-A7 mydomain.it mailbox2@gmail.com
2020-01-22 14:55:46 1iuGTy-00026o-A7 Sender identification U=me D=mydomain.it S=info@mydomain.it
2020-01-22 14:55:46 1iuGTy-00026o-A7 SMTP connection outbound 1579701346 1iuGTy-00026o-A7 mydomain.it joe.blow@somedomain.com
2020-01-22 14:55:46 1iuGTy-00026o-A7 Sender identification U=me D=mydomain.it S=info@mydomain.it
2020-01-22 14:55:46 1iuGTy-00026o-A7 SMTP connection outbound 1579701346 1iuGTy-00026o-A7 mydomain.it mailbox1@virgilio.it
2020-01-22 14:55:46 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'
2020-01-22 14:55:46 1iuGTy-00026o-A7 [213.209.1.130] SSL verify error: certificate name mismatch: DN="/C=IT/ST=Milano/L=Assago/OU=Information Technology/O=Italiaonline S.p.A./CN=*.libero.it" H="smtp-in.virgilio.it"
2020-01-22 14:55:47 1iuGTy-00026o-A7 => mailbox2@gmail.com R=dkim_lookuphost T=dkim_remote_smtp H=gmail-smtp-in.l.google.com [74.125.143.26] X=TLSv1.2:ECDHE-RSA-AES128-GCM-SHA256:128 CV=yes C="250 2.0.0 OK 1579701347 ch4si24988759ejb.125 - gsmtp"
2020-01-22 14:55:47 1iuGTy-00026o-A7 => mailbox1@virgilio.it R=dkim_lookuphost T=dkim_remote_smtp H=smtp-in.virgilio.it [213.209.1.130] X=TLSv1.2:ECDHE-RSA-AES256-GCM-SHA384:256 CV=no C="250 uGTyiu7OrahRKuGTzi6igF mail accepted for delivery"
2020-01-22 14:56:06 1iuGTy-00026o-A7 [78.47.57.127] SSL verify error: certificate name mismatch: DN="/OU=Domain Control Validated/OU=PositiveSSL/CN=myhost" H="mail.mydomain.it"
2020-01-22 14:56:28 1iuGTy-00026o-A7 => mailbox3@mydomain.it R=dkim_lookuphost T=dkim_remote_smtp H=mail.mydomain.it [1.2.3.4] X=TLSv1.2:ECDHE-RSA-AES256-GCM-SHA384:256 CV=no C="250 OK id=1iuGUd-0004D1-9t"
2020-01-22 14:59:11 1iuGTy-00026o-A7 Sender identification U=me D=mydomain.it S=info@mydomain.it
2020-01-22 14:59:11 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'
2020-01-22 15:14:11 1iuGTy-00026o-A7 Sender identification U=me D=mydomain.it S=info@mydomain.it
2020-01-22 15:14:11 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'
2020-01-22 15:29:11 1iuGTy-00026o-A7 Sender identification U=me D=mydomain.it S=info@mydomain.it
2020-01-22 15:29:11 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'
2020-01-22 15:44:11 1iuGTy-00026o-A7 Sender identification U=me D=mydomain.it S=info@mydomain.it
2020-01-22 15:44:11 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'
2020-01-22 15:59:11 1iuGTy-00026o-A7 Sender identification U=me D=mydomain.it S=info@mydomain.it
2020-01-22 15:59:11 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'
2020-01-22 16:14:11 1iuGTy-00026o-A7 Sender identification U=me D=mydomain.it S=info@mydomain.it
2020-01-22 16:14:11 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'
2020-01-22 16:29:11 1iuGTy-00026o-A7 Sender identification U=me D=mydomain.it S=info@mydomain.it
2020-01-22 16:29:11 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'
2020-01-22 16:44:11 1iuGTy-00026o-A7 Sender identification U=me D=mydomain.it S=info@mydomain.it
2020-01-22 16:44:11 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'
2020-01-22 16:59:11 1iuGTy-00026o-A7 Sender identification U=me D=mydomain.it S=info@mydomain.it
2020-01-22 16:59:11 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'
2020-01-22 17:14:12 1iuGTy-00026o-A7 Sender identification U=me D=mydomain.it S=info@mydomain.it
2020-01-22 17:14:12 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'
2020-01-22 17:29:11 1iuGTy-00026o-A7 Sender identification U=me D=mydomain.it S=info@mydomain.it
2020-01-22 17:29:11 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'
2020-01-22 17:44:11 1iuGTy-00026o-A7 Sender identification U=me D=mydomain.it S=info@mydomain.it
2020-01-22 17:44:11 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'
2020-01-22 17:59:11 1iuGTy-00026o-A7 Sender identification U=me D=mydomain.it S=info@mydomain.it
2020-01-22 18:01:18 1iuGTy-00026o-A7 H=HDRedirect-LB5-1afb6e2973825a56.elb.us-east-1.amazonaws.com [23.20.239.12] Connection timed out
2020-01-22 18:01:18 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (110): Connection timed out
2020-01-22 18:14:11 1iuGTy-00026o-A7 Sender identification U=me D=mydomain.it S=info@mydomain.it
2020-01-22 18:14:11 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'
2020-01-22 18:29:11 1iuGTy-00026o-A7 Sender identification U=me D=mydomain.it S=info@mydomain.it
2020-01-22 18:29:11 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'
(END)-
Hello, Based on the exim retry rules in their documentation this appears to be functioning normally:
We really only want to look at the final rule:* * F,2h,15m; G,16h,1h,1.5; F,5d,8h
This indicates that the rule will try:- every 15 minutes for 2 hours
- then with intervals starting at one hour and increasing by a factor of 1.5 up to 16 hours
- then every 8 hours up to 5 days.
- 1st Retry:
2020-01-22 15:14:11 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'
- Last Retry for first rule (2h:15m):
2020-01-22 17:14:12 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'- 1st retry of second rule:
-
2020-01-22 18:14:11 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'
- Logged Retry:
2020-01-22 18:29:11 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'
- 15:14:11 through 17:14:12 - are F,2h,15m
- 18:14:11 is G,16,1h,1.5
- Specifically 1h
- This takes place one hour after the last retry was attempted at the same time the initial sending of the 1st retry was attempted on the F,2h,15m which finalized at 17:14:12
- 18:29:11 is G,16,1h,1.5
- Specifically 1.5
- This is where this gets a bit complicated - the 1.5h retry took place at 1.5 hours after the first message delivery attempt (14:59:11) following the final retry of the first rule (this rule isn't used until the 1st set have been exceeded)
Another good note is they do have a retry db at/var/spool/exim/db/
[QUOTE]The data in the retry hints database can be inspected by using the exim_dumpdb or exim_fixdb utility programs (see chapter 54. Exim utilities Basically the following should get you some information on the retry hints and what exim is translating the rules as:exim_dumpdb /var/spool/exim retry0 -
Hello, Based on the exim retry rules in their documentation this appears to be functioning normally: [...] Initial send time: 2020-01-22 14:55:46 - 2020-01-22 14:59:11
- 1st Retry:
2020-01-22 15:14:11 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'
- Last Retry for first rule (2h:15m):
2020-01-22 17:14:12 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'- 1st retry of second rule:
-
2020-01-22 18:14:11 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'
- Logged Retry:
2020-01-22 18:29:11 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com'
Thanks but what about the retries made at 17:29 and 17:44? :confused: If the last retry of first rule is at 17:14 and the 1st retry of second rule is at 18:14 why does he makes two more retries at 17:29 and 17:44?2020-01-22 17:29:11 1iuGTy-00026o-A7 Sender identification U=me D=mydomain.it S=info@mydomain.it 2020-01-22 17:29:11 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com' 2020-01-22 17:44:11 1iuGTy-00026o-A7 Sender identification U=me D=mydomain.it S=info@mydomain.it 2020-01-22 17:44:11 1iuGTy-00026o-A7 == joe.blow@somedomain.com R=dkim_lookuphost T=dkim_remote_smtp defer (-53): retry time not reached for any host for 'somedomain.com' 2020-01-22 17:59:11 ...0 - 1st Retry:
-
Hello, I'd be curious to see what the outcome of the rest of the information I requested is. 0
Please sign in to leave a comment.
Comments
3 comments