[7.901][BUG][FIXED] SMTP proxy stopped processing new incoming/outgoing email following up2date

Hi,

I applied the 7.901 up2date at circa 19.35 BST, it seems from that point onwards - after the system had rebooted no more incoming/outgoing email was processed until I went into the mail queue and forced a retry circa 23.19 BST.  I did notice that Astaro generated emails were being processed during this time though.

Any incoming/outgoing emails were processed with the final log entry being:
2010:04:08-19:36:12 mercury smtpd[5281]: QMGR[5281]: 1NzwaI-0001lp-0e moved to work queue

Entries in the log following the forced retry of email:
2010:04:08-23:19:55 mercury smtpd[5229]: MASTER[5229]: Action: retrying 1Nzz3f-0008SI-2S (moved from error to input)
2010:04:08-23:19:55 mercury smtpd[5229]: MASTER[5229]: Action: retrying 1NzwaI-0001lp-0e (moved from error to input)
2010:04:08-23:19:55 mercury smtpd[5229]: MASTER[5229]: Action: retrying 1Nzxll-0004vN-0U (moved from error to input)
2010:04:08-23:19:55 mercury smtpd[5229]: MASTER[5229]: Action: retrying 1NzzJJ-0000kI-2i (moved from error to input)
2010:04:08-23:19:55 mercury smtpd[5229]: MASTER[5229]: Action: retrying 1NzxQL-0003tv-18 (moved from error to input)
2010:04:08-23:19:55 mercury smtpd[5229]: MASTER[5229]: Action: retrying 1NzzZa-0001U3-2b (moved from error to input)
2010:04:08-23:19:55 mercury smtpd[5229]: MASTER[5229]: Action: retrying 1NzxYg-0004K7-1G (moved from error to input)
2010:04:08-23:19:55 mercury smtpd[5229]: MASTER[5229]: Action: retrying 1NzxpH-00053p-00 (moved from error to input)
2010:04:08-23:19:55 mercury smtpd[5229]: MASTER[5229]: Action: retrying 1Nzy5O-0005lY-31 (moved from error to input)
2010:04:08-23:19:55 mercury smtpd[5229]: MASTER[5229]: Action: retrying 1NzyGv-0006IJ-2P (moved from error to input)
2010:04:08-23:19:55 mercury smtpd[5229]: MASTER[5229]: Action: retrying 1NzwbO-0001o4-2I (moved from error to input)
2010:04:08-23:19:55 mercury smtpd[5229]: MASTER[5229]: Action: retrying 1NzyOB-0006dc-0a (moved from error to input)
2010:04:08-23:19:55 mercury smtpd[5229]: MASTER[5229]: Action: retrying 1NzwmI-00027g-2q (moved from error to input)
2010:04:08-23:19:55 mercury smtpd[5229]: MASTER[5229]: Action: retrying 1NzwiJ-0001z2-0B (moved from error to input)
2010:04:08-23:19:55 mercury smtpd[5229]: MASTER[5229]: Action: retrying 1Nzztl-0002PP-08 (moved from error to input)

All held incoming/outgoing email was then processed.  Monitoring to see if any further email becomes trapped.


Cheers,

Darren
  • Astaro Beta Report
    
    --------------------------------
    Version: 7.901
    Type: BUG
    State: CLOSED/FIXED
    Reporter: darrenl++++
    Contributor: barkas, Billybob, Copyright, remybiersteker, Robert Tausend
    MantisID: 13324
    Target version: 7.902
    Fixed in version: 7.902
    --------------------------------
  • So only the mails that were supposed to go through the ASG were trapped, but not the notifications? The trapped mails, were they incoming, outgoing or both?
  • Correct, Astaro notifications were not trapped.

    Trapped emails were incoming (from external sources) and outgoing - originating from our SMTP servers.

    Some additional incoming emails have become trapped however when forced to retry from Mail Manager/STMP Spool/Retry - the email is processed OK.
  • if we leave aside the notificatiosn, was the whole SMTP traffic affected or did some email go through the ASG?
  • No email got past the Astaro once the condition occurred:

    This was the first *eternal* email it tried to process following the 7.901 up2date reboot.

    2010:04:08-19:35:13 mercury exim[5290]: 2010-04-08 19:35:13 SMTP connection from [206.165.242.112]:7460 (TCP/IP connection count = 1)
    2010:04:08-19:35:13 mercury exim[5670]: 2010-04-08 19:35:13 H=ziffdavismedia-112.ziffdavismedia.tracker.postdirect.com [206.165.242.112]:7460 Warning: mydomain.net profile excludes greylisting: Skipping greylisting for this message
    2010:04:08-19:35:14 mercury exim[5290]: 2010-04-08 19:35:14 pid 5290: SIGHUP received: re-exec daemon
    2010:04:08-19:35:14 mercury smtpd[5229]: MASTER[5229]: (Re-)loading configuration from Confd
    2010:04:08-19:35:14 mercury exim[5290]: 2010-04-08 19:35:14 exim 4.69 daemon started: pid=5290, no queue runs, listening for SMTP on port 25 (IPv6 and IPv4) port 587 (IPv6 and IPv4) and for SMTPS on port 465 (IPv6 and IPv4)
    2010:04:08-19:35:15 mercury smtpd[5229]: MASTER[5229]: Past 07:00:00, QR status one set to 'sent'
    2010:04:08-19:35:15 mercury smtpd[5229]: MASTER[5229]: Past 18:00:00, QR status two set to 'sent'
    2010:04:08-19:35:15 mercury exim[5670]: 2010-04-08 19:35:15 [206.165.242.112] F= R= Verifying recipient address with callout
    2010:04:08-19:35:15 mercury smtpd[5229]: MASTER[5229]: (Re-)loading configuration from Confd
    2010:04:08-19:35:15 mercury exim[5290]: 2010-04-08 19:35:15 pid 5290: SIGHUP received: re-exec daemon
    2010:04:08-19:35:15 mercury exim[5290]: 2010-04-08 19:35:15 exim 4.69 daemon started: pid=5290, no queue runs, listening for SMTP on port 25 (IPv6 and IPv4) port 587 (IPv6 and IPv4) and for SMTPS on port 465 (IPv6 and IPv4)
    2010:04:08-19:35:16 mercury smtpd[5229]: MASTER[5229]: Past 07:00:00, QR status one set to 'sent'
    2010:04:08-19:35:16 mercury smtpd[5229]: MASTER[5229]: Past 18:00:00, QR status two set to 'sent'
    2010:04:08-19:35:16 mercury exim[5290]: 2010-04-08 19:35:16 pid 5290: SIGHUP received: re-exec daemon
    2010:04:08-19:35:16 mercury exim[5290]: 2010-04-08 19:35:16 exim 4.69 daemon started: pid=5290, no queue runs, listening for SMTP on port 25 (IPv6 and IPv4) port 587 (IPv6 and IPv4) and for SMTPS on port 465 (IPv6 and IPv4)
    2010:04:08-19:35:17 mercury exim[5670]: 2010-04-08 19:35:17 1NzwZQ-0001TS-1T malware acl condition: cssd: connection to 127.0.0.1, port 1234 failed (Connection refused)
    2010:04:08-19:35:17 mercury exim[5670]: 2010-04-08 19:35:17 1NzwZQ-0001TS-1T H=ziffdavismedia-112.ziffdavismedia.tracker.postdirect.com [206.165.242.112]:7460 Warning: ACL "warn" statement skipped: condition test deferred
    2010:04:08-19:35:17 mercury exim[5670]: 2010-04-08 19:35:17 1NzwZQ-0001TS-1T malware acl condition: cssd: connection to 127.0.0.1, port 1234 failed (Connection refused)
    2010:04:08-19:35:17 mercury exim[5670]: [1\26] 2010-04-08 19:35:17 1NzwZQ-0001TS-1T H=ziffdavismedia-112.ziffdavismedia.tracker.postdirect.com [206.165.242.112]:7460 F= temporarily rejected after DATA
    2010:04:08-19:35:17 mercury exim[5670]: [2\26] Envelope-from: 
    2010:04:08-19:35:17 mercury exim[5670]: [3\26] Envelope-to: 
    2010:04:08-19:35:17 mercury exim[5670]: [4\26] P Received: from ziffdavismedia-112.ziffdavismedia.tracker.postdirect.com ([206.165.242.112]:7460)
    2010:04:08-19:35:17 mercury exim[5670]: [5\26]  by astaro.mydomain.*** with esmtp (Exim 4.69)
    2010:04:08-19:35:17 mercury exim[5670]: [6\26]  (envelope-from )
    2010:04:08-19:35:17 mercury exim[5670]: [7\26]  id 1NzwZQ-0001TS-1T
    2010:04:08-19:35:17 mercury exim[5670]: [8\26]  for ***X@mydomain.net; Thu, 08 Apr 2010 19:35:17 +0100
    2010:04:08-19:35:17 mercury exim[5670]: [9\26]   DomainKey-Signature: q=dns; a=rsa-sha1; c=nofws;
    2010:04:08-19:35:17 mercury exim[5670]: [10\26]  s=yesmail1; d=enews.pcmag.com;
    2010:04:08-19:35:17 mercury exim[5670]: [11\26]  h=Date:From:Subject:To:Message-ID:X-Vitals:List-Unsubscribe:X-Header-Versions:Reply-To:X-Header-CompanyDBUserName:X-Header-MasterId:MIME-Version:Content-Type;
    2010:04:08-19:35:17 mercury exim[5670]: [12\26]  b=abqSSdyUSgSLAp1+z3yFD1lkfXWWUBx0v1Uc8kmKesxN+mlAMNu/uwNc1u7BRWxD
    2010:04:08-19:35:17 mercury exim[5670]: [13\26]  QkjsHemB1hIVQat3hgZCQUEIMoKwvsArxU9d+CrvdEuWcg+HRe1xXU4RCv35TeXU
    2010:04:08-19:35:17 mercury exim[5670]: [14\26]   Date: Thu, 08 Apr 2010 11:34:23 PDT
    2010:04:08-19:35:17 mercury exim[5670]: [15\26] F From: "PCMag.com Daily News" 
    2010:04:08-19:35:17 mercury exim[5670]: [16\26]   Subject: Apple's iPad Takes Video Gaming Seriously; Google, AOL Win Affirmed By Appeals  Court
    2010:04:08-19:35:17 mercury exim[5670]: [17\26] T To: ***X@mydomain.net
    2010:04:08-19:35:17 mercury exim[5670]: [18\26] I Message-ID: 
    2010:04:08-19:35:17 mercury exim[5670]: [19\26]   X-Vitals: 1.112903.2046952.1217503.11.9e64
    2010:04:08-19:35:17 mercury exim[5670]: [20\26]   List-Unsubscribe: 
    2010:04:08-19:35:17 mercury exim[5670]: [21\26]   X-Header-Versions: PCMag_comDailyNews.***@enews.pcmag.com
    2010:04:08-19:35:17 mercury exim[5670]: [22\26] R Reply-To: PCMag_comDailyNews.***@enews.pcmag.com
    2010:04:08-19:35:17 mercury exim[5670]: [23\26]   X-Header-CompanyDBUserName: ziffdavismedia
    2010:04:08-19:35:17 mercury exim[5670]: [24\26]   X-Header-MasterId: 1217503
    2010:04:08-19:35:17 mercury exim[5670]: [25\26]   MIME-Version: 1.0
    2010:04:08-19:35:17 mercury exim[5670]: [26/26]   Content-Type: text/html; charset=us-ascii

    2010:04:08-19:35:17 mercury exim[5670]: 2010-04-08 19:35:17 1NzwZQ-0001TS-1T malware acl condition: cssd: connection to 127.0.0.1, port 1234 failed (Connection refused)
    2010:04:08-19:35:17 mercury exim[5670]: [1\26] 2010-04-08 19:35:17 1NzwZQ-0001TS-1T H=ziffdavismedia-112.ziffdavismedia.tracker.postdirect.com [206.165.242.112]:7460 F= temporarily rejected after DATA
  • Just found in the logfile:
    2010:04:09-00:01:00 mercury smtpd[5229]: MASTER[5229]: 1O00YV-0003cH-0h Scanner crash - moving to error queue

    2010:04:09-00:06:50 mercury smtpd[5229]: MASTER[5229]: Action: retrying 1O00Ih-0003HC-1L (moved from error to input)
    2010:04:09-00:06:50 mercury smtpd[5229]: MASTER[5229]: Action: retrying 1O00YV-0003cH-0h (moved from error to input)
    2010:04:09-00:06:52 mercury smtpd[5281]: QMGR[5281]: 1O00Ih-0003HC-1L moved to work queue
    2010:04:09-00:06:52 mercury smtpd[5281]: QMGR[5281]: 1O00YV-0003cH-0h moved to work queue

    Unfortunately now it's not processing any emails being forced via the retry option and they've gone 'missing' from the SMTP Spool list.

  • 2010:04:08-19:35:17 mercury exim[5670]: 2010-04-08 19:35:17 1NzwZQ-0001TS-1T malware acl condition: cssd: connection to 127.0.0.1, port 1234 failed (Connection refused)


    I'm afraid there's something going wrong with the AV patterns... we had a similar issue with the folks that participated in the closed beta phase and upgraded from 7.89x to 7.900.
  • Don't worry, they'll reappear in the error queue soon, probably in half an hour or so. Mine did.
  • I think this is a new bug and is not related to the pattern update. My screenshots of the scanner crashes that started with this version. The error mails are being collected in the error spool.
  • The same issue here, almost every external, incoming Mail is blocked and ends up in "SMTP Spool" with state "Error".

    As workaround, I have to mark all stuck messages and hit "retry" to get them through our SMTP proxy. Right now, I do this every 30 mins an hope, that this bug is fixed soon.

    The issue started after up2date to 7.901.