Replies... > On Nov 12, 2021, at 1:48 AM, Giovanni Bechis <[email protected]> wrote: > > more inline comments. > On Thu, Nov 11, 2021 at 08:35:47PM -0700, Philip Prindeville wrote: >> Inline. >> >>> On Nov 11, 2021, at 1:01 AM, Giovanni Bechis <[email protected]> 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=<[email protected]>, size=400289, class=-60, nrcpts=1, >>>> msgid=<20211110063928.GB30217@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=<[email protected]>, 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,,,<[email protected]>,<[email protected]>,[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? >> > because the timeout did not hit in filter_end but it was a timeout > generated by something else (SpamAssassin in this case)
In our case we enable the SpamAssassin feature and it gets called from within filter_end(). > >> 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... >> > you can run "spamassassin -D rules -t <file.eml" to have an idea of > which rule takes that much. Okay, seeing this: ... Nov 12 11:43:37.936 [36367] dbg: rules: ran eval rule __UPPERCASE_25_50 ======> got hit (1) Nov 12 11:45:38.048 [36367] dbg: rules: ran eval rule __ANY_TEXT_ATTACH_DOC ======> got hit (1) ... Nov 12 11:45:38.063 [36367] dbg: rules: ran eval rule __ANY_TEXT_ATTACH ======> got hit (1) Nov 12 11:49:58.565 [36367] info: check: exceeded time limit in Mail::SpamAssassin::Plugin::Check::_eval_tests_type11_pri0_set1, skipping further tests Wait, what??? Why is this taking 4:30s to execute??? And how to dig into this further? Googling the error message doesn't return much that's useful... > > >> >> >>> >>>> 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... >> > I am trying to split mimedefang.pl code into modules without breaking > current mimedefang-filter code, this way it will be possible to load > some more code (like DKIM checking) only if a user needs it. I've done some customization that might be generically useful that I'd like to contribute: * we pay attention to $SendmailMacros{daemon_port} and only apply certain checks when the port is 25... for internal clients using 587 w/ authentication, we skip certain rules; * skip running a scanner on email sent to [email protected]; * if we find a virus, we elide the attachment and replace it with a warning saying it was deleted; * certain types of spam/phishing get converted into ARF complaints and put into a drafts folder; * skip running SpamAssassin if the submitting host is 127.0.0.1; * skip running SpamAssassin if the server port isn't 25; * in filter_relay(), allow blocking based on: + country-code from a GeoIP database; + ISP from a GeoIP database; + country-code TLD; * log connections with client IP address and client port (many ISP's won't accept reports without the client port number, since they can't trace it through NATting without it); * in filter_helo(), allow blocking on: + blacklist of client name in HELO message; + block hosts lying about their [n.n.n.n] in HELO messages; + blacklist of TLD's from rDNS on client IP; + blacklist of client IP in CIDR list; + spamhaus.org RBL blacklisting (not for 127.0.0.10 or 127.0.0.11); + block a HELO n.n.n.n that isn't enclosed in brackets, per RFC-2821; + block a HELO [n.n.n.n] that isn't a valid dotted quad; + block a HELO [n.n.n.n] that claims to be any of my addresses; + block a HELO [n.n.n.n] that disagrees with the actual $hostip; + block a HELO that's "localhost", "localhost.localdomain", or any of my own FQDNs; + block HELO names from a list of strings known to be baked into malware/ratware; + block HELO names that aren't FQDN's (i.e. hostname only); + block external hosts whose IP address doesn't have a matching rDNS record to their greeting; * in filter_sender(), block based on a blacklist of domain names; * in filter_recipient(), block based on: + a list of falsified addresses that harvesters padded their lists with (otherwise the Postmaster mailbox fills up with bounces); + a pattern to match Message-Id's that have been mistakenly harvested as addresses (WTH?); All of our IP handling is IPv4-based, since our ISP doesn't offer IPv6... some assembly required. > > > >> Kevin: Maybe we could revisit the issue under different direction? >> >> -Philip _______________________________________________ NOTE: If there is a disclaimer or other legal boilerplate in the above message, it is NULL AND VOID. You may ignore it. MIMEDefang mailing list [email protected] https://lists.mimedefang.org/mailman/listinfo/mimedefang_lists.mimedefang.org
