Re: [Assp-test] fixes in assp 2.6.6 *SPAM-Evaporator* build 21280
Friends, The crashing was ALL caused by a griplist database location misconfiguration. I had a bad path in the config, which made the berkeley DB module leave too many connections to the griplist dbd-error.txt file open, ultimately crashing ASSP. Lesson learned: don't be a dope and have a bad path to the griplist!!! Thank you, as always, to Thomas for helping figure this one out!! On Fri, Oct 8, 2021 at 8:34 PM K Post wrote: > So this is odd running handle on perl.exe gives me stuff I'd expect > (though I don't know what it all is) > >78: File (RW-) > C:\Windows\WinSxS\amd64_microsoft.windows.common-controls_6595b64144ccf1df_6.0.17763.2213_none_de6ea00a534da176 > 18C: File (R-D) C:\Windows\System32\en-US\KernelBase.dll.mui > 1B0: File (RW-) > d:\StrawberryPerl\perl\site\lib\Net\DNS\Resolver\Base.pm > 280: File (RW-) d:\assp > 2DC: File (R-D) C:\Windows\System32\en-US\mswsock.dll.mui > 678: File (RW-) L:\ASSP Logs\maillog.txt <-- link of d:\assp\logs > to another drive > 67C: File (RW-) L:\ASSP Logs\bmaillog.txt <-- link of d:\assp\logs > to another drive > 704: Section \BaseNamedObjects\__ComCatalogCache__ > 718: Section \BaseNamedObjects\__ComCatalogCache__ > 71C: Section \RPC Control\DSECFAC > 7D8: File (RW-) d:\assp\pid > > and then about *1300* additional identical entries (with different > handles), that are: > > xxx: *File (RW-) d:\assp\tmpDB\Griplist\BDB-error.txt* > > And those 1300 idential lines is with ASSP trucking along quite nicely. > No errors in the 15 hours or so since it crashed last. I can't imagine > that 1300 open handles to DBD-error.txt is normal though. And I have no > idea what it shows when it's crashing. I'm not sure how to find that out > either, as once I'm alerted to SMTP being down, it's already too late - > ASSP has crashed. > > DBD-error.txt is 0 bytes. In the Griplist folder. It appears to have > been "modified" about a minute ago, but still 0bytes. > > I also see: > __db.001 888kb > __db.002 120kb > __db.003 648kb > > I don't believe that I use the griplist. noGriplistUpload and > noGriplistDownload are both checked. Due to our charity privacy policy :( > > I just restarted the ASSP service in Windows and see 10 of the > griplist\DBD-error.txt handles. Is >>that<< normal? I temporarily > reverted to 21218 (I happened to have that old version on hand) and seems > to have 9 of the griplist\DBD-error.txt handles, so having a bunch doesn't > seem to be a new problem, if it's a problem at all. > > I feel like some loop happens when there TLS errors with the new versions > though that somehow gets more of these griplist\dbd-error.txt handels to > open until there no more file handles left > > > > > > > > > > On Fri, Oct 8, 2021 at 7:27 PM K Post wrote: > >> That's funny Bob, I was just looking at Sysinternals to see if there was >> such a tool. Also looking to see if there's anything like this: >> >> https://stackoverflow.com/questions/8845949/how-to-find-open-global-filehandles-in-a-perl-program >> that would work for Windows. >> >> >> >> On Fri, Oct 8, 2021 at 1:56 PM Robert K Coffman Jr. -Info From Data Corp. >> wrote: >> >>> I'm curious what handle (Sysinternals tool) says when you hit the file >>> limit... >>> >>> - Bob >>> >>> On 10/8/2021 10:47 AM, K Post wrote: >>> > And a similar thing just happened again with 21280. ASSP gets to the >>> > point where it can't open any more files, griplist can't be opened, >>> and >>> > it goes into a shutdown process. >>> >>> >>> >>> ___ >>> Assp-test mailing list >>> Assp-test@lists.sourceforge.net >>> https://lists.sourceforge.net/lists/listinfo/assp-test >>> >> ___ Assp-test mailing list Assp-test@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/assp-test
Re: [Assp-test] fixes in assp 2.6.6 *SPAM-Evaporator* build 21280
So this is odd running handle on perl.exe gives me stuff I'd expect (though I don't know what it all is) 78: File (RW-) C:\Windows\WinSxS\amd64_microsoft.windows.common-controls_6595b64144ccf1df_6.0.17763.2213_none_de6ea00a534da176 18C: File (R-D) C:\Windows\System32\en-US\KernelBase.dll.mui 1B0: File (RW-) d:\StrawberryPerl\perl\site\lib\Net\DNS\Resolver\Base.pm 280: File (RW-) d:\assp 2DC: File (R-D) C:\Windows\System32\en-US\mswsock.dll.mui 678: File (RW-) L:\ASSP Logs\maillog.txt <-- link of d:\assp\logs to another drive 67C: File (RW-) L:\ASSP Logs\bmaillog.txt <-- link of d:\assp\logs to another drive 704: Section \BaseNamedObjects\__ComCatalogCache__ 718: Section \BaseNamedObjects\__ComCatalogCache__ 71C: Section \RPC Control\DSECFAC 7D8: File (RW-) d:\assp\pid and then about *1300* additional identical entries (with different handles), that are: xxx: *File (RW-) d:\assp\tmpDB\Griplist\BDB-error.txt* And those 1300 idential lines is with ASSP trucking along quite nicely. No errors in the 15 hours or so since it crashed last. I can't imagine that 1300 open handles to DBD-error.txt is normal though. And I have no idea what it shows when it's crashing. I'm not sure how to find that out either, as once I'm alerted to SMTP being down, it's already too late - ASSP has crashed. DBD-error.txt is 0 bytes. In the Griplist folder. It appears to have been "modified" about a minute ago, but still 0bytes. I also see: __db.001 888kb __db.002 120kb __db.003 648kb I don't believe that I use the griplist. noGriplistUpload and noGriplistDownload are both checked. Due to our charity privacy policy :( I just restarted the ASSP service in Windows and see 10 of the griplist\DBD-error.txt handles. Is >>that<< normal? I temporarily reverted to 21218 (I happened to have that old version on hand) and seems to have 9 of the griplist\DBD-error.txt handles, so having a bunch doesn't seem to be a new problem, if it's a problem at all. I feel like some loop happens when there TLS errors with the new versions though that somehow gets more of these griplist\dbd-error.txt handels to open until there no more file handles left On Fri, Oct 8, 2021 at 7:27 PM K Post wrote: > That's funny Bob, I was just looking at Sysinternals to see if there was > such a tool. Also looking to see if there's anything like this: > > https://stackoverflow.com/questions/8845949/how-to-find-open-global-filehandles-in-a-perl-program > that would work for Windows. > > > > On Fri, Oct 8, 2021 at 1:56 PM Robert K Coffman Jr. -Info From Data Corp. < > bcoff...@infofromdata.com> wrote: > >> I'm curious what handle (Sysinternals tool) says when you hit the file >> limit... >> >> - Bob >> >> On 10/8/2021 10:47 AM, K Post wrote: >> > And a similar thing just happened again with 21280. ASSP gets to the >> > point where it can't open any more files, griplist can't be opened, and >> > it goes into a shutdown process. >> >> >> >> ___ >> Assp-test mailing list >> Assp-test@lists.sourceforge.net >> https://lists.sourceforge.net/lists/listinfo/assp-test >> > ___ Assp-test mailing list Assp-test@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/assp-test
Re: [Assp-test] fixes in assp 2.6.6 *SPAM-Evaporator* build 21280
That's funny Bob, I was just looking at Sysinternals to see if there was such a tool. Also looking to see if there's anything like this: https://stackoverflow.com/questions/8845949/how-to-find-open-global-filehandles-in-a-perl-program that would work for Windows. On Fri, Oct 8, 2021 at 1:56 PM Robert K Coffman Jr. -Info From Data Corp. < bcoff...@infofromdata.com> wrote: > I'm curious what handle (Sysinternals tool) says when you hit the file > limit... > > - Bob > > On 10/8/2021 10:47 AM, K Post wrote: > > And a similar thing just happened again with 21280. ASSP gets to the > > point where it can't open any more files, griplist can't be opened, and > > it goes into a shutdown process. > > > > ___ > Assp-test mailing list > Assp-test@lists.sourceforge.net > https://lists.sourceforge.net/lists/listinfo/assp-test > ___ Assp-test mailing list Assp-test@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/assp-test
Re: [Assp-test] fixes in assp 2.6.6 *SPAM-Evaporator* build 21280
I'm curious what handle (Sysinternals tool) says when you hit the file limit... - Bob On 10/8/2021 10:47 AM, K Post wrote: And a similar thing just happened again with 21280. ASSP gets to the point where it can't open any more files, griplist can't be opened, and it goes into a shutdown process. ___ Assp-test mailing list Assp-test@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/assp-test
Re: [Assp-test] fixes in assp 2.6.6 *SPAM-Evaporator* build 21280
And a similar thing just happened again with 21280. ASSP gets to the point where it can't open any more files, griplist can't be opened, and it goes into a shutdown process. On Thu, Oct 7, 2021 at 2:50 PM K Post wrote: > Here's excerpts from my log. Odd stuff and concerning. > > > ASSP had been running for 24+ hours on 21279 without issue. Saw a bunch > of the got an unexpected TLSv1_2 handshake Client-Helo-Frame warnings > during that time, which ASSP seems to handle much better than with the > previous version. The transactions I saw are not dissimilar this this > sequence which happened just before things headed south: > > > Oct-07-21 11:52:03 Connected: session:AC2E2C40 212.102.59.230:53720 > > (assp internal ip):25 > (smtp internal ip):25 > Oct-07-21 11:52:03 212.102.59.230 *warning: got an unexpected TLSv1_2 > handshake Client-Helo-Frame of version (3.3)* from IP '212.102.59.230' at > local IP '(assp internal ip)' and Port '25' - the connection will be closed > Oct-07-21 11:52:03 212.102.59.230 Message-Score: added 25 (etValencePB) > for EarlyTalker, total score for this message is now 25 > Oct-07-21 11:52:03 212.102.59.230 info: PB-IP-Score for '212.102.59.0' is > 200, added 25 in this session > Oct-07-21 11:52:03 212.102.59.230 disconnected: session:AC2E2C40 > 212.102.59.230 - processing time 0 seconds > Oct-07-21 11:52:03 Connected: session:71BAB808 212.102.59.230:53722 > > (assp internal ip):25 > (smtp internal ip):25 > Oct-07-21 11:52:03 *Error: Worker_5 accept_SSL to client 212.102.59.230 > denied - the client failed before on SSL/TLS* > Oct-07-21 11:52:03 Error: Worker_5 accept_SSL to client 212.102.59.230 > denied - the client failed before on SSL/TLS > Oct-07-21 11:52:03 212.102.59.230 disconnected: session:71BAB808 > 212.102.59.230 - processing time 0 seconds > Oct-07-21 11:52:03 Connected: session:4DB26EA0 212.102.59.230:53726 > > (assp internal ip):25 > (smtp internal ip):25 > Oct-07-21 11:52:04 Connected: session:3050E3F0 212.102.59.230:53728 > > (assp internal ip):25 > (smtp internal ip):25 > Oct-07-21 11:52:04 212.102.59.230 disconnected: session:4DB26EA0 > 212.102.59.230 - processing time 1 seconds > Oct-07-21 11:52:05 Error: Worker_1 accept_SSL to client 212.102.59.230 > denied - the client failed before on SSL/TLS > Oct-07-21 11:52:05 212.102.59.230 disconnected: session:3050E3F0 > 212.102.59.230 - processing time 1 seconds > Oct-07-21 11:52:05 Error: Worker_1 accept_SSL to client 212.102.59.230 > denied - the client failed before on SSL/TLS > Oct-07-21 11:52:07 Connected: session:71BAB808 52.207.41.187:45398 > > (assp internal ip):25 > (smtp internal ip):25 > Oct-07-21 11:52:08 Connected: session:52815DB8 52.207.41.187:45442 > > (assp internal ip):25 > (smtp internal ip):25 > Oct-07-21 11:52:08 52.207.41.187 disconnected: session:71BAB808 > 52.207.41.187 - processing time 1 seconds > Oct-07-21 11:52:08 52.207.41.187 info: got STARTTLS request from > 52.207.41.187 > Oct-07-21 11:52:09 52.207.41.187 disconnected: session:52815DB8 > 52.207.41.187 - processing time 1 seconds > Oct-07-21 11:52:10 Connected: session:A91752E8 172.241.24.83:58278 > > (assp internal ip):25 > (smtp internal ip):25 > Oct-07-21 11:52:10 172.241.24.83 disconnected: session:A91752E8 > 172.241.24.83 - processing time 0 seconds > Oct-07-21 11:52:10 Connected: session:8B034AF0 172.241.24.83:58392 > > (assp internal ip):25 > (smtp internal ip):25 > Oct-07-21 11:52:11 172.241.24.83 info: got STARTTLS request from > 172.241.24.83 > Oct-07-21 11:52:12 172.241.24.83 disconnected: session:8B034AF0 > 172.241.24.83 - processing time 2 seconds > Oct-07-21 11:52:25 Connected: session:52C3B6D0 23.239.7.4:49106 > (assp > internal ip):25 > (smtp internal ip):25 > Oct-07-21 11:52:25 23.239.7.4 disconnected: session:52C3B6D0 23.239.7.4 - > processing time 0 seconds > Oct-07-21 11:52:25 Connected: session:874B2E68 23.239.7.4:49688 > (assp > internal ip):25 > (smtp internal ip):25 > Oct-07-21 11:52:25 23.239.7.4 info: got STARTTLS request from 23.239.7.4 > Oct-07-21 11:52:26 Connected: session:886EF9A0 192.82.209.81:9208 > (assp > internal ip):25 > (smtp internal ip):25 > Oct-07-21 11:52:26 192.82.209.81 info: got STARTTLS request from > 192.82.209.81 > Oct-07-21 11:52:26 23.239.7.4 disconnected: session:874B2E68 23.239.7.4 - > processing time 1 seconds > > > Then, a bunch of email is received normally, then this: > > > Oct-07-21 11:54:01 179.26.113.249 info: injected STARTTLS request to (smtp > internal ip)*<-- injected STARTTTLS request? Haven't noticed that > before* > Oct-07-21 11:54:02 msg25642-16992 179.26.113.249 > Message-Score: added 5 (fiphValencePB) for Suspicious HELO - contains IP: ' > r179-26-113-249.dialup.adsl.anteldata.net.uy', total score for this > message is now 5 > Oct-07-21 11:54:02 msg25642-16992 179.26.113.249 > [scoring] (Suspicious HELO - contains IP: ' > r179-26-113-249.dialup.adsl.anteldata.net.uy') > Oct-07-21 11:54:02 msg25642-16992 [SpoofedSender] 179.26.113.249 < >
Re: [Assp-test] fixes in assp 2.6.6 *SPAM-Evaporator* build 21280
Here's excerpts from my log. Odd stuff and concerning. ASSP had been running for 24+ hours on 21279 without issue. Saw a bunch of the got an unexpected TLSv1_2 handshake Client-Helo-Frame warnings during that time, which ASSP seems to handle much better than with the previous version. The transactions I saw are not dissimilar this this sequence which happened just before things headed south: Oct-07-21 11:52:03 Connected: session:AC2E2C40 212.102.59.230:53720 > (assp internal ip):25 > (smtp internal ip):25 Oct-07-21 11:52:03 212.102.59.230 *warning: got an unexpected TLSv1_2 handshake Client-Helo-Frame of version (3.3)* from IP '212.102.59.230' at local IP '(assp internal ip)' and Port '25' - the connection will be closed Oct-07-21 11:52:03 212.102.59.230 Message-Score: added 25 (etValencePB) for EarlyTalker, total score for this message is now 25 Oct-07-21 11:52:03 212.102.59.230 info: PB-IP-Score for '212.102.59.0' is 200, added 25 in this session Oct-07-21 11:52:03 212.102.59.230 disconnected: session:AC2E2C40 212.102.59.230 - processing time 0 seconds Oct-07-21 11:52:03 Connected: session:71BAB808 212.102.59.230:53722 > (assp internal ip):25 > (smtp internal ip):25 Oct-07-21 11:52:03 *Error: Worker_5 accept_SSL to client 212.102.59.230 denied - the client failed before on SSL/TLS* Oct-07-21 11:52:03 Error: Worker_5 accept_SSL to client 212.102.59.230 denied - the client failed before on SSL/TLS Oct-07-21 11:52:03 212.102.59.230 disconnected: session:71BAB808 212.102.59.230 - processing time 0 seconds Oct-07-21 11:52:03 Connected: session:4DB26EA0 212.102.59.230:53726 > (assp internal ip):25 > (smtp internal ip):25 Oct-07-21 11:52:04 Connected: session:3050E3F0 212.102.59.230:53728 > (assp internal ip):25 > (smtp internal ip):25 Oct-07-21 11:52:04 212.102.59.230 disconnected: session:4DB26EA0 212.102.59.230 - processing time 1 seconds Oct-07-21 11:52:05 Error: Worker_1 accept_SSL to client 212.102.59.230 denied - the client failed before on SSL/TLS Oct-07-21 11:52:05 212.102.59.230 disconnected: session:3050E3F0 212.102.59.230 - processing time 1 seconds Oct-07-21 11:52:05 Error: Worker_1 accept_SSL to client 212.102.59.230 denied - the client failed before on SSL/TLS Oct-07-21 11:52:07 Connected: session:71BAB808 52.207.41.187:45398 > (assp internal ip):25 > (smtp internal ip):25 Oct-07-21 11:52:08 Connected: session:52815DB8 52.207.41.187:45442 > (assp internal ip):25 > (smtp internal ip):25 Oct-07-21 11:52:08 52.207.41.187 disconnected: session:71BAB808 52.207.41.187 - processing time 1 seconds Oct-07-21 11:52:08 52.207.41.187 info: got STARTTLS request from 52.207.41.187 Oct-07-21 11:52:09 52.207.41.187 disconnected: session:52815DB8 52.207.41.187 - processing time 1 seconds Oct-07-21 11:52:10 Connected: session:A91752E8 172.241.24.83:58278 > (assp internal ip):25 > (smtp internal ip):25 Oct-07-21 11:52:10 172.241.24.83 disconnected: session:A91752E8 172.241.24.83 - processing time 0 seconds Oct-07-21 11:52:10 Connected: session:8B034AF0 172.241.24.83:58392 > (assp internal ip):25 > (smtp internal ip):25 Oct-07-21 11:52:11 172.241.24.83 info: got STARTTLS request from 172.241.24.83 Oct-07-21 11:52:12 172.241.24.83 disconnected: session:8B034AF0 172.241.24.83 - processing time 2 seconds Oct-07-21 11:52:25 Connected: session:52C3B6D0 23.239.7.4:49106 > (assp internal ip):25 > (smtp internal ip):25 Oct-07-21 11:52:25 23.239.7.4 disconnected: session:52C3B6D0 23.239.7.4 - processing time 0 seconds Oct-07-21 11:52:25 Connected: session:874B2E68 23.239.7.4:49688 > (assp internal ip):25 > (smtp internal ip):25 Oct-07-21 11:52:25 23.239.7.4 info: got STARTTLS request from 23.239.7.4 Oct-07-21 11:52:26 Connected: session:886EF9A0 192.82.209.81:9208 > (assp internal ip):25 > (smtp internal ip):25 Oct-07-21 11:52:26 192.82.209.81 info: got STARTTLS request from 192.82.209.81 Oct-07-21 11:52:26 23.239.7.4 disconnected: session:874B2E68 23.239.7.4 - processing time 1 seconds Then, a bunch of email is received normally, then this: Oct-07-21 11:54:01 179.26.113.249 info: injected STARTTLS request to (smtp internal ip)*<-- injected STARTTTLS request? Haven't noticed that before* Oct-07-21 11:54:02 msg25642-16992 179.26.113.249 Message-Score: added 5 (fiphValencePB) for Suspicious HELO - contains IP: ' r179-26-113-249.dialup.adsl.anteldata.net.uy', total score for this message is now 5 Oct-07-21 11:54:02 msg25642-16992 179.26.113.249 [scoring] (Suspicious HELO - contains IP: ' r179-26-113-249.dialup.adsl.anteldata.net.uy') Oct-07-21 11:54:02 msg25642-16992 [SpoofedSender] 179.26.113.249 < unkn...@ourcharity.org> [scoring] (No Spoofing Allowed ' unkn...@ourcharity.org' in 'mailfrom') Oct-07-21 11:54:02 msg25642-16992 179.26.113.249 Message-Score: added 25 (slValencePB) for No Spoofing Allowed ' unkn...@ourcharity.org' in 'mailfrom', total score for this message is now 30 Oct-07-21 11:54:02 msg25642-16992 179.26.113.249 Message-Score: added 35 (flValencePB) for No Spoofing Allowed '
Re: [Assp-test] fixes in assp 2.6.6 *SPAM-Evaporator* build 21280
Uh oh. I haven't moved away from the test version you provided yesterday
yet, but I just got a complete ASSP crash, which was preceded by:
error: Worker_1 accept to client failed IO::Socket::INET=GLOB(0x881a0c40)
(timeout: 2 s) : Too many open files
error: Worker_2 accept to client failed IO::Socket::INET=GLOB(0x82c3f108)
(timeout: 2 s) : Too many open files
error: unable to close Socket IO::Socket::INET=GLOB(0xd872058) - - Bad
file descriptor
ERROR: no answering DNS-SERVER found <--- all 3 of my internal
dns servers are operational
error: couldn't create server socket to (inernal smtp ip) --
abortion connection
error: Worker_2 accept to client failed IO::Socket::INET=GLOB(0x7e56c288)
(timeout: 2 s) : Too many open files
I was able to restart the ASSP service, but immediately started getting the
same error messages as before.
I've restarted Windows, working on getting it to start now, but I wanted to
post ASAP just in case this is related to the test version / new version
you just released.
On Thu, Oct 7, 2021 at 12:05 PM Thomas Eckardt
wrote:
> Hi all,
>
> fixed in assp 2.6.6 *SPAM-Evaporator* build 21280:
>
>
> - if $fakeAUTHsuccess was set, the collected .eml files contained only the
> X-Assp headers - not the spam mail data
>
> - build 21277 caused an error 'too many opened files' on windows, if there
> were too many SSL-connection at a plain port (25)
>
> - the definition of an invalid regular expression in 'NotifyRe' may caused
> a crash of the assp process
>
>
>
>
> changed:
>
> - The default value for
>
> $ignoreEarlySSLClientHelo
> # (0/1) 1 - unexpected early SSLv23/TLS handshake Client-Helo-Frames are
> ignored , 0 - unexpected early SSLv23/TLS handshake Client-Helo-Frames are
> NOT ignored and the connection will be closed
>
> is changed from 1 to 0 in assp.pl
>
> to recover the old setting, you may change assp.pl or you can set
> $main::ignoreEarlySSLClientHelo = 1; in lib/CorrectASSPcfg.pm sub set{}
> The setting '1' was used as default to ignore early SSL connections from
> local clients.
>
>
> - mails which are catched by 'fakeAUTHsuccess' are now counted for the
> statistics in STATS:msgMaxErrors and SCORESTATS:MaxErrors
>
>
> Thomas
>
> DISCLAIMER:
> ***
> This email and any files transmitted with it may be confidential, legally
> privileged and protected in law and are intended solely for the use of the
> individual to whom it is addressed.
> This email was multiple times scanned for viruses. There should be no
> known virus in this email!
> ***
>
> ___
> Assp-test mailing list
> Assp-test@lists.sourceforge.net
> https://lists.sourceforge.net/lists/listinfo/assp-test
>
___
Assp-test mailing list
Assp-test@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/assp-test
