More missing messages

[jbs]

I'm a long time and very enthusiastic paying user, so I am sorry to seem like I'm griping a lot lately, but I just saw some more mysterious behavior . . .

I submitted a request for info to a service that then passes my email address on to others. I'd expected to get a large number of responses, and I did.

Before the new SG address started deleting messages, I went in and added authorized senders to allow them through, but here's the strange part. In my inbox I had the following subjects:

blah blah blah (carscom: message 1 of 20)
blah blah blah (carscom: message 3 of 20)
blah blah blah (carscom: message 7 of 20)
blah blah blah (carscom: message 8 of 20)
blah blah blah (carscom: message 9 of 20)
blah blah blah (carscom: message 10 of 20)
blah blah blah (carscom: message 4 of 20)

When I loged into SG, it showed a count of 10, with no deletions (the address is setto 20 allowed) but messages number 2, 5, and 6 were nowhere to be found.

Unlike the messages from last week which were showing up hours and hours later, these messages are only about 5 kilobytes (no attachments). The one which arrived out of sequence (#4) shows a 30 minute delay between 2 different servers at Spamgourmet, but the others have been missing for about 90 minutes now . . .

I'm not sure yet whether they will eventually show up, but I'm wondering whether this is expected behavior?

Thanks!

--Jason

P.S. As I've stated before, nothing is being deleted by my email provider, Runbox. I manage my filters, whitelist/blacklist very carefully, and anything frmo SG is automatically delivered. Moreover the headers on the delayed message show that it was delayed at SG, and there are no backups on my email service provider.

[jbs]

About 9 hours after they were sent, still no sign of messages 2, 5 and 6.

Obviously, the main reason this worries me is because in this case I know they are missing, but I worry that I'm missing others and never knew it.

Any known problems occurring around 1pm Eastern Time today that might have caused this?

--Jason

[jbs]

Me again

Message 2 of 10 showed up -- it was only a 3 kilobyte message. The headers this time show a delay between Spamgourmet servers of . . . drum roll . . .

12 and a half hours!!

Here are the headers:

Received: from [216.218.230.146] (helo=gourmet.spamgourmet.com)
by snoopy.runbox.com with esmtp (Exim 4.34)
id 1CWr9U-0004Fe-EF
for xxxxxxxxx@runbox.com; Wed, 24 Nov 2004 08:01:20 +0100
Received: from gourmet.spamgourmet.com (localhost [127.0.0.1])
by localhost (8.12.10/8.12.9) with ESMTP id iAO6vgeG027171
for <xxxxxxxxx@runbox.com>; Tue, 23 Nov 2004 23:01:20 -0800
Received: (from jqh1@localhost)
by gourmet.spamgourmet.com (8.12.10/8.12.10/Submit) id iANIVGjU029013
for xxxxxxxxxxxx@runbox.com; Tue, 23 Nov 2004 10:31:16 -0800

[jbs]

Today I received what must have been messages 5 and 6, though strangely they were both marked message 4 of 20 in the subject appendage. That means I've received all 10, but three of them were numbered "4").

Here are the headers for one of these last couple, which show that they arrived at SG on Tuesday afternoon, and left SG 52 hours later on Thursday afternoon:

Received: from gourmet.spamgourmet.com (localhost [127.0.0.1])
by localhost (8.12.10/8.12.9) with ESMTP id iAPMqvHe005756
for <xxxxxxxx@runbox.com>; Thu, 25 Nov 2004 14:57:41 -0800
Received: (from jqh1@localhost)
by gourmet.spamgourmet.com (8.12.10/8.12.10/Submit) id iANIXmhc030433
for xxxxxxxx@runbox.com; Tue, 23 Nov 2004 10:33:48 -0800

Really would love to know if there's any explanation . . . again, I'm not trying to be a pest, since I'm a huge SG fan, longtime user and I recognize that it's a free service to the community (it's free even for those of us who contribute). I sincerely am just trying to get to the bottom of this so as to make the service ever more reliable.

Please let me know if there's anything you'd need to know to diagnose this!

--Jason

[josh]

What's happening is that the server is getting clobbered and becoming way backed up -- we use sendmail to forward messages out of spamgourmet, and it apparently has some curious rules about how to assign priority to messages. They do include a lower priority for messages with attachments, the bigger, the lower.

What appears to have happened with the three "4 of" messages is that the server got hit with the three messages at approximately the same time while under a heavy load. The three invocations of code each read the same number of remaning messages from the database and came up with "4" as the number remaning. The reason you only received 10 messages instead of 12 messages is because the countdown code sends an incrementer instruction to the database instead of a number (that is, "set Remaining = Remaining - 1" instead of "set Remaining = 3"). This is more or less a "known issue", in that the fix for it (database locking) would appear to cause more harm than good, at least with our current reckoning. Our current understanding of normal use leads us to believe that the problem of receiving several contemporaneous messages to the same unexpired address is fairly rare. Of course, the more load experienced by the server, the wider a window we're talking about for "contemporaneous" and the less rare the problem becomes (still seems like it would be pretty rare, though).

Anyway, all the messages got queued for delivery, and sendmail decided it should forward them on when it did, which was much later, in this case. Here lies the real problem -- we resolve the load issue somehow and things return to normal.

We don't have budget for a hardware upgrade, so we're looking at ways to squeeze better preformance out of what we have. Note that, to my knowlegde, this is not a bandwidth problem -- we have a bandwidth contract with HE which more than accomodates our current load (and, recently, costs a little more than we're taking in from ads and donations, but that's another story) -- rather, we have the more tractible issue of tanking our tiny hardware, so hopefully we'll get some benefit from our efforts.

[josh]

I'm digging through logs and queues, and it does look like there's been some abuse recently, with scripted addresses being given out to a particular online retailer, who is in turn blasting the very large number of addresses with messages. There are several user accounts involved, possibly all belonging to the same person. I've disabled the accounts, since doing the script thing is in direct violation of the TOS, and so that should lighten the server load a bit.

[josh]

I've been auditing the mail queue, server logs and load, etc., and identified several accounts that were consuming a greatly (vastly) disproportional amount of resources and had sequences of disposable addresses that appeared to be generated from scripts. I've disabled those accounts, and the mail queue and server load have dropped signficantly.

Please try your test again and see what happens

[jbs]

I've been auditing the mail queue, server logs and load, etc., and identified several accounts that were consuming a greatly (vastly) disproportional amount of resources and had sequences of disposable addresses that appeared to be generated from scripts. I've disabled those accounts, and the mail queue and server load have dropped signficantly.

Please try your test again and see what happens

Well, the latest message sent to me form the service was on Friday afternoon, and it showed an 8-hour delay at Spamgourmet:

Received: from gourmet.spamgourmet.com (localhost [127.0.0.1])
by localhost (8.12.10/8.12.9) with ESMTP id iB39CjqI018559
for <********+sg@runbox.com>; Fri, 3 Dec 2004 01:14:58 -0800

Received: (from jqh1@localhost)
by gourmet.spamgourmet.com (8.12.10/8.12.10/Submit) id iB31HAc8026181
for ********+sg@runbox.com; Thu, 2 Dec 2004 17:17:10 -0800

Those are just the steps before and after the delay (again, both inside SG. The complete trail is here:

Received: from exim by lassie.runbox.com with spamfilter (Exim 4.34)
for ********+sg@runbox.com; Fri, 03 Dec 2004 10:14:56 +0100

Received: from [216.218.230.146] (helo=gourmet.spamgourmet.com)
by lassie.runbox.com with esmtp (Exim 4.34)
for ********+sg@runbox.com; Fri, 03 Dec 2004 10:14:56 +0100

Received: from gourmet.spamgourmet.com (localhost [127.0.0.1])
by localhost (8.12.10/8.12.9) with ESMTP id iB39CjqI018559
for <********+sg@runbox.com>; Fri, 3 Dec 2004 01:14:58 -0800

Received: (from jqh1@localhost)
by gourmet.spamgourmet.com (8.12.10/8.12.10/Submit) id iB31HAc8026181
for ********+sg@runbox.com; Thu, 2 Dec 2004 17:17:10 -0800

Received: from efax.j2.com (iad12.efax.com [199.232.57.35] (may be forged))
by gourmet.spamgourmet.com (8.12.10/8.12.9) with ESMTP id iB2Heem8006577
for <jfax.10.********@xoxy.net>; Thu, 2 Dec 2004 09:40:41 -0800

Received: from media2.iad1.colo.j2noc.com (media2 [10.11.57.105])
by efax.j2.com (8.11.6/8.11.6) with ESMTP id iB2He5W11528;
Thu, 2 Dec 2004 17:40:05 GMT

Received: (from j2apps@localhost)
by media2.iad1.colo.j2noc.com (8.11.6/8.11.6) id iB2HZL903887;
Thu, 2 Dec 2004 17:35:21 GMT

What I'm doing at the moment is having jfax send both to my SG address and to the destination SG points to. If SG is working smoothly I'll get the second copy a few seconds after the first. Often times this is the case, with a delay of no more than a minute or so, but sometimes (as above) the delay is very long . . .

--Jason