[opendmarc-users] Deployment problems with Postfix + pypolicyd-spf + OpenDKIM
Nic Bernstein
nic at onlight.com
Fri Aug 16 14:42:07 PDT 2013
Folks,
We are attempting to deploy opendmarc(1.1.3) for receiving, with Postfix
(2.9.2), pypolicyd-spf(1.2) and OpenDKIM(2.6.8). We are getting mixed
results, in that while we do see the proper Authentication-Results
headers in our messages, opendmarc seems not to see the SPF headers.
Here is a sample from a recent test message:
Authentication-Results: smtp.onlight.com; spf=pass (sender SPF authorized) smtp.mailfrom=gmail.com (client-ip=209.85.212.68; helo=mail-vb0-f68.google.com; envelope-from=nb1onlight at gmail.com; receiver=nic at onlight.com)
Authentication-Results: smtp.onlight.com; dkim=pass
reason="2048-bit key; insecure key"
header.d=gmail.com header.i=@gmail.com header.b=gzXzLLLE;
dkim-adsp=pass; dkim-atps=neutral
<...>
Authentication-Results: ujiji.onlight.com/E85322025F; dmarc=pass header.from=gmail.com
However, in the history file we see this:
job E85322025F
reporter smtp.onlight.com
received 1376684253
ipaddr 209.85.212.68
from gmail.com
mfrom gmail.com
dkim gmail.com 0
spf -1
pdomain gmail.com
policy 15
rua mailto:mailauth-reports at google.com
pct 100
adkim 114
aspf 114
p 110
sp 0
align_dkim 4
align_spf 5
action 2
We have postfix configured like so:
/etc/postfix/main.cf:
smtpd_recipient_restrictions = permit_sasl_authenticated,
permit_mynetworks,
reject_unknown_recipient_domain,
reject_unauth_pipelining,
reject_unauth_destination,
check_policy_service unix:private/policyd-spf,
permit_auth_destination,
reject
smtpd_milters = unix:/var/run/opendkim/opendkim.sock
unix:/var/run/opendmarc/opendmarc.sock
/etc/postfix/master.cf:
policyd-spf unix - n n - 0 spawn
user=nobody argv=/usr/bin/policyd-spf
Yet it appears that the Authentication-Results header from pypolicyd-spf
is not in the message when it is processed by opendmarc. We turned on
full debugging in pypolicyd-spf, and added some debugging to mlfi_eom in
an effort to see what's going on, but while we do see the opendkim
headers being processed (result_method=1,5,7), we do not see the
SPF(result_method=4) stuff at all. It appears we're not even entering
the "if (ar.ares_result[c].result_method == ARES_METHOD_SPF)" section
of mlfi_eom(), even though pypolicyd-spf appears to be prepending the
proper header, and we do see that header in the final email:
Aug 16 15:17:26 ujiji postfix/postscreen[10307]: CONNECT from
[209.85.212.68]:57743 to [10.10.1.25]:25
Aug 16 15:17:32 ujiji postfix/postscreen[10307]: PASS NEW
[209.85.212.68]:57743
Aug 16 15:17:32 ujiji postfix/smtpd[10308]: connect from
mail-vb0-f68.google.com[209.85.212.68]
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line:
"request=smtpd_access_policy"
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line:
"protocol_state=RCPT"
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line:
"protocol_name=ESMTP"
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line:
"client_address=209.85.212.68"
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line:
"client_name=mail-vb0-f68.google.com"
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line:
"reverse_client_name=mail-vb0-f68.google.com"
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line:
"helo_name=mail-vb0-f68.google.com"
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line:
"sender=nb1onlight at gmail.com"
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line:
"recipient=nic at onlight.com"
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line: "recipient_count=0"
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line: "queue_id="
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line:
"instance=2844.520e88dc.c27e5.0"
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line: "size=0"
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line: "etrn_domain="
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line: "stress="
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line: "sasl_method="
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line: "sasl_username="
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line: "sasl_sender="
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line: "ccert_subject="
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line: "ccert_issuer="
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line:
"ccert_fingerprint="
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line:
"ccert_pubkey_fingerprint="
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line:
"encryption_protocol=TLSv1"
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line:
"encryption_cipher=RC4-SHA"
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line:
"encryption_keysize=128"
Aug 16 15:17:32 ujiji policyd-spf[10329]: Read line: ""
Aug 16 15:17:32 ujiji policyd-spf[10329]: Found the end of entry
Aug 16 15:17:32 ujiji policyd-spf[10329]: Config:
{'Mail_From_reject': 'Fail', 'Header_Type': 'AR', 'Whitelist':
'10.10.1.0/24,10.8.0.0/24', 'PermError_reject': 'False',
'HELO_reject': 'SPF_Not_Pass', 'Authserv_Id': 'smtp.onlight.com',
'defaultSeedOnly': 1, 'debugLevel': 9, 'skip_addresses':
'127.0.0.0/8,::ffff:127.0.0.0/104,::1', 'TempError_Defer': 'False'}
Aug 16 15:17:32 ujiji policyd-spf[10329]: Cached data for this
instance: []
Aug 16 15:17:32 ujiji policyd-spf[10329]: spfcheck: pyspf result:
"['None', '', 'helo']"
Aug 16 15:17:32 ujiji policyd-spf[10329]: None; identity=helo;
client-ip=209.85.212.68; helo=mail-vb0-f68.google.com;
envelope-from=nb1onlight at gmail.com; receiver=nic at onlight.com
Aug 16 15:17:32 ujiji policyd-spf[10329]: spfcheck: pyspf result:
"['Pass', 'sender SPF authorized', 'mailfrom']"
Aug 16 15:17:32 ujiji policyd-spf[10329]: Pass; identity=mailfrom;
client-ip=209.85.212.68; helo=mail-vb0-f68.google.com;
envelope-from=nb1onlight at gmail.com; receiver=nic at onlight.com
Aug 16 15:17:32 ujiji policyd-spf[10329]: Action: prepend: Text:
Authentication-Results: smtp.onlight.com; spf=pass (sender SPF
authorized) smtp.mailfrom=gmail.com (client-ip=209.85.212.68;
helo=mail-vb0-f68.google.com; envelope-from=nb1onlight at gmail.com;
receiver=nic at onlight.com)
Aug 16 15:17:32 ujiji postfix/smtpd[10308]: E85322025F:
client=mail-vb0-f68.google.com[209.85.212.68]
Aug 16 15:17:33 ujiji postfix/cleanup[10349]: E85322025F:
message-id=<CAAUC_Hbtw3iQGDKNDuZ+g71Umh_bFzZDkR0XRyBNWWUp7COqVw at mail.gmail.com>
Aug 16 15:17:33 ujiji opendmarc[9419]: mlfi_eom: entered
Aug 16 15:17:33 ujiji opendmarc[8186]: mlfi_eom:
hdr_name=Authentication-Results
Aug 16 15:17:33 ujiji opendmarc[8186]: mlfi_eom: hdr_name=Received
Aug 16 15:17:33 ujiji opendmarc[8186]: mlfi_eom: hdr_name=DKIM-Signature
Aug 16 15:17:33 ujiji opendmarc[8186]: mlfi_eom:
hdr_name=DomainKey-Signature
Aug 16 15:17:33 ujiji opendmarc[8186]: mlfi_eom: hdr_name=Received
Aug 16 15:17:33 ujiji opendmarc[8186]: mlfi_eom: hdr_name=Subject
Aug 16 15:17:33 ujiji opendmarc[8186]: mlfi_eom: hdr_name=From
Aug 16 15:17:33 ujiji opendmarc[8186]: mlfi_eom: hdr_name=Reply-To
Aug 16 15:17:33 ujiji opendmarc[8186]: mlfi_eom: hdr_name=To
Aug 16 15:17:33 ujiji opendmarc[8186]: mlfi_eom: hdr_name=Date
Aug 16 15:17:33 ujiji opendmarc[8186]: mlfi_eom: hdr_name=Message-ID
Aug 16 15:17:33 ujiji opendmarc[8186]: mlfi_eom: hdr_name=X-Mailer
Aug 16 15:17:33 ujiji opendmarc[8186]: mlfi_eom: hdr_name=X-Campaign
Aug 16 15:17:33 ujiji opendmarc[8186]: mlfi_eom: hdr_name=X-campaignid
Aug 16 15:17:33 ujiji opendmarc[8186]: mlfi_eom: hdr_name=X-Report-Abuse
Aug 16 15:17:33 ujiji opendmarc[8186]: mlfi_eom: hdr_name=X-MC-User
Aug 16 15:17:33 ujiji opendmarc[8186]: mlfi_eom: hdr_name=x-accounttype
Aug 16 15:17:33 ujiji opendmarc[8186]: mlfi_eom:
hdr_name=List-Unsubscribe
Aug 16 15:17:33 ujiji opendmarc[8186]: mlfi_eom: hdr_name=Sender
Aug 16 15:17:33 ujiji opendmarc[8186]: mlfi_eom: hdr_name=x-mcda
Aug 16 15:17:33 ujiji opendmarc[8186]: mlfi_eom: hdr_name=Content-Type
Aug 16 15:17:33 ujiji opendmarc[8186]: mlfi_eom: hdr_name=MIME-Version
Aug 16 15:17:33 ujiji opendmarc[9419]: mlfi_eom: c=0 result_method=1
result_result=0
Aug 16 15:17:33 ujiji opendmarc[9419]: mlfi_eom: c=1 result_method=5
result_result=0
Aug 16 15:17:33 ujiji opendmarc[9419]: mlfi_eom: c=2 result_method=7
result_result=3
Aug 16 15:17:33 ujiji opendmarc[9419]: E85322025F: gmail.com pass
Aug 16 15:17:33 ujiji postfix/qmgr[9995]: E85322025F:
from=<nb1onlight at gmail.com>, size=1964, nrcpt=1 (queue active)
Anyone have any thoughts? It seems as though the milters are getting
the message before the policy daemon, and yet the logs would appear to
say otherwise (and they should get it after).
Any guidance would be greatly appreciated.
Best regards,
-nic
--
Nic Bernstein nic at onlight.com
Onlight, Inc. www.onlight.com
219 N. Milwaukee St., Suite 2a v. 414.272.4477
Milwaukee, Wisconsin 53202
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.trusteddomain.org/pipermail/opendmarc-users/attachments/20130816/da692e0c/attachment.htm>
More information about the opendmarc-users
mailing list