Mailing List Archive: 4.0.0 noisier than earlier releases?

4.0.0 noisier than earlier releases?

May 15, 2023, 6:52 PM

Post #1 of 4 (179 views)

I remember writing in the past about what I saw in the debugger when running SA 3.4.6

It seems that 4.0.0 seems even noisier.

Again this is my programmatically calling SpamAssassin in a perlscript.

I’ve checked and I didn’t find any other version of NetAddr::IP in the @INC

Subroutine NetAddr::IP::STORABLE_freeze redefined at /usr/local/lib64/perl5/NetAddr/IP.pm line 365.
at /usr/local/lib64/perl5/NetAddr/IP.pm line 365.
NetAddr::IP::import('NetAddr::IP') called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/Plugin/WLBLEval.pm line 25
Mail::SpamAssassin::Plugin::WLBLEval::BEGIN() called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/Plugin/WLBLEval.pm line 25
eval {...} called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/Plugin/WLBLEval.pm line 25
require Mail/SpamAssassin/Plugin/WLBLEval.pm called at (eval 231)[/home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/PluginHandler.pm:129] line 1
eval ' require Mail::SpamAssassin::Plugin::WLBLEval;
;' called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/PluginHandler.pm line 129
Mail::SpamAssassin::PluginHandler::load_plugin('Mail::SpamAssassin::PluginHandler=HASH(0x4ec4a20)', 'Mail::SpamAssassin::Plugin::WLBLEval', undef, undef) called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/Conf.pm line 5308
Mail::SpamAssassin::Conf::load_plugin('Mail::SpamAssassin::Conf=HASH(0x4e255f8)', 'Mail::SpamAssassin::Plugin::WLBLEval', undef) called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/Conf.pm line 4300
Mail::SpamAssassin::Conf::__ANON__[/home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/Conf.pm:4301]('Mail::SpamAssassin::Conf=HASH(0x4e255f8)', 'loadplugin', 'Mail::SpamAssassin::Plugin::WLBLEval', 'loadplugin Mail::SpamAssassin::Plugin::WLBLEval') called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/Conf/Parser.pm line 437
Mail::SpamAssassin::Conf::Parser::parse('Mail::SpamAssassin::Conf::Parser=HASH(0x4e25688)', 'file start /home/elastica/SALOCAL-4.0.0/etc/mail/spamassassin...', 0) called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/Conf.pm line 5032
Mail::SpamAssassin::Conf::parse_rules('Mail::SpamAssassin::Conf=HASH(0x4e255f8)', 'file start /home/elastica/SALOCAL-4.0.0/etc/mail/spamassassin...') called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin.pm line 1792
Mail::SpamAssassin::init('Mail::SpamAssassin=HASH(0x4e25a90)', 1) called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin.pm line 580
Mail::SpamAssassin::check('Mail::SpamAssassin=HASH(0x4e25a90)', 'Mail::SpamAssassin::Message=HASH(0x4f06120)') called at filter70.pl line 2288
main::decorate_mail('Mail::Audit::MimeEntity=HASH(0x4e65e48)', 'SCALAR(0x4c7f1a0)') called at filter70.pl line 966
Subroutine NetAddr::IP::STORABLE_thaw redefined at /usr/local/lib64/perl5/NetAddr/IP.pm line 377.
at /usr/local/lib64/perl5/NetAddr/IP.pm line 377.
NetAddr::IP::import('NetAddr::IP') called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/Plugin/WLBLEval.pm line 25
Mail::SpamAssassin::Plugin::WLBLEval::BEGIN() called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/Plugin/WLBLEval.pm line 25
eval {...} called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/Plugin/WLBLEval.pm line 25
require Mail/SpamAssassin/Plugin/WLBLEval.pm called at (eval 231)[/home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/PluginHandler.pm:129] line 1
eval ' require Mail::SpamAssassin::Plugin::WLBLEval;
;' called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/PluginHandler.pm line 129
Mail::SpamAssassin::PluginHandler::load_plugin('Mail::SpamAssassin::PluginHandler=HASH(0x4ec4a20)', 'Mail::SpamAssassin::Plugin::WLBLEval', undef, undef) called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/Conf.pm line 5308
Mail::SpamAssassin::Conf::load_plugin('Mail::SpamAssassin::Conf=HASH(0x4e255f8)', 'Mail::SpamAssassin::Plugin::WLBLEval', undef) called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/Conf.pm line 4300
Mail::SpamAssassin::Conf::__ANON__[/home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/Conf.pm:4301]('Mail::SpamAssassin::Conf=HASH(0x4e255f8)', 'loadplugin', 'Mail::SpamAssassin::Plugin::WLBLEval', 'loadplugin Mail::SpamAssassin::Plugin::WLBLEval') called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/Conf/Parser.pm line 437
Mail::SpamAssassin::Conf::Parser::parse('Mail::SpamAssassin::Conf::Parser=HASH(0x4e25688)', 'file start /home/elastica/SALOCAL-4.0.0/etc/mail/spamassassin...', 0) called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/Conf.pm line 5032
Mail::SpamAssassin::Conf::parse_rules('Mail::SpamAssassin::Conf=HASH(0x4e255f8)', 'file start /home/elastica/SALOCAL-4.0.0/etc/mail/spamassassin...') called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin.pm line 1792
Mail::SpamAssassin::init('Mail::SpamAssassin=HASH(0x4e25a90)', 1) called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin.pm line 580
Mail::SpamAssassin::check('Mail::SpamAssassin=HASH(0x4e25a90)', 'Mail::SpamAssassin::Message=HASH(0x4f06120)') called at filter70.pl line 2288
main::decorate_mail('Mail::Audit::MimeEntity=HASH(0x4e65e48)', 'SCALAR(0x4c7f1a0)') called at filter70.pl line 966
config: registryboundaries: no tlds defined, need to run sa-update
at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/RegistryBoundaries.pm line 70.
Mail::SpamAssassin::RegistryBoundaries::new('Mail::SpamAssassin::RegistryBoundaries', 'Mail::SpamAssassin=HASH(0x4e25a90)') called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin.pm line 2286
Mail::SpamAssassin::call_plugins('Mail::SpamAssassin=HASH(0x4e25a90)', 'finish_parsing_end', 'HASH(0x4f112e0)') called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/Conf/Parser.pm line 1002
Mail::SpamAssassin::Conf::Parser::finish_parsing('Mail::SpamAssassin::Conf::Parser=HASH(0x4e25688)', 0) called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin/Conf.pm line 5274
Mail::SpamAssassin::Conf::finish_parsing('Mail::SpamAssassin::Conf=HASH(0x4e255f8)', 0) called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin.pm line 1793
Mail::SpamAssassin::init('Mail::SpamAssassin=HASH(0x4e25a90)', 1) called at /home/elastica/SALOCAL-4.0.0/share/perl5/Mail/SpamAssassin.pm line 580
Mail::SpamAssassin::check('Mail::SpamAssassin=HASH(0x4e25a90)', 'Mail::SpamAssassin::Message=HASH(0x4f06120)') called at filter70.pl line 2288
main::decorate_mail('Mail::Audit::MimeEntity=HASH(0x4e65e48)', 'SCALAR(0x4c7f1a0)') called at filter70.pl line 966

Re: 4.0.0 noisier than earlier releases? [ In reply to ]

robert.nicholson at gmail

May 18, 2023, 6:45 AM

Post #2 of 4 (177 views)

Permalink

For what it’s worth my perlscript has the following “imports”

use IO::Handle;
use Date::Parse;
use Time::Zone;
use Mail::Audit qw(List KillDups);
use Mail::SpamAssassin;
use Mail::SpamAssassin::Message;
use Mail::SpamAssassin::PerMsgStatus;
use Mail::SpamAssassin::PluginHandler;
use IO::Scalar;
use MIME::Parser;
use MIME::Entity;
use Mail::Address;
use Email::Valid;
use Text::Wrap;
use File::Path;
#use SOAP::Lite;
use Mail::IMAPClient;
use HTTP::Request::Common qw(GET POST);
use LWP::UserAgent;
use XML::XPath;
use Getopt::Long;
use HTML::LinkExtor;

use DB_File::Lock;
use Fcntl qw(:DEFAULT :flock);
use POSIX qw(strftime);

use Authen::Captcha;

use MIME::Base64;
use Digest::HMAC_SHA1 qw(hmac_sha1 hmac_sha1_hex);
use URI::Escape qw(uri_escape);

It’s not a coincidence is it that when you research these errors you end up finding SA specific reference like the following

https://www.mail-archive.com/users@spamassassin.apache.org/msg100167.html?

perl -version

This is perl 5, version 16, subversion 3 (v5.16.3) built for x86_64-linux-thread-multi
(with 44 registered patches, see perl -V for more detail)

Copyright 1987-2012, Larry Wall

Perl may be copied only under the terms of either the Artistic License or the
GNU General Public License, which may be found in the Perl 5 source kit.

Complete documentation for Perl, including FAQ lists, should be found on
this system using "man perl" or "perldoc perl". If you have access to the
Internet, point your browser at http://www.perl.org/, the Perl Home Page.

> On May 15, 2023, at 8:52 PM, Robert Nicholson <robert@elastica.com> wrote:
>
> Subroutine NetAddr::IP::STORABLE_freeze redefined at /usr/local/lib64/perl5/NetAddr/IP.pm line 365.

Re: 4.0.0 noisier than earlier releases? [ In reply to ]

hege at hege

May 18, 2023, 9:10 AM

Post #3 of 4 (177 views)

Permalink

On Mon, May 15, 2023 at 08:52:23PM -0500, Robert Nicholson wrote:
> I remember writing in the past about what I saw in the debugger when running SA 3.4.6
>
> It seems that 4.0.0 seems even noisier.
>
> Again this is my programmatically calling SpamAssassin in a perlscript.
>
> I’ve checked and I didn’t find any other version of NetAddr::IP in the @INC
>
> Subroutine NetAddr::IP::STORABLE_freeze redefined at /usr/local/lib64/perl5/NetAddr/IP.pm line 365.

Funny that you had the same problem almost 10 years ago? It fixed itself until now?

https://lists.archive.carbon60.com/spamassassin/users/184448

Cleaned up the code a bit, likely makes zero difference, but try trunk if you want..

https://svn.apache.org/viewvc?view=revision&revision=1909909

Maybe try something like this to check if something is actually loading
IP.pm twice. Dunno what else to check, as it seems hard to reproduce.

$ strace -f perl yourscript.pl 2>&1 | egrep 'open.*NetAddr/IP.pm'
openat(AT_FDCWD, "/usr/local/perlbrew/perls/perl-5.16.3/lib/site_perl/5.16.3/x86_64-linux/NetAddr/IP.pm", O_RDONLY) = 9

Re: 4.0.0 noisier than earlier releases? [ In reply to ]

robert at elastica

May 19, 2023, 6:09 AM

Post #4 of 4 (176 views)

Permalink

Thanks for the suggestion here what I see

strace -f perl filter73.pl -runsa 2>&1 < /tmp/4.txt | egrep 'open.*NetAddr/IP.pm'
open("/usr/local/lib64/perl5/NetAddr/IP.pm", O_RDONLY) = 7

"Funny that you had the same problem almost 10 years ago? It fixed itself until now?”

Point taken.

I’m looking into things because for some reason I’m seeing the following on specific email addresses when the filter runs from exim.

Not sure why exim errors the way it does but it’s a problem. Especially since it’s not for all mail that it does this.

2023-05-19 00:55:09 1pzuxA-0003dL-2A <= 64560-91387-2288-13855-robert=elastica.com@mail.clarisilz.today H=spaintainly.com (meade.clarisilz.today) [23.228.94.50] P=esmtp S=10556 id=ocdba49pesclq2io-ipgpueqvh8tdtg26-164fb-8f0@clarisilz.today T="Your Participation is Needed!" from <64560-91387-2288-13855-robert=elastica.com@mail.clarisilz.today> for robert@elastica.com
2023-05-19 00:55:09 1pzuxA-0003dL-2A SIGSEGV (fault address: (nil))
2023-05-19 00:55:09 1pzuxA-0003dL-2A SIGSEGV (null pointer indirection)
2023-05-19 00:55:09 1pzuxA-0003dL-2A internal problem in userforward router (recipient is elastica@lhvm02.lizardhill.com): failure to transfer data from subprocess: status=0100 readerror='No such file or directory'
2023-05-19 00:55:09 1pzuxA-0003dL-2A == elastica@lhvm02.lizardhill.com <robert@elastica.com> R=userforward defer (-1): internal problem in userforward router (recipient is elastica@lhvm02.lizardhill.com): failure to transfer data from subprocess: status=0100 readerror='No such file or directory'
2023-05-19 01:16:13 1pzuxA-0003dL-2A SIGSEGV (fault address: (nil))
2023-05-19 01:16:13 1pzuxA-0003dL-2A SIGSEGV (null pointer indirection)
2023-05-19 01:16:13 1pzuxA-0003dL-2A internal problem in userforward router (recipient is elastica@lhvm02.lizardhill.com): failure to transfer data from subprocess: status=0100 readerror='No such file or directory'
2023-05-19 01:16:13 1pzuxA-0003dL-2A == elastica@lhvm02.lizardhill.com <robert@elastica.com> R=userforward defer (-1): internal problem in userforward router (recipient is elastica@lhvm02.lizardhill.com): failure to transfer data from subprocess: status=0100 readerror='No such file or directory'
2023-05-19 02:16:34 1pzuxA-0003dL-2A SIGSEGV (fault address: (nil))
2023-05-19 02:16:34 1pzuxA-0003dL-2A SIGSEGV (null pointer indirection)
2023-05-19 02:16:34 1pzuxA-0003dL-2A internal problem in userforward router (recipient is elastica@lhvm02.lizardhill.com): failure to transfer data from subprocess: status=0100 readerror='No such file or directory'
2023-05-19 02:16:34 1pzuxA-0003dL-2A == elastica@lhvm02.lizardhill.com <robert@elastica.com> R=userforward defer (-1): internal problem in userforward router (recipient is elastica@lhvm02.lizardhill.com): failure to transfer data from subprocess: status=0100 readerror='No such file or directory'
2023-05-19 03:16:19 1pzuxA-0003dL-2A SIGSEGV (fault address: (nil))
2023-05-19 03:16:19 1pzuxA-0003dL-2A SIGSEGV (null pointer indirection)
2023-05-19 03:16:19 1pzuxA-0003dL-2A internal problem in userforward router (recipient is elastica@lhvm02.lizardhill.com): failure to transfer data from subprocess: status=0100 readerror='No such file or directory'
2023-05-19 03:16:19 1pzuxA-0003dL-2A == elastica@lhvm02.lizardhill.com <robert@elastica.com> R=userforward defer (-1): internal problem in userforward router (recipient is elastica@lhvm02.lizardhill.com): failure to transfer data from subprocess: status=0100 readerror='No such file or directory'
2023-05-19 04:16:13 1pzuxA-0003dL-2A SIGSEGV (fault address: (nil))
2023-05-19 04:16:13 1pzuxA-0003dL-2A SIGSEGV (null pointer indirection)
2023-05-19 04:16:13 1pzuxA-0003dL-2A internal problem in userforward router (recipient is elastica@lhvm02.lizardhill.com): failure to transfer data from subprocess: status=0100 readerror='No such file or directory'
2023-05-19 04:16:13 1pzuxA-0003dL-2A == elastica@lhvm02.lizardhill.com <robert@elastica.com> R=userforward defer (-1): internal problem in userforward router (recipient is elastica@lhvm02.lizardhill.com): failure to transfer data from subprocess: status=0100 readerror='No such file or directory'

There’s many addresses for which this error does not appear.

this is normal behavior

2023-05-14 03:54:45 1py9NE-0003sa-1P <= 1444+robert=elastica.com@news.dempubblicitarie.it H=mta11151.dempubblicitarie.it [185.153.111.51] P=esmtps X=TLS1.2:ECDHE-ECDSA-AES128-GCM-SHA256:128 CV=no S=20168 DKIM=news.dempubblicitarie.it id=184077.314.1444.3239248@news.dempubblicitarie.it T="GRATIS 1 anno di canone UnipolMove e sconto fino al 30% sulla polizza\n auto UnipolSai" from <1444+robert=elastica.com@news.dempubblicitarie.it> for robert@elastica.com
2023-05-14 03:54:49 1py9NE-0003sa-1P => |nice -10 $home/perlscripts/filter.pl -runsa (elastica@lhvm02.lizardhill.com) <robert@elastica.com> F=<1444+robert=elastica.com@news.dempubblicitarie.it> R=userforward T=address_pipe S=20248
2023-05-14 03:54:49 1py9NE-0003sa-1P => /home/elastica/Maildir/.INBOX.intray.backup/ (elastica@lhvm02.lizardhill.com) <robert@elastica.com> F=<1444+robert=elastica.com@news.dempubblicitarie.it> R=userforward T=address_directory S=20312
2023-05-14 03:54:49 1py9NE-0003sa-1P Completed

I think SA is effectively in the clear now since I’m operating it within invoking SA. I had thought the additional noise I was seeing may contribute to how exim interacts with the filter script.

> On May 18, 2023, at 11:10 AM, Henrik K <hege@hege.li> wrote:
>
> On Mon, May 15, 2023 at 08:52:23PM -0500, Robert Nicholson wrote:
>> I remember writing in the past about what I saw in the debugger when running SA 3.4.6
>>
>> It seems that 4.0.0 seems even noisier.
>>
>> Again this is my programmatically calling SpamAssassin in a perlscript.
>>
>> I’ve checked and I didn’t find any other version of NetAddr::IP in the @INC
>>
>> Subroutine NetAddr::IP::STORABLE_freeze redefined at /usr/local/lib64/perl5/NetAddr/IP.pm line 365.
>
> Funny that you had the same problem almost 10 years ago? It fixed itself until now?
>
> https://lists.archive.carbon60.com/spamassassin/users/184448
>
> Cleaned up the code a bit, likely makes zero difference, but try trunk if you want..
>
> https://svn.apache.org/viewvc?view=revision&revision=1909909
>
> Maybe try something like this to check if something is actually loading
> IP.pm twice. Dunno what else to check, as it seems hard to reproduce.
>
> $ strace -f perl yourscript.pl 2>&1 | egrep 'open.*NetAddr/IP.pm'
> openat(AT_FDCWD, "/usr/local/perlbrew/perls/perl-5.16.3/lib/site_perl/5.16.3/x86_64-linux/NetAddr/IP.pm", O_RDONLY) = 9
>

Mailing List Archive

Mailing List Archive

Attached Files: