Spam Filter ISP Support Forum

  New Posts New Posts RSS Feed - Mail being delivered in duplicate
  FAQ FAQ  Forum Search   Register Register  Login Login

Mail being delivered in duplicate

 Post Reply Post Reply
Author
Terry View Drop Down
Senior Member
Senior Member


Joined: 06 February 2005
Status: Offline
Points: 155
Post Options Post Options   Thanks (0) Thanks(0)   Quote Terry Quote  Post ReplyReply Direct Link To This Post Topic: Mail being delivered in duplicate
    Posted: 29 January 2008 at 9:24am
We are having a problem lately with several problems on spamfilter.  We are at version 3.5.4.718 and we are seeing the message " Too many connections" coming up at least once or twice a day and seem to get stuck at that point where only a reboot will reduce the count of connections.  When this error occurs mail will often start getting delivered in duplicate to the internal recipients.  When I looked this morning we were getting the message "Too many connections" and the count was about 165.....I restarted the server and it is sitting at around 14 or so connections now....
 
here is a log snippet from earlier in the morning..
01/28/08 23:59:35:768 -- (340) Too many connections. Disconnecting: 216.99.193.136
01/28/08 23:59:35:768 -- (340) Connection from: 216.99.193.136  -  Originating country : United States
01/28/08 23:59:35:784 -- (1092) Sending email from mwynton@lycos.com to vanwot@portptld.com --
01/28/08 23:59:35:784 -- (3468) Connection from: 76.170.54.33  -  Originating country : United States
01/28/08 23:59:35:784 -- (3468) Too many connections. Disconnecting: 76.170.54.33
01/28/08 23:59:35:831 -- (340) No Data Received
01/28/08 23:59:35:831 -- (340) Disconnect
01/28/08 23:59:35:862 -- (3468) No Data Received
01/28/08 23:59:35:862 -- (3468) Disconnect
01/28/08 23:59:35:940 -- (1092) EMail from mwynton@lycos.com to vanwot@portptld.com --  was forwarded to portexfe.pop.portptld.com:25
01/28/08 23:59:36:096 -- (2452) - SFDB filter match - relevance:10
01/28/08 23:59:36:096 -- (2452) 68.163.251.116 - Mail from: CarmenmulctEscobar@thestirring.net To: colin.doherty@portofportland.com will be rejected
01/28/08 23:59:36:253 -- (2452) Received RCPT TO: chuck.wiley@portofportland.com
01/28/08 23:59:36:300 -- (2452) Mail from: CarmenmulctEscobar@thestirring.net
01/28/08 23:59:36:300 -- (2452) 68.163.251.116 - Mail from: CarmenmulctEscobar@thestirring.net To: chuck.wiley@portofportland.com will be rejected
01/28/08 23:59:36:331 -- (1856) Blacklist cache - Added 202.79.25.147 to limbo
01/28/08 23:59:36:409 -- (2452) Received RCPT TO: ernie.phelan@portofportland.com
01/28/08 23:59:36:456 -- (2452) Mail from: CarmenmulctEscobar@thestirring.net
01/28/08 23:59:36:471 -- (2452) 68.163.251.116 - Mail from: CarmenmulctEscobar@thestirring.net To: ernie.phelan@portofportland.com will be rejected
01/28/08 23:59:36:581 -- (1856) Disconnect
01/28/08 23:59:36:581 -- (1856) SFDB - Added 202.79.25.147 - Response: Error=0
01/28/08 23:59:36:643 -- (2452) Received RCPT TO: frank.jolly@portofportland.com
01/28/08 23:59:36:706 -- (2452) Mail from: CarmenmulctEscobar@thestirring.net
01/28/08 23:59:36:706 -- (2452) 68.163.251.116 - Mail from: CarmenmulctEscobar@thestirring.net To: frank.jolly@portofportland.com will be rejected
01/28/08 23:59:37:018 -- (2072) Start virus scan
01/28/08 23:59:37:190 -- (2072) Starting quarantine procedures
01/28/08 23:59:37:221 -- (2072) Starting bayesian procedures
01/28/08 23:59:37:221 -- (2072) Created thread (532) to add email to quarantine
01/28/08 23:59:37:268 -- (3968) Connection from: 60.1.87.70  -  Originating country : China
01/28/08 23:59:37:331 -- (532) EMail from enacttgr@stockingslaves.com to harrim@portptld.com was received and quarantined. Size: 1 KB, 1024 bytes
01/28/08 23:59:37:581 -- (2452) Start virus scan
01/28/08 23:59:37:659 -- (2452) Starting quarantine procedures
01/28/08 23:59:37:784 -- (2452) Starting bayesian procedures
01/28/08 23:59:37:784 -- (2452) Created thread (3476) to add email to quarantine
01/28/08 23:59:37:987 -- (3476) EMail from CarmenmulctEscobar@thestirring.net to colin.doherty@portofportland.com, chuck.wiley@portofportland.com, ernie.phelan@portofportland.com, frank.jolly@portofportland.com was received and quarantined. Size: 3 KB, 3072 bytes
01/28/08 23:59:38:128 -- (3968) Received MAIL FROM: <salone@neste.com>
01/28/08 23:59:38:440 -- (3968) Received RCPT TO: bridgetcarrillocirculatory@portptld.com
01/28/08 23:59:38:737 -- (3968) Resolving 60.1.87.70 - Not found
01/28/08 23:59:38:737 -- (3968) - Reverse DNS not found -
01/28/08 23:59:38:737 -- (3968) 60.1.87.70 - Mail from: salone@neste.com To: bridgetcarrillocirculatory@portptld.com will be rejected
01/28/08 23:59:39:268 -- (2196) Connection from: 211.211.30.199  -  Originating country : Korea, Republic of
01/28/08 23:59:39:846 -- (2196) Received MAIL FROM: <jhy907655@tom.com>
01/28/08 23:59:40:018 -- (3968) Start virus scan
01/28/08 23:59:40:112 -- (2196) Received RCPT TO: obried@portptld.com
01/28/08 23:59:40:143 -- (2196) - Reverse DNS not found -
01/28/08 23:59:40:143 -- (2196) Resolving 211.211.30.199 - Not found
01/28/08 23:59:40:143 -- (2196) 211.211.30.199 - Mail from: jhy907655@tom.com To: obried@portptld.com will be rejected
01/28/08 23:59:40:190 -- (3968) Starting quarantine procedures
01/28/08 23:59:40:237 -- (3968) Created thread (3780) to add email to quarantine
01/28/08 23:59:40:253 -- (3968) Starting bayesian procedures
01/28/08 23:59:40:362 -- (3780) EMail from salone@neste.com to bridgetcarrillocirculatory@portptld.com was received and quarantined. Size: 3 KB, 3072 bytes
01/28/08 23:59:40:362 -- (3840) Connection from: 67.218.167.201  -  Originating country : N/A
01/28/08 23:59:40:362 -- (3840) Too many connections. Disconnecting: 67.218.167.201
01/28/08 23:59:40:425 -- (3840) No Data Received
01/28/08 23:59:40:425 -- (3840) Disconnect
01/28/08 23:59:40:581 -- (2196) Start virus scan
01/28/08 23:59:40:643 -- (2196) Starting quarantine procedures
01/28/08 23:59:40:659 -- (2196) Starting bayesian procedures
01/28/08 23:59:40:675 -- (2196) Created thread (2632) to add email to quarantine
01/28/08 23:59:40:768 -- (2632) EMail from jhy907655@tom.com to obried@portptld.com was received and quarantined. Size: 2 KB, 2048 bytes
01/28/08 23:59:42:534 -- (2352) Connection from: 60.50.255.176  -  Originating country : Malaysia
01/28/08 23:59:42:550 -- (2352) Too many connections. Disconnecting: 60.50.255.176
01/28/08 23:59:42:596 -- (2352) No Data Received
01/28/08 23:59:42:612 -- (2352) Disconnect
01/28/08 23:59:43:175 -- (2188) Connection from: 124.82.124.173  -  Originating country : Malaysia
01/28/08 23:59:43:206 -- (2188) Too many connections. Disconnecting: 124.82.124.173
01/28/08 23:59:43:237 -- (2188) Disconnect
01/28/08 23:59:43:237 -- (2188) No Data Received
01/28/08 23:59:44:487 -- (3908) Connection from: 209.97.214.168  -  Originating country : Canada
01/28/08 23:59:44:487 -- (3908) Too many connections. Disconnecting: 209.97.214.168
01/28/08 23:59:44:518 -- (3908) No Data Received
01/28/08 23:59:44:518 -- (3908) Disconnect
01/28/08 23:59:48:346 -- (808) Connection from: 67.218.166.66  -  Originating country : N/A
01/28/08 23:59:48:362 -- (808) Too many connections. Disconnecting: 67.218.166.66
Back to Top
LogSat View Drop Down
Admin Group
Admin Group
Avatar

Joined: 25 January 2005
Location: United States
Status: Offline
Points: 4065
Post Options Post Options   Thanks (0) Thanks(0)   Quote LogSat Quote  Post ReplyReply Direct Link To This Post Posted: 29 January 2008 at 9:21pm
Terry,

If you can please zip and email us SpamFilter's activity logfile for the 28th we'll take a look. It's not unusual for servers to become victims of mail bombs, when SpamFilter will often receive a steady flow of even 200-400 concurrent connections for a few minutes. These attacks however die down after 5-10 minutes, in part thanks to the blacklist cache SpamFilter ses to temporarily ban IPs. If however the "Too many connections" message is seen for more than those 10 minutes, we'd like to examine the logs to ensure that there are no other issues.
Roberto Franceschetti

LogSat Software

Spam Filter ISP
Back to Top
Terry View Drop Down
Senior Member
Senior Member


Joined: 06 February 2005
Status: Offline
Points: 155
Post Options Post Options   Thanks (0) Thanks(0)   Quote Terry Quote  Post ReplyReply Direct Link To This Post Posted: 30 January 2008 at 9:25am
When I got in yesterday and today the server was again max'd out on connections (over 150).  I have to reboot the server to clear the condition.  After the reboot I am sitting at around 14-15 connections.   One other thing I noticed is that the cpu is running at 100% when I looked and we were max'd on connections today.   This is a dual processor 3.06ghz xeon machine and should be able to handle this application.  Per your request I emailed the log file in zip format but your system wouldn't accept the file...it said you mailbox was full or unable to take that big of file...can you give me the ftp instructions for sending a file to you... 
Back to Top
Terry View Drop Down
Senior Member
Senior Member


Joined: 06 February 2005
Status: Offline
Points: 155
Post Options Post Options   Thanks (0) Thanks(0)   Quote Terry Quote  Post ReplyReply Direct Link To This Post Posted: 30 January 2008 at 10:11am
One other note of possible relevance....when I correlate the time the first "too many connections" show up last night...the backup job was running on the d"drive of the server (where spamfilter is installed).....I don't know if that is a factor but I will investigate further and see if it is possible.
Back to Top
LogSat View Drop Down
Admin Group
Admin Group
Avatar

Joined: 25 January 2005
Location: United States
Status: Offline
Points: 4065
Post Options Post Options   Thanks (0) Thanks(0)   Quote LogSat Quote  Post ReplyReply Direct Link To This Post Posted: 30 January 2008 at 7:15pm
Terry,

I'll be sending you a PM with the FTP instructions. In the meantime, it is to note that SpamFilter  v3.5.4.718 and earlier will recognize if the database is offline, and will skip the archival process. In you case, it is possible that the backup process may be placing locks on the database tables. A lock would not make the database offline, but will greatly increase the time required to insert data in it. It is thus theortically possible that this could cause longer time to process emails, and thus cause connections to increase. Please note the "ifs" here, as we have never seen this problem before.
This said, starting from v3.5.4.725 SpamFilter uses a different multithreaded process to queue emails to be quarantine, which places in a queue emails that can't be quarantined due to database problems. If you upgrade to either the latest build of SpamFilter 3.5.4.730 or the new v4.0.0.772, this problem may resolve itself.
We'll take a look at your logs in the meantime to see if this is indeed the problem.
Roberto Franceschetti

LogSat Software

Spam Filter ISP
Back to Top
Terry View Drop Down
Senior Member
Senior Member


Joined: 06 February 2005
Status: Offline
Points: 155
Post Options Post Options   Thanks (0) Thanks(0)   Quote Terry Quote  Post ReplyReply Direct Link To This Post Posted: 30 January 2008 at 8:20pm
the log file for 01/28/2008 has been uploaded to the ftp site.....I will also look at the upgraded release....just for information...the backup I was talking about is the backup of the spamfilter server not the database server.....
Back to Top
LogSat View Drop Down
Admin Group
Admin Group
Avatar

Joined: 25 January 2005
Location: United States
Status: Offline
Points: 4065
Post Options Post Options   Thanks (0) Thanks(0)   Quote LogSat Quote  Post ReplyReply Direct Link To This Post Posted: 30 January 2008 at 9:34pm
In this case, I think the backp is just a coincidence.
Looking at your logfile, we see several errors like:
01/28/08 00:12:04:183 -- (5284) Exception occurred during TTerminateIdleThreads.Execute: Access violation at address 004DF51E in module 'SpamFilterSvc.exe'. Read of address FFFFFFB4

These were caused by a bug fixed by:
// New to VersionNumber = '3.5.4.726';
{TODO -cFix : Exception occurred during TTerminateIdleThreads.Execute: Access violation at address 004A6BA6 in module 'SpamFilterSvc.exe'. Read of address FFFFFFB4}


We also see many database-related errors similar to:
01/28/08 00:04:12:167 -- (3408) Exception occurred during TDeliverQuarantineThread.Execute: Timeout expired 1 2 3 4 5 6 7 36 37 38

These too have already been addressed by the new feature that queues the database operations in case the database is mis-behaving:
// New to VersionNumber = '3.5.4.725';
{TODO -cNew : Implemented a queue for quarantined emails in case the database is offline. The archival process is queued and will resume when the DB is back online}

Thus the initial recommendation still stands even after going thru the logs :-)

Both SpamFilter v3.5.4.730 (for the v3.5 series) and the latest v4.0.0.772 that we officially supported as of an hour ago should be able to solve the problem. If not, if you can provide us the latest logfile with the new release and we'll go back to the drawing board.

Roberto Franceschetti

LogSat Software

Spam Filter ISP
Back to Top
Terry View Drop Down
Senior Member
Senior Member


Joined: 06 February 2005
Status: Offline
Points: 155
Post Options Post Options   Thanks (0) Thanks(0)   Quote Terry Quote  Post ReplyReply Direct Link To This Post Posted: 31 January 2008 at 9:13am
thank you for looking into it....I went ahead and upgraded to 4.0.0.772 and will see how that goes.....
Back to Top
Terry View Drop Down
Senior Member
Senior Member


Joined: 06 February 2005
Status: Offline
Points: 155
Post Options Post Options   Thanks (0) Thanks(0)   Quote Terry Quote  Post ReplyReply Direct Link To This Post Posted: 31 January 2008 at 10:09am
I have the new version in and running and greylisting turned on....I am getting mail through as it should it appears...however I do see a lot of these timeout messages...01/31/08 07:03:51:843 -- (2964) Exception occurred during TDeliverQuarantineThread.Execute: Timeout expired 1 2 3 4 5 6 7 36 37 38---
in my log now...I have restarted the server several times and they still occur..I have also checked the quarantine database and stuff is being added to it...should I be worried or have you made something more sensitive than it was in the past?
Back to Top
LogSat View Drop Down
Admin Group
Admin Group
Avatar

Joined: 25 January 2005
Location: United States
Status: Offline
Points: 4065
Post Options Post Options   Thanks (0) Thanks(0)   Quote LogSat Quote  Post ReplyReply Direct Link To This Post Posted: 31 January 2008 at 3:58pm
Terry,

I have to correct my last post. The error regarding the "Exception occurred during TDeliverQuarantineThread.Execute" is not a huge issue. SpamFilter checks the quarantine database every 5 seconds for spam emails that have been marked for force-delivery by the users. Since this query occurs every 5 seconds, SpamFilter uses a more aggressive timeout for it, as if it fails, it will be repeated within a few seconds.
Unless you receive several of these entries every seconds throughout the entire day, it is usually not a problem and won't cause issues. They do indicate performance problems with the database however, so you may want to look into what can be done to optimize it.

As far as SpamFilter is concerned, there's a couple of things that can be done to improve database performance when SpamFilter routinely (every hour by default) deletes expired quarantined emails from the DB. It's possible that this deletion process takes so long that it is interfering with normal DB operations.

if using MySQL, some users have seen benefits by adding the following combined indexes:

ALTER TABLE `SpamFilter`.`tblquarantine` ADD INDEX Optimize_1(`emailto`, `msgid`, `msgdate`, `deliver`, `expire`);
ALTER TABLE `SpamFilter`.`tblquarantine` ADD INDEX Optimize_2(`msgid`, `deliver`, `expire`, `serverid`);


If using SQL Server, please see this posting for a way to improve the deletion process with this database.

Roberto Franceschetti

LogSat Software

Spam Filter ISP
Back to Top
 Post Reply Post Reply
  Share Topic   

Forum Jump Forum Permissions View Drop Down



This page was generated in 0.109 seconds.