spf-discuss
[Top] [All Lists]

persistent spfd connection failures

2004-04-19 13:09:14
    I've been observing some peculiar recurrent connection failures from
spfd. While more than 90% of the time I can connect to the spfd socket
w/o any problem, and most of the remaining 10% occur when my mail server
is heavily loaded while being hit with a wave of spam, these are different.
    There are some mailers from which messages seem to keep being
plagued with persistent and recurring connection failures. They seem to
be associated with certain sender/receiver pairs. Two representative
samples from my logs are appended below. I'm currently using
Mail::SPF::Query-1.996's spfd with perl-5.8.3 and the latest perl
dependencies of MSQ, based on the srpms from
http://www.city-fan.org/ftp/contrib/perl-modules/, invoked from
exim-4.14 via David Saez's ACL v2.09, though as I pore over older logs I
see that the first example seems to have been going on for nearly three
weeks, during which time I've done some upgrades of various components.
The second example is notable in its frequency. When I turn debugging on
for spfd, the output reveals that the queries the messages trigger seem
to be spanning several other queries (see below).
I wrote a little test perl script that uses Mail::SPF::Query for these connections. What appears to be happening is that MQS is taking around 80 seconds to time out when querying the DNS servers for these zones. The readsocket in the SPF ACL timesout in just 20 seconds, hence the errors. dig'ing for txt records from the command line times out in around 12 seconds.
    Has anyone else seen this problem? Any ideas?

        Joe

Example 1:
2004-04-18 03:51:54 H=mailx.concordmc.com (EXCALEPH.ConcordMortgage.com)
[216.255.123.130] F=<xxxxxx(_at_)concordmc(_dot_)com> temporarily rejected RCPT
<yyyyyyy(_at_)foooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect to spfd
2004-04-18 07:52:49 H=mailx.concordmc.com (EXCALEPH.ConcordMortgage.com)
[216.255.123.130] F=<xxxxxx(_at_)concordmc(_dot_)com> temporarily rejected RCPT
<yyyyyyy(_at_)foooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect to spfd
2004-04-18 08:04:54 H=mailx.concordmc.com (EXCALEPH.ConcordMortgage.com)
[216.255.123.130] F=<xxxxxx(_at_)concordmc(_dot_)com> temporarily rejected RCPT
<yyyyyyy(_at_)foooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect to spfd
2004-04-18 12:05:45 H=mailx.concordmc.com (EXCALEPH.ConcordMortgage.com)
[216.255.123.130] F=<xxxxxx(_at_)concordmc(_dot_)com> temporarily rejected RCPT
<yyyyyyy(_at_)foooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect to spfd
2004-04-18 20:08:04 H=mailx.concordmc.com (EXCALEPH.ConcordMortgage.com)
[216.255.123.130] F=<xxxxxx(_at_)concordmc(_dot_)com> temporarily rejected RCPT
<yyyyyyy(_at_)foooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect to spfd
2004-04-19 04:10:22 H=mailx.concordmc.com (EXCALEPH.ConcordMortgage.com)
[216.255.123.130] F=<xxxxxx(_at_)concordmc(_dot_)com> temporarily rejected RCPT
<yyyyyyy(_at_)foooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect to spfd
2004-04-19 08:11:17 H=mailx.concordmc.com (EXCALEPH.ConcordMortgage.com)
[216.255.123.130] F=<xxxxxx(_at_)concordmc(_dot_)com> temporarily rejected RCPT
<yyyyyyy(_at_)foooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect to spfd
2004-04-19 09:25:13 H=mailx.concordmc.com (EXCALEPH.ConcordMortgage.com)
[216.255.123.130] F=<xxxxxx(_at_)concordmc(_dot_)com> temporarily rejected RCPT
<yyyyyyy(_at_)foooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect to spfd

Example 2:
2004-04-19 01:10:16 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 01:16:08 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 01:22:00 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 01:45:55 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 02:03:36 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 02:09:29 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 02:21:22 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 02:27:14 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 02:56:33 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 03:14:15 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 03:20:07 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 03:25:59 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 03:31:54 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 03:37:45 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 03:43:38 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 03:49:29 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 04:12:57 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 04:18:50 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 04:42:31 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 04:48:23 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 05:11:55 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 05:17:49 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 05:41:22 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 05:47:13 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 05:53:19 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 06:05:02 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 06:28:35 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 06:46:08 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 06:57:58 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 07:09:41 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 07:21:24 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 07:27:19 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 07:39:03 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 07:44:58 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 07:50:54 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 07:56:46 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 08:02:41 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 08:08:55 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 08:15:15 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 08:26:57 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 08:38:41 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 08:44:34 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 08:50:27 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 09:02:13 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
2004-04-19 09:14:03 H=mail.ifm-uk.co.uk (bamldnmasw01.baring-asset.com)
[130.32.42.40] F=<zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com> temporarily
rejected RCPT <wwwwwwwww(_at_)fooooooooooo(_dot_)bar(_dot_)baz>: Cannot connect 
to spfd
===============
Mon Apr 19 10:30:39 2004
learned helo = bamldnmasw01.baring-asset.com
learned ip = 130.32.42.40
learned sender = zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com
Mon Apr 19 10:31:12 2004
learned helo = mail16.savings-avenue.com
learned ip = 216.219.110.165
learned sender = ...
moo!  output all done.

...

Mon Apr 19 10:31:39 2004
learned helo = mail.savings-avenue.com
learned ip = 216.219.110.150
learned sender = ...
moo!  output all done.

moo!  result=none
moo! smtp_comment=SPF: domain of sender zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com does not designate mailers moo! header_comment=scf01.mailcleanser.com: domain of zzzzzzzzzzzzzzzzzz(_at_)baring-asset(_dot_)com does not designate permitted sender hosts
moo!  guess=neutral
moo!  smtp_guess=
moo!  header_guess=
moo!  guess_tf=neutral
moo!  smtp_tf=
moo!  header_tf=
moo!  spf_record=
Mon Apr 19 10:32:09 2004
learned helo = mail13.wwwoptinmail.com
learned ip = 69.6.65.62
learned sender = ...



<Prev in Thread] Current Thread [Next in Thread>