[Mimedefang] New errors following update to 2.85

[Philip Prindeville]

Inline.

> On Nov 11, 2021, at 1:01 AM, Giovanni Bechis <giovanni at paclan.it> wrote:
> 
> On Wed, Nov 10, 2021 at 03:23:25PM -0700, Philip Prindeville via MIMEDefang wrote:
>> Hi,
>> 
>> I just updated my mail server from Fedora 33 to Fedora 34, and I noticed right away seeing these messages:
>> 
>> Nov 10 14:37:17 localhost mimedefang.pl[9141]: 1AALbHB8009400: relay: vger.kernel.org (23.128.96.18:56344 => 192.168.4.3:25)
>> Nov 10 14:37:22 localhost mimedefang.pl[7873]: 1AALbHB8009400: helo: vger.kernel.org (23.128.96.18:56344) said "helo vger.kernel.org"
>> Nov 10 14:37:22 localhost sendmail[9400]: 1AALbHB8009400: from=<netdev-owner at vger.kernel.org>, size=400289, class=-60, nrcpts=1, msgid=<20211110063928.GB30217 at xsang-OptiPlex-9020>, bodytype=8BITMIME, proto=ESMTP, daemon=MTA-v4, relay=vger.kernel.org [23.128.96.18]
>> Nov 10 14:39:22 localhost sendmail[9400]: 1AALbHB8009400: Milter (mimedefang): timeout before data read, where=eom
>> Nov 10 14:39:22 localhost sendmail[9400]: 1AALbHB8009400: Milter (mimedefang): to error state
>> Nov 10 14:39:22 localhost sendmail[9400]: 1AALbHB8009400: Milter: data, reject=451 4.3.2 Please try again later
>> Nov 10 14:39:22 localhost sendmail[9400]: 1AALbHB8009400: to=<foo at bar.com>, delay=00:02:00, pri=538289, stat=Please try again later
>> Nov 10 14:43:38 localhost mimedefang.pl[8384]: 1AALbHB8009400: MDLOG,1AALbHB8009400,mail_in,,,<netdev-owner at vger.kernel.org>,<philipp_subx at redfish-solutions.com>,[af_unix]  95e381b609: WARNING:possible_recursive_locking_detected
>> Nov 10 14:43:38 localhost mimedefang[1258]: 1AALbHB8009400: smfi_addheader returned MI_FAILURE
>> 
>> Looking through the logs, this happens over and over, and only with the delivery of this one message.  Since it can't be delivered for some reason, I looked it up on MARC:
>> 
>> https://marc.info/?l=linux-netdev&m=163652637632433&w=2
>> 
>> Anyone have an idea what's going on?  Is there a timeout I need to increase?
>> 
> you are hitting R=2m timeout while milter is sending data to mimedefang,
> this may happen when some code inside mimedefang.pl times out for a
> reason (antispam, antivirus ?).
> The code that triggers the problem may be near a call to
> action_add_header or action_change_header in your mimedefang-filter.


Why is it the R=2m timeout and not the E=10m timeout?

I took the message, copied it to a flat file on the mail server, and did a test:

% spamassassin -t < /tmp/test.eml

Content analysis details:   (-2.3 points, 5.0 required)

 pts rule name              description
---- ---------------------- --------------------------------------------------
-2.3 RCVD_IN_DNSWL_MED      RBL: Sender listed at https://www.dnswl.org/,
                            medium trust
                            [134.134.136.100 listed in list.dnswl.org]
 0.0 SPF_HELO_NONE          SPF: HELO does not publish an SPF Record
 0.0 TIME_LIMIT_EXCEEDED    Exceeded time limit / deadline


real	6m37.324s
user	0m6.569s
sys	0m0.250s
% 

Which seems like a really long time to run over the message.

This is a 2 core VM running on a 2.3GHz Xeon-D with Qemu/KVM.  I'd think that spamassassin would be quicker than that for a barely 400K message...

I must have some rules that are painfully expensive.  Any suggestions on which ones to watch out for?

I'm guessing the 60 or so "body" or "rawbody" rules are killing me...

Nope, just checked.  Commented about half of them out (that haven't had hits in 5 years or more) and it took almost exactly the same amount of time...



> 
>> Looking at:
>> 
>> Xmimedefang, S=unix:/var/spool/MIMEDefang/mimedefang.sock, F=T, T=S:2m;R:2m;E:10m
>> 
>> That looks like plenty...  
>> 
>> Other than that, everything seems to be working fine (well, I did have to change the $qid variable to filter_relay() and filter_helo() as that changed, but that was relatively minor).
>> 
>> BTW: who now owns the direction of development of MimeDefang?  Who is the designer-in-chief?
>> 
> MIMEDefang development now happens on https://github.com/The-McGrail-Foundation/MIMEDefang
> You can find some info about MIMEDefang project management at https://mimedefang.org/mimedefang-project-charter/
> 
> Giovanni


Okay, thanks.  I had suggested to Dianne some time ago that we include extra functionality (like DKIM checking, etc.) but leave the invocation commented out, and she was opposed to that because it cluttered the code.

I don't see it that way, and the time to parse code that doesn't get executed seems to be negligible in Perl, especially if the same instance gets run 300 times before being terminated...

Kevin: Maybe we could revisit the issue under different direction?

-Philip