Inbound connections stuck on processing a |
Post Reply 
|
| Author | |
lyndonje 
Senior Member 
Joined: 31 January 2006 Location: United Kingdom Status: Offline Points: 192 |
 Post Options
 Thanks(0)
 Quote Reply
 Topic: Inbound connections stuck on processing aPosted: 01 March 2006 at 12:33pm |
|
Hi All.
Just had a problem whereby connections seems to be left open on processing (and not closing), causing our maximum number of concurrent inbound connections being reached and not accepting anymore mail. I doubled this limit and saw concurrent connections rise. Restarting the SF service seemed to return things back to normal. In the log I see multiple of the following: 03/01/06 17:23:23:405 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 3296 03/01/06 17:23:23:405 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 856 03/01/06 17:23:23:405 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 2256 03/01/06 17:23:23:405 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 2484 03/01/06 17:23:23:405 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 2656 03/01/06 17:23:23:405 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 4056 Also see: 03/01/06 17:23:40:249 -- (2388) TSpamFilterForm - corpus.db copy of files not exist - exiting 03/01/06 17:23:40:249 -- (2388) TSpamFilterForm - End LoadFromFile for corpus.db (db.dat) (0) In corpus\queue directory there are 31 token files - is this normal? Anything to worry about? Then start to see: 03/01/06 17:24:54:436 -- (2896) Too many connections. Disconnecting: x.x.x.x And: 03/01/06 17:24:54:655 -- (2128) No Data Received 03/01/06 17:24:54:655 -- (2128) Disconnect Any ideas? |
|
 |
|
|
LogSat
Admin Group 
Joined: 25 January 2005 Location: United States Status: Offline Points: 4104 |
Post Options
Thanks(0)
Quote Reply
Posted: 01 March 2006 at 4:51pm |
|
lyndonje,
Could you please zip and email us a copy of your SpamFilter's activity logfile? Please also let us know what version of SpamFilter you're using. |
|
|
|
|
lyndonje
Senior Member
Joined: 31 January 2006 Location: United Kingdom Status: Offline Points: 192 |
Post Options
Thanks(0)
Quote Reply
Posted: 02 March 2006 at 3:48am |
|
I've emailed the log, and I'm running v.2.7.1.523. Thanks.
|
|
|
|
|
LogSat
Admin Group
Joined: 25 January 2005 Location: United States Status: Offline Points: 4104 |
Post Options
Thanks(0)
Quote Reply
Posted: 03 March 2006 at 12:06am |
|
lyndonje,
We've received your log and analyzed it thoroughly. At exactly 14:27 your incoming connections started to rise and within minutes reached the maximium allowed. They remained peaked until you restarted SpamFilter. We've looked over and over your log, but could not find any indication of what may have caused this to happen. Is there anything relevant in the Windows Event Logs at that time that could explain what happened? Unfortunately for now I do not have an answer. Should this happen again, I hope that with a 2nd logfile we can find common entries that can point us in the right direction. In regards to the other errors with the corpus.db file, it's likely that your Bayesian filter's corpus database became corrupted. To solve that the best way to proceed is to start with an empty database. To do that please stop SpamFilter, delete or rename the \SpamFilter\Corpus directory, and restart SpamFilter. I do not believe this is related to the connection problem above, but can't be 100% sure... |
|
|
|
|
lyndonje
Senior Member
Joined: 31 January 2006 Location: United Kingdom Status: Offline Points: 192 |
Post Options
Thanks(0)
Quote Reply
Posted: 03 March 2006 at 4:58am |
|
Hi,
Quick question with regard to corpus, what would happen is spam filter was running on the console, a user RDP's into the server and opens a second instance of the spam filter interface? Just thinking.... Regards, Lyndon. |
|
|
|
|
LogSat
Admin Group
Joined: 25 January 2005 Location: United States Status: Offline Points: 4104 |
Post Options
Thanks(0)
Quote Reply
Posted: 03 March 2006 at 4:10pm |
|
Lyndon,
This is a popular topic in the forum :-) The post at http://www.logsat.com/spamfilter/forums/forum_posts.asp?TID= 5301 has more details. The major points are (in bold at the end is the solution for Windows 2003): ============================ SpamFilter ISP can be run in two different ways. The first is as a Windows service (the most common - SpamFilterSvc.exe), the second is as a standalone application using SpamFilter.exe. The latter is mostly used for troubleshooting, even though several users have asked to be able to run SpamFilter in non-service mode. If you are already running SpamFilter as a service, subsequently running the standalone application (SpamFilter.exe) will open a new instance of SpamFilter, it will not be the GUI for your service. Since it's using the same settings as your service, it is trying to listen on the same IPs used by the service, and since it can't it will display the "could not bind socket error". Please note that the service does show display a GUI (launched from an icon in the tray bar), but if accessing a Windows 2000 server remotely using Terminal Services will not be able to display the GUI. This is because Terminal Services in Win2K is not able to display the server's physical console. Looking at the physical server's screen, or using a product like PCAnywhere, DameWare, VNC etc that display the actual screen will reveal the console. Windows 2003 server's terminal services does not have this limitation. ============================ and ============================ Please note that in Windows 2000 Server, Terminal Services does not provide access to the "real" Console 0 (console 0 is the primary physical display), but rather it displays a "virtual" console that does not allow to display, among other things, the SpamFilter GUI. Microsoft fixed this in Windows 2003, where Terminal Services instead does allow RDP to connect on the Console 0. Some Terminal Services clients have a checkbox in their settings to connect to the console. In the XP Remote Desktop, Microsoft (in)conveniently decided to not make it available. You'll need to invoke Remote Desktop from the command line as follows to enable this: mstsc /console ============================ |
|
|
|
|
lyndonje
Senior Member
Joined: 31 January 2006 Location: United Kingdom Status: Offline Points: 192 |
Post Options
Thanks(0)
Quote Reply
Posted: 06 March 2006 at 4:07am |
|
OK thanks.
|
|
|
|
|
Gary
Guest Group 
|
Post Options
Thanks(0)
Quote Reply
Posted: 20 April 2006 at 12:25am |
|
Same version - same problem. Runs for a bit and very quickly fills up. I can see my inbound connections just sitting and not getting disconnected.
|
|
|
|
|
richard
Newbie 
Joined: 12 August 2005 Status: Offline Points: 16 |
Post Options
Thanks(0)
Quote Reply
Posted: 20 April 2006 at 11:10am |
|
yesterday i noticed the following in my logs
04/19/06 00:00:00:633 -- Exception occurred during DoDeliverQuarantineList: Thread creation error: Not enough storage is available to process this command 04/19/06 00:00:00:633 -- (3828) Listen Exception occurred: Access violation at address 0043E2A8 in module 'SpamFilterSvc.exe'. Read of address 00000000 04/19/06 00:00:04:992 -- (3828) Listen Exception occurred: Access violation at address 0043E2A8 in module 'SpamFilterSvc.exe'. Read of address 00000000 04/19/06 00:00:05:633 -- Exception occurred during DoDeliverQuarantineList: Thread creation error: Not enough storage is available to process this command 04/19/06 00:00:06:976 -- (3828) Listen Exception occurred: Access violation at address 0043E2A8 in module 'SpamFilterSvc.exe'. Read of address 00000000 04/19/06 00:00:10:633 -- Exception occurred during DoDeliverQuarantineList: Thread creation error: Not enough storage is available to process this command 04/19/06 00:00:11:133 -- (3828) Listen Exception occurred: Access violation at address 0043E2A8 in module 'SpamFilterSvc.exe'. Read of address 00000000 04/19/06 00:00:12:117 -- (3828) Listen Exception occurred: Access violation at address 0043E2A8 in module 'SpamFilterSvc.exe'. Read of address 00000000 04/19/06 00:00:15:633 -- Exception occurred during DoDeliverQuarantineList: Thread creation error: Not enough storage is available to process this command 04/19/06 00:00:18:195 -- (3828) Listen Exception occurred: Access violation at address 0043E2A8 in module 'SpamFilterSvc.exe'. Read of address 00000000 04/19/06 00:00:18:195 -- (3828) Listen Exception occurred: Access violation at address 0043E2A8 in module 'SpamFilterSvc.exe'. Read of address 00000000 04/19/06 00:00:20:633 -- Exception occurred during DoDeliverQuarantineList: Thread creation error: Not enough storage is available to process this command 04/19/06 00:00:22:726 -- (3828) Listen Exception occurred: Access violation at address 0043E2A8 in module 'SpamFilterSvc.exe'. Read of address 00000000 04/19/06 00:00:25:633 -- Exception occurred during DoDeliverQuarantineList: Thread creation error: Not enough storage is available to process this command 04/19/06 00:00:30:633 -- Exception occurred during DoDeliverQuarantineList: Thread creation error: Not enough storage is available to process this command 04/19/06 00:00:30:789 -- (3828) Listen Exception occurred: Access violation at address 0043E2A8 in module 'SpamFilterSvc.exe'. Read of address 00000000 04/19/06 00:00:30:805 -- (3828) Listen Exception occurred: Access violation at address 0043E2A8 in module 'SpamFilterSvc.exe'. Read of address 00000000 04/19/06 00:00:30:805 -- (3828) Listen Exception occurred: Access violation at address 0043E2A8 in module 'SpamFilterSvc.exe'. Read of address 00000000 04/19/06 00:00:31:180 -- (3828) Listen Exception occurred: Access violation at address 0043E2A8 in module 'SpamFilterSvc.exe'. Read of address 00000000 04/19/06 00:00:31:726 -- (3828) Listen Exception occurred: Access violation at address 0043E2A8 in module 'SpamFilterSvc.exe'. Read of address 00000000 04/19/06 00:00:33:180 -- (3828) Listen Exception occurred: Access violation at address 0043E2A8 in module 'SpamFilterSvc.exe'. Read of address 00000000 04/19/06 00:00:33:430 -- (8672) TBayesianThread - Begin LoadFromFile for corpus.db (db.dat) 04/19/06 00:00:33:445 -- (8672) TBayesianThread - LoadFromFile for Corpus.db - copied db.dat -> Ind9018.tmp 04/19/06 00:00:33:461 -- (8672) TBayesianThread - LoadFromFile for Corpus.db - copied db.dat.prb -> Ind9019.tmp 04/19/06 00:00:33:461 -- (8672) TBayesianThread - LoadFromFile for Corpus.db - setting Buffer size to 5775637 04/19/06 00:00:33:461 -- (8672) TBayesianThread - End LoadFromFile for corpus.db (db.dat) (0) 04/19/06 00:00:33:461 -- (8672) TBayesianThread - Exception occurred during LoadFromFile: Out of memory 04/19/06 00:00:33:476 -- (8672) SpamFilterForm - corpus.db cannot be loaded, waiting 60 seconds 04/19/06 00:00:35:633 -- Exception occurred during DoDeliverQuarantineList: Thread creation error: Not enough storage is available to process this command 04/19/06 00:00:38:242 -- (3828) Listen Exception occurred: Access violation at address 0043E2A8 in module 'SpamFilterSvc.exe'. Read of address 00000000 04/19/06 00:00:40:633 -- Exception occurred during DoDeliverQuarantineList: Thread creation error: Not enough storage is available to process this command 04/19/06 00:00:40:648 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 1860 04/19/06 00:00:40:648 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 2868 04/19/06 00:00:40:648 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 2228 04/19/06 00:00:40:648 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 3164 04/19/06 00:00:40:648 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 3576 04/19/06 00:00:40:648 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 2424 04/19/06 00:00:40:648 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 2004 04/19/06 00:00:40:648 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 1764 04/19/06 00:00:40:648 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 3800 04/19/06 00:00:40:648 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 892 04/19/06 00:00:40:648 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 3980 04/19/06 00:00:40:648 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 1224 04/19/06 00:00:40:648 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 1724 04/19/06 00:00:40:648 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 3896 04/19/06 00:00:40:648 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 2772 04/19/06 00:00:40:648 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 3428 04/19/06 00:00:40:648 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 1824 04/19/06 00:00:40:648 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 1840 04/19/06 00:00:40:648 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 3900 04/19/06 00:00:40:648 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 948 04/19/06 00:00:40:664 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 2592 I was running SF3.0.1.552 when this occurred. i downloaded SF3.0.1.555 and installed and have not had any more problems |
|
|
|
|
Desperado
Senior Member
Joined: 27 January 2005 Location: United States Status: Offline Points: 1143 |
Post Options
Thanks(0)
Quote Reply
Posted: 20 April 2006 at 11:21am |
|
Richard, I had sent logs to LogSat showing the same thing and believe that was one of the issues he addressed in the 555 build or ... it is still being addressed. I also do not believe I have seen any since the 555 but have not looked today yet. |
|
|
The Desperado
Dan Seligmann. Work: http://www.mags.net Personal: http://www.desperado.com |
|
|
|
|
Gary
Guest Group
|
Post Options
Thanks(0)
Quote Reply
Posted: 20 April 2006 at 12:38pm |
|
Yeah... this is a bug. If a database entry is not possible for whatever reason, Spamfilter will never release the connection. We had our SQL server fail, which caused Spamfilter to keep every connection open indefinately. This should probably be changed.
|
|
|
|
|
LogSat
Admin Group
Joined: 25 January 2005 Location: United States Status: Offline Points: 4104 |
Post Options
Thanks(0)
Quote Reply
Posted: 20 April 2006 at 3:42pm |
|
Actually the issue is the error "Listen Exception occurred: Access violation". From then on, different erros start to cascade, but they appear to be triggered by the "Listen" access violation. This is related to SMTP sockets, not a database connection. We're trying to identify the problem, and even though we haven't pinpointed it yet, it's possible build 555 has addressed it.
In ragrds to the database connections, SpamFilter will usually be aware that the database server is down, and will still process messages as usual, but will not be storing spam in the quarantine. It will continuosly poll the DB server, and when it's back online, it will automatically resume the archiving of spam. Please note that the "IdleDisconnectMinutesTimeout reached" indicates a timeout in an SMTP connection, not a database connection. |
|
|
|
|
richard
Newbie
Joined: 12 August 2005 Status: Offline Points: 16 |
Post Options
Thanks(0)
Quote Reply
Posted: 21 April 2006 at 8:00am |
|
|
|
|
|
|
richard
Newbie
Joined: 12 August 2005 Status: Offline Points: 16 |
Post Options
Thanks(0)
Quote Reply
Posted: 21 April 2006 at 8:03am |
|
Sorry for second post...since i have upgraded to 555 i have not had any issues. thank you for a great product and excellent support
|
|
|
|
|
richard
Newbie
Joined: 12 August 2005 Status: Offline Points: 16 |
Post Options
Thanks(0)
Quote Reply
Posted: 25 April 2006 at 11:12am |
|
I am running ver 555 and am still experiencing the following problem
I am not sure what is causing the problem.. any help will be apreciated thanks Richard 04/25/06 00:00:57:397 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 9180 04/25/06 00:00:57:397 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 5672 04/25/06 00:00:57:397 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 8004 04/25/06 00:00:57:397 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 2552 04/25/06 00:00:57:397 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 6616 04/25/06 00:00:57:397 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 5284 04/25/06 00:00:57:397 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 8292 04/25/06 00:00:57:397 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 9612 04/25/06 00:00:57:397 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 7740 04/25/06 00:00:57:397 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 2684 04/25/06 00:00:57:397 -- Notice - IdleDisconnectMinutesTimeout reached. Removing threadID 9580 |
|
|
|
|
caratking
Groupie 
Joined: 13 March 2006 Location: United States Status: Offline Points: 79 |
Post Options
Thanks(0)
Quote Reply
Posted: 25 April 2006 at 10:02pm |
|
I thought I would post a situation that I have, that shows something simmilar. On a server that gets about 250k emails a day, we had no problem. Then it started using 50% of the processor, then 100% (dual processor machine). I looked everywhere to find the problem, including downgrading the version of Spam Filter we were using, same problem. In the connection list, it would show a message processing. It could stay there for a LONG time, perhaps 20 minutes. During this time it could not handle the incoming messages and start backing up until the max connection limit is reached. Eventually the connection would drop, and the server would return to normal operation. A while later, it would happen again. After watching it for a couple of days, it was always the same few emails... the sending server would keep retrying assuming it was not being delivered. I eventually found the problem (sorta), it was due to the fact that I started using REGEX in the keyword filter list. Some combination of my regex keywords, and these few emails caused Spam Filter to freak out. I did not do any furhter testing, I just removed the few REGEX based keyword filters I was using and it has been fine ever since. I'm including the REGEX filters I was using if anyone is interested. (\bbad credit\b) So, the problem would happen on the same emails, perhaps 3 or 4 out of 250,000 so it is not easy to reproduce. When it does happen, all hell breaks loose. My main clue was the processing window of the task list that led me to find the problem. |
|
|
|
|
LogSat
Admin Group
Joined: 25 January 2005 Location: United States Status: Offline Points: 4104 |
Post Options
Thanks(0)
Quote Reply
Posted: 25 April 2006 at 11:11pm |
|
Richard,
Are you receiving any erros after those events? If not, please note that those events by themselves are perfectly normal. SpamFiter will routinely check connections that have been connected to SpamFilter for too long (default is 20 minutes), and will terminate them if so. The forced disconnect event is logged as you reported.
|
|
|
|
|
richard
Newbie
Joined: 12 August 2005 Status: Offline Points: 16 |
Post Options
Thanks(0)
Quote Reply
Posted: 26 April 2006 at 8:40am |
|
Roberto i am seeing no errors. i did notice that when i observed the high number of these messages my connection queue was extremely long.
i guess i am only concerned because i dont recall ever seeing this type of message before. thanks for the information richard |
|
|
|
Topic Options
richard wrote:|
Post Reply
|
|
Tweet
|
| Forum Jump | Forum Permissions You cannot post new topics in this forum You cannot reply to topics in this forum You cannot delete your posts in this forum You cannot edit your posts in this forum You cannot create polls in this forum You cannot vote in polls in this forum |
This page was generated in 0.297 seconds.