1 Topic by reelr

  • reelr
  • reelr
  • Member
  • Offline
  • Registered: 2020-12-04
  • Posts: 3

Topic: Incoming SPF check not working

==== REQUIRED BASIC INFO OF YOUR IREDMAIL SERVER ====
- iRedMail version (check /etc/iredmail-release): 1.4.0 MARIADB edition.
- Deployed with iRedMail Easy or the downloadable installer? downloadable installer
- Linux/BSD distribution name and version: Ubuntu 20.04.2 LTS
- Store mail accounts in which backend (LDAP/MySQL/PGSQL): MySQL
- Web server (Apache or Nginx): Nginx
- Manage mail accounts with iRedAdmin-Pro? Yes
- [IMPORTANT] Related original log or error message is required if you're experiencing an issue.
====

Hi,

Recently we received emails message from external server to our iRedMail (iRedAdmin-Pro) server that would musn't pass SPF check.

The From address and To address were the same and corresponds to a real user of our server, and the SPF record of that domain do not permit the remote server IP address.

Obviously, the messages are spam. This kind of message must  be rejected due SPF policy. Then, why has passed and delivered to the recipient?

Best regards,

This is the header of the message received: The IP 5.53.124.135 do not pass SPF for topfranquicias.es.

-------------------------------------------------------------------------------
Received: from mail1.reelr.es ([127.0.0.1])
    by mail1.reelr.es (mail1.reelr.es [127.0.0.1]) (amavisd-new, port 10024)
    with ESMTP id HbWYx2DCiuwM for <user1@topfranquicias.es>;
    Thu,  6 May 2021 04:30:48 +0000 (UTC)
Received: from pva.com (unknown [5.53.124.135])
    by mail1.reelr.es (Postfix) with ESMTP id 4FbLHD0tRQz1xqG
    for <user1@topfranquicias.es>; Thu,  6 May 2021 04:30:48 +0000 (UTC)
Received: by pva.com (Postfix, from userid 33)
    id C65AC99E3D; Thu,  6 May 2021 03:37:54 +0000 (UTC)
Received: from mail1.reelr.es (localhost [127.0.0.1])
    by mail1.reelr.es (Postfix) with ESMTP id 4FbLHD5Bs7z1xtk
    for <user1@topfranquicias.es>; Thu,  6 May 2021 04:30:48 +0000 (UTC)
From: <user1@topfranquicias.es>
To: <user1@topfranquicias.es>
Subject: Malas noticias para ti
Date: Thu, 6 May 2021 05:37:54 +0200
Message-ID: <f7df46bde5dad97f14e637826f5908ad@5.53.124.135>
MIME-Version: 1.0
Content-Type: text/plain;
    charset="utf-8"
Content-Transfer-Encoding: quoted-printable
X-Mailer: Microsoft Outlook 16.0
Thread-Index: AQGBv53JDyV2iLGoE/Ctk8Ju7OHm7w==
-------------------------------------------------------------------------------

----

Spider Email Archiver: On-Premises, lightweight email archiving software developed by iRedMail team. Supports Amazon S3 compatible storage and custom branding.

2 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 31,082

Re: Incoming SPF check not working

- Did you disable Amavisd-new integration in Postfix? Please show us command output: "postconf content_filter".
- Please show us log lines related to this message in Postfix log file?

3 Reply by reelr

  • reelr
  • reelr
  • Member
  • Offline
  • Registered: 2020-12-04
  • Posts: 3

Re: Incoming SPF check not working

- Did you disable Amavisd-new integration in Postfix? No.
- Please show us command output: "postconf content_filter". content_filter = smtp-amavis:[127.0.0.1]:10024
- Please show us log lines related to this message in Postfix log file?

I found this in Postfix log:
May  6 06:09:46 mail1 postfix/smtpd[3668427]: warning: hostname dm22ws9fd5giw34a.com does not resolve to address 5.53.124.135: Name or service not known

Shouldn't the server reject this connection due to an unresolved hostname?

Extracted from Postfix log:
-------------------------------------------------------------------
May  6 03:57:56 mail1 postfix/postscreen[4365]: CONNECT from [5.53.124.135]:42284 to [51.178.189.43]:25
May  6 03:58:02 mail1 postfix/postscreen[4365]: PASS NEW [5.53.124.135]:42284
May  6 03:58:02 mail1 postfix/smtpd[3645463]: warning: hostname dm22ws9fd5giw34a.com does not resolve to address 5.53.124.135: Name or service not known
May  6 03:58:02 mail1 postfix/smtpd[3645463]: connect from unknown[5.53.124.135]
May  6 03:58:02 mail1 postfix/smtpd[3645463]: NOQUEUE: reject: RCPT from unknown[5.53.124.135]: 451 4.7.1 <user1@topfranquicias.es>: Recipient address rejected: Intentional policy rejection, please try again later; from=<noreply@pva.com> to=<user1@topfranquicias.es> proto=ESMTP helo=<pva.com>
May  6 03:58:03 mail1 postfix/smtpd[3645463]: disconnect from unknown[5.53.124.135] ehlo=1 mail=1 rcpt=0/1 data=0/1 rset=1 quit=1 commands=4/6
May  6 04:00:57 mail1 postfix/postscreen[4365]: CONNECT from [5.53.124.135]:51434 to [51.178.189.43]:25
May  6 04:00:57 mail1 postfix/postscreen[4365]: PASS OLD [5.53.124.135]:51434
May  6 04:00:57 mail1 postfix/smtpd[3646601]: warning: hostname dm22ws9fd5giw34a.com does not resolve to address 5.53.124.135: Name or service not known
May  6 04:00:57 mail1 postfix/smtpd[3646601]: connect from unknown[5.53.124.135]
May  6 04:00:57 mail1 postfix/smtpd[3646601]: NOQUEUE: reject: RCPT from unknown[5.53.124.135]: 451 4.7.1 <user2@topfranquicias.es>: Recipient address rejected: Intentional policy rejection, please try again later; from=<noreply@pva.com> to=<user2@topfranquicias.es> proto=ESMTP helo=<pva.com>
May  6 04:00:57 mail1 postfix/smtpd[3646601]: disconnect from unknown[5.53.124.135] ehlo=1 mail=1 rcpt=0/1 data=0/1 rset=1 quit=1 commands=4/6
May  6 04:28:07 mail1 postfix/postscreen[4365]: CONNECT from [5.53.124.135]:41922 to [51.178.189.43]:25
May  6 04:28:07 mail1 postfix/postscreen[4365]: PASS OLD [5.53.124.135]:41922
May  6 04:28:08 mail1 postfix/smtpd[3648786]: warning: hostname dm22ws9fd5giw34a.com does not resolve to address 5.53.124.135: Name or service not known
May  6 04:28:08 mail1 postfix/smtpd[3648786]: connect from unknown[5.53.124.135]
May  6 04:28:08 mail1 postfix/smtpd[3648786]: NOQUEUE: reject: RCPT from unknown[5.53.124.135]: 451 4.7.1 <user3@topfranquicias.es>: Recipient address rejected: Intentional policy rejection, please try again later; from=<noreply@pva.com> to=<user3@topfranquicias.es> proto=ESMTP helo=<pva.com>
May  6 04:28:08 mail1 postfix/smtpd[3648786]: disconnect from unknown[5.53.124.135] ehlo=1 mail=1 rcpt=0/1 data=0/1 rset=1 quit=1 commands=4/6
May  6 04:29:39 mail1 postfix/smtpd[3648788]: NOQUEUE: reject: RCPT from unknown[82.148.31.159]: 451 4.7.1 <user4@topfranquicias.es>: Recipient address rejected: Intentional policy rejection, please try again later; from=<noreply@pva.com> to=<user4@topfranquicias.es> proto=ESMTP helo=<pva.com>
May  6 04:30:47 mail1 postfix/postscreen[4365]: CONNECT from [5.53.124.135]:48880 to [51.178.189.43]:25
May  6 04:30:47 mail1 postfix/postscreen[4365]: PASS OLD [5.53.124.135]:48880
May  6 04:30:47 mail1 postfix/smtpd[3648786]: warning: hostname dm22ws9fd5giw34a.com does not resolve to address 5.53.124.135: Name or service not known
May  6 04:30:47 mail1 postfix/smtpd[3648786]: connect from unknown[5.53.124.135]
May  6 04:30:48 mail1 postfix/smtpd[3648786]: 4FbLHD0tRQz1xqG: client=unknown[5.53.124.135]
May  6 04:30:48 mail1 postfix/cleanup[3651748]: 4FbLHD0tRQz1xqG: message-id=<f7df46bde5dad97f14e637826f5908ad@5.53.124.135>
May  6 04:30:48 mail1 postfix/qmgr[3682]: 4FbLHD0tRQz1xqG: from=<noreply@pva.com>, size=3448, nrcpt=1 (queue active)
May  6 04:30:48 mail1 postfix/smtpd[3648786]: disconnect from unknown[5.53.124.135] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
May  6 04:30:48 mail1 postfix/10025/smtpd[3651923]: connect from localhost[127.0.0.1]
May  6 04:30:48 mail1 postfix/10025/smtpd[3651923]: 4FbLHD5Bs7z1xtk: client=localhost[127.0.0.1]
May  6 04:30:48 mail1 postfix/cleanup[3651850]: 4FbLHD5Bs7z1xtk: message-id=<f7df46bde5dad97f14e637826f5908ad@5.53.124.135>
May  6 04:30:48 mail1 postfix/qmgr[3682]: 4FbLHD5Bs7z1xtk: from=<noreply@pva.com>, size=4264, nrcpt=1 (queue active)
May  6 04:30:48 mail1 postfix/10025/smtpd[3651923]: disconnect from localhost[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
May  6 04:30:48 mail1 amavis[3651301]: (3651301-02) Passed CLEAN {RelayedInbound}, [5.53.124.135]:48880 [5.53.124.135] ESMTP/ESMTP <noreply@pva.com> -> <user1@topfranquicias.es>, (ESMTP://[5.53.124.135]:48880), Queue-ID: 4FbLHD0tRQz1xqG, Message-ID: <f7df46bde5dad97f14e637826f5908ad@5.53.124.135>, mail_id: HbWYx2DCiuwM, b: TzGF8nIJ_, Hits: 3.861, size: 3446, queued_as: 4FbLHD5Bs7z1xtk, Subject: "Malas noticias para ti", From: <user1@topfranquicias.es>, X-Mailer: PHP/5.6.4.1+deb.sury.org+1, helo=pva.com, Tests: [BITCOIN_SPAM_07=1,BITCOIN_XPRIO=0.001,CTE_8BIT_MISMATCH=0.837,HEADER_FROM_DIFFERENT_DOMAINS=0.249,PDS_BTC_ID=0.498,RDNS_NONE=1.274,SPF_HELO_NONE=0.001,SPF_NONE=0.001], autolearn=no autolearn_force=no, autolearnscore=3.861, 557 ms
May  6 04:30:48 mail1 postfix/amavis/smtp[3651796]: 4FbLHD0tRQz1xqG: to=<user1@topfranquicias.es>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.66, delays=0.1/0/0/0.56, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 4FbLHD5Bs7z1xtk)
May  6 04:30:48 mail1 postfix/qmgr[3682]: 4FbLHD0tRQz1xqG: removed
May  6 04:30:48 mail1 postfix/pipe[3651800]: 4FbLHD5Bs7z1xtk: to=<user1@topfranquicias.es>, relay=dovecot, delay=0.05, delays=0.01/0.01/0/0.03, dsn=2.0.0, status=sent (delivered via dovecot service)
May  6 04:30:48 mail1 postfix/qmgr[3682]: 4FbLHD5Bs7z1xtk: removed
May  6 04:31:25 mail1 postfix/10025/smtpd[3651923]: connect from localhost[127.0.0.1]
May  6 04:31:25 mail1 postfix/10025/smtpd[3651923]: 4FbLHx2dqqz1xtk: client=localhost[127.0.0.1]
May  6 04:31:25 mail1 postfix/10025/smtpd[3651923]: disconnect from localhost[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
May  6 04:31:49 mail1 postfix/10025/smtpd[3651923]: connect from localhost[127.0.0.1]
May  6 04:31:49 mail1 postfix/10025/smtpd[3651923]: 4FbLJP1Hpqz1xtk: client=localhost[127.0.0.1]
May  6 04:31:49 mail1 postfix/10025/smtpd[3651923]: disconnect from localhost[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
May  6 04:31:50 mail1 postfix/10025/smtpd[3651923]: connect from localhost[127.0.0.1]
May  6 04:31:50 mail1 postfix/10025/smtpd[3651923]: 4FbLJQ3xmpz1xtk: client=localhost[127.0.0.1]
May  6 04:31:50 mail1 postfix/10025/smtpd[3651923]: disconnect from localhost[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
May  6 04:32:18 mail1 postfix/10025/smtpd[3651923]: connect from localhost[127.0.0.1]
May  6 04:32:18 mail1 postfix/10025/smtpd[3651923]: 4FbLJy0l2Cz1xtk: client=localhost[127.0.0.1]
May  6 04:32:18 mail1 postfix/10025/smtpd[3651923]: disconnect from localhost[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
May  6 05:13:25 mail1 postfix/postscreen[4365]: CONNECT from [5.53.124.135]:43218 to [51.178.189.43]:25
May  6 05:13:25 mail1 postfix/postscreen[4365]: PASS OLD [5.53.124.135]:43218
May  6 05:13:25 mail1 postfix/smtpd[3660135]: warning: hostname dm22ws9fd5giw34a.com does not resolve to address 5.53.124.135: Name or service not known
May  6 05:13:25 mail1 postfix/smtpd[3660135]: connect from unknown[5.53.124.135]
May  6 05:13:25 mail1 postfix/smtpd[3660135]: 4FbMDP5fK7z1xqG: client=unknown[5.53.124.135]
May  6 05:13:25 mail1 postfix/cleanup[3657528]: 4FbMDP5fK7z1xqG: message-id=<0ed5c97f0f74e0a7bd2ce252f5419468@5.53.124.135>
May  6 05:13:25 mail1 postfix/qmgr[3682]: 4FbMDP5fK7z1xqG: from=<noreply@pva.com>, size=3439, nrcpt=1 (queue active)
May  6 05:13:25 mail1 postfix/smtpd[3660135]: disconnect from unknown[5.53.124.135] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
May  6 05:13:26 mail1 postfix/cleanup[3657524]: 4FbMDQ21Mbz1xrf: message-id=<0ed5c97f0f74e0a7bd2ce252f5419468@5.53.124.135>
May  6 05:13:26 mail1 postfix/qmgr[3682]: 4FbMDQ21Mbz1xrf: from=<noreply@pva.com>, size=4249, nrcpt=1 (queue active)
May  6 05:13:26 mail1 amavis[3657748]: (3657748-08) Passed CLEAN {RelayedInbound}, [5.53.124.135]:43218 [5.53.124.135] ESMTP/ESMTP <noreply@pva.com> -> <user3@topfranquicias.es>, (ESMTP://[5.53.124.135]:43218), Queue-ID: 4FbMDP5fK7z1xqG, Message-ID: <0ed5c97f0f74e0a7bd2ce252f5419468@5.53.124.135>, mail_id: ZR-qS6CA09gZ, b: TzGF8nIJ_, Hits: 3.861, size: 3437, queued_as: 4FbMDQ21Mbz1xrf, Subject: "Malas noticias para ti", From: <user3@topfranquicias.es>, X-Mailer: PHP/5.6.4.1+deb.sury.org+1, helo=pva.com, Tests: [BITCOIN_SPAM_07=1,BITCOIN_XPRIO=0.001,CTE_8BIT_MISMATCH=0.837,HEADER_FROM_DIFFERENT_DOMAINS=0.249,PDS_BTC_ID=0.498,RDNS_NONE=1.274,SPF_HELO_NONE=0.001,SPF_NONE=0.001], autolearn=no autolearn_force=no, autolearnscore=3.861, 445 ms
May  6 06:09:46 mail1 postfix/postscreen[4365]: CONNECT from [5.53.124.135]:40078 to [51.178.189.43]:25
May  6 06:09:46 mail1 postfix/postscreen[4365]: PASS OLD [5.53.124.135]:40078
May  6 06:09:46 mail1 postfix/smtpd[3668427]: warning: hostname dm22ws9fd5giw34a.com does not resolve to address 5.53.124.135: Name or service not known
May  6 06:09:46 mail1 postfix/smtpd[3668427]: connect from unknown[5.53.124.135]
May  6 06:09:46 mail1 postfix/smtpd[3668427]: NOQUEUE: reject: RCPT from unknown[5.53.124.135]: 550 5.1.1 <marketing@reelr.es>: Recipient address rejected: User unknown; from=<noreply@pva.com> to=<marketing@reelr.es> proto=ESMTP helo=<pva.com>
May  6 06:09:46 mail1 postfix/smtpd[3668427]: disconnect from unknown[5.53.124.135] ehlo=1 mail=1 rcpt=0/1 data=0/1 rset=1 quit=1 commands=4/6
May  6 06:33:58 mail1 postfix/postscreen[4365]: CONNECT from [5.53.124.135]:43584 to [51.178.189.43]:25
May  6 06:33:58 mail1 postfix/postscreen[4365]: PASS OLD [5.53.124.135]:43584
May  6 06:33:58 mail1 postfix/smtpd[3661629]: warning: hostname dm22ws9fd5giw34a.com does not resolve to address 5.53.124.135: Name or service not known
May  6 06:33:58 mail1 postfix/smtpd[3661629]: connect from unknown[5.53.124.135]
May  6 06:33:58 mail1 postfix/smtpd[3661629]: 4FbP1L2yzJz1xrf: client=unknown[5.53.124.135]
May  6 06:33:58 mail1 postfix/cleanup[3675266]: 4FbP1L2yzJz1xrf: message-id=<9c698f0f701fd465d10cdf97979089f9@5.53.124.135>
May  6 06:33:58 mail1 postfix/qmgr[3682]: 4FbP1L2yzJz1xrf: from=<noreply@pva.com>, size=3448, nrcpt=1 (queue active)
May  6 06:33:58 mail1 postfix/smtpd[3661629]: disconnect from unknown[5.53.124.135] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
May  6 06:33:58 mail1 postfix/cleanup[3674924]: 4FbP1L69zDz1xrh: message-id=<9c698f0f701fd465d10cdf97979089f9@5.53.124.135>
May  6 06:33:58 mail1 postfix/qmgr[3682]: 4FbP1L69zDz1xrh: from=<noreply@pva.com>, size=4264, nrcpt=1 (queue active)
May  6 06:33:58 mail1 amavis[3677990]: (3677990-01) Passed CLEAN {RelayedInbound}, [5.53.124.135]:43584 [5.53.124.135] ESMTP/ESMTP <noreply@pva.com> -> <user2@topfranquicias.es>, (ESMTP://[5.53.124.135]:43584), Queue-ID: 4FbP1L2yzJz1xrf, Message-ID: <9c698f0f701fd465d10cdf97979089f9@5.53.124.135>, mail_id: wlsqWC7km8Cn, b: TzGF8nIJ_, Hits: 3.858, size: 3446, queued_as: 4FbP1L69zDz1xrh, Subject: "Malas noticias para ti", From: <user2@topfranquicias.es>, X-Mailer: PHP/5.6.4.1+deb.sury.org+1, helo=pva.com, Tests: [BITCOIN_SPAM_07=1,BITCOIN_XPRIO=0.001,CTE_8BIT_MISMATCH=0.835,HEADER_FROM_DIFFERENT_DOMAINS=0.248,PDS_BTC_ID=0.498,RDNS_NONE=1.274,SPF_HELO_NONE=0.001,SPF_NONE=0.001], autolearn=no autolearn_force=no, autolearnscore=3.858, 408 ms
-------------------------------------------------------------------

4 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 31,082

Re: Incoming SPF check not working

reelr wrote:

May  6 04:30:48 mail1 amavis[3651301]: ..., Hits: 3.861, ..., Tests: [BITCOIN_SPAM_07=1,BITCOIN_XPRIO=0.001,CTE_8BIT_MISMATCH=0.837,HEADER_FROM_DIFFERENT_DOMAINS=0.249,PDS_BTC_ID=0.498,RDNS_NONE=1.274,SPF_HELO_NONE=0.001,SPF_NONE=0.001], ...

As you can see, it matches few spamassassin rules, you can increase the score of these rules to catch similar spams. Add these lines in /etc/mail/spamassassin/local.cf, then restart amavis service:

score BITCOIN_SPAM_07 1
score BITCOIN_XPRIO 0.001
score CTE_8BIT_MISMATCH 0.837
score HEADER_FROM_DIFFERENT_DOMAINS 0.249

Increase the score to a greater one which you think it's proper.

5 Reply by reelr

  • reelr
  • reelr
  • Member
  • Offline
  • Registered: 2020-12-04
  • Posts: 3

Re: Incoming SPF check not working

Thank you for your answer.

I will try to change spamassassin scoring.

But I belive that this kind of messages wouldn't be delivered due SPF policy, isn't it? Why is not rejected by SPF check?

Best regards,

6 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 31,082

Re: Incoming SPF check not working

SpamAssassin does the SPF check and it tags a score for this message, it does NOT reject the message by default.