More notes and questions that might be of interest based on what I've witnessed:
Yesterday, I improved my script to update an included IP list file ONLY when there is an IP change detected. I ran the script fresh, then restarted ASSP. No main thread stuck warnings for several hours. ASSP wasn't saying that the files were modified, because they weren't. At 10:30pm, one of the SPF records changed, so a single include file was updated. At 10:33 the main thread warning unable to transfer messages start. Before each hang (every 5 minutes), ASSP's bug would tell me that the included file has changed. I am guessing that the bug you found is ASSP getting the file mod date at startup, but not recording the new date after it detects a change. At least we know why this happens every 5 minutes, but I'm more interested in *why it's happening even once.* To me, the main thread unable to transfer error indicates that there's something going really slow when the rebuild of the regexes happens. Because the external file changes, at least the group that uses that file needs to be rebuilt. Or, does the whole groups file get rebuilt and then all rules that reference groups also gets rebuilt with the new regex? Could my newly reformed DKIMWLAddress list that starts generally with [@|.] be pushing me over the threshold, since each line is now an OR or does ASSP handle optimizing that so it's a non-issue? Whatever the case, not knowing how threading/workers actually work, why is the regex rebuild seemingly using all workers and not just the maintenance worker, leaving the other workers available? thanks On Wed, Oct 27, 2021 at 1:40 PM K Post <nntp.p...@gmail.com> wrote: > > Apart from the fact that the MaintThread (10000) does not store the > file time correctly for 'Groups' included files (which will be fixed), > Okay, at least that explains why it was trying to reload every 5 minutes. > Hopefully the fix in the ASSP code combined with mine (see below) to stop > my script from updating the included files hourly, will stop the main > thread from getting stuck so often during the reload. Once an hour is > bearable. > > >everything else you asked is answered in the GUI for an IT prof. > I know you don't believe that I've ever read the GUI. I'm a big proponent > of RTFM, and always search and re-read sections before asking questions > here. Believe it or not, I write a whole lot of documentation. It's the > least favorite part of my "IT Pro" job, but I, as you do, recognize it as > essential. I cannot find anywhere in the ASSP GUI where it talks about > an included external files being encrypted once it's read by ASSP. This > detail is either not in the GUI or isn't clear enough that I was able to > find it. > > > >Every security related content is encryped or not shown by assp. > ASSP has no way of knowing if those external includes have passwords for > LDAP in them, so I understand encrypting them, and that's fine. Being > that I was trying to ascertain why my config reloads were seemingly causing > the main thread, and I didn't *see or read *anything (not that it's not > there, I just don't see where), I asked about this encoding / encryption to > make sure that this was expected and wasn't the cause of the issues I am > seeing. > > > >>1 33 s call to > ConfigChangeTLSPorts->(TLStoProxyListenPorts,'',,Initializing) > >This is the last finished (debug) step (and the seconds since then - 33) > in rereading the config, before the new regular expressions (IP) are build > by each thread. > > That's very helpful information. Could / should the status screen be > updated to show processes as they start, instead of showing the last one > that finished? ConfigChangeTLS isn't really the current action as the > status gui says, the regex rebuild has started. I still don't follow why > all of the workers are showing this previous step though. Shouldn't only 1 > worker have been doing it, leaving the others available? I have no idea, > that's why I'm asking. > > > Last night, I disabled the SPF update process then restarted ASSP (the bug > you found seems to only be after a file changes. If assp starts and the > external files don't change after that, they're not detected as changed > every time). NO hangs all night. I ran the script manually once just now > and received the unable to transfer warning one assp picked up the > changes. So it sure seems like my issue is directly related to these > external files. > > The IP lists that I generate from the SPF records are only 50kb combined > in total, so by no means massive. I was seeing the error when they were > only 25kb total (before I discovered an issue with the URL I was getting > yahoo ip's from). Maybe the rebuild of those plus the other regexes just > takes too long? I'm not sure why though. Is there a more efficient way > for me to list the addresses? Could it be something not with building the > group file itself, but in building the multiple places that the group > definitions are used? > > If an external IP list is detected as changed, would the DKIMWLAddress > regex be also rebuilt right then, even if DKIMWLAddrsses isn't changed? I > ask because this problem seems to have been happening much more > frequently after my changing from about 500 DKIMWLAddress lines to about > 300, most of which now start with [@|.] Could that be giving just enough > overhead during the regex rebuild that happens when the external SPF ip > list change is erroneously detected to not let it finish in the allotted 30 > seconds? > > I've modified my script to only update the config files when the compiled > IP list differs from what it found the last time it ran. Hopefully that'll > help too, so config reloads won't happen every hour (after your > modification detection fix), and only happen when one of the spf files > actually changes. > > > >>>For years, I've run an external script to query various providers' SPF > records and get the IP addresses for them into a file. > >For what reason? > > I'm glad you asked. We talked about this years ago, and I've posted the > script here a couple of times. The new version is attached to this reply. > > The script creates files containing a list of the IP addresses and ranges > specified in each domain's SPF record. It processes them recursively, > going through includes too. Those files are then used in the Groups > definition. For example, I use the SPF records for outlook.com and > hotmail.com like this in the Groups file: > > [GROUP-MICROSOFT-IPS] > # include IP-Lists/IPS-outlook.com.cfg > # include IP-Lists/IPS-hotmail.com.cfg > > The outlook.com SPF includes the same records for the vast majority of > Office365 users spf.protection.outlook.com > The outlook.com.cfg file looks like: > > # > # Generated by WriteFile-GetDomainIPSFromSPF.pl > # > 157.56.232.0/21 FROMSPF: spf-a.outlook.com > 157.56.240.0/20 FROMSPF: spf-a.outlook.com > 207.46.198.0/25 FROMSPF: spf-a.outlook.com > 207.46.4.128/25 FROMSPF: spf-a.outlook.com > 157.56.24.0/25 FROMSPF: spf-a.outlook.com > (more) > 157.55.9.128/25 FROMSPF: > 40.92.0.0/15 FROMSPF: spf.protection.outlook.com > 40.107.0.0/16 FROMSPF: spf.protection.outlook.com > 52.100.0.0/14 FROMSPF: spf.protection.outlook.com > 104.47.0.0/17 FROMSPF: spf.protection.outlook.com > (more) > 157.55.2.0/25 FROMSPF: spf-a.hotmail.com > 65.54.190.0/24 FROMSPF: spf-a.hotmail.com > 65.54.51.64/26 FROMSPF: spf-a.hotmail.com > 65.54.61.64/26 FROMSPF: spf-a.hotmail.com > 65.55.111.0/24 FROMSPF: spf-a.hotmail.com > (more) > 94.245.112.0/27 FROMSPF: _spf-ssg-c.microsoft.com > 111.221.26.0/27 FROMSPF: _spf-ssg-c.microsoft.com > 207.46.50.192/26 FROMSPF: _spf-ssg-c.microsoft.com > 207.46.50.224 FROMSPF: _spf-ssg-c.microsoft.com > > > > So WHY am I doing this? > Microsoft Outlook/Hotmail/365 IPs are often abused, but the vast majority > of users are legitimate. There's tons of shared outgoing mail IP's in this > massive infrastructure. I use the IP's that my script builds in: > > noHelo - so one really bad office365 user doesn't manage to get the helo > for any microsoft SMTP server blocked for everyone else who is using it > noBlockingIPs - same concept. Once bad actor shouldn't get a MS ip > blocked for the rest > noPB - same > noPBWhite also, don't make it so that good senders automatically make it > easier for bad senders to use Microsoft IP's > noExtremePB - probably not necessary since it's already in noPB > noDelay - stuff sent through MS IP's will be retried, so delaying is > pointless. Might as well let legit senters come through right away. > noRBL - we've seen Microsoft ip's get on the DNSBL. > > The same principles are used for other providers who send on behalf of > many organizations, including legitimate bulk emailers like constant > contact who sometimes are guilty of sending spam, but usually are good. > > Is there a better way? Is this a bad idea? It's worked well for me, with > the exception of ASSP giving the main thread stuck warnings occasionally at > reload. I'd be happy to be able to stop using the script, but I don't know > of another way to accomplish what I'm looking for there. What do you do to > make sure that a provider like Google or Microsoft doesn't have shared SMTP > ip's blocked because of a couple bad actors? > > Thanks again for hearing me out! > > > On Wed, Oct 27, 2021 at 5:26 AM Thomas Eckardt <thomas.ecka...@thockar.com> > wrote: > >> Apart from the fact that the MaintThread (10000) does not store the file >> time correctly for 'Groups' included files (which will be fixed), >> everything else you asked is answered in the GUI for an IT prof. Every >> security related content is encryped or not shown by assp. >> >> >I just saw this again in the statusassp gui >> 1 33 s call to >> ConfigChangeTLSPorts->(TLStoProxyListenPorts,'',,Initializing) >> >> >> >> This is the last finished (debug) step (and the seconds since then - 33) >> in rereading the config, before the new regular expressions (IP) are build >> by each thread. >> >> >For years, I've run an external script to query various providers' SPF >> records and get the IP addresses for them into a file. >> >> For what reason? >> >> Thomas >> >> >> >> >> Von: "K Post" <nntp.p...@gmail.com> >> An: "ASSP development mailing list" < >> assp-test@lists.sourceforge.net> >> Datum: 27.10.2021 08:45 >> Betreff: Re: [Assp-test] Main_Thread is unable to transfer >> connection to any worker - try again >> ------------------------------ >> >> >> >> >> Looking more at these include files in my groups definition. If I open >> them in the OS immediately after they're generated, it looks as expected. >> Something like: >> # >> # Generated by WriteFile-GetDomainIPSFromSPF.pl >> # >> *198.2.128.0/24* <http://198.2.128.0/24> FROMSPF: *spf.mandrillapp.com* >> <http://spf.mandrillapp.com/> >> *198.2.132.0/22* <http://198.2.132.0/22> FROMSPF: *spf.mandrillapp.com* >> <http://spf.mandrillapp.com/> >> *198.2.136.0/23* <http://198.2.136.0/23> FROMSPF: *spf.mandrillapp.com* >> <http://spf.mandrillapp.com/> >> *198.2.145.0/24* <http://198.2.145.0/24> FROMSPF: *spf.mandrillapp.com* >> <http://spf.mandrillapp.com/> >> >> Once ASSP loads them though, it goes into some kind of encoded/encrypted >> format, a single long line, all hexidecimal like: >> 2acc4d3156084a1a3edc250c1f32bc5........ (continues) >> >> *Is this normal behavior?* I haven't found any mention of it in the >> GUI. I'm not using configuration sharing. The other config files don't >> seem to have this hexidecimal conversion, only the ones I generate with my >> script. >> >> I can edit the included files from the Groups section, by clicking the >> various "Edit included file <path>" button. It looks normal, not hex >> encoded. >> >> Note: the bottom of the editor window says: "First line specifies text >> that appears in the subject of report message. The remaining lines are the >> report message body." I'm guessing that's just an oversight. >> >> >> >> On Tue, Oct 26, 2021 at 11:17 AM K Post <*nntp.p...@gmail.com* >> <nntp.p...@gmail.com>> wrote: >> That's helpful Thomas, thank you. I've clearly got more digging to do, >> and I will, but I could use more guidance on what I've found so far if you >> have the time. >> >> 1) *ConfigChangeTLSPorts->(TLStoProxyListenPorts,'',,Initializing)* >> >> I just saw this again in the statusassp gui >> 1 33 s call to >> ConfigChangeTLSPorts->(TLStoProxyListenPorts,'',,Initializing) >> 2 32 s call to >> ConfigChangeTLSPorts->(TLStoProxyListenPorts,'',,Initializing) >> 3 31 s call to >> ConfigChangeTLSPorts->(TLStoProxyListenPorts,'',,Initializing) >> 4 30 s call to >> ConfigChangeTLSPorts->(TLStoProxyListenPorts,'',,Initializing) >> 5 29 s call to >> ConfigChangeTLSPorts->(TLStoProxyListenPorts,'',,Initializing) >> 6 19 s call to >> ConfigChangeTLSPorts->(TLStoProxyListenPorts,'',,Initializing) >> 7 27 s call to >> ConfigChangeTLSPorts->(TLStoProxyListenPorts,'',,Initializing) >> 10000 26 s call to >> ConfigChangeTLSPorts->(TLStoProxyListenPorts,'',,Initializing) >> 10001 39 s call to >> ConfigChangeTLSPorts->(TLStoProxyListenPorts,'',,Initializing) >> >> With worker logging set to diagnostic, I see saw a full screen of >> Oct-26-21 10:14:06 Info: Main_Thread can't interrupt Worker_4 (2) at the >> moment - try next worker >> >> Oct-26-21 10:14:06 Info: Main_Thread is unable to interrupt any worker >> for new connection - wait for available worker (max 30 seconds) >> Oct-26-21 10:14:06 Info: try to interrupt worker Worker_3 (0) for new >> connection >> Oct-26-21 10:14:06 Info: Main_Thread can't interrupt Worker_3 (0) at the >> moment - try next worker >> Oct-26-21 10:14:06 Info: try to interrupt worker Worker_2 (0) for new >> connection >> Oct-26-21 10:14:06 Info: Main_Thread can't interrupt Worker_2 (0) at the >> moment - try next worker >> Oct-26-21 10:14:06 Info: try to interrupt worker Worker_5 (0) for new >> connection >> Oct-26-21 10:14:06 Info: Main_Thread can't interrupt Worker_5 (0) at the >> moment - try next worker >> >> ...many many lines of that in a row. >> >> What could be causing ConfigChangeTLSPorts to be initializing using all >> workers? I've seen this before with POP3 configure, even though POP3 isn't >> used and isn't configured. >> >> >> 2) External config files always showing as changed??? >> >> For years, I've run an external script to query various providers' SPF >> records and get the IP addresses for them into a file. (provided a couple >> times here for community use). I then use that file in group definitions. >> For example, in the Groups file, I have: >> [GROUP-SENDGRID-IPS] >> # include IP-Lists/IPS-sendgrid.com.cfg >> # include IP-Lists/IPS-sendgrid.net.cfg >> >> Those 2 .cfg files are generated by the script doing a spf lookup for >> *sendgrid.com* <http://sendgrid.com/> and another for *sendgrid.net* >> <http://sendgrid.net/>. It recursively processes the records. The >> script runs once every 3 hours to capture any DNS changes that providers >> might make. The script isn't smart enough to know if anything has >> changed, it just re-writes the files every time. Once ASSP reads them, it >> seems that they get saved encrypted. I am able to view them fune using the >> GUI, but opening the .cfg files from the OS shows an encrypted long string. >> >> Even though my script only changes the files every 3 hours, I'm seeing >> entries in the log (with maintenance logging set to diagnostic) which >> indicates that ASSP thinks that they're changing every time, and it seems >> to be checking these files twice per scheduled reload. >> >> >> Oct-26-21 10:36:00 Worker_4 will sleep now >> Oct-26-21 10:36:03 Info: (re)scheduled ReloadOptionFiles -> >> nextOptionCheck for Oct-26-21 10:41:03 >> Oct-26-21 10:36:03 Info: found changed include file >> 'IP-Lists/IPS-sendgrid.net.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) *<-- It changed at 9:33, but also >> 8:33, 7:33, etc. Why does it think last change was yesterday at 21:30? * >> Oct-26-21 10:36:03 Info: found changed include file >> 'IP-Lists/IPS-amazon.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:03 Info: found changed include file >> 'IP-Lists/IPS-yahoo.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:03 Info: found changed include file >> 'IP-Lists/IPS-mailchimp.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:03 Info: found changed include file >> 'IP-Lists/IPS-myngp.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:03 Info: found changed include file >> 'IP-Lists/IPS-salesforce.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:03 Info: found changed include file >> 'IP-Lists/IPS-mandrillapp.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:03 Info: found changed include file >> 'IP-Lists/IPS-verticalresponse.com.cfg' for config 'Groups' - old >> (Oct-25-21 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:03 Info: found changed include file >> 'IP-Lists/IPS-bluestatedigital.com.cfg' for config 'Groups' - old >> (Oct-25-21 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:03 Info: found changed include file >> 'IP-Lists/IPS-google.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:03 Info: found changed include file >> 'IP-Lists/IPS-force.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:03 Info: found changed include file >> 'IP-Lists/IPS-constantcontact.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:03 Info: found changed include file >> 'IP-Lists/IPS-facebookmail.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:03 Info: found changed include file >> 'IP-Lists/IPS-outlook.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:03 Info: found changed include file >> 'IP-Lists/IPS-hotmail.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:03 Info: found changed include file >> 'IP-Lists/IPS-pphosted.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:03 Info: found changed include file >> 'IP-Lists/IPS-ccsend.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:03 Info: found changed include file >> 'IP-Lists/IPS-spf.constantcontact.com.cfg' for config 'Groups' - old >> (Oct-25-21 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:03 Info: found changed include file >> 'IP-Lists/IPS-facebook.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:03 Info: found changed include file >> 'IP-Lists/IPS-sendgrid.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:03 Info: (re)scheduled ReloadOptionFiles -> >> nextHashFileCheck for Oct-26-21 10:41:03 >> Oct-26-21 10:36:03 Saving config >> Oct-26-21 10:36:03 Info: no configuration changes detected - nothing to >> save - file d:/assp/assp.cfg is unchanged >> Oct-26-21 10:36:03 Worker_5 wakes up >> Oct-26-21 10:36:03 Worker_1 wakes up >> Oct-26-21 10:36:03 Worker_4 wakes up >> Oct-26-21 10:36:03 Worker_3 wakes up >> Oct-26-21 10:36:03 Worker_6 wakes up >> Oct-26-21 10:36:03 Worker_7 wakes up >> Oct-26-21 10:36:03 Info: DNS-check-interval is set to 60 seconds, >> DNS-error-recovery-interval is set to 5 seconds >> Oct-26-21 10:36:04 Info: Main_Thread got connection request >> Oct-26-21 10:36:04 Info: Main_Thread freed by idle Worker_3 in 0.067 >> seconds and 1 cycles - got (ok) >> Oct-26-21 10:36:04 Info: Worker_3 is interrupted to get new connection >> Oct-26-21 10:36:04 Connected: session:7327C910 *193.169.253.240:55146* >> <http://193.169.253.240:55146/> > a.b.c.60:25 > a.b.c.35:25 >> Oct-26-21 10:36:05 Info: Main_Thread got connection request >> Oct-26-21 10:36:05 Info: Main_Thread freed by interrupted Worker_3 in >> 0.069 seconds and 1 cycles - got (ok) >> Oct-26-21 10:36:05 Info: Worker_3 is interrupted to get new connection >> Oct-26-21 10:36:05 x.y.z.90 IP x.y.z.90 matches acceptAllMail - with >> x.y.z.90/32 >> Oct-26-21 10:36:05 Connected: session:89B52FB0 x.y.z.90:54247 > >> a.b.c.60:62974 > a.b.c.35:25 >> Oct-26-21 10:36:05 msg58965-29399 [unsupported_AUTH] 193.169.253.240 AUTH >> not allowed >> Oct-26-21 10:36:05 msg58965-29399 193.169.253.240 Message-Score: added >> 126 (autValencePB) for too many (1) AUTH errors from 193.169.253.0, total >> score for this message is now 126 >> Oct-26-21 10:36:05 msg58965-29399 193.169.253.240 [SMTP Error] 502 AUTH >> not supported >> Oct-26-21 10:36:09 Info: spam folder content was reread for MaxAllowedDups >> Oct-26-21 10:36:11 Info: found changed include file >> 'IP-Lists/IPS-sendgrid.net.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) *<-- it just notified of this at >> 10:36:03. Is it just notifying twice, or is it checking twice? Why does >> it still think the previous update was yesterday? It does this with all of >> the ip lists that are included.* >> Oct-26-21 10:36:11 Info: found changed include file >> 'IP-Lists/IPS-amazon.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:11 Info: found changed include file >> 'IP-Lists/IPS-yahoo.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:11 Info: found changed include file >> 'IP-Lists/IPS-mailchimp.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:11 Info: found changed include file >> 'IP-Lists/IPS-myngp.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:11 Info: found changed include file >> 'IP-Lists/IPS-salesforce.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:11 Info: found changed include file >> 'IP-Lists/IPS-mandrillapp.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:11 Info: found changed include file >> 'IP-Lists/IPS-verticalresponse.com.cfg' for config 'Groups' - old >> (Oct-25-21 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:11 Info: found changed include file >> 'IP-Lists/IPS-bluestatedigital.com.cfg' for config 'Groups' - old >> (Oct-25-21 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:11 Info: found changed include file >> 'IP-Lists/IPS-google.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:11 Info: found changed include file >> 'IP-Lists/IPS-force.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:11 Info: found changed include file >> 'IP-Lists/IPS-constantcontact.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:11 Info: found changed include file >> 'IP-Lists/IPS-facebookmail.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:11 Info: found changed include file >> 'IP-Lists/IPS-outlook.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:11 Info: found changed include file >> 'IP-Lists/IPS-hotmail.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:11 Info: found changed include file >> 'IP-Lists/IPS-pphosted.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:11 Info: found changed include file >> 'IP-Lists/IPS-ccsend.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:11 Info: found changed include file >> 'IP-Lists/IPS-spf.constantcontact.com.cfg' for config 'Groups' - old >> (Oct-25-21 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:11 Info: found changed include file >> 'IP-Lists/IPS-facebook.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:11 Info: found changed include file >> 'IP-Lists/IPS-sendgrid.com.cfg' for config 'Groups' - old (Oct-25-21 >> 21:30:41), new (Oct-26-21 09:33:11) >> Oct-26-21 10:36:15 Info: Main_Thread got connection request <-- nothing >> for 30 seconds, then the main thread unable to transfer >> Oct-26-21 10:36:46 Info: notification message queued to sent to >> assp-not...@ourcharity.org >> *Oct-26-21 10:36:46 Warning: Main_Thread is unable to transfer connection >> to any worker - try again!* >> *Oct-26-21 10:37:17 Warning: Main_Thread is unable to transfer connection >> to any worker - try again! -- 30 seconds after the first one.* >> Oct-26-21 *10:37:33* Worker_6 *finished reloading configuration* >> Oct-26-21 10:37:33 Info: Main_Thread freed by interrupted Worker_3 in >> 78.187 seconds and 1 cycles - got (ok) >> Oct-26-21 10:37:33 Worker_3 finished reloading configuration >> Oct-26-21 10:37:33 Info: Main_Thread got connection request >> Oct-26-21 10:37:33 Info: Main_Thread freed by interrupted Worker_3 in >> 0.199 seconds and 1 cycles - got (ok) >> Oct-26-21 10:37:33 Info: Main_Thread got connection request >> Oct-26-21 10:37:33 Info: Main_Thread freed by idle Worker_4 in 0.014 >> seconds and zero cycles - got (ok) >> Oct-26-21 10:37:33 Info: Main_Thread got connection request >> Oct-26-21 10:37:33 Info: Main_Thread freed by idle Worker_6 in 0.014 >> seconds and zero cycles - got (ok) >> Oct-26-21 10:37:33 Info: Worker_3 is interrupted to get new connection >> Oct-26-21 10:37:33 Connected: session:258FF548 *216.160.207.10:42420* >> <http://216.160.207.10:42420/> > a.b.c.60:25 > a.b.c.35:25 >> Oct-26-21 10:37:33 msg58965-29399 193.169.253.240 info: PB-IP-Score for >> '193.169.253.0' is 2268, added 126 in this session >> Oct-26-21 10:37:33 msg58965-29399 193.169.253.240 disconnected: >> session:7327C910 193.169.253.240 - processing time 89 seconds >> Oct-26-21 10:37:33 Worker_4 finished reloading configuration >> Oct-26-21 10:37:33 Worker_4 will sleep now >> Oct-26-21 10:37:33 Worker_6 will sleep now >> Oct-26-21 10:37:33 Info: Worker_3 is interrupted to get new connection >> Oct-26-21 10:37:33 Connected: session:8FC33A40 *104.237.139.48:57300* >> <http://104.237.139.48:57300/> > a.b.c.60:25 > a.b.c.35:25 >> Oct-26-21 10:37:33 Worker_4 wakes up >> Oct-26-21 10:37:33 Info: Worker_4 got connection from MainThread >> >> This type of behavior shouldn't be expected should it? >> >> >> >> >> >> >> On Tue, Oct 26, 2021 at 6:01 AM Thomas Eckardt < >> *thomas.ecka...@thockar.com* <thomas.ecka...@thockar.com>> wrote: >> >I tried to see where SaveConfig() >> >> SaveConfig() is called in the Main_Thread (Worker_0) every time, >> anything in the assp configuration was changed. >> And under normal cirumstances, after that, all workers are told to check >> there configuration (and reload) in relation to the new one (lists, files, >> recompile regexes ....). >> >> > I >>think<< >> >> if I would have a problem with >"Saving config"< (which is a maintenance >> task) - I would increase the 'MaintenanceLog' level >> if I would have a problem with workers >"unable to transfer connection >> to any worker"< - I would enable WorkerLog and WorkerLogging >> >> example log: >> >> Oct-25-21 23:12:58 [Worker_10000] Downloading level-2-TLDlist via direct >> HTTP connection >> Oct-25-21 23:12:58 [Worker_10000] Level-2-TLDlist download completed >> Oct-25-21 23:12:58 [Worker_10000] Downloading level-3-TLDlist via direct >> HTTP connection >> Oct-25-21 23:12:59 [Worker_10000] Level-3-TLDlist download completed >> Oct-25-21 23:12:59 [Worker_10000] Info: next TLDlist download in 1 day 5 >> hours 58 minutes >> Oct-25-21 23:12:59 [Worker_10000] Info: file >> c:/assp/files/URIBLCCTLDS.txt updated for URIBLCCTLDS >> Oct-25-21 23:13:00 [Main_Thread] Saving config >> Oct-25-21 23:13:00 [Main_Thread] Info: no configuration changes detected >> - nothing to save - file c:/assp/assp.cfg is unchanged >> Oct-25-21 23:13:00 [Main_Thread] Adminupdate: file >> 'c:/assp/files/URIBLCCTLDS.txt' for config 'URIBLCCTLDS' was changed >> Oct-25-21 23:13:00 [Main_Thread] Option list file: >> 'c:/assp/files/URIBLCCTLDS.txt' reloaded (URIBLCCTLDS) with 12,280 records >> Oct-25-21 23:13:02 [Worker_1] Worker_1 wakes up >> Oct-25-21 23:13:02 [Worker_5] Worker_5 wakes up >> Oct-25-21 23:13:02 [Worker_4] Worker_4 wakes up >> Oct-25-21 23:13:02 [Worker_3] Worker_3 wakes up >> Oct-25-21 23:13:02 [Worker_2] Worker_2 wakes up >> Oct-25-21 23:13:03 [Worker_1] Worker_1 finished reloading configuration >> Oct-25-21 23:13:03 [Worker_1] Worker_1 will sleep now >> Oct-25-21 23:13:04 [Worker_2] Worker_2 finished reloading configuration >> Oct-25-21 23:13:04 [Worker_2] Worker_2 will sleep now >> Oct-25-21 23:13:05 [Worker_3] Worker_3 finished reloading configuration >> Oct-25-21 23:13:05 [Worker_3] Worker_3 will sleep now >> Oct-25-21 23:13:06 [Worker_4] Worker_4 finished reloading configuration >> Oct-25-21 23:13:06 [Worker_4] Worker_4 will sleep now >> Oct-25-21 23:13:07 [Worker_5] Worker_5 finished reloading configuration >> Oct-25-21 23:13:07 [Worker_5] Worker_5 will sleep now >> Oct-25-21 23:13:08 [Worker_10000] Worker_10000 finished reloading >> configuration >> Oct-25-21 23:13:10 [Worker_10001] Worker_10001 finished reloading >> configuration >> Oct-25-21 23:13:29 [Worker_10000] Downloading Extended Droplist via >> direct HTTP connection >> Oct-25-21 23:13:29 [Worker_10000] Extended Droplist already up to date >> Oct-25-21 23:13:29 [Worker_10000] Info: next droplist download in 7 hours >> 34 minutes >> >> >> debug may help >> for time related debugging, I (or some one who read the manual) would >> consider to use ConfigChangeSchedule >> >> notice: analyzing all the produced debug files (in general debug mode) is >> a very time consuming task >> >> Check your option files for bad (too greedy) regular expressions. Check, >> if there are other processes modifying assp files. Check that required >> services (DNS, SQL,ClamAV,..... ) are responsive at this time. >> >> If (for any reason) it is expected, that the config reload takes 30 >> seconds or longer - 'ConnectionTransferTimeOut' should be changed - or the >> "Warning: >> Main_Thread is unable to transfer connection to any worker - try again!" >> should be ignored. >> >> If the reload takes X seconds for the MainThread. Within these X seconds >> all new connections are queued by the OS. After this time (the reload) the >> MainThread tries to transfer all these new connections within some >> (milli)seconds to the workers - this may overload the SMTP-workers for some >> time. >> >> Thomas >> >> >> >> Von: "K Post" <*nntp.p...@gmail.com* <nntp.p...@gmail.com>> >> An: "ASSP development mailing list" < >> *assp-test@lists.sourceforge.net* <assp-test@lists.sourceforge.net>> >> Datum: 25.10.2021 17:20 >> Betreff: Re: [Assp-test] Main_Thread is unable to transfer >> connection to any worker - try again >> ------------------------------ >> >> >> >> We are lucky to have a new (to us) faster server donated since this >> original May posting on the "unable to transfer connection to any worker" >> error. However, with the new box with Windows 2019 installation, fully >> patched, MySQL latest community, and Strawberry perl 5.32 it's still >> happening in spurts. Not a heavy load, 16gb ram. 12 cores total. ASSP >> uses about 1.7gb after running for a bit. MySQL seems fast, ClamAV in use. >> >> Sometimes I get the warning just once in a day, often it's every *5 >> minutes* for a while. This morning, there were 3 occurrences with 10 >> minutes in between each. But always, when I look at the log, it's right >> after the "Saving config" process, always when there's no config changes. >> >> I tried to see where SaveConfig() is being called from every 5 minutes. >> I >>think<< it's when the ReloadOptionFiles timer hits, but I'm not sure. >> ReloadOptionFiles is set to 300 (5 minutes) >> AutoReloadCfg is enabled, though I'm never modifying assp.cfg without >> using the GUI >> What else should I be looking at? >> >> >> From today: >> Oct-25-21 11:09:24 Saving config >> Oct-25-21 11:09:24 Info: no configuration changes detected - nothing to >> save - file d:/assp/assp.cfg is unchanged >> (a message processed) >> Oct-25-21 11:09:57 Info: notification message queued to sent to >> assp-not...@ourcharity.org >> Oct-25-21 11:09:57 Warning: Main_Thread is unable to transfer connection >> to any worker - try again! >> >> assp acts normally for 10 minutes, then: >> >> Oct-25-21 11:19:28 Saving config >> Oct-25-21 11:19:28 Info: no configuration changes detected - nothing to >> save - file d:/assp/assp.cfg is unchanged >> Oct-25-21 11:20:00 Info: notification message queued to sent to >> assp-not...@ourcharity.org >> Oct-25-21 11:20:00 Warning: Main_Thread is unable to transfer connection >> to any worker - try again! >> >> assp resumes >> >> Oct-25-21 11:29:32 Saving config >> Oct-25-21 11:29:32 Info: no configuration changes detected - nothing to >> save - file d:/assp/assp.cfg is unchanged >> (a single message processed fine here) >> Oct-25-21 11:30:04 Info: notification message queued to sent to >> assp-not...@ourcharity.org >> Oct-25-21 11:30:04 Warning: Main_Thread is unable to transfer connection >> to any worker - try again! >> >> >> >> On Mon, May 17, 2021 at 8:53 PM K Post <*nntp.p...@gmail.com* >> <nntp.p...@gmail.com>> wrote: >> I'm desperate for help. It seems that ASSP has thread problems >> frequently when it reloads the config. I see warnings that the Main_Thread >> is unable to transfer connection to any worker, often every 5 minutes for >> hours. >> >> May-17-21 20:40:35 Saving config >> May-17-21 20:40:35 Info: no configuration changes detected - nothing to >> save - file c:/assp/assp.cfg is unchanged >> May-17-21 20:41:08 Info: notification message queued to sent to >> assp-not...@ourcharity.org >> May-17-21 20:41:08 Warning: Main_Thread is unable to transfer connection >> to any worker - try again! >> >> Even when there's no settings detected (line 2 above), it can hang. >> >> I can't seem to figure out why. >> >> Windows 2012 R2 >> Strawberry Perl >> Latest ASSP >> >> Any guidance on where to start? >> >> Thank you >> _______________________________________________ >> Assp-test mailing list >> *Assp-test@lists.sourceforge.net* <Assp-test@lists.sourceforge.net> >> *https://lists.sourceforge.net/lists/listinfo/assp-test* >> <https://lists.sourceforge.net/lists/listinfo/assp-test> >> >> >> >> >> 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* <Assp-test@lists.sourceforge.net> >> *https://lists.sourceforge.net/lists/listinfo/assp-test* >> <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 >> >> >> >> >> 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
