Sticky MX for queued messages. Bug??
alf
Consider this:
# dig +short atom.it MX
10 mxe1.idc.extra.it.
10 mxe2.idc.extra.it.
20 mx1.idc.extra.it.
the hoghest priority MXs (mxe2, mxe1) are on machine that both time
out - dunno why, it may be a new cockamamie antispam scheme. The third
MX (mx1) is responsive and accepting messages.
The problem:
messages sent to atom.it are permanently associated to one of the two
highest priority MXs and get stuck in the queue - forever (a log for
sendmail -q -v -d is appended). The messages are stuck on a 440
connection timed out condition. The third MX is never considered. This
is in violation of the following segment of the docs (sendmail.org):
"....If sendmail is allowed to look up MX records, it calls the
res_search(3) BIND library routine [9] to find all the MX records for
the host. If it finds any MX records, it sorts them in order of cost,
selecting the least cost first. If V8 sendmail finds two costs that
are the same, it randomizes the selection between the two when
sorting. [10] After all MX records are found,....the sendmail program
then tries to deliver the message to each host in the list of MX
hosts, one at a time, until one of them succeeds or until they all
fail. Beginning with V8.8 sendmail, any host in the list that returns
a 5xy SMTP code (permanent failure) causes all subsequent MX hosts to
be ignored (but temporary and connect failures continue to the next MX
host as usual).
Suggestions? Ideas? Advanced thanks.
Cheers,
alf
output of sendmail -d -qIo4QACJJp015146 -v
----
[root@rigel ~]# sendmail -d -qIo4QACJJp015146 -v
Version 8.13.8
Compiled with: DNSMAP HESIOD HES_GETMAILHOST LDAPMAP LOG MAP_REGEX
MATCHGECOS MILTER MIME7TO8 MIME8TO7 NAMED_BIND NETINET
NETINET6
NETUNIX NEWDB NIS PIPELINING SASLv2 SCANF SOCKETMAP
STARTTLS
TCPWRAPPERS USERDB USE_LDAP_INIT
getla(): 0.01
setoption Verbose (v)=T
setoption SevenBitInput (7)=False
setoption AliasWait (a)=10
setoption AliasFile (A)=/etc/aliases
setoption MinFreeBlocks (b)=100
setoption MaxMessageSize (0x8a)=25000000
setoption BlankSub (B)=.
setoption HoldExpensive (c)=False
setoption DeliveryMode (d)=background
setoption TempFileMode (F)=0600
setoption HelpFile (H)=/etc/mail/helpfile
setoption SendMimeErrors (j)=True
setoption ForwardPath (J)=$z/.forward.$w:$z/.forward
setoption ConnectionCacheSize (k)=2
setoption ConnectionCacheTimeout (K)=5m
setoption UseErrorsTo (l)=False
setoption LogLevel (L)=9
setoption CheckAliases (n)=False
setoption OldStyleHeaders (o)=True
setoption DaemonPortOptions (O)=Port=smtp, Name=MTA
Daemon MTA flags:
setoption DaemonPortOptions (O)=Port=smtps, Name=TLSMTA, M=s
Daemon TLSMTA flags: <SMTPS>
setoption PrivacyOptions (p)=authwarnings,restrictqrun,nobodyreturn
setoption QueueSortOrder (0x81)=host
setoption QueueDirectory (Q)=/var/spool/mqueue
setoption Timeout (r).initial=2m
setoption Timeout (r).connect=1m
setoption Timeout (r).aconnect=2m
setoption Timeout (r).iconnect=30s
setoption Timeout (r).helo=2m
setoption Timeout (r).mail=1m
setoption Timeout (r).rcpt=2m
setoption Timeout (r).datainit=1m
setoption Timeout (r).datablock=1m
setoption Timeout (r).datafinal=1m
setoption Timeout (r).rset=1m
setoption Timeout (r).quit=1m
setoption Timeout (r).misc=1m
setoption Timeout (r).command=1m
setoption Timeout (r).ident=0
setoption Timeout (r).queuereturn=28d
setoption Timeout (r).queuewarn=4h
setoption Timeout (r).starttls=2m
setoption SuperSafe (s)=True
setoption StatusFile (S)=/etc/mail/statistics
setoption DefaultUser (u)=8:12
setoption UserDatabaseSpec (U)=/etc/mail/userdb.db
setoption TryNullMXList (w)=true
setoption QueueLA (x)=10
setoption RefuseLA (X)=14
setoption DelayLA (0xcd)=10
setoption MaxDaemonChildren (0x8d)=400
setoption ConnectionRateThrottle (0x97)=10
setoption SmtpGreetingMessage (0x90)=$j Sendmail $v/$Z; $b
setoption UnixFromLine (0x91)=From $g $d
setoption OperatorChars (0x92)=.:%@!^/[]+
setoption MaxRecipientsPerMessage (0xa2)=35
setoption BadRcptThrottle (0xc3)=2
setoption DontProbeInterfaces (0xa1)=true
setoption AuthMechanisms (0xae)=LOGIN PLAIN
setoption AuthOptions (0xbd)=A
setoption InputMailFilters (0xbb)=greylist
setoption Milter (0xbc).LogLevel=9
setoption Milter (0xbc).macros.connect=j, _, {daemon_name}, {if_name},
{if_addr}
setoption Milter (0xbc).macros.helo={tls_version}, {cipher},
{cipher_bits}, {cert_subject}, {cert_issuer}, {verify}
setoption Milter (0xbc).macros.envfrom=i, {auth_type}, {auth_authen},
{auth_ssf}, {auth_author}, {mail_mailer}, {mail_host}, {mail_addr}
setoption Milter (0xbc).macros.envrcpt={rcpt_mailer}, {rcpt_host},
{rcpt_addr}, {greylist}
setoption Milter (0xbc).macros.eom={msg_id}
setoption CACertPath (0xb9)=/etc/mail/certs
setoption CACertFile (0xb8)=/etc/mail/certs/cacert.pem
setoption ServerCertFile (0xb4)=/etc/mail/certs/cert.pem
setoption ServerKeyFile (0xb5)=/etc/mail/certs/key.pem
drop_privileges(0): Real[UG]id=0:0, get[ug]id=0:0, gete[ug]id=0:51,
RunAs[UG]id=0:0
getauthinfo: root@localhost
============ SYSTEM IDENTITY (after readcf) ============
(short domain name) $w = rigel
(canonical domain name) $j = rigel.xxx.yy
(subdomain name) $m = xxx.yy
(node name) $k = rigel.xxx.yy
========================================================
setoption HoldExpensive (c)=F
setoption DeliveryMode (d)=
assign_queueid: assigned id o4QAavGM020957, e=0x2b7229d8ad40
getla(): 0.01
drop_privileges(0): Real[UG]id=0:0, get[ug]id=0:0, gete[ug]id=0:51,
RunAs[UG]id=0:0
assign_queueid: assigned id o4QAavGN020957, e=0x2b7229da4d60
gatherq:
QueueLimitId = o4QACJJp015146
grow_wlist: WorkListSize=0
grow_wlist: WorkListSize now 1000
qfo4QACJJp015146: pri=520039 >ti.mota
Running /var/spool/mqueue/o4QACJJp015146 (sequence 1 of 1)
dowork(/var/spool/mqueue/o4QACJJp015146)
getla(): 0.01
setsender(<joe....@xxx.yy>)
--parseaddr(<joe....@xxx.yy>)
rewrite: ruleset canonify input: < joe . blow @ xxx . yy >
rewrite: ruleset Canonify2 input: joe . blow < @ xxx . yy >
map_lookup(host, xxx.yy) => host_map_lookup(xxx.yy) =>
map_rewrite(xxx.yy), av =
xxx.yy
map_rewrite => xxx.yy.
FOUND xxx.yy
xxx.yy. (0)
rewrite: ruleset Canonify2 returns: joe . blow < @ xxx . yy . >
rewrite: ruleset canonify returns: joe . blow < @ xxx . yy . >
rewrite: ruleset parse input: joe . blow < @ xxx . yy . >
rewrite: ruleset Parse0 input: joe . blow < @ xxx . yy . >
rewrite: ruleset Parse0 returns: joe . blow < @ xxx . yy . >
rewrite: ruleset ParseLocal input: joe . blow < @ xxx . yy . >
rewrite: ruleset ParseLocal returns: joe . blow < @ xxx . yy . >
rewrite: ruleset Parse1 input: joe . blow < @ xxx . yy . >
map_lookup(mailertable, xxx.yy) => NOT FOUND (0)
rewrite: ruleset Mailertable input: < xxx . yy > joe . blow < @
xxx . yy . >
map_lookup(mailertable, .it) => NOT FOUND (0)
rewrite: ruleset Mailertable input: orion . < it > joe . blow <
@ xxx . yy . >
map_lookup(mailertable, .) => NOT FOUND (0)
rewrite: ruleset Mailertable returns: joe . blow < @ xxx . yy . >
rewrite: ruleset Mailertable returns: joe . blow < @ xxx . yy . >
rewrite: ruleset MailerToTriple input: < > joe . blow < @ xxx .
yy . >
rewrite: ruleset MailerToTriple returns: joe . blow < @ xxx . yy . >
rewrite: ruleset Parse1 returns: $# esmtp $@ xxx . yy . $:
joe . blow < @ xxx . yy . >
rewrite: ruleset parse returns: $# esmtp $@ xxx . yy . $:
joe . blow < @ xxx . yy . >
rewrite: ruleset 2 input: joe . blow < @ xxx . yy . >
rewrite: ruleset 2 returns: joe . blow < @ xxx . yy . >
rewrite: ruleset EnvToSMTP input: joe . blow < @ xxx . yy . >
rewrite: ruleset PseudoToReal input: joe . blow < @ xxx . yy . >
rewrite: ruleset PseudoToReal returns: joe . blow < @ xxx . yy . >
rewrite: ruleset MasqSMTP input: joe . blow < @ xxx . yy . >
rewrite: ruleset MasqSMTP returns: joe . blow < @ xxx . yy . >
rewrite: ruleset EnvToSMTP returns: joe . blow < @ xxx . yy . >
rewrite: ruleset final input: joe . blow < @ xxx . yy . >
rewrite: ruleset final returns: joe . blow @ xxx . yy
parseaddr-->0x2b7229da4d80=<joe....@xxx.yy>:
mailer 4 (esmtp), host `xxx.yy.'
user `joe....@xxx.yy', ruser `<null>'
state=OK, next=0x0, alias 0x0, uid 0, gid 0
flags=180<QPINGONFAILURE,QPINGONDELAY>
owner=(none), home="(none)", fullname="(none)"
orcpt="(none)", statmta=(none), status=(none)
finalrcpt="(none)"
rstatus="(none)"
statdate=(none)
rewrite: ruleset canonify input: < joe . blow @ xxx . yy >
rewrite: ruleset Canonify2 input: joe . blow < @ xxx . yy >
map_lookup(host, xxx.yy) => host_map_lookup(xxx.yy) => CACHE xxx.yy
map_rewrite(xxx.yy), av =
xxx.yy
map_rewrite => xxx.yy.
xxx.yy. (0)
rewrite: ruleset Canonify2 returns: joe . blow < @ xxx . yy . >
rewrite: ruleset canonify returns: joe . blow < @ xxx . yy . >
rewrite: ruleset 1 input: joe . blow < @ xxx . yy . >
rewrite: ruleset 1 returns: joe . blow < @ xxx . yy . >
rewrite: ruleset final input: joe . blow < @ xxx . yy . >
rewrite: ruleset final returns: joe . blow @ xxx . yy
--parseaddr(<jane...@atom.it>)
rewrite: ruleset canonify input: < jane . doe @ atom . it >
rewrite: ruleset Canonify2 input: jane . doe < @ atom . it >
map_lookup(host, atom.it) => host_map_lookup(atom.it) =>
map_rewrite(atom.it), av =
atom.it
map_rewrite => atom.it.
FOUND atom.it
atom.it. (0)
rewrite: ruleset Canonify2 returns: jane . doe < @ atom . it .
>
rewrite: ruleset canonify returns: jane . doe < @ atom . it .
>
rewrite: ruleset parse input: jane . doe < @ atom . it .
>
rewrite: ruleset Parse0 input: jane . doe < @ atom . it .
>
rewrite: ruleset Parse0 returns: jane . doe < @ atom . it .
>
rewrite: ruleset ParseLocal input: jane . doe < @ atom . it .
>
rewrite: ruleset ParseLocal returns: jane . doe < @ atom . it .
>
rewrite: ruleset Parse1 input: jane . doe < @ atom . it .
>
map_lookup(mailertable, atom.it) => NOT FOUND (0)
rewrite: ruleset Mailertable input: < atom . it > jane . doe <
@ atom . it . >
map_lookup(mailertable, .it) => NOT FOUND (0)
rewrite: ruleset Mailertable input: atom . < it > jane . doe <
@ atom . it . >
map_lookup(mailertable, .) => NOT FOUND (0)
rewrite: ruleset Mailertable returns: jane . doe < @ atom . it .
>
rewrite: ruleset Mailertable returns: jane . doe < @ atom . it .
>
rewrite: ruleset MailerToTriple input: < > jane . doe < @ atom .
it . >
rewrite: ruleset MailerToTriple returns: jane . doe < @ atom . it .
>
rewrite: ruleset Parse1 returns: $# esmtp $@ atom . it . $:
jane . doe < @ atom . it . >
rewrite: ruleset parse returns: $# esmtp $@ atom . it . $:
jane . doe < @ atom . it . >
rewrite: ruleset 2 input: jane . doe < @ atom . it .
>
rewrite: ruleset 2 returns: jane . doe < @ atom . it .
>
rewrite: ruleset EnvToSMTP input: jane . doe < @ atom . it .
>
rewrite: ruleset PseudoToReal input: jane . doe < @ atom . it .
>
rewrite: ruleset PseudoToReal returns: jane . doe < @ atom . it .
>
rewrite: ruleset MasqSMTP input: jane . doe < @ atom . it .
>
rewrite: ruleset MasqSMTP returns: jane . doe < @ atom . it .
>
rewrite: ruleset EnvToSMTP returns: jane . doe < @ atom . it .
>
rewrite: ruleset final input: jane . doe < @ atom . it .
>
rewrite: ruleset final returns: jane . doe @ atom . it
parseaddr-->0x2b722e2c5d30=<jane...@atom.it>:
mailer 4 (esmtp), host `atom.it.'
user `jane...@atom.it', ruser `<null>'
state=OK, next=0x0, alias 0x0, uid 0, gid 0
flags=180<QPINGONFAILURE,QPINGONDELAY>
owner=(none), home="(none)", fullname="(none)"
orcpt="(none)", statmta=(none), status=(none)
finalrcpt="(none)"
rstatus="(none)"
statdate=(none)
recipient (0): 0x2b722e2c5d30=<jane...@atom.it>:
mailer 4 (esmtp), host `atom.it.'
user `jane...@atom.it', ruser `<null>'
state=OK, next=0x0, alias 0x0, uid 0, gid 0
flags=182<QPRIMARY,QPINGONFAILURE,QPINGONDELAY>
owner=(none), home="(none)", fullname="(none)"
orcpt="(none)", statmta=(none), status=(none)
finalrcpt="RFC822; jane...@atom.it"
rstatus="(none)"
statdate=(none)
----- collected header -----
Return-Path: <$g>
Received: from [10.115.64.80] (venus.xxx.yy [87.12.173.6])\n\tby
rigel.xxx.yy (8.13.8/8.13.8) with ESMTP id o4QACJJp015146;\n\tWed, 26
May 2010 12:12:19 +0200
Message-ID: <4BFCF3F9...@xxx.yy>
Date: Wed, 26 May 2010 12:12:09 +0200
From: "Joe Blow" <joe....@xxx.yy>
User-Agent: Thunderbird 2.0.0.24 (Windows/20100228)
MIME-Version: 1.0
To: jane...@atom.it
Subject: Re: [orion #2770] RICHIESTA DI CONTROLLO
References: <RT-Tick...@xxx.yy>
<17390AC162B44981...@dominio.zzz>
<rt-3.8.2-6729-12747...@xxx.yy>
In-Reply-To: <rt-3.8.2-6729-12747...@xxx.yy>
Content-Type: text/plain; charset=UTF-8; format=flowed
Content-Transfer-Encoding: quoted-printable
X-Greylist: Sender DNS name whitelisted, not delayed by milter-
greylist-3.0 (rigel.xxx.yy [212.115.64.10]); Wed, 26 May 2010 12:12:19
+0200 (CEST)
----------------------------
===== SENDALL: mode i, id o4QACJJp015146, e_from
0x2b7229da4d80=<joe....@xxx.yy>:
mailer 4 (esmtp), host `xxx.yy.'
user `joe....@xxx.yy', ruser `<null>'
state=SENDER, next=0x0, alias 0x0, uid 0, gid 0
flags=180<QPINGONFAILURE,QPINGONDELAY>
owner=(none), home="(none)", fullname="(none)"
orcpt="(none)", statmta=(none), status=(none)
finalrcpt="(none)"
rstatus="(none)"
statdate=(none)
e_flags =
605842<INQUEUE,DELETE_BCC,QUEUERUN,GLOBALERRS,METOO,HAS_DF,IS_MIME>
sendqueue:
0x2b722e2c5d30=<jane...@atom.it>:
mailer 4 (esmtp), host `atom.it.'
user `jane...@atom.it', ruser `<null>'
state=OK, next=0x0, alias 0x0, uid 0, gid 0
flags=80000182<QPRIMARY,QPINGONFAILURE,QPINGONDELAY,QRCPTOK>
owner=(none), home="(none)", fullname="(none)"
orcpt="(none)", statmta=(none), status=(none)
finalrcpt="RFC822; jane...@atom.it"
rstatus="(none)"
statdate=(none)
--deliver, id=o4QACJJp015146, mailer=esmtp, host=`atom.it.', first
user=`jane...@atom.it'
remotename(<joe....@xxx.yy>)
rewrite: ruleset canonify input: < joe . blow @ xxx . yy >
rewrite: ruleset Canonify2 input: joe . blow < @ xxx . yy >
map_lookup(host, xxx.yy) => host_map_lookup(xxx.yy) => CACHE xxx.yy
map_rewrite(xxx.yy), av =
xxx.yy
map_rewrite => xxx.yy.
xxx.yy. (0)
rewrite: ruleset Canonify2 returns: joe . blow < @ xxx . yy . >
rewrite: ruleset canonify returns: joe . blow < @ xxx . yy . >
rewrite: ruleset 1 input: joe . blow < @ xxx . yy . >
rewrite: ruleset 1 returns: joe . blow < @ xxx . yy . >
rewrite: ruleset EnvFromSMTP input: joe . blow < @ xxx . yy . >
rewrite: ruleset PseudoToReal input: joe . blow < @ xxx . yy . >
rewrite: ruleset PseudoToReal returns: joe . blow < @ xxx . yy . >
rewrite: ruleset MasqSMTP input: joe . blow < @ xxx . yy . >
rewrite: ruleset MasqSMTP returns: joe . blow < @ xxx . yy . >
rewrite: ruleset MasqEnv input: joe . blow < @ xxx . yy . >
rewrite: ruleset MasqEnv returns: joe . blow < @ xxx . yy . >
rewrite: ruleset EnvFromSMTP returns: joe . blow < @ xxx . yy . >
rewrite: ruleset final input: joe . blow < @ xxx . yy . >
rewrite: ruleset final returns: joe . blow @ xxx . yy
remotename => `joe....@xxx.yy'
hostsignature(atom.it.) =
mxe1.idc.extra.it.,mxe2.idc.extra.it.:mx1.idc.extra.it.
send to 0x2b722e2c5d30=<jane...@atom.it>:
mailer 4 (esmtp), host `atom.it.'
user `jane...@atom.it', ruser `<null>'
state=OK, next=0x0, alias 0x0, uid 0, gid 0
flags=80000182<QPRIMARY,QPINGONFAILURE,QPINGONDELAY,QRCPTOK>
owner=(none), home="(none)", fullname="(none)"
orcpt="(none)", statmta=(none), status=(none)
finalrcpt="RFC822; jane...@atom.it"
rstatus="(none)"
statdate=(none)
checkcompat(to=<jane...@atom.it>, from=<joe....@xxx.yy>)
openmailer: TCP atom.it.
<jane...@atom.it>... Connecting to mxe2.idc.extra.it. via esmtp...
makeconnection (mxe2.idc.extra.it. [217.27.71.21].25 (10))
makeconnection: fd=7
Connecting to [217.27.71.21]...
Connect failed (Connection timed out with mxe2.idc.extra.it.);
retrying with AF_INET....
makeconnection (mxe2.idc.extra.it. [217.27.71.21].25 (2))
makeconnection: fd=7
Connecting to [217.27.71.21]...
Connect failed (Connection timed out with mxe2.idc.extra.it.)
openmailer: makeconnection => stat=75, errno=110
openmailer: MCI@0x2b722e2d0ea8: flags=0,
errno=110, herrno=1, exitstat=75, state=0, pid=0,
maxsize=0, phase=initial connection, mailer=esmtp,
status=4.4.1, rstatus=(null),
host=mxe2.idc.extra.it., lastuse=Wed May 26 12:38:57 2010
<jane...@atom.it>... Deferred: Connection timed out with
mxe2.idc.extra.it.
dropenvelope 0x2b7229da4d60: id=o4QACJJp015146,
flags=4605842<INQUEUE,DELETE_BCC,QUEUERUN,GLOBALERRS,METOO,HAS_DF,IS_MIME,SPLIT>
>>>>> queueing /var/spool/mqueue/./qfo4QACJJp015146 >>>>>
queueing 0x2b722e2c5d30=<jane...@atom.it>:
mailer 4 (esmtp), host `atom.it.'
user `jane...@atom.it', ruser `<null>'
state=QUEUEUP, next=0x0, alias 0x0, uid 0, gid 0
flags=80000182<QPRIMARY,QPINGONFAILURE,QPINGONDELAY,QRCPTOK>
owner=(none), home="(none)", fullname="(none)"
orcpt="(none)", statmta=mxe2.idc.extra.it., status=4.4.1
finalrcpt="RFC822; jane...@atom.it"
rstatus="(none)"
statdate=Wed May 26 12:38:57 2010
remotename("Joe Blow" <joe....@xxx.yy>)
remotename(jane...@atom.it)
<<<<< done queueing o4QACJJp015146 <<<<<
dropenvelope 0x2b7229da4d60: id=<null>,
flags=4405042<INQUEUE,DELETE_BCC,GLOBALERRS,METOO,IS_MIME,SPLIT>
====finis: stat 75 e_id=NOQUEUE
e_flags=4405042<INQUEUE,DELETE_BCC,GLOBALERRS,METOO,IS_MIME,SPLIT>
alf
On May 26, 3:22 pm, alf <alessandro.forghi...@gmail.com> wrote:
[....]
> The problem:
> messages sent to atom.it are permanently associated to one of the two
> highest priority MXs and get stuck in the queue - forever (a log for
> sendmail -q -v -d is appended). The messages are stuck on a 440
> connection timed out condition. The third MX is never considered. This
> is in violation of the following segment of the docs (sendmail.org):
NOT. (Not the problem, that is). Symptoms are as explained, however
the actual culprits are:
> setoption Timeout (r).connect=1m
> setoption Timeout (r).aconnect=2m
and especially the second one, brought about by (myself) sticking the
following in sendmail.mc:
define(`confTO_ACONNECT', `2m')dnl
The docs state:
confTO_ACONNECT: Timeout.aconnect
[0] The overall timeout waiting for all connection
for a single delivery attempt to succeed.
If 0, no overall limit is applied.
So, in the delivery trace above, sendmail tries the first MX, times
out in a minute, tries the second MX, times out in aminute , then
gives up because the overall delivery time (2 minutes) is expired....
dandy, except it does so while failing to say anything about it -
which methinks is a bug, because it then appears as if the delaying TO
is MX related (when it is in fact config related).
Cheers,
alf