postfix silently lost emails during kolab restart?

[Gavin McCullagh]

Hi,

from time to time, we need to stop and start Kolab for small maintenance
tasks.  For example, having recently discovered a few bogus entries in
mailboxes.db, I took kolab down last night for a few minutes so I could use
cyr_dbtool to prune them.

During this time, one of our clients tried to send a mail.  She apparently
got it through to postfix, but the mail then failed to get through
kolabmailboxfilter which gave "service unavailable".  Rather than deferring
the mail for a while, a bounce was generated in response to this.  The
bounce then also hit kolabmailboxfilter and got a service unavailable.

According to the user, she didn't get a bounce and it looks like the mail
never reached the destination either.  That seems quite serious to me.  The
user (using outlook) didn't get a copy written to sent mail, though I'm not
sure how connected that process is.

Is this a bug perhaps?  I would have thought mail should never get silently
dropped like this, even in the event of mail server restart.

Gavin


Jun 29 23:11:58 paidi <info> postfix/smtpd[25786]: connect from ghrmgr.staff.aaa.bbb[172.16.17.60]
Jun 29 23:11:58 paidi <info> postfix/smtpd[25786]: 7AB9D440C2: client=ghrmgr.staff.aaa.bbb[172.16.17.60]
Jun 29 23:11:59 paidi <info> postfix/cleanup[25588]: 7AB9D440C2: message-id=<01f201cc36a9$c51432f0$4f3c98d0$@xxxxxx at aaa.bbb>
Jun 29 23:11:59 paidi <info> postfix/qmgr[24920]: 7AB9D440C2: from=<xxxx.xxxxxx at aaa.bbb>, size=10862, nrcpt=2 (queue active)
Jun 29 23:11:59 paidi <info> postfix/smtpd[25591]: table hash:/kolab/etc/postfix/virtual(0,lock|fold_fix) has changed -- restarting
Jun 29 23:11:59 paidi <info> postfix/cleanup[25592]: 2A2FE440C5: message-id=<01f201cc36a9$c51432f0$4f3c98d0$@xxxxxx at aaa.bbb>
Jun 29 23:11:59 paidi <info> postfix/qmgr[24920]: 2A2FE440C5: from=<xxxx.xxxxxx at aaa.bbb>, size=11006, nrcpt=3 (queue active)
Jun 29 23:11:59 paidi <info> postfix/smtpd[26072]: disconnect from localhost[127.0.0.1]
Jun 29 23:11:59 paidi <info> postfix/pipe[25589]: 7AB9D440C2: to=<zzzzzzzzzz at aaa.bbb>, relay=kolabfilter, delay=0.74, delays=0.64/0/0/0.1, dsn=2.0.0, status=sent (delivered via kolabfilter service)
Jun 29 23:11:59 paidi <info> postfix/pipe[25589]: 7AB9D440C2: to=<yyyyyyy.yyyyyy at aaa.bbb>, relay=kolabfilter, delay=0.74, delays=0.64/0/0/0.1, dsn=2.0.0, status=sent (delivered via kolabfilter service)
Jun 29 23:11:59 paidi <info> postfix/qmgr[24920]: 7AB9D440C2: removed
Jun 29 23:11:59 paidi <info> postfix/smtpd[25596]: table hash:/kolab/etc/postfix/virtual(0,lock|fold_fix) has changed -- restarting
Jun 29 23:11:59 paidi <info> postfix/smtpd[26074]: connect from localhost[127.0.0.1]
Jun 29 23:11:59 paidi <info> postfix/smtpd[26074]: CC707440C2: client=localhost[127.0.0.1]
Jun 29 23:11:59 paidi <info> postfix/cleanup[25592]: CC707440C2: message-id=<01f201cc36a9$c51432f0$4f3c98d0$@xxxxxx at aaa.bbb>
Jun 29 23:11:59 paidi <info> postfix/smtpd[26074]: disconnect from localhost[127.0.0.1]
Jun 29 23:11:59 paidi <info> postfix/qmgr[24920]: CC707440C2: from=<xxxx.xxxxxx at aaa.bbb>, size=11372, nrcpt=4 (queue active)
Jun 29 23:11:59 paidi <info> postfix/smtp[25593]: 2A2FE440C5: to=<zzzzzzzzzz at aaa.bbb>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.74, delays=0.04/0/0/0.69, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as CC707440C2)
Jun 29 23:11:59 paidi <info> postfix/smtp[25593]: 2A2FE440C5: to=<zzzzzzzzzz at aaa.bbb>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.74, delays=0.04/0/0/0.69, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as CC707440C2)
Jun 29 23:11:59 paidi <info> postfix/smtp[25593]: 2A2FE440C5: to=<yyyyyyy.yyyyyy at aaa.bbb>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.74, delays=0.04/0/0/0.69, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as CC707440C2)
Jun 29 23:11:59 paidi <info> postfix/qmgr[24920]: 2A2FE440C5: removed
Jun 29 23:11:59 paidi <info> postfix/pipe[25633]: CC707440C2: to=<yyyyyyy.yyyyyy at aaa.bbb>, relay=kolabmailboxfilter, delay=0.09, delays=0.01/0/0/0.08, dsn=5.3.0, status=bounced (service unavailable)
Jun 29 23:11:59 paidi <info> postfix/pipe[25638]: CC707440C2: to=<zzzzzzzzzz at aaa.bbb>, relay=kolabmailboxfilter, delay=0.09, delays=0.01/0/0/0.08, dsn=5.3.0, status=bounced (service unavailable)
Jun 29 23:11:59 paidi <info> postfix/pipe[25604]: CC707440C2: to=<zzzzzzzzzz at aaa.bbb>, relay=kolabmailboxfilter, delay=0.09, delays=0.01/0/0/0.08, dsn=5.3.0, status=bounced (service unavailable)
Jun 29 23:11:59 paidi <info> postfix/pipe[25632]: CC707440C2: to=<zzzzzzzzzz at aaa.bbb>, relay=kolabmailboxfilter, delay=0.14, delays=0.01/0.08/0/0.05, dsn=5.3.0, status=bounced (service unavailable)
Jun 29 23:11:59 paidi <info> postfix/cleanup[25588]: table hash:/kolab/etc/postfix/virtual(0,lock|fold_fix) has changed -- restarting
Jun 29 23:11:59 paidi <info> postfix/cleanup[26081]: EEC4C440D5: message-id=<20110629221159.EEC4C440D5 at paidi.aaa.bbb>
Jun 29 23:11:59 paidi <info> postfix/qmgr[24920]: EEC4C440D5: from=<>, size=13336, nrcpt=1 (queue active)
Jun 29 23:11:59 paidi <info> postfix/bounce[26079]: CC707440C2: sender non-delivery notification: EEC4C440D5
Jun 29 23:11:59 paidi <info> postfix/qmgr[24920]: CC707440C2: removed
Jun 29 23:12:00 paidi <info> postfix/pipe[25617]: EEC4C440D5: to=<xxxx.xxxxxx at aaa.bbb>, relay=kolabmailboxfilter, delay=0.06, delays=0.01/0/0/0.05, dsn=5.3.0, status=bounced (service unavailable)
Jun 29 23:12:00 paidi <info> postfix/qmgr[24920]: EEC4C440D5: removed
Jun 29 23:12:08 paidi <info> postfix/trivial-rewrite[25784]: table hash:/kolab/etc/postfix/virtual(0,lock|fold_fix) has changed -- restarting
Jun 29 23:12:27 paidi <info> postfix/smtpd[25786]: disconnect from ghrmgr.staff.aaa.bbb[172.16.17.60]
Jun 29 23:12:27 paidi <info> postfix/smtpd[25538]: table hash:/kolab/etc/postfix/virtual(0,lock|fold_fix) has changed -- restarting
Jun 29 23:12:27 paidi <info> postfix/smtpd[25786]: table hash:/kolab/etc/postfix/virtual(0,lock|fold_fix) has changed -- restarting



-- 
Gavin McCullagh
Senior System Administrator
IT Services
Griffith College 
South Circular Road
Dublin 8
Ireland
Tel: +353 1 4163365
http://www.gcd.ie
http://www.gcd.ie/brochure.pdf
http://www.gcd.ie/opendays
http://www.gcd.ie/ebrochure

This E-mail is from Griffith College.
The E-mail and any files transmitted with it are confidential and may be
privileged and are intended solely for the use of the individual or entity
to whom they are addressed. If you are not the addressee you are prohibited
from disclosing its content, copying it or distributing it otherwise than to
the addressee. If you have received this e-mail in error, please immediately
notify the sender by replying to this e-mail and delete the e-mail from your
computer.

Bellerophon Ltd, trades as Griffith College (registered in Ireland No.
60469) with its registered address as Griffith College Campus, South
Circular Road, Dublin 8, Ireland.