Google Groups no longer supports new Usenet posts or subscriptions. Historical content remains viewable.
Dismiss

Bug#990832: spamass-milter: Postfix has increased unparseable relay failures leading to SPF_FAIL

246 views
Skip to first unread message

William Haller

unread,
Jul 8, 2021, 5:10:03 PM7/8/21
to
Package: spamass-milter
Version: 0.4.0-1+b1
Severity: important

Dear Maintainer,

* What led up to the situation?

Migration from CentOS 7 to Debian buster. Minor configuration file changes from CentOS due to Postfix chroot, but was working there. Users reported missing mail on Debian which we discovered was being routed to system
junk files due to SPF failures from spamassassin.

* What exactly did you do (or not do) that was effective (or
ineffective)?

Removing the spamass-milter from the stream and letting the spamc program be run at delivery time via procmail dropped the number of unparseable relay e-mails (and several subsequent SPF failures) from 2600 or so per day
to around 100 per day. No changes to the spamassassin configuration - just dropping the spamass-milter. Since SPF is failing, it is almost certainly the last hop that is not parsed right (usually the first listed).
A sample is included... I didn't test this message, but I did test some others that failed by running them directly through spamc and they gave a correct report with no unparseable relay errors.

Return-Path: <EmailAddr...@nfpa.org>
Delivered-To: EmailAddr...@autoelect.com
Received: from NFRSProdINF1.us.nfpa.org (NFRSProdINF1.us.nfpa.org [161.47.147.140])
by postoffice-2.autoelect.com (Postfix) with ESMTP id 5100AA03E0
for <EmailAddr...@autoelect.com>; Tue, 6 Jul 2021 12:31:48 -0600 (MDT)
DKIM-Filter: OpenDKIM Filter v2.11.0 postoffice-2.autoelect.com 5100AA03E0
Received: from NFRSProdWeb10.us.nfpa.org ([172.24.32.139]) by NFRSProdINF1.us.nfpa.org with Microsoft SMTPSVC(10.0.14393.4169);
Tue, 6 Jul 2021 14:31:47 -0400
Received: from NFRSProdWeb10 ([127.0.0.1]) by NFRSProdWeb10.us.nfpa.org with Microsoft SMTPSVC(10.0.14393.4169);
Tue, 6 Jul 2021 14:31:47 -0400
MIME-Version: 1.0
From: EmailAddr...@nfpa.org
To: EmailAddr...@autoelect.com
Date: 6 Jul 2021 14:31:47 -0400
Subject: NFPA 70 Document Alert
Content-Type: text/html; charset=utf-8
Content-Transfer-Encoding: base64
Message-ID: <NFRSPRODWEB10...@NFRSProdWeb10.us.nfpa.org>
X-OriginalArrivalTime: 06 Jul 2021 18:31:47.0761 (UTC) FILETIME=[2DF78A10:01D77295]
X-Greylist: Sender DNS name whitelisted, not delayed by milter-greylist-4.5.11 (postoffice-2.autoelect.com [207.109.102.68]); Tue, 06 Jul 2021 12:31:48 -0600 (MDT)
X-Virus-Scanned: clamav-milter 0.103.2 at postoffice-2.autoelect.com
X-Virus-Status: Clean
X-Spam-Status: No, score=3.7 required=7.0 tests=HTML_IMAGE_ONLY_20,
HTML_MESSAGE,HTML_MIME_NO_HTML_TAG,MIME_HTML_ONLY,RDNS_NONE,SPF_FAIL,
T_REMOTE_IMAGE,UNPARSEABLE_RELAY autolearn=no autolearn_force=no
version=3.4.2
X-Spam-Report:
* 0.0 SPF_FAIL SPF: sender does not match SPF record (fail)
* [SPF failed: Please see http://www.openspf.org/Why?s=mfrom;id=EmailAddressRemoved%40nfpa.org;ip=172.24.32.139;r=postoffice-2.autoelect.com]
* 0.0 HTML_MESSAGE BODY: HTML included in message
* 1.1 MIME_HTML_ONLY BODY: Message only has text/html MIME parts
* 0.7 HTML_IMAGE_ONLY_20 BODY: HTML: images with 1600-2000 bytes of
* words
* 0.0 UNPARSEABLE_RELAY Informational: message has unparseable relay
* lines
* 1.3 RDNS_NONE Delivered to internal network by a host with no rDNS
* 0.6 HTML_MIME_NO_HTML_TAG HTML-only message, but there is no HTML
* tag
* 0.0 T_REMOTE_IMAGE Message contains an external image
X-Spam-Level: ***
X-Spam-Checker-Version: SpamAssassin 3.4.2 (2018-09-13) on
postoffice-2.autoelect.com

body of message omitted.

* What was the outcome of this action?
Mail was incorrectly flagged as forged and hid from the user.

* What outcome did you expect instead?
Mail to be correctly parsed and delivered.


-- System Information:
Debian Release: 10.10
APT prefers stable-updates
APT policy: (500, 'stable-updates'), (500, 'stable')
Architecture: amd64 (x86_64)

Kernel: Linux 5.10.0-0.bpo.7-amd64 (SMP w/4 CPU cores)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8), LANGUAGE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /usr/bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled

Versions of packages spamass-milter depends on:
ii adduser 3.118
ii libc6 2.28-10
ii libgcc1 1:8.3.0-6
ii libmilter1.0.1 8.15.2-14~deb10u1
ii libstdc++6 8.3.0-6
ii spamc 3.4.2-1+deb10u3

Versions of packages spamass-milter recommends:
ii postfix 3.4.14-0+deb10u1
ii spamassassin 3.4.2-1+deb10u3

spamass-milter suggests no packages.

-- Configuration Files:
/etc/default/spamass-milter changed [not included]

-- no debconf information

Don Armstrong

unread,
Jul 10, 2021, 7:30:03 PM7/10/21
to
On Thu, 08 Jul 2021, William Haller wrote:
> I didn't test this message, but I did test some others that failed by
> running them directly through spamc and they gave a correct report
> with no unparseable relay errors.

spamass-milter has to build up a Received: header because one doesn't
exist at the moment it has to send the header to spamassassin. I'm
suspecting that a configuration issue (or a bug) is causing the
Received: header to not be parsable (or doesn't match localnet in
spamassassin).

Try running spamass-milter with -d spamc; to have it output the received
header it is sending to spamc (and compare with the actual received
header that gets generated).

--
Don Armstrong https://www.donarmstrong.com

Live and learn
or die and teach by example
-- a softer world #625
http://www.asofterworld.com/index.php?id=625

William Haller

unread,
Jul 12, 2021, 2:50:03 PM7/12/21
to
Just a quick update. I'm doing some logging. To me it looks like DNS
replies may not come fast enough. For some reason, with calls from spamc
from procmail they aren't timing out and moving to the next hop (thereby
marking it as the sender and causing the SPF failures) like happens in
spamass-milter.

It is possible that an IPV6 reply from the first address is also an
issue, but I'm not certain of this. It does appear that it's IPV6
addresses that cause the most issues from a brief perusal. It could also
be that only the bigger e-mail senders are using IPV6 at this point and
when another company uses something like outlook.com as its final relay,
then checking through all the possible includes in that company's SPF
records for which outlook.com is one just takes too long to finish
processing the first time but is then available by the time
procmail/spamc is hitting it.

As long as DNS resolution occurs, I haven't seen any issues with
internal/trusted settings.

I've added dns to received-header for the logging and will post again if
I get something definitive.

William Haller

unread,
Jul 14, 2021, 11:00:04 AM7/14/21
to
Look at moving the two assassin->connected = 1 statements down after you
try to connect. I put them after the catch block when I made the change.
I think setting the flag to 1 early causes the output to fail to buffer
and it is the first line which is frequently not able to be transmitted
to the pipe that is not yet running but marked as connected. I admit I
don't know the code very well and it may cause other issues I don't see,
but this seems to make a huge difference.

If this looks like a fix could you remove the message #18 from the bug
report. Thanks.

Bill

William Haller

unread,
Jul 15, 2021, 12:20:04 PM7/15/21
to
Still see some dropped header information - drastically less, but not 0.
So I'd say there still might be a race condition or error handling that
isn't right.

I tried to move the outputbuffer handling into ::output, moving any
existing outputbuffer contents to a temporary buffer, killing the
outputbuffer, and dumping that temp buffer first once connected was set,
but I was still getting unparseable relays. Then I pulled the connection
attempt for each line completely letting everything be buffered and just
did the connection attempt after the _eoh was buffered to the
outputbuffer (turning on connected before the Connect call as it was
before - just done after everything was buffered). This also gave
unparseable relays, but in both of these cases at least all received
headers were examined by spamd.

So I'm thinking that the dropped lines are one problem - and either of
the above solutions might help with that - I don't know - but that there
is also a received header formation problem that spamd doesn't like the
result of.


A sample header in the text e-mail might be

Received: from mail02.connect.hpe.com (mail02.connect.hpe.com
[204.92.22.193])
    (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits))
    (No client certificate requested)
    by postoffice-2.autoelect.com (Postfix) with ESMTPS id 9278E9FFB5
    for <EmailR...@autoelect.com>; Thu, 15 Jul 2021 09:53:19 -0600 (MDT)

and I see

Received header for spamc: Received: from mail02.connect.hpe.com
(unknown)#015#012#011by postoffice-2.autoelect.com (8.13.0/8.13.0) with
SMTP id unknown#015#012#011Thu, 15 Jul 2021 09:53:19
-0600#015#012#011(envelope-from <bounc...@connect.hpe.com>);#015

output "Received: from mail02.connect.hpe.com (unknown)#015#012#011by
postoffice-2.autoelect.com (8.13.0/8.13.0) with SMTP id
unknown#015#012#011Thu, 15 Jul 2021 09:53:19
-0600#015#012#011(envelope-from <bounc...@connect.hpe.com>);#015#012"

output "Received: from P01SNJ404 (10.32.120.245) by
mail02.connect.hpe.com id hu1cus2q38k7 for <EmailR...@autoelect.com>;
Thu, 15 Jul 2021 11:53:18 -0400 (envelope-from
<bounc...@connect.hpe.com>)#015#012"

from spamass-milter logging and


received-header: unparseable: from mail02.connect.hpe.com (unknown) by
postoffice-2.autoelect.com (8.13.0/8.13.0) with SMTP id unknown Thu, 15
Jul 2021 09:53:19 -0600 (envelope-from <bounc...@connect.hpe.com>);

received-header: parsed as [ ip=10.32.120.245 rdns=P01SNJ404
helo=P01SNJ404 by=mail02.connect.hpe.com ident=
envfrom=bounc...@connect.hpe.com intl=0 id=hu1cus2q38k7 auth= msa=0 ]

received-header: relay 10.32.120.245 trusted? yes internal? yes msa? no

from spamd's logging


Thanks, Bill

William Haller

unread,
Jul 16, 2021, 12:40:03 PM7/16/21
to
Applied fixes from here to fedora 34 base for spamass-milter:
https://bz.apache.org/SpamAssassin/attachment.cgi?id=5745&action=diff

With the exception of setting a default macro_r based on whether or not
there was a cipher since r doesn't seem to be a postfix thing.

macro_cipher = smfi_getsymval(ctx, const_cast<char *>("{cipher}"));
if (!macro_cipher)
{
  macro_cipher = "";
  /* Protocol used to receive the message */
  macro_r = smfi_getsymval(ctx, const_cast<char *>("r"));
  if (!macro_r)
  {
    macro_r = "ESMTP";
    warnmacro("r", "ENVRCPT");
  }
}
else {
  /* Protocol used to receive the message */
  macro_r = smfi_getsymval(ctx, const_cast<char *>("r"));
  if (!macro_r)
  {
    macro_r = "ESMTPS";
    warnmacro("r", "ENVRCPT");
  }
}

and including the changes to append so the lines aren't dropped (setting
the connected flag after a successful connect, moving the dump of the
buffer to be after if (!connected) in ::output before the output of
desired line).

Then corrected the fedora 34 base to include the -I option in the debian
code.

Then made the final output for computed last hop to be

rec_header = (string) "Received: from " + macro_s + " (" + macro__ +
")\r\n\t";
if (strlen(macro_tls_version)!=0)
{
  rec_header += (string) "(using ";
  if (strlen(macro_tls_version)!=0) {
    rec_header+=macro_tls_version;
  }
  if (strlen(macro_cipher)!=0) {
    rec_header+=(string) " cipher="+macro_cipher;
  }
  if (strlen(macro_auth_ssf))
  {
    rec_header += (string) " ("+macro_auth_ssf+"/"+macro_auth_ssf+" bits)";
  }
  rec_header += (string) ")\r\n\t";
}
if (strlen(macro_auth_authen)!=0) {
  rec_header += (string) "(Authenticated sender:
"+macro_auth_authen+")\r\n\t";
}
rec_header += (string) "by " + macro_j + " (Postfix) with " +
  macro_r + " id " + macro_i + ";\r\n\t" +
  "for "+envrcpt[0]+"; "+macro_b + "\r\n";

Which gets rid of unparseable relays and dropped lines. I'm not sure
what the best fix would or should be - adding a postfix flag so it would
generate postfix worthy lines for spamassassin or making spamassassin
recognize the lines put out by spamass-milter as "sendmail" lines. But
getting the client ip address for the sender seems to be the big thing.

Bill

Don Armstrong

unread,
Jul 19, 2021, 11:00:04 AM7/19/21
to

Thanks for all of the work and the patching.

The debug output that you're showing looks a lot like some of the
necessary macros aren't enabled in the postfix config; can you compare
what you have to what is listed in README.Debian?

I'll try to take another look at the code that you have which is working
and see what is going on there.


--
Don Armstrong https://www.donarmstrong.com

I learned really early the difference between knowing the name of
something and knowing something
-- Richard Feynman "What is Science" Phys. Teach. 7(6) 1969
0 new messages