Skip to content

[BUG] opendmarc rejects mails that should be passed (SPF) #3078

@ap-wtioit

Description

@ap-wtioit

Miscellaneous first checks

  • I checked that all ports are open and not blocked by my ISP / hosting provider.
  • I know that SSL errors are likely the result of a wrong setup on the user side and not caused by DMS itself. I'm confident my setup is correct.

Affected Component(s)

opendmarc, policyd-spf

What happened and when does this occur?

When using certain local parts (discovered when servers using SRS tried to send us mails), the combination of policyd-spf and opendmarc rejects mails that should have passed DMARC checks.

e.g. a mail from `[email protected]` cannot be received with docker-mailserver when external.tld has DMARC (_dmarc.external.tld) enabled.

What did you expect to happen?

The email should be accepted by docker-mailserver.

How do we replicate the issue?

1. send an email from `[email protected]` with a dmarc enabled domain to docker-mailserver

DMS version

11.3.1

What operating system is DMS running on?

Linux

Which operating system version?

Ubuntu 22.04 LTS (local dev), Debian 10 (prod)

What instruction set architecture is DMS running on?

AMD64 / x86_64

What container orchestration tool are you using?

Docker Compose

docker-compose.yml

version: "2.4"
services:
  mail:
    image: "${CI_REGISTRY_IMAGE}:${IMAGE_VERSION}"
    build:
      dockerfile: Dockerfile
      context: .
      args:
        CI_JOB_TOKEN: "${CI_JOB_TOKEN}"
    hostname: "mail"
    domainname: "redacted.domain.tld"
    container_name: "mail"
    ports:
      # allow receiving emails for configured addresses from the world
      - "25:25"
      # attention only bind munin-node to internal ip addresses (allows connections from everywhere)
      - "redacted_ipv4:4950:4949"
      # bind sending email ports only to internal ip addresses
      - "redacted_ipv4:465:465" # SSL Client email submission
      - "redacted_ipv4:587:587" # TLS Client email submission
    volumes:
      - maildata:/var/mail
      - mailstate:/var/mail-state
      - maillogs:/var/log/mail
      - filebeat:/var/lib/filebeat
      - ./config/:/tmp/docker-mailserver/
    cap_add:
      - NET_ADMIN
    restart: unless-stopped
    environment:
      - ENABLE_SPAMASSASSIN=0
      - ENABLE_CLAMAV=0
      - ENABLE_FAIL2BAN=1
      - ENABLE_POSTGREY=0
      - ONE_DIR=1
      - DMS_DEBUG=0
      - LOG_LEVEL=info
      - HOSTNAME=redacted.domain.tld
      - SSL_TYPE=self-signed
      # forward log files to graylog
      - ENABLE_ELK_FORWARDER=1
      - ELK_HOST=other_redacted_ipv4
      - ELK_PORT=5044

volumes:
  maildata:
    driver: local
  mailstate:
    driver: local
  maillogs:
    driver: local
  filebeat:
    driver: local

Relevant log output

log output with devel dns to show dns requests for _dmarc and SPF (TXT)

mail_1        | Feb  9 10:13:05 redacted-hostname postfix/postscreen[1321]: CONNECT from [172.16.20.68]:60190 to [172.16.20.67]:25
mail_1        | Feb  9 10:13:11 redacted-hostname postfix/postscreen[1321]: PASS NEW [172.16.20.68]:60190
docker_dns_1  | 09-Feb-2023 10:13:11.447 queries: info: client @0x7f820fe3b000 172.16.20.67#32785 (68.20.16.172.in-addr.arpa): query: 68.20.16.172.in-addr.arpa IN PTR +E(0) (172.16.20.66)
docker_dns_1  | 09-Feb-2023 10:13:11.447 queries: info: client @0x7f820e68c000 172.16.20.67#36177 (client.external.tld): query: client.external.tld IN A +E(0) (172.16.20.66)
mail_1        | Feb  9 10:13:11 redacted-hostname postfix/smtpd[1343]: connect from client.external.tld[172.16.20.68]
docker_dns_1  | 09-Feb-2023 10:13:11.467 queries: info: client @0x7f820ee6c000 172.16.20.67#34497 (external.tld): query: external.tld IN MX + (172.16.20.66)
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Starting
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "request=smtpd_access_policy"
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "protocol_state=RCPT"
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "protocol_name=ESMTP"
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "client_address=172.16.20.68"
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "client_name=client.external.tld"
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "client_port=60190"
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "reverse_client_name=client.external.tld"
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "server_address=172.16.20.67"
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "server_port=25"
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "helo_name=client.external.tld"
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "[email protected]"
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "[email protected]"
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "recipient_count=0"
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "queue_id="
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "instance=53f.63e4c737.7363a.0"
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "size=0"
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "etrn_domain="
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "stress="
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "sasl_method="
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "sasl_username="
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "sasl_sender="
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "ccert_subject="
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "ccert_issuer="
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "ccert_fingerprint="
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "ccert_pubkey_fingerprint="
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "encryption_protocol="
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "encryption_cipher="
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "encryption_keysize=0"
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: "policy_context="
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Read line: ""
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Found the end of entry
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Config: {'debugLevel': 5, 'HELO_reject': 'Fail', 'Mail_From_reject': 'Fail', 'PermError_reject': 'False', 'TempError_Defer': 'False', 'skip_addresses': '127.0.0.0/8,::ffff:127.0.0.0/104,::1', 'TestOnly': 1, 'SPF_Enhanced_Status_Codes': 'Yes', 'Header_Type': 'SPF', 'Hide_Receiver': 'Yes', 'Authserv_Id': 'redacted-hostname', 'Lookup_Time': 20, 'Whitelist_Lookup_Time': 10, 'Void_Limit': 2, 'Reason_Message': 'Message {rejectdefer} due to: {spf}.', 'No_Mail': False, 'Mock': False, 'Socket': 'local:/run/pyspf-milter/pyspf-milter.sock', 'PidFile': '/run/pyspf-milter/pyspf-milter.pid', 'UserID': 'pyspf-milter', 'UMask': 7, 'InternalHosts': '127.0.0.1', 'IntHosts': False, 'MacroListVerify': ''}
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Cached data for this instance: []
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: skip_addresses enabled.
docker_dns_1  | 09-Feb-2023 10:13:11.503 queries: info: client @0x7f820d86e000 172.16.20.67#46621 (client.external.tld): query: client.external.tld IN TXT +E(0) (172.16.20.66)
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: _get_resultcodes: scope: helo, Reject_Not_Pass_Domains: None, helo_policy: Fail, mfrom_policy: Fail
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Scope helo unused results: ['Pass', 'None', 'Neutral', 'Softfail', 'Temperror', 'Permerror']
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: helo policy true results: actions: {'defer': [], 'reject': ['Fail'], 'prepend': ['Pass', 'None', 'Neutral', 'Softfail', 'Temperror', 'Permerror']} local {'local_helo': False, 'local_mfrom': False}
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: spfcheck: pyspf result: "['None', '', 'helo']"
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: None; identity=helo; client-ip=172.16.20.68; helo=client.external.tld; [email protected]; receiver=<UNKNOWN> 
docker_dns_1  | 09-Feb-2023 10:13:11.503 queries: info: client @0x7f820e26c000 172.16.20.67#45867 (external.tld): query: external.tld IN TXT +E(0) (172.16.20.66)
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: _get_resultcodes: scope: mfrom, Reject_Not_Pass_Domains: None, helo_policy: Fail, mfrom_policy: Fail
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Scope mfrom unused results: ['Pass', 'None', 'Neutral', 'Softfail', 'Temperror', 'Permerror']
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: mfrom policy true results: actions: {'defer': [], 'reject': ['Fail'], 'prepend': ['Pass', 'None', 'Neutral', 'Softfail', 'Temperror', 'Permerror']} local {'local_helo': False, 'local_mfrom': False}
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: spfcheck: pyspf result: "['Pass', 'sender SPF authorized', 'mailfrom']"
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Pass; identity=mailfrom; client-ip=172.16.20.68; helo=client.external.tld; [email protected]; receiver=<UNKNOWN> 
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: not peruser
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: Action: prepend: Text: Received-SPF: Pass (mailfrom) identity=mailfrom; client-ip=172.16.20.68; helo=client.external.tld; [email protected]; receiver=<UNKNOWN>  Reject action: 550 5.7.23
mail_1        | Feb  9 10:13:11 redacted-hostname policyd-spf[1352]: prepend Received-SPF: Pass (mailfrom) identity=mailfrom; client-ip=172.16.20.68; helo=client.external.tld; [email protected]; receiver=<UNKNOWN> 
mail_1        | Feb  9 10:13:11 redacted-hostname dovecot: auth: passwd-file([email protected]): unknown user 
mail_1        | Feb  9 10:13:11 redacted-hostname postfix/smtpd[1343]: 7E4E32D85919: client=client.external.tld[172.16.20.68]
mail_1        | Feb  9 10:13:11 redacted-hostname postfix/cleanup[1354]: 7E4E32D85919: message-id=<>
docker_dns_1  | 09-Feb-2023 10:13:11.559 queries: info: client @0x7f8248268000 172.16.20.67#55921 (_dmarc.external.tld): query: _dmarc.external.tld IN TXT +E(0)D (172.16.20.66)
mail_1        | Feb  9 10:13:11 redacted-hostname opendmarc[823]: 7E4E32D85919: external.tld fail
mail_1        | Feb  9 10:13:11 redacted-hostname postfix/cleanup[1354]: 7E4E32D85919: milter-reject: END-OF-MESSAGE from client.external.tld[172.16.20.68]: 5.7.1 rejected by DMARC policy for external.tld; from=<[email protected]> to=<[email protected]> proto=ESMTP helo=<client.external.tld>
mail_1        | Feb  9 10:13:11 redacted-hostname postfix/smtpd[1343]: disconnect from client.external.tld[172.16.20.68] ehlo=1 mail=1 rcpt=1 data=0/1 quit=1 commands=4/5

Other relevant information

We found the following workaround:
user-patches.sh:

echo "SPFIgnoreResults true" >> /etc/opendmarc.conf
echo "SPFSelfValidate true" >> /etc/opendmarc.conf

it seems to happen since #2933 but it looks like this only made it appear and the underlying issue existed before.

not sure if the issue is related to the discussion in trusteddomainproject/OpenDMARC#158

bind9 config during the test shown in the log output

; BIND reverse data file for external.tld
;
;
$TTL	86400
@	IN	SOA	ns1.external.tld. redacted\.redacted.redacted.domain.tld. (
			      4		; Serial, increment on changes
			 604800		; Refresh
			  86400		; Retry
			2419200		; Expire
			  86400 )	; Negative Cache TTL
;
;@	IN	NS	localhost.
; name servers - NS records
	IN	NS	ns1.external.tld.

ns1.external.tld.	IN	A	172.16.20.66

external.tld.	IN	MX	10 mail.external.tld.
mail.external.tld.	IN	A	172.16.20.67
client.external.tld.	IN	A	172.16.20.68

_dmarc.external.tld.	IN	CNAME	dmarcreject.external.tld.
dmarcreject.external.tld.	IN	TXT	"v=DMARC1;p=reject;pct=100;fo=1;rua=mailto:[email protected];ruf=mailto:[email protected]"
external.tld.	IN	TXT	"v=spf1 ip4:172.16.0.0/12 ~all"

testing.com "acts" as our test mailserver domain (additional to redacted.domain.tld) and the following relevant accounts/emails where defined in tests:

./setup.sh email add "[email protected]" redactedtestpassword
./setup.sh alias add [email protected] root@localhost
echo '/^postmaster@(subdomain\.)?domain\.tld$/     [email protected]'

What level of experience do you have with Docker and mail servers?

  • I am inexperienced with docker
  • I am rather experienced with docker
  • I am inexperienced with mail servers
  • I am rather experienced with mail servers
  • I am uncomfortable with the CLI
  • I am rather comfortable with the CLI

Code of conduct

Improvements to this form?

No response
Edit: make it clear in the form where inputs will be surronded with

```
input
```

Edit2: fixed the link to the OpenDMARC issue

Metadata

Metadata

Assignees

Labels

bug/confirmedA bug report whose bug is confirmedbug/no solution proposedA bug report, whose bug is confirmed, but no solution was proposed yetkind/bug/reportA report about a bugmeta/closed due to age or inactivityThis issue / PR has been closed due to inactivitymeta/staleThis issue / PR has become stale and will be closed if there is no further activitypriority/medium

Type

No type

Projects

Status

Done

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions