tags:

views:

163

answers:

3

I have a website which processes orders from a Windows application. This works as follows:

  1. User clicks "Order now" in the windows app
  2. App uploads a file with POST to a PHP script
  3. The script immediately calls the PHP mail() function (order is not stored in a db)

This works fine most of the time. However, sometimes a big delay occurs (several days). Customers calls why the product has not yet been delivered.

E-mail headers of delayed mail follows:

Microsoft Mail Internet Headers Version 2.0
Received: from barracuda.nkl.nl ([10.0.0.1]) by smtp.nkl.nl with Microsoft SMTPSVC(6.0.3790.3959);
     Wed, 26 May 2010 16:26:51 +0200
X-ASG-Debug-ID: 1274883818-2f8800000000-X58hIK
X-Barracuda-URL: http://10.0.0.1:8000/cgi-bin/mark.cgi
Received: from server45.firstfind.nl (localhost [127.0.0.1])
    by barracuda.nkl.nl (Spam & Virus Firewall) with ESMTP id ECAFD15776A
    for <[email protected]>; Wed, 26 May 2010 16:23:38 +0200 (CEST)
Received: from server45.firstfind.nl (server45.firstfind.nl [93.94.226.76]) by barracuda.nkl.nl with ESMTP id 85bAT2AU58kkxjPb for <[email protected]>; Wed, 26 May 2010 16:23:38 +0200 (CEST)
X-Barracuda-Envelope-From: [email protected]
Received: from server45.firstfind.nl (localhost [127.0.0.1])
    by server45.firstfind.nl (8.13.8/8.13.8/Debian-3+etch1) with ESMTP id o4QEM3Hb004301
    for <[email protected]>; Wed, 26 May 2010 16:23:31 +0200
Received: (from nklsemin@localhost)
    by server45.firstfind.nl (8.13.8/8.13.8/Submit) id o4J9lA7M031307;
    Wed, 19 May 2010 11:47:10 +0200
Date: Wed, 19 May 2010 11:47:10 +0200
Message-Id: <[email protected]>
To: [email protected]
X-ASG-Orig-Subj: easyfit - ref: Hoen3443
Subject: easyfit - ref: Hoen3443
X-PHP-Script: www.nklseminar.nl/emailer/upload.php for 77.61.220.217
From: [email protected]
Content-type: text/html
X-Virus-Scanned: by amavisd-new
X-Barracuda-Connect: server45.firstfind.nl[93.94.226.76]
X-Barracuda-Start-Time: 1274883820
X-Barracuda-Bayes: INNOCENT GLOBAL 0.0000 1.0000 -2.0210
X-Barracuda-Virus-Scanned: by Barracuda Spam & Virus Firewall at nkl.nl
X-Barracuda-Spam-Score: 0.92
X-Barracuda-Spam-Status: No, SCORE=0.92 using global scores of TAG_LEVEL=2.0 QUARANTINE_LEVEL=1000.0 KILL_LEVEL=3.0 tests=DATE_IN_PAST_96_XX, DATE_IN_PAST_96_XX_2, HTML_MESSAGE, MIME_HEADER_CTYPE_ONLY, MIME_HTML_ONLY, NO_REAL_NAME
X-Barracuda-Spam-Report: Code version 3.2, rules version 3.2.2.30817
    Rule breakdown below
     pts rule name              description
    ---- ---------------------- --------------------------------------------------
    0.00 NO_REAL_NAME           From: does not include a real name
    0.01 DATE_IN_PAST_96_XX     Date: is 96 hours or more before Received: date
    0.00 MIME_HTML_ONLY         BODY: Message only has text/html MIME parts
    0.00 HTML_MESSAGE           BODY: HTML included in message
    0.86 MIME_HEADER_CTYPE_ONLY 'Content-Type' found without required MIME
                               headers
    2.07 DATE_IN_PAST_96_XX_2   DATE_IN_PAST_96_XX_2
Return-Path: [email protected]
X-OriginalArrivalTime: 26 May 2010 14:26:51.0343 (UTC) FILETIME=[7B80DDF0:01CAFCDF]

The delay seems to occur here:

Received: from server45.firstfind.nl (localhost [127.0.0.1]) by server45.firstfind.nl (8.13.8/8.13.8/Debian-3+etch1) with ESMTP id
o4QEM3Hb004301
for <[email protected]>; Wed, 26 May 2010 16:23:31 +0200
Received: (from nklsemin@localhost)
by server45.firstfind.nl (8.13.8/8.13.8/Submit) id o4J9lA7M031307;
Wed, 19 May 2010 11:47:10 +0200

I've reported this issue various times to the web hosting service that hosts my website. They say the delay does not occur in their network (impossible).

But they do confirm that the e-mail is first seen in their mail server on May 26, which is 7 days after the mail has been composed. The order is marked with the timestamp of the user's local PC, which also matches May 19 (so it's not a PC clock problem)

It's also interesting to see that all delayed mails (orders were placed on different days) come in at once. So I suddenly receive 14 e-mail in my mailbox from various days.

Any idea were this delay may be introduced? Could there be a bug in my PHP code that causes this? (I cannot believe I can introduce a loop of 7 days in my PHP code)

+1  A: 

You're right - its nothing to do with PHP.

Normally, slow mail problems are all about DNS issues - but that is not the problem here.

Whenever I've configured an MTA (Mail Transport Agent) I'd have told it to give up long before 7 days had expired.

It's also interesting to see that all delayed mails (orders were placed on different days) come in at once.

Sounds like either the MTA is only configured to dequeue mail every 7 days (!) or something went wrong and it took 7 days for your hosting company to fix it.

They say the delay does not occur in their network

Time to find a new hosting company.

C.

symcbean
A: 

email just isn't very reliable way of sending information like this.

Chances are there were just some short term issue on one of the 2 servers involved that meant attempts to send the email encountered problems.

Mail servers will often wait a while before retrying, (though I would have expected a much shorter time than 6 days for the initial retry). The reason you are probably getting a little burst of them is that all the retries finally get through together.

It does seem a little odd that it would wait so long to retry though.

You would probably have to look at your mail server logs to see if they were having any problems around the time that message was sent.

rikh
They've checked their mailserver's logs, and the mail is first seen in their logs at May 26 (7 days after composing). They say there is nothing more that can queue the mail between PHP mail() and this mail server - which MUST be wrong
Robbert Dam
A: 

There's also this:

X-Virus-Scanned: by amavisd-new

This would indicate that there's at least ONE more step after accepting the mail originally. amavis itself would most likely be passing the mail on to ClamAV, Spamassassin, etc... and any one of those could for some reason be introducing delay.

Given the 8.13 version number on the webserver's SMTP, it's most likely Sendmail. If you have any kind of access to the server, check the outgoing mail queue with 'mailq', if you have the rights, or have the admins there do it for you. Since the delay's occurring somewhere within the server, at some point it should be getting stuffed into sendmail's pending queue, and that will also have the delay reason attached.

Marc B