problems with retry logic

FAQ

Memberlist

Usergroups

Profile

Preferences

· nixdoc.net

· man pages

· Linux HOWTOs

· FreeBSD Tips

· Forums

Forum index » Apps » Exim

problems with retry logic

Page 1 of 1 [6 Posts]

View previous topic :: View next topic

Author

Message

Pavel Gulchouck
*nix forums beginner

Joined: 15 Mar 2006
Posts: 7

Posted: Thu May 04, 2006 10:32 pm Post subject: Note

problems with retry logic

Hi,

I have two problems with retries, and I think its are relative.
I did not found any hints in the spec about this.

I have a default retry line:

# Domain Error Retries
# ------ ----- -------
* * F,2h,15m; G,16h,1h,1.5; F,4d,6h

1. When many undelivirable messages to the single email exists in the
queue, exim makes only single delivery attempt each time. Messages
are very old (8 days and older), so each time exim deletes only one
message from the queue, and says "retry time not reached" about
other messages to the same address. IMHO more reasonable behavior
is to delete (or freeze and then delete) all messages to this
destination older then 4 days.
Current queue state:
root@hamster:~>mailq | head -5
6d 1.8K 1FZbYM-000IDB-Hk <>
frenzy2008@gmail.com

6d 1.8K 1FZbrw-000HzZ-Up <>
frenzy2008@gmail.com
root@hamster:~>exim -v -q 1FZbYM-000IDB-Hk 1FZbrw-000HzZ-Up
LOG: queue_run MAIN
Start queue run: pid=47160
delivering 1FZbrw-000HzZ-Up (queue run pid 47160)
LOG: retry_defer MAIN
== frenzy2008@gmail.com routing defer (-51): retry time not reached
delivering 1FZbYM-000IDB-Hk (queue run pid 47160)
LOG: retry_defer MAIN
== frenzy2008@gmail.com routing defer (-51): retry time not reached
LOG: queue_run MAIN
End queue run: pid=47160

2. Sometimes I see following life of the message:

root@hamster:~>grep 1FbcLg-0003Cg-3G /var/log/maillog
May 4 14:50:24 hamster exim[12318]: 1FbcLg-0003Cg-3G <= netmon@f16.pfts.com H=f16.pfts.com [213.133.160.25] P=esmtps X=TLSv1:AES256-SHA:256 S=682 id=L66pOY9UXEX3kVSZ@f16.pfts.com from <netmon@f16.pfts.com> for alarm@itsinternet.net
May 4 14:50:25 hamster exim[12319]: 1FbcLg-0003Cg-3G == its@gul.kiev.ua <alarm@itsinternet.net> R=dnslookup T=remote_smtp defer (-44): SMTP error from remote mail server after RCPT TO:<its@gul.kiev.ua>: host relay2.carrier.kiev.ua [193.193.193.119]: 450 4.7.1 <its@gul.kiev.ua>... No route back to <netmon@f16.pfts.com>, best MX unavailable. (relay2.pfts.com) RCPT TO: 250 Accepted
May 4 15:10:38 hamster exim[13981]: 1FbcLg-0003Cg-3G Completed

No delivery, no bounces, no retries. Sad

But it was successful delivery before it:

May 4 14:49:05 hamster exim[12177]: 1FbcKP-0003AP-7k <= netmon@f16.pfts.com H=f16.pfts.com [213.133.160.25] P=esmtps X=TLSv1:AES256-SHA:256 S=796 id=PY5DVVTlBPaawtFQ@f16.pfts.com from <netmon@f16.pfts.com> for alarm@itsinternet.net
May 4 14:49:06 hamster exim[12191]: 1FbcKP-0003AP-7k => its@gul.kiev.ua <alarm@itsinternet.net> F=<netmon@f16.pfts.com> R=dnslookup T=remote_smtp S=820 H=happy.kiev.ua [193.109.241.145] X=TLSv1:AES256-SHA:256
May 4 14:49:06 hamster exim[12191]: 1FbcKP-0003AP-7k Completed

I'm afraid delivery was not retried because of failing in the
delivery to this address in the past. Is it possible? Or, may be,
it is wrong configuration? What config parameters should I check?

Exim 4.60.

Thanks.

--
Lucky carrier,
Pavel.

--
## List details at http://www.exim.org/mailman/listinfo/exim-users
## Exim details at http://www.exim.org/
## Please use the Wiki with this list - http://www.exim.org/eximwiki/

Philip Hazel
*nix forums Guru

Joined: 27 Jan 2005
Posts: 863

Posted: Fri May 05, 2006 8:48 am Post subject: Note

Re: problems with retry logic

On Fri, 5 May 2006, Pavel Gulchouck wrote:

Quote:

I have a default retry line:

# Domain Error Retries
# ------ ----- -------
* * F,2h,15m; G,16h,1h,1.5; F,4d,6h

1. When many undelivirable messages to the single email exists in the
queue, exim makes only single delivery attempt each time. Messages
are very old (8 days and older), so each time exim deletes only one
message from the queue, and says "retry time not reached" about
other messages to the same address.

That should not happen. What kind of delivery problem? Local? Remote?
Have you tried running a delivery with debugging turned on for one of
these messages?

Quote:

IMHO more reasonable behavior
is to delete (or freeze and then delete) all messages to this
destination older then 4 days.

That is what should happen.

Quote:

root@hamster:~>exim -v -q 1FZbYM-000IDB-Hk 1FZbrw-000HzZ-Up
LOG: queue_run MAIN
Start queue run: pid=47160
delivering 1FZbrw-000HzZ-Up (queue run pid 47160)
LOG: retry_defer MAIN
== frenzy2008@gmail.com routing defer (-51): retry time not reached
delivering 1FZbYM-000IDB-Hk (queue run pid 47160)
LOG: retry_defer MAIN
== frenzy2008@gmail.com routing defer (-51): retry time not reached
LOG: queue_run MAIN
End queue run: pid=47160

When the retry time *is* reached, those messages should be tried, and
then deleted. Sounds like something is going wrong at that point. Debug
output might show what.

Quote:

2. Sometimes I see following life of the message:

root@hamster:~>grep 1FbcLg-0003Cg-3G /var/log/maillog
May 4 14:50:24 hamster exim[12318]: 1FbcLg-0003Cg-3G <= netmon@f16.pfts.com H=f16.pfts.com [213.133.160.25] P=esmtps X=TLSv1:AES256-SHA:256 S=682 id=L66pOY9UXEX3kVSZ@f16.pfts.com from <netmon@f16.pfts.com> for alarm@itsinternet.net
May 4 14:50:25 hamster exim[12319]: 1FbcLg-0003Cg-3G == its@gul.kiev.ua <alarm@itsinternet.net> R=dnslookup T=remote_smtp defer (-44): SMTP error from remote mail server after RCPT TO:<its@gul.kiev.ua>: host relay2.carrier.kiev.ua [193.193.193.119]: 450 4.7.1 <its@gul.kiev.ua>... No route back to <netmon@f16.pfts.com>, best MX unavailable. (relay2.pfts.com) RCPT TO: 250 Accepted
May 4 15:10:38 hamster exim[13981]: 1FbcLg-0003Cg-3G Completed

No delivery, no bounces, no retries. Sad

That looks most weird. But I note there was a 20-minute delay, which is
also odd.

--
Philip Hazel University of Cambridge Computing Service
Get the Exim 4 book: http://www.uit.co.uk/exim-book

--
## List details at http://www.exim.org/mailman/listinfo/exim-users
## Exim details at http://www.exim.org/
## Please use the Wiki with this list - http://www.exim.org/eximwiki/

Pavel Gulchouck
*nix forums beginner

Joined: 15 Mar 2006
Posts: 7

Posted: Fri May 05, 2006 12:09 pm Post subject: Note

Re: problems with retry logic

On Fri, May 05, 2006 at 09:48:08AM +0100, Philip Hazel writes:
PH> On Fri, 5 May 2006, Pavel Gulchouck wrote:

Quote:

PH> That should not happen. What kind of delivery problem? Local? Remote?

Remote. Here's an example of delivering another messages to this address
(and I think this attempt shifts next try time for the old message to
the future in the retry database):

May 5 08:46:25 hamster exim[68595]: 1Fa3F5-000L9R-6U == frenzy2008@gmail.com R=dnslookup T=remote_smtp defer (-44): SMTP error from remote mail server after RCPT TO:<frenzy2008@gmail.com>: host gsmtp183.google.com [64.233.183.27]: 450-4.2.1 The Gmail user you are trying to contact is receiving\n450-4.2.1 mail at a rate that prevents additional messages from\n450-4.2.1 being delivered. Please resend your message at a later\n450-4.2.1 time; if the user is able to receive mail at that time,\n450 4.2.1 your message will be delivered. c28si5047491nfb
May 5 08:46:25 hamster exim[68595]: 1Fa3F5-000L9R-6U ** frenzy2008@gmail.com: retry timeout exceeded
May 5 08:46:25 hamster exim[68595]: 1Fa3F5-000L9R-6U frenzy2008@gmail.com: error ignored
May 5 08:46:25 hamster exim[68595]: 1Fa3F5-000L9R-6U Completed

PH> Have you tried running a delivery with debugging turned on for one of
PH> these messages?

root@hamster:~>exim -d+retry -v -q 1FZbYM-000IDB-Hk 1FZbYM-000IDB-Hk
Exim version 4.60 (FreeBSD 5.4) uid=0 gid=0 pid=4531 D=fbb95cfd
Probably Berkeley DB version 1.8x (native mode)
Support for: crypteq iconv() PAM OpenSSL Content_Scanning Old_Demime
Lookups: lsearch wildlsearch nwildlsearch iplsearch cdb dbm dbmnz
dnsdb dsearch nis nis0 passwd
Authenticators: cram_md5 plaintext spa
Routers: accept dnslookup ipliteral manualroute queryprogram redirect
Transports: appendfile autoreply lmtp pipe smtp
Fixed never_users: 0
changed uid/gid: forcing real = effective
uid=0 gid=0 pid=4531
auxiliary group list: 0
configuration file is /usr/local/etc/exim/configure
log selectors = 00000dfc 00044c09
cwd=/home/gul 6 args: exim -d+retry -v -q 1FZbYM-000IDB-Hk
1FZbYM-000IDB-Hk
trusted user
admin user
skipping ACL configuration - not needed
finduser used cached passwd data for mailnull
finduser used cached passwd data for mailnull
finduser used cached passwd data for mailnull
finduser used cached passwd data for mailnull
Single queue run starting at 1FZbYM-000IDB-Hk stopping at
1FZbYM-000IDB-Hk
set_process_info: 4531 running the queue (single queue run)
LOG: queue_run MAIN
Start queue run: pid=4531
queue running main directory
search_tidyup called
set_process_info: 4531 running queue: 1FZbYM-000IDB-Hk-H
set_process_info: 4531 running queue: waiting for 1FZbYM-000IDB-Hk
(4532)
set_process_info: 4532 delivering 1FZbYM-000IDB-Hk (queue run pid
4531)
reading spool file 1FZbYM-000IDB-Hk-H
user=mailnull uid=26 gid=26 sender=
sender_local=0 ident=mailnull
Non-recipients:
Empty Tree
---- End of tree ----
recipients_count=1
body_linecount=40 message_linecount=10
running system filter
rda_interpret (file): /usr/local/etc/exim/system_filter.exim
expanded: /usr/local/etc/exim/system_filter.exim
1202 bytes read from /usr/local/etc/exim/system_filter.exim
data is an Exim filter program
Filter: start of processing
Filter: end of processing
system filter returned 1
Delivery address list:
frenzy2008@gmail.com
locking /var/spool/exim/db/retry.lockfile
locked /var/spool/exim/db/retry.lockfile
EXIM_DBOPEN(/var/spool/exim/db/retry)
returned from EXIM_DBOPEN
opened hints database /var/spool/exim/db/retry: flags=0

Quote:

Considering: frenzy2008@gmail.com

unique = frenzy2008@gmail.com
dbfn_read: key=R:gmail.com
dbfn_read: key=R:frenzy2008@gmail.com
no domain retry record
post-process frenzy2008@gmail.com (1)
LOG: retry_defer MAIN
== frenzy2008@gmail.com routing defer (-51): retry time not reached

Quote:

After routing:

Local deliveries:
Remote deliveries:
Failed addresses:
Deferred addresses:
frenzy2008@gmail.com
search_tidyup called

Quote:

deliveries are done
changed uid/gid: post-delivery tidying

uid=26 gid=26 pid=4532
auxiliary group list: 26
set_process_info: 4532 tidying up after delivering 1FZbYM-000IDB-Hk
Processing retry items
Succeeded addresses:
Failed addresses:
Deferred addresses:
frenzy2008@gmail.com: no retry items
end of retry processing
delivery deferred: update_spool=0 header_rewritten=0
end delivery of 1FZbYM-000IDB-Hk
search_tidyup called
set_process_info: 4531 running queue: waiting for children of 4532
set_process_info: 4531 running queue
LOG: queue_run MAIN
End queue run: pid=4531
search_tidyup called

Quote:

Exim pid=4531 terminating with rc=0

IMHO more reasonable behavior
is to delete (or freeze and then delete) all messages to this
destination older then 4 days.

PH> That is what should happen.

I do not understand logic...
Exim should inspect all queue for old messages to the same destination
after each delivery attempt of any other message?

Quote:

PH> When the retry time *is* reached, those messages should be tried, and
PH> then deleted.

AFAIU retry time is relative to the destination, not to the message.
Retry time for this message shold be reached several times last
2 days, but the message is still in the queue without any tryes,
because when retry time for frenzy2008@gmail.com was reached another
message to this destination was tryed (example is above).
But I can misunderstand retry logic.

PH> Sounds like something is going wrong at that point. Debug
PH> output might show what.

Quote:

PH> That looks most weird. But I note there was a 20-minute delay, which is
PH> also odd.

I assume that after 20-minutes delay queue runner was started and it
decides that this message is too old and removes it, its decision was
based on retry database (relative to the destination email or to the
relay used in this attempt). But I'm not sure of this. It's hard to
reproduce with debug, such behavior is rare in my system.

--
Lucky carrier,
Pavel.

--
## List details at http://www.exim.org/mailman/listinfo/exim-users
## Exim details at http://www.exim.org/
## Please use the Wiki with this list - http://www.exim.org/eximwiki/

Philip Hazel
*nix forums Guru

Joined: 27 Jan 2005
Posts: 863

Posted: Fri May 05, 2006 1:08 pm Post subject: Note

Re: problems with retry logic

On Fri, 5 May 2006, Pavel Gulchouck wrote:

Quote:

root@hamster:~>exim -d+retry -v -q 1FZbYM-000IDB-Hk 1FZbYM-000IDB-Hk

Please try

exim -d+retry -M 1FZbYM-000IDB-Hk

so that it does actually try a delivery (that's what I intended) - but
first see below.

Quote:

Considering: frenzy2008@gmail.com
unique = frenzy2008@gmail.com
dbfn_read: key=R:gmail.com
dbfn_read: key=R:frenzy2008@gmail.com
no domain retry record
post-process frenzy2008@gmail.com (1)
LOG: retry_defer MAIN
== frenzy2008@gmail.com routing defer (-51): retry time not reached

You can find out what it thinks the retry time is by using the exinext
utility. This is a routing retry that will apply just to one address.

You are running 4.60, I seem to recall. This change was made for 4.61:

PH/19 When calculating a retry time, Exim used to measure the "time since
failure" by looking at the "first failed" field in the retry record. Now
it does not use this if it is later than than the arrival time of the
message. Instead it uses the arrival time. This makes for better
behaviour in cases where some deliveries succeed, thus re-setting the
"first failed" field. An example is a quota failure for a huge message
when small messages continue to be delivered. Without this change, the
"time since failure" will always be short, possible causing more frequent
delivery attempts for the huge message than are intended.
[Note: This change was subsequently modified - see PH/04 for 4.62.]

Subsequently modified for 4.62:

PH/04 Change PH/19 for 4.61 was too wide. It should not be applied to host
errors. Otherwise a message that provokes a temporary error (when other
messages do not) can cause a whole host to time out.

I am not sure if this will affect routing retries, but I think it might.
So perhaps you should start by upgrading to 4.62.

Quote:

I do not understand logic...

One of the problems is that *I* no longer fully understand all of it. It
probably needs somebody to draw out a flowchart or something to try to
see what is going on.

Quote:

Exim should inspect all queue for old messages to the same destination
after each delivery attempt of any other message?

Exim always inspects all messages, but if one message has a temporary
error, the remaining messages will see "retry time not reached". BUT, if
they have been on the queue sufficiently long, they should be bounced.

Quote:

AFAIU retry time is relative to the destination, not to the message.

Your error is a recipient error, so it's also relative to the recipient.

Quote:

I assume that after 20-minutes delay queue runner was started and it
decides that this message is too old and removes it, its decision was
based on retry database (relative to the destination email or to the
relay used in this attempt). But I'm not sure of this. It's hard to
reproduce with debug, such behavior is rare in my system.

Exim should never remove a message without logging *something*.

--
Philip Hazel University of Cambridge Computing Service
Get the Exim 4 book: http://www.uit.co.uk/exim-book

--
## List details at http://www.exim.org/mailman/listinfo/exim-users
## Exim details at http://www.exim.org/
## Please use the Wiki with this list - http://www.exim.org/eximwiki/

Pavel Gulchouck
*nix forums beginner

Joined: 15 Mar 2006
Posts: 7

Posted: Fri May 05, 2006 1:35 pm Post subject: Note

Re: problems with retry logic

On Fri, May 05, 2006 at 02:08:35PM +0100, Philip Hazel writes:

Quote:

root@hamster:~>exim -d+retry -v -q 1FZbYM-000IDB-Hk 1FZbYM-000IDB-Hk

PH> Please try

PH> exim -d+retry -M 1FZbYM-000IDB-Hk

PH> so that it does actually try a delivery (that's what I intended) - but
PH> first see below.

Quote:

PH> You can find out what it thinks the retry time is by using the exinext
PH> utility. This is a routing retry that will apply just to one address.

When I ran "exim -d+retry -M 1FZbYM-000IDB-Hk", the delivery attempt
was failed with temporary error and message was successfully removed
from the queue as too old. Debug output is ~34K, I'm not sure to include
it here. Here's a log:

May 5 16:13:47 hamster exim[13761]: 1FZbYM-000IDB-Hk == frenzy2008@gmail.com R=dnslookup T=remote_smtp defer (-44): SMTP error from remote mail server after RCPT TO:<frenzy2008@gmail.com>: host gsmtp163.google.com [64.233.163.27]: 450-4.2.1 The Gmail user you are trying to contact is receiving\n450-4.2.1 mail at a rate that prevents additional messages from\n450-4.2.1 being delivered. Please resend your message at a later\n450-4.2.1 time; if the user is able to receive mail at that time,\n450 4.2.1 your message will be delivered. 34si2162847nza
May 5 16:13:47 hamster exim[13761]: 1FZbYM-000IDB-Hk ** frenzy2008@gmail.com: retry timeout exceeded
May 5 16:13:47 hamster exim[13761]: 1FZbYM-000IDB-Hk frenzy2008@gmail.com: error ignored
May 5 16:13:47 hamster exim[13761]: 1FZbYM-000IDB-Hk Completed

But after this the next message to this recipient is still in the queue
with increased next try time:

root@hamster:~>mailq | head -3
7d 1.8K 1FZbrw-000HzZ-Up <>
frenzy2008@gmail.com
root@hamster:~>exinext frenzy2008@gmail.com
Route: frenzy2008@gmail.com error -44: SMTP error from remote mail server after RCPT TO:<frenzy2008@gmail.com>: host gsmtp163.google.com [64.233.163.27]: 450-4.2.1 The Gmail user you are tr
first failed: 29-Apr-2006 01:35:16
last tried: 05-May-2006 16:13:47
next try at: 05-May-2006 22:13:47
past final cutoff time

PH> You are running 4.60, I seem to recall.
[...]
PH> I am not sure if this will affect routing retries, but I think it might.
PH> So perhaps you should start by upgrading to 4.62.

Ok, thanks, I will try it.

Quote:

I do not understand logic...

PH> One of the problems is that *I* no longer fully understand all of it.
PH> It probably needs somebody to draw out a flowchart or something to try
PH> to see what is going on.

Quote:

Exim should inspect all queue for old messages to the same destination
after each delivery attempt of any other message?

PH> Exim always inspects all messages, but if one message has a temporary
PH> error, the remaining messages will see "retry time not reached". BUT, if
PH> they have been on the queue sufficiently long, they should be bounced.

If the problem is still in 4.62, I'll tell you.

Thanks.

--
Lucky carrier,
Pavel.

--
## List details at http://www.exim.org/mailman/listinfo/exim-users
## Exim details at http://www.exim.org/
## Please use the Wiki with this list - http://www.exim.org/eximwiki/

Pavel Gulchouck
*nix forums beginner

Joined: 15 Mar 2006
Posts: 7

Posted: Fri May 05, 2006 2:02 pm Post subject: Re: problems with retry logic

On Fri, May 05, 2006 at 04:35:40PM +0300, Pavel Gulchouck writes: PH>> Exim always inspects all messages, but if one message has a temporary PH>> error, the remaining messages will see "retry time not reached". BUT, if PH>> they have been on the queue sufficiently long, they should be bounced. PG> If the problem is still in 4.62, I'll tell you. Situation did not change on 4.62. :-( I have a message in the queue: root@hamster:~>mailq \| head -3 7d 1.8K 1FZbrw-000HzZ-Up <> frenzy2008@gmail.com root@hamster:~>exinext frenzy2008@gmail.com Route: frenzy2008@gmail.com error -44: SMTP error from remote mail server after RCPT TO:<frenzy2008@gmail.com>: host gsmtp163.google.com [64.233.163.27]: 450-4.2.1 The Gmail user you are tr first failed: 29-Apr-2006 01:35:16 last tried: 05-May-2006 16:13:47 next try at: 05-May-2006 22:13:47 past final cutoff time Then I sent another message to this recipient using command "exim -d+retry -M 1FaiWp-000Msh-04" (got temporary error, output is saved). After this message 1FZbrw-000HzZ-Up is still in the queue and next try time was increased: root@hamster:~>exinext frenzy2008@gmail.com Route: frenzy2008@gmail.com error -44: SMTP error from remote mail server after RCPT TO:<frenzy2008@gmail.com>: host gsmtp183.google.com [64.233.183.27]: 450-4.2.1 The Gmail user you are tr first failed: 29-Apr-2006 01:35:16 last tried: 05-May-2006 16:49:04 next try at: 05-May-2006 22:49:04 past final cutoff time The result is having many messages older then 4 days in the queue, which can be removed only when next delivery trying to this recipient will be with this messages, but not with any other. One try every 6 hours, so, one removed old message to this recipient every 6 hours in the best case. :-( -- Lucky carrier, Pavel. -- ## List details at http://www.exim.org/mailman/listinfo/exim-users ## Exim details at http://www.exim.org/ ## Please use the Wiki with this list - http://www.exim.org/eximwiki/

Google

Display posts from previous:

Page 1 of 1 [6 Posts]

View previous topic :: View next topic

The time now is Sat Jan 10, 2009 4:27 am | All times are GMT

Forum index » Apps » Exim

Jump to:

Topic		Author	Forum	Replies	Last Post
Similar Topics
	Winbind problems for ADS authentication	nlinley	networking	1	Tue Sep 19, 2006 9:22 am
	problems using oddmuse with mod_perl2 inside apache2.2 pe...	Fergus McMenemie	Perl	0	Fri Jul 21, 2006 9:48 am
	Problems with make-kpkg and skas patch	Todd A. Jacobs	Debian	0	Fri Jul 21, 2006 12:30 am
	Problems with relay control	Félix Martos Trenado	Postfix	3	Thu Jul 20, 2006 3:33 pm
	again a newbie... :( compiler problems	Thorsten Kaben	C++	18	Thu Jul 20, 2006 2:52 am

Buy Anything On eBay | Loans | Loans | Bankruptcy | Loans and Credit Cards

Other DeniX Solutions sites: Unix/Linux blog | electronics forum | medicine forum | science forum |

[ Time: 0.2395s ][ Queries: 16 (0.0852s) ][ GZIP on - Debug on ]