[Mimedefang] Revisiting the bombardment of 451 Tempfailing errors
Justin Shore
listuser at numbnuts.net
Mon Jul 7 23:30:01 EDT 2003
Howdy all. I'm still having trouble with my server deciding to tempfail
everything after only a handful of minutes running. It has all but made
the mail system unusable. I have a cronjob restart MD and Sendmail every
5 minutes just to hold off the tempfailing (or at least restart the
daemons shortly after they go wacko). This dual MP 2400 box now has 2GB
of RAM. The spool directory is now on a 512MB tmpfs volume. Mail load is
typically low. I'm getting a lot of bounces from a joe job but this
problem started long before that. It's handling all of my mailing list
mail. The only other CPU consuming process is the folding at home clients I
have running. They are niced down to an insane level so they are never a
problem. I've disabled $SALocalTestsOnly. I've disabled all AV checks
via the ./configure option. I'm running SA 2.60 from nightly CVS builds.
The problem exists with older versions though (I've tested this).
Sendmail is the latest greatest (well I say that but I know 8.12.10b2 is
out) 8.12.9. I'm running the following startup options (minus the no
brainer ones):
MX_SLAVE_DELAY=5
MX_REQUESTS=50
MX_MINIMUM=20
MX_MAXIMUM=65
MX_IDLE=120
MX_BUSY=300
I've messed with a number of options to try and find something that
helped. Really none of them help in any way shape or form. I see
frequent errors like this in my maillog:
Jul 7 21:14:59 bubba mimedefang[20616]: h682EmlQ020615: Unknown command
'%' in RESULTS file
I see an occasional error like this that ends in a single tempfail:
Jul 7 21:15:48 bubba mimedefang[20707]: h682FclO020706: Could not open
/var/mail/MIMEDefang/spool/mdefang-h682FclO020706/NEWBODY for reading: No
such file or directory
Mail delivery procedes like normal after that though. When things fail
they look like this (sorry, this is going to wrap badly):
Jul 6 05:16:10 bubba sm-mta[650]: h66AGAKO000650:
from=<root at oak.numbnuts.net>, size=8257, class=0, nrcpts=1,
msgid=<r4i9p9$58w$--376@
im0coq.24.o1i>, proto=ESMTP, daemon=MTA, relay=oak.numbnuts.net [1.2.3.4]
Jul 6 05:16:12 bubba mimedefang.pl[32721]:
MDLOG,h66AGAKO000650,spam,41.593,1.2.3.4,<root at oak.numbnuts.net>,<spamhole at numbnuts.net>
,***SPAM*** Best of all, results may be evident in just a few short weeks!
m ry yqirpmtpyxv
Jul 6 05:16:12 bubba mimedefang[651]: h66AGAKO000650: Bouncing because
filter instructed us to
Jul 6 05:17:12 bubba sm-mta[650]: h66AGAKO000650: Milter (mimedefang):
timeout before data read
Jul 6 05:17:12 bubba sm-mta[650]: h66AGAKO000650: Milter (mimedefang): to
error state
Jul 6 05:17:12 bubba sm-mta[650]: h66AGAKO000650: Milter: data,
reject=451 4.7.1 Please try again later
Jul 6 05:17:12 bubba sm-mta[650]: h66AGAKO000650:
to=<spamcan at numbnuts.net>, delay=00:01:02, pri=34224, stat=Please try
again late
r
Jul 6 05:17:13 bubba sm-mta[650]: h66AGAKQ000650: Milter:
from=<root at oak.numbnuts.net>, reject=451 4.7.1 Please try again later
Jul 6 05:17:13 bubba sm-mta[650]: h66AGAKQ000650:
from=<root at oak.numbnuts.net>, size=8285, class=0, nrcpts=0, proto=ESMTP,
daemon=MTA,
relay=oak.numbnuts.net [1.2.3.4]
Jul 6 05:17:13 bubba sm-mta[650]: h66AGAKR000650: Milter:
from=<root at oak.numbnuts.net>, reject=451 4.7.1 Please try again later
Jul 6 05:17:13 bubba sm-mta[650]: h66AGAKR000650:
from=<root at oak.numbnuts.net>, size=8285, class=0, nrcpts=0, proto=ESMTP,
daemon=MTA,
relay=oak.numbnuts.net [1.2.3.4]
Jul 6 05:17:13 bubba sm-mta[650]: h66AGAKS000650: Milter:
from=<root at oak.numbnuts.net>, reject=451 4.7.1 Please try again later
Jul 6 05:17:13 bubba sm-mta[650]: h66AGAKS000650:
from=<root at oak.numbnuts.net>, size=8285, class=0, nrcpts=0, proto=ESMTP,
daemon=MTA,
relay=oak.numbnuts.net [1.2.3.4]
Jul 6 05:17:13 bubba sm-mta[650]: h66AGAKT000650: Milter:
from=<root at oak.numbnuts.net>, reject=451 4.7.1 Please try again later
Jul 6 05:17:13 bubba sm-mta[650]: h66AGAKT000650:
from=<root at oak.numbnuts.net>, size=8285, class=0, nrcpts=0, proto=ESMTP,
daemon=MTA,
relay=oak.numbnuts.net [1.2.3.4]
Jul 6 05:17:13 bubba sm-mta[650]: h66AGAKU000650: Milter:
from=<root at oak.numbnuts.net>, reject=451 4.7.1 Please try again later
Jul 6 05:17:13 bubba sm-mta[650]: h66AGAKU000650:
from=<root at oak.numbnuts.net>, size=8285, class=0, nrcpts=0, proto=ESMTP,
daemon=MTA,
relay=oak.numbnuts.net [1.2.3.4]
Jul 6 05:17:13 bubba sm-mta[650]: h66AGAKV000650: Milter:
from=<root at oak.numbnuts.net>, reject=451 4.7.1 Please try again later
Jul 6 05:17:14 bubba sm-mta[650]: h66AGAKV000650:
from=<root at oak.numbnuts.net>, size=8285, class=0, nrcpts=0, proto=ESMTP,
daemon=MTA,
relay=oak.numbnuts.net [1.2.3.4]
Jul 6 05:17:14 bubba sm-mta[650]: h66AGAKW000650: Milter:
from=<root at oak.numbnuts.net>, reject=451 4.7.1 Please try again later
Jul 6 05:17:14 bubba sm-mta[650]: h66AGAKW000650:
from=<root at oak.numbnuts.net>, size=8285, class=0, nrcpts=0, proto=ESMTP,
daemon=MTA,
relay=oak.numbnuts.net [1.2.3.4]
Jul 6 05:17:14 bubba sm-mta[650]: h66AGAKX000650: Milter:
from=<root at oak.numbnuts.net>, reject=451 4.7.1 Please try again later
Jul 6 05:17:14 bubba sm-mta[650]: h66AGAKX000650:
from=<root at oak.numbnuts.net>, size=8285, class=0, nrcpts=0, proto=ESMTP,
daemon=MTA,
relay=oak.numbnuts.net [1.2.3.4]
Jul 6 05:17:14 bubba sm-mta[650]: h66AGAKY000650: Milter:
from=<root at oak.numbnuts.net>, reject=451 4.7.1 Please try again later
Jul 6 05:17:14 bubba sm-mta[650]: h66AGAKY000650:
from=<root at oak.numbnuts.net>, size=8654, class=0, nrcpts=0, proto=ESMTP,
daemon=MTA,
relay=oak.numbnuts.net [1.2.3.4]
Jul 6 05:17:14 bubba sm-mta[650]: h66AGAKZ000650: Milter:
from=<root at oak.numbnuts.net>, reject=451 4.7.1 Please try again later
Jul 6 05:18:05 bubba sm-mta[655]: NOQUEUE: connect from oak.numbnuts.net
[1.2.3.4]
Jul 6 05:18:31 bubba sm-mta[656]: NOQUEUE: connect from oak.numbnuts.net
[1.2.3.4]
Jul 6 05:19:05 bubba sm-mta[655]: h66AI5KO000655: Milter (mimedefang):
timeout before data read
Jul 6 05:19:05 bubba sm-mta[655]: h66AI5KO000655: Milter (mimedefang): to
error state
Jul 6 05:19:05 bubba sm-mta[655]: h66AI5KO000655: Milter (mimedefang):
init failed to open
Jul 6 05:19:05 bubba sm-mta[655]: h66AI5KO000655: Milter (mimedefang): to
error state
Jul 6 05:19:05 bubba sm-mta[655]: h66AI5KO000655: Milter: initialization
failed, temp failing commands
Jul 6 05:19:05 bubba sm-mta[655]: h66AI5KO000655: SMTP MAIL command
(<root at oak.numbnuts.net> SIZE=5588) from oak.numbnuts.net [1.2.3.4
] tempfailed (due to previous checks)
Jul 6 05:19:15 bubba sm-mta[650]: h66AGAKZ000650:
from=<root at oak.numbnuts.net>, size=14439, class=0, nrcpts=0, proto=ESMTP,
daemon=MTA
, relay=oak.numbnuts.net [1.2.3.4]
Jul 6 05:19:15 bubba sm-mta[650]: h66AGAKa000650: Milter:
from=<root at oak.numbnuts.net>, reject=451 4.7.1 Please try again later
Jul 6 05:19:31 bubba sm-mta[656]: h66AIVKO000656: Milter (mimedefang):
timeout before data read
Jul 6 05:19:31 bubba sm-mta[656]: h66AIVKO000656: Milter (mimedefang): to
error state
Jul 6 05:19:31 bubba sm-mta[656]: h66AIVKO000656: Milter (mimedefang):
init failed to open
Jul 6 05:19:31 bubba sm-mta[656]: h66AIVKO000656: Milter (mimedefang): to
error state
Jul 6 05:19:31 bubba sm-mta[656]: h66AIVKO000656: Milter: initialization
failed, temp failing commands
Jul 6 05:19:32 bubba sm-mta[656]: h66AIVKO000656: SMTP MAIL command
(<root at oak.numbnuts.net> SIZE=5685) from oak.numbnuts.net [1.2.3.4
] tempfailed (due to previous checks)
Jul 6 05:19:50 bubba sm-mta[657]: NOQUEUE: connect from
IDENT:postfix@[61.113.41.3]
Jul 6 05:20:01 bubba sm-mta[657]: h66AJoKO000657: Milter (mimedefang):
read returned -1: Connection reset by [61.113.41.3]
Jul 6 05:20:01 bubba sm-mta[657]: h66AJoKO000657: Milter (mimedefang): to
error state
Jul 6 05:20:01 bubba sm-mta[657]: h66AJoKO000657: Milter (mimedefang):
init failed to open
Jul 6 05:20:01 bubba sm-mta[657]: h66AJoKO000657: Milter (mimedefang): to
error state
Jul 6 05:20:01 bubba sm-mta[657]: h66AJoKO000657: Milter: initialization
failed, temp failing commands
In this case a few seconds later my cronjob restarted MD and Sendmail and
all was well for a little longer. I was watching my maillog just now when
it happened again. The remote host connected and was in the middle of
DATA. Sendmail made the first syslog entry, saying who the messages was
from. Then 1 minute later it repored that MD never responded and went to
an error state. In the log above MD actually had time to write the MDLOG
spam results to syslog before it went braindead. In that example Sendmail
waited a minute before saying MD timed out. In most of these examples
only a single remote host was connected to Sendmail in a single connection
and the thing still tempfails.
This problem appeared over a weekend where I wasn't even home to make
changes to the config. I've experienced it in 2.33, 2.34 beta releases,
and now 2.35. I've reverted my sa-mimedefang.cf to a slightly modified
version of the example file rather than my heavily modified version to no
avail. I can't seem to shake this problem no matter what I try. If
anyone has any inkling as to what's causing this, I'd love to hear it.
If anyone wants my sendmail, MD, or SA configs let me know and I'll gladly
send them your way. If you want a non-wrapping version of the log, let me
know as well. Many thanks
Justin
More information about the MIMEDefang
mailing list