policyd-spf and temperrors

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
17 messages Options
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

policyd-spf and temperrors

James B. Byrne
OS=CentOS-6.8 (Linux)

postconf -d | grep mail_version # version
mail_version = 2.11.1
milter_macro_v = $mail_name $mail_version


We are currently experiencing an outage at a remote site that happens
to provide two of our four DNS services.  We have also recently, I am
tempted to write co-incidentally, begun to reject mail from many sites
due to policyd-spf DNS timeout errors similar to the following:


Mar 17 10:57:58 inet08 policyd-spf[12275]: Temperror; identity=helo;
client-ip=208.33.203.70; helo=mgmx.mohawkglobal.com;
envelope-from=[hidden email];
receiver=[hidden email]

Mar 17 10:58:18 inet08 policyd-spf[12275]: Temperror;
identity=mailfrom; client-ip=208.33.203.70;
helo=mgmx.mohawkglobal.com; envelope-from=[hidden email];
receiver=[hidden email]


When I test our policyd-spf.conf this is what I see:


/usr/libexec/postfix/policyd-spf /etc/python-policyd-spf/policyd-spf.conf
protocol_name=SMTP
protocol_state=RCPT
request=smtpd_access_policy
client_address=208.33.203.70
client_name=mgmx.mohawkglobal.com
helo_name=mgmx.mohawkglobal.com
sender=[hidden email]
recipient=[hidden email]

action=prepend Received-SPF: Temperror (SPF Temporary Error: DNS
Timeout) identity=mailfrom;
  client-ip=208.33.203.70;
  helo=mgmx.mohawkglobal.com;
  envelope-from=[hidden email];
  receiver=[hidden email]


However if I dig the sender's address from the same host then I see no
delay:

dig mohawkglobalta.com TXT

; <<>> DiG 9.8.2rc1-RedHat-9.8.2-0.47.rc1.el6_8.4 <<>>
mohawkglobalta.com TXT
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 34357
;; flags: qr rd ra; QUERY: 1, ANSWER: 2, AUTHORITY: 4, ADDITIONAL: 1

;; QUESTION SECTION:
;mohawkglobalta.com.            IN      TXT

;; ANSWER SECTION:
mohawkglobalta.com.     1476    IN      TXT     "v=spf1
include:spf.protection.outlook.com ip4:208.33.203.70/31 -all"
mohawkglobalta.com.     1476    IN      TXT     "MS=ms37967191"

;; AUTHORITY SECTION:
mohawkglobalta.com.     10552   IN      NS      ns1190.dns.dyn.com.
mohawkglobalta.com.     10552   IN      NS      ns3159.dns.dyn.com.
mohawkglobalta.com.     10552   IN      NS      ns2166.dns.dyn.com.
mohawkglobalta.com.     10552   IN      NS      ns4181.dns.dyn.com.

;; ADDITIONAL SECTION:
ns4181.dns.dyn.com.     1603    IN      A       208.76.61.181

;; Query time: 3 msec
;; SERVER: 127.0.0.1#53(127.0.0.1)
;; WHEN: Fri Mar 17 11:12:20 2017
;; MSG SIZE  rcvd: 250


Suddenly began getting these Temperrors reports for multiple sites
while there has been no changes made to our mail server or
configuration for some time.  This does not appear to be a problem
with the senders but I cannot fathom what local issue could be causing
the problem.

To short-circuit the issue I have set defaultSeedOnly = 0 in
/etc/python-policyd-spf/policyd-spf.conf.  However, this is a
temporary measure and I need to uncover and deal with the underlying
issue quickly.

Does anyone have a clue as to why this is happening and how to correct
it?

Configuration files follow:


postconf -nf
alias_maps = hash:/etc/aliases
broken_sasl_auth_clients = yes
command_directory = /usr/sbin
config_directory = /etc/postfix
content_filter = smtp-amavis:[127.0.0.1]:10024
daemon_directory = /usr/libexec/postfix
data_directory = /var/lib/postfix
debugger_command = PATH=/bin:/usr/bin:/usr/local/bin:/usr/X11R6/bin ddd
    $daemon_directory/$process_name $process_id & sleep 5
delay_warning_time = 15m
disable_vrfy_command = yes
header_checks = regexp:/etc/postfix/header_checks.regexp
home_mailbox = Maildir/
html_directory = no
ignore_mx_lookup_error = no
inet_interfaces = localhost, inet08.hamilton.harte-lyne.ca
inet_protocols = all
local_transport = smtp
mail_spool_directory = /var/spool/mail
mailman_destination_recipient_limit = 1
mailq_path = /usr/bin/mailq.postfix
manpage_directory = /usr/share/man
message_size_limit = 20480000
milter_default_action = accept
milter_protocol = 2
mydestination =
mynetworks = 216.185.71.0/26, 216.185.71.64/27, 209.47.176.0/26,
    192.168.216.0/24, 192.168.8.0/24, 192.168.7.0/24, 192.168.6.0/24,
    127.0.0.0/8
newaliases_path = /usr/bin/newaliases.postfix
non_smtpd_milters = $smtpd_milters
policyd-spf_time_limit = 3600
queue_minfree = 40960000
rbl_reply_maps = hash:/etc/postfix/rbl_reply
readme_directory = /usr/share/doc/postfix-2.11.1/README_FILES
recipient_delimiter = +
relay_clientcerts = hash:/etc/postfix/relay_clientcerts
relay_domains = hash:/etc/postfix/relay_domains
sample_directory = /usr/share/doc/postfix-2.11.1/samples
sender_canonical_maps = hash:/etc/postfix/canonical
sendmail_path = /usr/sbin/sendmail.postfix
setgid_group = postdrop
smtp_dns_support_level = dnssec
smtp_host_lookup = dns
smtp_tls_CAfile = /etc/pki/tls/certs/ca-bundle.crt
smtp_tls_cert_file = /etc/pki/tls/certs/ca.harte-lyne.smtp.crt
smtp_tls_ciphers = medium
smtp_tls_exclude_ciphers = MD5, aDSS, SRP, PSK, aECDH, aDH, SEED,
IDEA, RC2, RC5
smtp_tls_key_file = /etc/pki/tls/private/ca.harte-lyne.smtp.key
smtp_tls_protocols = !SSLv2, !SSLv3
smtp_tls_security_level = dane
smtp_tls_session_cache_database = btree:/var/lib/postfix/smtp_scache
smtp_tls_session_cache_timeout = 3600s
smtpd_client_restrictions = permit
smtpd_data_restrictions = permit_mynetworks,
reject_multi_recipient_bounce,
    reject_unauth_pipelining, permit
smtpd_helo_required = yes
smtpd_helo_restrictions = permit_mynetworks, check_helo_access
    pcre:/etc/postfix/helo_checks.pcre, reject_non_fqdn_helo_hostname,
    reject_unknown_helo_hostname, permit
smtpd_milters = inet:127.0.0.1:8891
smtpd_proxy_timeout = 300s
smtpd_recipient_restrictions = reject_non_fqdn_recipient,
    reject_unknown_recipient_domain, permit_mynetworks,
    permit_sasl_authenticated, reject_unauth_destination,
    reject_unauth_pipelining, check_policy_service
    unix:/var/spool/postfix/postgrey/socket, check_policy_service
    unix:private/policyd-spf, permit
smtpd_relay_restrictions = permit_mynetworks, permit_sasl_authenticated,
    defer_unauth_destination
smtpd_sasl_auth_enable = yes
smtpd_sasl_path = smtpd
smtpd_sender_restrictions = permit_mynetworks, check_sender_access
    hash:/etc/postfix/sender_access, check_sender_mx_access
    hash:/etc/postfix/sender_mx_access, check_sender_ns_access
    hash:/etc/postfix/sender_ns_access, permit_sasl_authenticated,
    reject_non_fqdn_sender, reject_unknown_sender_domain, permit
smtpd_starttls_timeout = ${stress?10}${stress:120}s
smtpd_timeout = ${stress?10}${stress:120}s
smtpd_tls_CAfile = /etc/pki/tls/certs/ca-bundle.crt
smtpd_tls_ask_ccert = yes
smtpd_tls_auth_only = yes
smtpd_tls_cert_file = /etc/pki/tls/certs/ca.harte-lyne.smtpd.crt
smtpd_tls_ciphers = medium
smtpd_tls_dh1024_param_file = ${config_directory}/dh2048.pem
smtpd_tls_fingerprint_digest = sha1
smtpd_tls_key_file = /etc/pki/tls/private/ca.harte-lyne.smtpd.key
smtpd_tls_protocols = !SSLv2, !SSLv3
smtpd_tls_received_header = yes
smtpd_tls_security_level = may
smtpd_tls_session_cache_database = btree:/var/lib/postfix/smtpd_scache
smtpd_tls_session_cache_timeout = 3600s
soft_bounce = no
strict_rfc821_envelopes = yes
tls_random_source = dev:/dev/urandom
transport_maps = hash:/etc/postfix/transport
unknown_local_recipient_reject_code = 550
virtual_alias_maps = hash:/etc/postfix/virtual,
    regexp:/etc/postfix/virtual.regexp

postconf -Mf
smtp       inet  n       -       n       -       -       smtpd
    -o smtpd_tls_security_level=may
    -o smtpd_proxy_filter=127.0.0.1:10024
    -o smtpd_client_connection_count_limit=10
    -o smtpd_proxy_options=speed_adjust
    -o syslog_name=postfix-p25
submission inet  n       -       n       -       -       smtpd -v
    -o smtpd_tls_security_level=encrypt
    -o smtpd_sasl_auth_enable=yes
    -o
smtpd_client_restrictions=permit_mynetworks,permit_sasl_authenticated,reject
    -o
smtpd_recipient_restrictions=permit_sasl_authenticated,permit_tls_clientcerts,reject_unauth_destination
    -o
smtpd_sender_restrictions=permit_sasl_authenticated,permit_tls_clientcerts,reject
    -o milter_macro_daemon_name=ORIGINATING
    -o syslog_name=postfix-p587
smtps      inet  n       -       n       -       -       smtpd -v
    -o smtpd_tls_wrappermode=yes
    -o smtpd_sasl_auth_enable=yes
    -o smtpd_client_restrictions=permit_sasl_authenticated,reject
    -o
smtpd_recipient_restrictions=permit_sasl_authenticated,permit_tls_clientcerts,reject_unauth_destination
    -o
smtpd_sender_restrictions=permit_sasl_authenticated,permit_tls_clientcerts,reject_unauth_destination
    -o milter_macro_daemon_name=ORIGINATING
    -o syslog_name=postfix-p465
pickup     fifo  n       -       n       60      1       pickup
    -o content_filter=
    -o receive_override_options=no_header_body_checks
cleanup    unix  n       -       n       -       0       cleanup
qmgr       fifo  n       -       n       300     1       qmgr
tlsmgr     unix  -       -       n       1000?   1       tlsmgr
rewrite    unix  -       -       n       -       -       trivial-rewrite
bounce     unix  -       -       n       -       0       bounce
defer      unix  -       -       n       -       0       bounce
trace      unix  -       -       n       -       0       bounce
verify     unix  -       -       n       -       1       verify
flush      unix  n       -       n       1000?   0       flush
proxymap   unix  -       -       n       -       -       proxymap
proxywrite unix  -       -       n       -       1       proxymap
smtp       unix  -       -       n       -       -       smtp
relay      unix  -       -       n       -       -       smtp
    -o smtp_fallback_relay=
showq      unix  n       -       n       -       -       showq
error      unix  -       -       n       -       -       error
retry      unix  -       -       n       -       -       error
discard    unix  -       -       n       -       -       discard
local      unix  -       n       n       -       -       local
virtual    unix  -       n       n       -       -       virtual
lmtp       unix  -       -       n       -       -       lmtp
anvil      unix  -       -       n       -       1       anvil
scache     unix  -       -       n       -       1       scache
mailman    unix  -       n       n       -       -       pipe flags=FR
    user=mailman:mailman
argv=/usr/lib/mailman/postfix/postfix-to-mailman.py
    ${nexthop} ${user}
127.0.0.1:2626 inet n    -       n       -       -       smtpd
    -o smtpd_tls_security_level=none
    -o smtpd_sasl_auth_enable=no
    -o smtpd_client_restrictions=
    -o smtpd_helo_restrictions=
    -o smtpd_sender_restrictions=
    -o smtpd_recipient_restrictions=permit_mynetworks,reject
    -o smtpd_data_restrictions=
    -o milter_macro_daemon_name=ORIGINATING
    -o syslog_name=postfix-p2626
policyd-spf unix y       n       n       -       -       spawn
user=nobody
    argv=/usr/libexec/postfix/policyd-spf
smtp-amavis unix -       -       n       -       6       smtp
    -o smtp_data_done_timeout=1200
    -o smtp_send_xforward_command=yes
    -o disable_dns_lookups=yes
    -o max_use=20
127.0.0.1:10025 inet n   -       n       -       -       smtpd
    -o content_filter=
    -o local_header_rewrite_clients=
    -o local_recipient_maps=
    -o mynetworks=127.0.0.0/8
    -o relay_recipient_maps=
    -o smtpd_client_restrictions=permit_mynetworks,reject
    -o smtpd_delay_reject=no
    -o smtpd_milters=
    -o smtpd_helo_restrictions=
    -o smtpd_sender_restrictions=
    -o smtpd_recipient_restrictions=permit_mynetworks,reject
    -o smtpd_data_restrictions=reject_unauth_pipelining
    -o smtpd_end_of_data_restrictions=
    -o smtpd_restriction_classes=
    -o smtpd_error_sleep_time=0
    -o smtpd_soft_error_limit=1001
    -o smtpd_hard_error_limit=1000
    -o smtpd_client_connection_count_limit=0
    -o smtpd_client_connection_rate_limit=0
    -o
receive_override_options=no_header_body_checks,no_unknown_recipient_checks,no_milters,no_address_mappings






--
***          e-Mail is NOT a SECURE channel          ***
        Do NOT transmit sensitive data via e-Mail
 Do NOT open attachments nor follow links sent by e-Mail

James B. Byrne                mailto:[hidden email]
Harte & Lyne Limited          http://www.harte-lyne.ca
9 Brockley Drive              vox: +1 905 561 1241
Hamilton, Ontario             fax: +1 905 561 0757
Canada  L8E 3C3

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: policyd-spf and temperrors

Viktor Dukhovni

> On Mar 17, 2017, at 11:31 AM, James B. Byrne <[hidden email]> wrote:
>
> mohawkglobalta.com.     1476    IN      TXT     "v=spf1 include:spf.protection.outlook.com ip4:208.33.203.70/31 -all"

Don't forget the lookups needed to process the "include:" clause, and the fact that DNS observations vary with time.

$ dig +short -t txt spf.protection.outlook.com
"v=spf1 ip4:207.46.101.128/26 ip4:207.46.100.0/24 ip4:207.46.163.0/24 ip4:65.55.169.0/24 ip4:157.56.110.0/23 ip4:157.55.234.0/24 ip4:213.199.154.0/24 ip4:213.199.180.0/24 include:spfa.protection.outlook.com -all"

$ dig +short -t txt spfa.protection.outlook.com
"v=spf1 ip4:157.56.112.0/24 ip4:207.46.51.64/26 ip4:157.55.158.0/23 ip4:64.4.22.64/26 ip4:40.92.0.0/14 ip4:40.107.0.0/17 ip4:40.107.128.0/18 ip4:134.170.140.0/24 include:spfb.protection.outlook.com -all"

$ dig +short -t txt spfb.protection.outlook.com
"v=spf1 ip6:2a01:111:f400::/48 ip4:23.103.128.0/19 ip4:23.103.198.0/23 ip4:65.55.88.0/24 ip4:104.47.0.0/17 ip4:23.103.200.0/21 ip4:23.103.208.0/21 ip4:23.103.191.0/24 ip4:216.32.180.0/23 ip4:94.245.120.64/26 -all"

[ These have a 10 minute TTL ]

--
        Viktor.

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: policyd-spf and temperrors

James B. Byrne

On Fri, March 17, 2017 11:41, Viktor Dukhovni wrote:

>
>> On Mar 17, 2017, at 11:31 AM, James B. Byrne <[hidden email]>
>> wrote:
>>
>> mohawkglobalta.com.     1476    IN      TXT     "v=spf1
>> include:spf.protection.outlook.com ip4:208.33.203.70/31 -all"
>
> Don't forget the lookups needed to process the "include:" clause, and
> the fact that DNS observations vary with time.
>
> $ dig +short -t txt spf.protection.outlook.com
> "v=spf1 ip4:207.46.101.128/26 ip4:207.46.100.0/24 ip4:207.46.163.0/24
> ip4:65.55.169.0/24 ip4:157.56.110.0/23 ip4:157.55.234.0/24
> ip4:213.199.154.0/24 ip4:213.199.180.0/24
> include:spfa.protection.outlook.com -all"
>
> $ dig +short -t txt spfa.protection.outlook.com
> "v=spf1 ip4:157.56.112.0/24 ip4:207.46.51.64/26 ip4:157.55.158.0/23
> ip4:64.4.22.64/26 ip4:40.92.0.0/14 ip4:40.107.0.0/17
> ip4:40.107.128.0/18 ip4:134.170.140.0/24
> include:spfb.protection.outlook.com -all"
>
> $ dig +short -t txt spfb.protection.outlook.com
> "v=spf1 ip6:2a01:111:f400::/48 ip4:23.103.128.0/19 ip4:23.103.198.0/23
> ip4:65.55.88.0/24 ip4:104.47.0.0/17 ip4:23.103.200.0/21
> ip4:23.103.208.0/21 ip4:23.103.191.0/24 ip4:216.32.180.0/23
> ip4:94.245.120.64/26 -all"
>
> [ These have a 10 minute TTL ]
>

However, dig lookups performed on these exact domains return virtually
instantaneously on our MX server running spf.  I can set the spf
timeout higher than 20 seconds but I suspect that something else is at
work here.

This Temperror is also affecting these sites and many more:

Mar 17 11:39:47 inet08 policyd-spf[13505]: Temperror; identity=helo;
client-ip=69.89.30.42; helo=gproxy3-pub.mail.unifiedlayer.com;
envelope-from=[hidden email];
receiver=[hidden email]
. . .
Mar 17 11:42:52 inet08 policyd-spf[13032]: Temperror; identity=helo;
client-ip=168.100.1.4; helo=russian-caravan.cloud9.net;
envelope-from=[hidden email];
receiver=[hidden email]
. . .
Mar 17 11:51:36 inet08 policyd-spf[13709]: Temperror; identity=helo;
client-ip=66.135.215.173; helo=mxslcpool71.ebay.com;
envelope-from=[hidden email]; receiver=[hidden email]

They cannot all be suddenly affected by a DNS outage?

(P.S. thecargosolutionscanada.com would fail anyway due to too many
DNS lookups, but it does not get that far in the process.)


--
***          e-Mail is NOT a SECURE channel          ***
        Do NOT transmit sensitive data via e-Mail
 Do NOT open attachments nor follow links sent by e-Mail

James B. Byrne                mailto:[hidden email]
Harte & Lyne Limited          http://www.harte-lyne.ca
9 Brockley Drive              vox: +1 905 561 1241
Hamilton, Ontario             fax: +1 905 561 0757
Canada  L8E 3C3

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: policyd-spf and temperrors

Viktor Dukhovni

> On Mar 17, 2017, at 12:08 PM, James B. Byrne <[hidden email]> wrote:
>
> Mar 17 11:39:47 inet08 policyd-spf[13505]: Temperror; identity=helo;
> client-ip=69.89.30.42; helo=gproxy3-pub.mail.unifiedlayer.com;
> envelope-from=[hidden email];
> receiver=[hidden email]
> . . .
> Mar 17 11:42:52 inet08 policyd-spf[13032]: Temperror; identity=helo;
> client-ip=168.100.1.4; helo=russian-caravan.cloud9.net;
> envelope-from=[hidden email];
> receiver=[hidden email]
> . . .
> Mar 17 11:51:36 inet08 policyd-spf[13709]: Temperror; identity=helo;
> client-ip=66.135.215.173; helo=mxslcpool71.ebay.com;
> envelope-from=[hidden email]; receiver=[hidden email]
>
> They cannot all be suddenly affected by a DNS outage?

Well, just today a notice was posted by the RIPE NCC (see below
my signature) announcing an outage in reverse delegations from
ARIN to RIPE.  It is not clear whether that could contribute to
tempfails in your SPF policy daemon (I'd rather expect spurious
NXDOMAIN results for PTR lookups), but bulk outages can certainly
happen.

Enable more detailed logging in the SPF policy daemon and perhaps
also your resolver.

--
        Viktor.

Dear colleagues,

Between 17:00 UTC yesterday and 10:00 UTC today, we had an issue that
affected some reverse DNS delegations. The delegations in the
RIPE Database where the parent zone is operated by ARIN were affected.

RIPE NCC publishes zonelet files containing these delegations, and these
are picked up by ARIN's DNS provisioning system periodically. At the end
of these zonelet files is a summary of the counts of various types of
DNS records. A bug in our code accidentally published these summaries
with zero counts, and as a result, the ARIN DNS provisioning system
appears to have removed the delegations.

We have corrected this bug, and the zonelet files now contain the
correct counts. They have been published on the RIPE NCC FTP server, and
ARIN's DNS provisioning system has picked them up and reintroduced the
delegations.

We apologise for any inconvenience caused by this. This is the first
time that such an issue has occurred with delegations that are exchanged
by the zonelet mechanism, and we will try to engineer monitoring to
prevent such an outage in the future.

RIPE NCC's delegations in the following ARIN-operated zones were
affected. The majority of the other delegations in these zones come from
ARIN and the other registries, and were not affected.

104.in-addr.arpa.
107.in-addr.arpa.
128.in-addr.arpa.
129.in-addr.arpa.
130.in-addr.arpa.
131.in-addr.arpa.
132.in-addr.arpa.
134.in-addr.arpa.
135.in-addr.arpa.
136.in-addr.arpa.
137.in-addr.arpa.
138.in-addr.arpa.
139.in-addr.arpa.
13.in-addr.arpa.
140.in-addr.arpa.
143.in-addr.arpa.
144.in-addr.arpa.
146.in-addr.arpa.
147.in-addr.arpa.
148.in-addr.arpa.
149.in-addr.arpa.
152.in-addr.arpa.
156.in-addr.arpa.
157.in-addr.arpa.
158.in-addr.arpa.
159.in-addr.arpa.
160.in-addr.arpa.
161.in-addr.arpa.
164.in-addr.arpa.
165.in-addr.arpa.
166.in-addr.arpa.
168.in-addr.arpa.
169.in-addr.arpa.
170.in-addr.arpa.
173.in-addr.arpa.
198.in-addr.arpa.
199.in-addr.arpa.
206.in-addr.arpa.
209.in-addr.arpa.
216.in-addr.arpa.
23.in-addr.arpa.
24.in-addr.arpa.
45.in-addr.arpa.
52.in-addr.arpa.
65.in-addr.arpa.
66.in-addr.arpa.

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: policyd-spf and temperrors

James B. Byrne
In reply to this post by Viktor Dukhovni
I have just noticed this error.  I suspect this points to the root of
our problems.  What does it mean?


Mar 17 12:16:58 inet08 postfix-p25/smtpd[14495]: connect from
russian-caravan.cloud9.net[168.100.1.4]
Mar 17 12:16:59 inet08 postfix-p25/smtpd[14529]: warning: problem
talking to server private/policyd-spf: Connection timed out



--
***          e-Mail is NOT a SECURE channel          ***
        Do NOT transmit sensitive data via e-Mail
 Do NOT open attachments nor follow links sent by e-Mail

James B. Byrne                mailto:[hidden email]
Harte & Lyne Limited          http://www.harte-lyne.ca
9 Brockley Drive              vox: +1 905 561 1241
Hamilton, Ontario             fax: +1 905 561 0757
Canada  L8E 3C3

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: policyd-spf and temperrors

Thomas Leuxner
* James B. Byrne <[hidden email]> 2017.03.17 17:20:

> Mar 17 12:16:58 inet08 postfix-p25/smtpd[14495]: connect from
> russian-caravan.cloud9.net[168.100.1.4]
> Mar 17 12:16:59 inet08 postfix-p25/smtpd[14529]: warning: problem
> talking to server private/policyd-spf: Connection timed out

It means Postfix is unable to communicate with the UNIX socket policy-spf is supposed to listen on.

Regards
Thomas

signature.asc (188 bytes) Download Attachment
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: policyd-spf and temperrors

James B. Byrne
In reply to this post by Viktor Dukhovni
I have also seen this:

Mar 17 12:31:22 inet08 postfix/spawn[14598]: warning: command
/usr/libexec/postfix/policyd-spf exit status 1


However, these message only began to appear yesterday evening.  This
is the first occurrence found in logs going back to February 12:

var/log/maillog:Mar 16 17:15:09 inet08 postfix-p25/smtpd[17270]:
warning: problem talking to server private/policyd-spf: Connection
timed out

Temperrors have apparently being going on forever. Often related to
outbound.protection.outlook.com.  So it is possible that there really
is no problem.  But there are lots of regular correspondents that are
suddenly having this problem delivering their mail to us so I remain
suspicious that we have a problem somewhere in our setup.


--
***          e-Mail is NOT a SECURE channel          ***
        Do NOT transmit sensitive data via e-Mail
 Do NOT open attachments nor follow links sent by e-Mail

James B. Byrne                mailto:[hidden email]
Harte & Lyne Limited          http://www.harte-lyne.ca
9 Brockley Drive              vox: +1 905 561 1241
Hamilton, Ontario             fax: +1 905 561 0757
Canada  L8E 3C3

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: policyd-spf and temperrors

Thomas Leuxner
* James B. Byrne <[hidden email]> 2017.03.17 17:44:

> Mar 17 12:31:22 inet08 postfix/spawn[14598]: warning: command
> /usr/libexec/postfix/policyd-spf exit status 1

It is spawned per mail in my configuration:

$ postconf -nf | grep -A1 private/policyd
    check_policy_service { unix:private/policyd-spf, timeout=10s,
    default_action=DUNNO }

$ postconf -Mf | grep policyd
policyd-spf unix -       n       n       -       0       spawn user=policyd-spf
    argv=/usr/bin/policyd-spf

As its written in Python it depends on a working environment. Any chance this recently has been updated on this machine?

Regards
Thomas

signature.asc (188 bytes) Download Attachment
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: policyd-spf and temperrors

Viktor Dukhovni
In reply to this post by James B. Byrne

> On Mar 17, 2017, at 12:20 PM, James B. Byrne <[hidden email]> wrote:
>
> I have just noticed this error.  I suspect this points to the root of
> our problems.

Not the cause, but a related symptom...

> What does it mean?

DNS lookups in policyd-spf are sufficient slow to not keep up with
demand.  You may need to raise the process limit on the service,
or make sure that it does non-blocking DNS lookups and is willing
to have more outstanding queries...


>
> Mar 17 12:16:58 inet08 postfix-p25/smtpd[14495]: connect from
> russian-caravan.cloud9.net[168.100.1.4]
> Mar 17 12:16:59 inet08 postfix-p25/smtpd[14529]: warning: problem
> talking to server private/policyd-spf: Connection timed out
>

--
        Viktor.

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: policyd-spf and temperrors

Wietse Venema
In reply to this post by Thomas Leuxner
Thomas Leuxner:

Checking application/pgp-signature: FAILURE
-- Start of PGP signed section.
> * James B. Byrne <[hidden email]> 2017.03.17 17:20:
>
> > Mar 17 12:16:58 inet08 postfix-p25/smtpd[14495]: connect from
> > russian-caravan.cloud9.net[168.100.1.4]
> > Mar 17 12:16:59 inet08 postfix-p25/smtpd[14529]: warning: problem
> > talking to server private/policyd-spf: Connection timed out

It times out after 1 second. That seems very short to me, even for
UNIX-domain.

        Wietse
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: policyd-spf and temperrors

Noel Jones-2
On 3/17/2017 1:09 PM, Wietse Venema wrote:

> Thomas Leuxner:
>
> Checking application/pgp-signature: FAILURE
> -- Start of PGP signed section.
>> * James B. Byrne <[hidden email]> 2017.03.17 17:20:
>>
>>> Mar 17 12:16:58 inet08 postfix-p25/smtpd[14495]: connect from
>>> russian-caravan.cloud9.net[168.100.1.4]
>>> Mar 17 12:16:59 inet08 postfix-p25/smtpd[14529]: warning: problem
>>> talking to server private/policyd-spf: Connection timed out
>
> It times out after 1 second. That seems very short to me, even for
> UNIX-domain.
>
> Wietse
>

different process numbers above.


  -- Noel Jones
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: policyd-spf and temperrors

Scott Kitterman-4
In reply to this post by James B. Byrne


On March 17, 2017 12:20:11 PM EDT, "James B. Byrne" <[hidden email]> wrote:
>I have just noticed this error.  I suspect this points to the root of
>our problems.  What does it mean?
>
>
>Mar 17 12:16:58 inet08 postfix-p25/smtpd[14495]: connect from
>russian-caravan.cloud9.net[168.100.1.4]
>Mar 17 12:16:59 inet08 postfix-p25/smtpd[14529]: warning: problem
>talking to server private/policyd-spf: Connection timed out

You didn't say what version of the policy server you are running.  There was a design issue that caused it to make multiple, sequential lookups of the same domain.  Depending on how fast your DNS is and the configuration, it could cause these kinds of problems.

I reworked all that in version 2.0.  If you are running an earlier version, upgrading will likely help.

You also didn't mention if there's a caching resolver on the server.  That would also help since the redundant lookups would at least hit the local cache.

You can ask questions or file bugs specific to this policy server at https://launchpad.net/pypolicyd-spf

Scott K
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: policyd-spf and temperrors

James B. Byrne
On Fri, March 17, 2017 16:49, Scott Kitterman wrote:

>
>
> On March 17, 2017 12:20:11 PM EDT, "James B. Byrne"
> <[hidden email]> wrote:
>>I have just noticed this error.  I suspect this points to the root of
>>our problems.  What does it mean?
>>
>>
>>Mar 17 12:16:58 inet08 postfix-p25/smtpd[14495]: connect from
>>russian-caravan.cloud9.net[168.100.1.4]
>>Mar 17 12:16:59 inet08 postfix-p25/smtpd[14529]: warning: problem
>>talking to server private/policyd-spf: Connection timed out
>
> You didn't say what version of the policy server you are running.
> There was a design issue that caused it to make multiple, sequential
> lookups of the same domain.  Depending on how fast your DNS is and the
> configuration, it could cause these kinds of problems.
>
> I reworked all that in version 2.0.  If you are running an earlier
> version, upgrading will likely help.
>
> You also didn't mention if there's a caching resolver on the server.
> That would also help since the redundant lookups would at least hit
> the local cache.
>
> You can ask questions or file bugs specific to this policy server at
> https://launchpad.net/pypolicyd-spf
>
> Scott K
>

Installed Packages
Name        : pypolicyd-spf
Arch        : noarch
Version     : 1.3.2
Release     : 1.el6
Size        : 106 k
Repo        : installed
From repo   : epel
Summary     : SPF Policy Server for Postfix (Python implementation)
URL         : https://launchpad.net/pypolicyd-spf
License     : ASL 2.0

We currently run a DNS service on that host.  It is operating
correctly as far as I can see.

In the meantime I have had to disable SPF checking entirely as it was
preventing the delivery of any mail whatsoever.

--
***          e-Mail is NOT a SECURE channel          ***
        Do NOT transmit sensitive data via e-Mail
 Do NOT open attachments nor follow links sent by e-Mail

James B. Byrne                mailto:[hidden email]
Harte & Lyne Limited          http://www.harte-lyne.ca
9 Brockley Drive              vox: +1 905 561 1241
Hamilton, Ontario             fax: +1 905 561 0757
Canada  L8E 3C3

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: policyd-spf and temperrors

James B. Byrne
In reply to this post by Thomas Leuxner

On Fri, March 17, 2017 12:57, Thomas Leuxner wrote:

> * James B. Byrne <[hidden email]> 2017.03.17 17:44:
>
>> Mar 17 12:31:22 inet08 postfix/spawn[14598]: warning: command
>> /usr/libexec/postfix/policyd-spf exit status 1
>
> It is spawned per mail in my configuration:
>
> $ postconf -nf | grep -A1 private/policyd
>     check_policy_service { unix:private/policyd-spf, timeout=10s,
>     default_action=DUNNO }
>
> $ postconf -Mf | grep policyd
> policyd-spf unix -       n       n       -       0       spawn
> user=policyd-spf
>     argv=/usr/bin/policyd-spf
>
> As its written in Python it depends on a working environment. Any
> chance this recently has been updated on this machine?
>
> Regards
> Thomas
>

The host system runs under CentOS-6.  Other than Postfix itself all
the packages on this system are either from CentOS or EPEL.  Python
was last updated in September 2016.  pypolicd-spf was last updated
January 2017.  These problems only evidenced themselves very recently:

[root@inet08 ~]# ll  /var/log/maillog*
-rw-------. 1 root root 53522676 Mar 17 17:27 /var/log/maillog
-rw-------. 1 root root 40029710 Feb 19 03:10 /var/log/maillog-20170219
-rw-------. 1 root root 53658030 Feb 26 03:45 /var/log/maillog-20170226
-rw-------. 1 root root 53710015 Mar  5 03:32 /var/log/maillog-20170305
-rw-------. 1 root root 48568993 Mar 12 03:39 /var/log/maillog-20170312

[root@inet08 ~]# grep Temperror /var/log/maillog-20170219 | wc -l
187
[root@inet08 ~]# grep Temperror /var/log/maillog-20170226 | wc -l
72
[root@inet08 ~]# grep Temperror /var/log/maillog-20170305 | wc -l
107
[root@inet08 ~]# grep Temperror /var/log/maillog-20170312 | wc -l
134
[root@inet08 ~]# grep Temperror /var/log/maillog | wc -l
11615

The issue was first noticed yesterday. but appears to have started on
the 15th.

[root@inet08 ~]# grep Temperror /var/log/maillog | grep 'Mar 12' | wc -l
2
[root@inet08 ~]# grep Temperror /var/log/maillog | grep 'Mar 13' | wc -l
3
[root@inet08 ~]# grep Temperror /var/log/maillog | grep 'Mar 14' | wc -l
4
[root@inet08 ~]# grep Temperror /var/log/maillog | grep 'Mar 15' | wc -l
1516
[root@inet08 ~]# grep Temperror /var/log/maillog | grep 'Mar 16' | wc -l
3696
[root@inet08 ~]# grep Temperror /var/log/maillog | grep 'Mar 17' | wc -l
6394

Moving to the most recent version of pypolicyd-spf requires upgrading
python.  Since the YUM package manager on CentOS-6 requires python 2.6
this is a non-starter.

We are in the process of moving off Linux to FreeBSD in any case.  I
will spin up a BHyve FreeBSD instance for Postfix and migrate our MX
address to the new server.  So much for the weekend.


--
***          e-Mail is NOT a SECURE channel          ***
        Do NOT transmit sensitive data via e-Mail
 Do NOT open attachments nor follow links sent by e-Mail

James B. Byrne                mailto:[hidden email]
Harte & Lyne Limited          http://www.harte-lyne.ca
9 Brockley Drive              vox: +1 905 561 1241
Hamilton, Ontario             fax: +1 905 561 0757
Canada  L8E 3C3

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: policyd-spf and temperrors

Alex JOST-2
Am 17.03.2017 um 22:38 schrieb James B. Byrne:
> The host system runs under CentOS-6.  Other than Postfix itself all
> the packages on this system are either from CentOS or EPEL.  Python
> was last updated in September 2016.  pypolicd-spf was last updated
> January 2017.  These problems only evidenced themselves very recently:

> Moving to the most recent version of pypolicyd-spf requires upgrading
> python.  Since the YUM package manager on CentOS-6 requires python 2.6
> this is a non-starter.

AFAIK Red Hat provides a newer version of python via Software
Collections. That should make it easy to run both versions side by side.

--
Alex JOST
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: policyd-spf and temperrors

Scott Kitterman-4


On March 18, 2017 6:13:15 AM EDT, Alex JOST <[hidden email]> wrote:

>Am 17.03.2017 um 22:38 schrieb James B. Byrne:
>> The host system runs under CentOS-6.  Other than Postfix itself all
>> the packages on this system are either from CentOS or EPEL.  Python
>> was last updated in September 2016.  pypolicd-spf was last updated
>> January 2017.  These problems only evidenced themselves very
>recently:
>
>> Moving to the most recent version of pypolicyd-spf requires upgrading
>> python.  Since the YUM package manager on CentOS-6 requires python
>2.6
>> this is a non-starter.
>
>AFAIK Red Hat provides a newer version of python via Software
>Collections. That should make it easy to run both versions side by
>side.

The new version needs python3, FYI.

Scott K
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: policyd-spf and temperrors

Alex JOST-2
Am 18.03.2017 um 13:42 schrieb Scott Kitterman:

> On March 18, 2017 6:13:15 AM EDT, Alex JOST <[hidden email]> wrote:
>> Am 17.03.2017 um 22:38 schrieb James B. Byrne:
>>> The host system runs under CentOS-6.  Other than Postfix itself all
>>> the packages on this system are either from CentOS or EPEL.  Python
>>> was last updated in September 2016.  pypolicd-spf was last updated
>>> January 2017.  These problems only evidenced themselves very
>> recently:
>>
>>> Moving to the most recent version of pypolicyd-spf requires upgrading
>>> python.  Since the YUM package manager on CentOS-6 requires python
>> 2.6
>>> this is a non-starter.
>>
>> AFAIK Red Hat provides a newer version of python via Software
>> Collections. That should make it easy to run both versions side by
>> side.
>
> The new version needs python3, FYI.

Python 3.4.2 is available for CentOS 7.

See: https://wiki.centos.org/SpecialInterestGroup/SCLo/CollectionsList

--
Alex JOST
Loading...