Connection timeouts in postfix

What version of the policy sever are you running? That's not the same line number that command occurs in for the current release.

I don't know for sure, but that seems like it means postfix isn't listening on it's end of the pipe. If you could provide more complete mail logs, it might help diagnose what's going on.

The version number is __version__ = "1.2: JULY 25, 2013"

Called from master.cf with:
policy-spf unix - n n - - spawn
     user=nobody argv=/usr/bin/policyd-spf

apt-get says postfix-policyd-spf-python is already the newest version. Running Ubuntu 14.04.1 LTS (GNU/Linux 3.11.0-19-generic x86_64)

Is there a way to force a newer version through apt-get?

Here are two issues from this morning, as they have slightly different error messages. First, is from a gettyimages.com mail server and second from prezi.com.

First:

Aug 27 08:12:03 carson policyd-spf[29415]: spfcheck: pyspf result: "['None', '', 'helo']"
Aug 27 08:12:03 carson policyd-spf[29415]: None; identity=helo; client-ip=216.169.250.44; helo=in-outbound.example.com; envelope-from=<sender redacted>; receiver=<recipient redacted>
Aug 27 08:13:44 carson policyd-spf[29417]: spfcheck: pyspf result: "['None', '', 'helo']"
Aug 27 08:13:44 carson policyd-spf[29417]: None; identity=helo; client-ip=216.169.250.44; helo=in-outbound.example.com; envelope-from=<sender redacted>; receiver=<recipient redacted>
Aug 27 08:14:33 carson policyd-spf[29415]: spfcheck: pyspf result: "['Softfail', 'domain owner discourages use of this host', 'mailfrom']"
Aug 27 08:14:33 carson policyd-spf[29415]: Softfail; identity=mailfrom; client-ip=216.169.250.44; helo=in-outbound.example.com; envelope-from=<sender redacted>; receiver=<recipient redacted>
Aug 27 08:14:33 carson policyd-spf[29415]: Traceback (most recent call last):
Aug 27 08:14:33 carson policyd-spf[29415]: File "/usr/bin/policyd-spf", line 690, in <module>
Aug 27 08:14:33 carson policyd-spf[29415]: sys.stdout.flush()
Aug 27 08:14:33 carson policyd-spf[29415]: BrokenPipeError: [Errno 32] Broken pipe
Aug 27 08:14:34 carson postfix/spawn[29414]: warning: command /usr/bin/policyd-spf exit status 1
Aug 27 08:14:54 carson postfix/smtpd[29410]: warning: problem talking to server private/policy-spf: Connection timed out
Aug 27 08:14:54 carson postfix/smtpd[29410]: NOQUEUE: reject: RCPT from in-outbound.example.com[216.169.250.44]: 451 4.3.5 Server configuration problem; from=<<sender redacted>> to=<<recipient redacted>> proto=ESMTP helo=<in-outb
ound.example.com>
Aug 27 08:14:54 carson postfix/smtpd[29410]: disconnect from in-outbound.example.com[216.169.250.44]
Aug 27 08:16:15 carson policyd-spf[29417]: spfcheck: pyspf result: "['Softfail', 'domain owner discourages use of this host', 'mailfrom']"
Aug 27 08:16:15 carson policyd-spf[29417]: Softfail; identity=mailfrom; client-ip=216.169.250.44; helo=in-outbound.example.com; envelope-from=<sender redacted>; receiver=<recipient redacted>
Aug 27 08:16:15 carson policyd-spf[29417]: Traceback (most recent call last):
Aug 27 08:16:15 carson policyd-spf[29417]: File "/usr/bin/policyd-spf", line 642, in <module>
Aug 27 08:16:15 carson policyd-spf[29417]: line = sys.stdin.readline()
Aug 27 08:16:15 carson policyd-spf[29417]: ConnectionResetError: [Errno 104] Connection reset by peer
Aug 27 08:16:15 carson postfix/spawn[29416]: warning: command /usr/bin/policyd-spf exit status 1

And second:

Aug 27 08:17:33 carson postfix/smtpd[29445]: Trusted TLS connection established from mail-ie0-f179.google.com[209.85.223.179]: TLSv1 with cipher ECDHE-RSA-AES128-SHA (128/128 bits)
Aug 27 08:18:08 carson policyd-spf[29451]: spfcheck: pyspf result: "['None', '', 'helo']"
Aug 27 08:18:08 carson policyd-spf[29451]: None; identity=helo; client-ip=209.85.223.179; helo=mail-ie0-f179.google.com; envelope-from=<sender redacted>; receiver=<recipient redacted>
Aug 27 08:20:38 carson policyd-spf[29451]: spfcheck: pyspf result: "['Pass', 'sender SPF authorized', 'mailfrom']"
Aug 27 08:20:38 carson policyd-spf[29451]: Pass; identity=mailfrom; client-ip=209.85.223.179; helo=mail-ie0-f179.google.com; envelope-from=<sender redacted>; receiver=<recipient redacted>
Aug 27 08:20:38 carson policyd-spf[29451]: Traceback (most recent call last):
Aug 27 08:20:38 carson policyd-spf[29451]: File "/usr/bin/policyd-spf", line 690, in <module>
Aug 27 08:20:38 carson policyd-spf[29451]: sys.stdout.flush()
Aug 27 08:20:38 carson policyd-spf[29451]: BrokenPipeError: [Errno 32] Broken pipe
Aug 27 08:20:59 carson postfix/smtpd[29445]: warning: problem talking to server private/policy-spf: Connection timed out
Aug 27 08:20:59 carson postfix/smtpd[29445]: NOQUEUE: reject: RCPT from mail-ie0-f179.google.com[209.85.223.179]: 451 4.3.5 Server configuration problem; from=<<sender redacted>> to=<<recipient redacted>> proto=ESMTP helo=<ma
il-ie0-f179.google.com>

Thanks. A real head scratcher as most emails are getting through. Some trip the issue some of the time but the prezi.com example (2nd one) fails every time they send to me. (And they're a biz contact.)

sudo apt-get -t trusty-backports install python3-spf postfix-policyd-spf-python

That will upgrade both pyspf and the policy server to the current, RFC 7208 compliant, version.

Thanks.

That gave me the following error message:

The value 'trusty-backports' is invalid for APT::Default-Release as such a release is not available in the sources.

Breaking out my Google Fu....

Added deb http://archive.ubuntu.com/ubuntu trusty-backports main restricted universe multiverse to /etc/apt/sources.list and the install worked.

Will keep an eye out if my problem is still there and will let you know ASAP.

Haven't seen any of the other errors yet, but did notice a lot of:

spfcheck: pyspf result: "['Temperror', 'SPF Temporary Error: DNS Error: exceeded max query lookup time', 'mailfrom']"

Any conf I need to change to fix that?

You would set Lookup_Time to a higher value. See man 5 policyd-spf.conf for details. The default is, however, 20 seconds, which is a pretty long time. You should also probably investigate why DNS lookups are resolving so slowly.

Thanks for your help. Perhaps I should look at DNS caching for the server.

I ran into the same symptoms, and found that although DNS was working fine via UDP, it was firewalled for TCP. Normal DNS resulted in small responses which worked fine with UDP, but some long SPF strings for particular addresses were truncated, requiring a retry on TCP. This retry failed due to firewall, leading to the timeouts. Hope that helps.