[Dovecot] Mail lost - maybe a bug???
Hello everybody
I'm struggling against what seems a really serious trouble: sometimes
mail get lost
I did all the possible checks, but they seems really lost - I know is
absurd, but it seems so
it has been noticed by two users on my server: intially I tought that
was their mistake (mail deleted, mail into spam, ecc), but it wasn't
I deeply checked mail logs, and it seems that mail are delivered (the
path is postfix->amavis->dovecotlda) - log files says that messages
are delivered, but sometimes we lost a message.
I also tried to get into the Maildir and grep the subject of the lost
email: if it was addressed to more recipients I'm able to get it on
some of them, but not to all (look at the example below)
I hope I have clearly explained everything, otherwise let me
knowmydomain
now an extract from the log file:
Oct 27 11:20:29 srv001 postfix/smtpd[24562]: connect from usstlz-
psecap06.emerson.com[144.191.128.17]
Oct 27 11:20:30 srv001 postfix/smtpd[24562]: CE0B74E4A9F:
client=usstlz-psecap06.emerson.com[144.191.128.17]
Oct 27 11:20:31 srv001 postfix/cleanup[25157]: CE0B74E4A9F: warning:
header Subject: =?utf-8?B?
RW1lcnNvbiBHbG9iYWwgVXNlcnMgRXhjaGFuZ2UgMjAxMiBpbiBEw7xzc2VsZG9yZiA6IFJlaWNoZW4gU2llIGpldHp0IElocmUgUHLDpHNlbnRhdGlvbmVuIGVpbg
==?= from usstlz-psecap06.emerson.com[144.191.128.17]; from=<Emerson.News@emersonprocess.com
to=<oil@mydomain.ch> proto=ESMTP helo=<USSTLZ-PSECAP06.EMERSON.COM> Oct 27 11:20:31 srv001 postfix/cleanup[25157]: CE0B74E4A9F: message- id=<e9447410-51fe-45ff-b624-197840b9a862@usstlz-pinfez02.emrsn.org> Oct 27 11:20:31 srv001 postfix/qmgr[11827]: CE0B74E4A9F: from=<Emerson.News@emersonprocess.com , size=22689, nrcpt=3 (queue active) Oct 27 11:20:33 srv001 dovecot: imap(lromano): Disconnected: Logged
out bytes=632/34319 Oct 27 11:20:34 srv001 postfix/smtpd[25162]: connect from
localhost.localdomain[127.0.0.1] Oct 27 11:20:34 srv001 postfix/smtpd[25162]: B16284E4AA2:
client=localhost.localdomain[127.0.0.1] Oct 27 11:20:34 srv001 postfix/cleanup[25157]: B16284E4AA2: message- id=<e9447410-51fe-45ff-b624-197840b9a862@usstlz-pinfez02.emrsn.org> Oct 27 11:20:34 srv001 postfix/qmgr[11827]: B16284E4AA2: from=<Emerson.News@emersonprocess.com , size=23094, nrcpt=3 (queue active) Oct 27 11:20:34 srv001 amavis[22923]: (22923-01) Passed CLEAN,
[144.191.128.17] [155.177.20.144] <Emerson.News@emersonprocess.com> ->
<user1@mydomain.local>,<user2@mydomain.local>,<user3@mydomain.local>,
Message-ID: <e9447410-51fe-45ff-b624-197840b9a862@usstlz-pinfez02.emrsn.org , mail_id: 6rtF4927FAjt, Hits: -0.518, size: 22687, queued_as:
B16284E4AA2, 3293 ms Oct 27 11:20:34 srv001 postfix/lmtp[25158]: CE0B74E4A9F: to=<user1@mydomain.local , orig_to=<oil@mydomain.ch>, relay=127.0.0.1[127.0.0.1]:10024,
delay=4.2, delays=0.95/0.01/0.01/3.3, dsn=2.0.0, status=sent (250
2.0.0 from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as B16284E4AA2) Oct 27 11:20:34 srv001 postfix/lmtp[25158]: CE0B74E4A9F: to=<user2@mydomain.local , orig_to=<oil@mydomain.ch>, relay=127.0.0.1[127.0.0.1]:10024,
delay=4.2, delays=0.95/0.01/0.01/3.3, dsn=2.0.0, status=sent (250
2.0.0 from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as B16284E4AA2) Oct 27 11:20:34 srv001 postfix/lmtp[25158]: CE0B74E4A9F: to=<user3@mydomain.local , orig_to=<oil@mydomain.ch>, relay=127.0.0.1[127.0.0.1]:10024,
delay=4.2, delays=0.95/0.01/0.01/3.3, dsn=2.0.0, status=sent (250
2.0.0 from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as B16284E4AA2) Oct 27 11:20:34 srv001 postfix/qmgr[11827]: CE0B74E4A9F: removed Oct 27 11:20:34 srv001 dovecot: lda(user1): msgid=<e9447410-51fe-45ff-b624-197840b9a862@usstlz-pinfez02.emrsn.org : saved mail to INBOX Oct 27 11:20:34 srv001 postfix/pipe[25165]: B16284E4AA2: to=<user1@mydomain.local , relay=dovecot, delay=0.04, delays=0.01/0.01/0/0.02, dsn=2.0.0,
status=sent (delivered via dovecot service) Oct 27 11:20:34 srv001 dovecot: lda(user2): msgid=<e9447410-51fe-45ff-b624-197840b9a862@usstlz-pinfez02.emrsn.org : saved mail to INBOX Oct 27 11:20:34 srv001 postfix/pipe[25168]: B16284E4AA2: to=<user2@mydomain.local , relay=dovecot, delay=0.04, delays=0.01/0.01/0/0.02, dsn=2.0.0,
status=sent (delivered via dovecot service) Oct 27 11:20:34 srv001 dovecot: lda(user3): msgid=<e9447410-51fe-45ff-b624-197840b9a862@usstlz-pinfez02.emrsn.org : saved mail to INBOX Oct 27 11:20:34 srv001 postfix/pipe[25170]: B16284E4AA2: to=<user3@mydomain.local , relay=dovecot, delay=0.05, delays=0.01/0.02/0/0.02, dsn=2.0.0,
status=sent (delivered via dovecot service) Oct 27 11:20:34 srv001 postfix/qmgr[11827]: B16284E4AA2: removed Oct 27 11:20:36 srv001 postfix/smtpd[24562]: disconnect from usstlz- psecap06.emerson.com[144.191.128.17]
as you can see there was a message for oil@mydomain.ch (I obviously
changed the domain for privacy) - logs says that all the three users
got the email, but the third user didn't.
I do not know why and when it happens, but seldom we have this issue
maybe is there some kind of bug in the maildrop version I use? by the
way, I had this issue also before installing amavisd-new
now some infos:
CentOS 5.3 postfix-2.3.3-2.1.el5_2 amavisd-new-2.6.6-1.el5.rf dovecot-2.0.11-1_126 dovecot-managesieve-0.2.2-15 dovecot-pigeonhole-0.2.2-15
users are on a Kerberized OpenLDAP
please help me because this is really driving me crazy -
don't leave me alone, please
Marco Carcano
On Fri, 2011-10-28 at 00:55 +0200, Marco Carcano wrote:
I'm struggling against what seems a really serious trouble: sometimes
mail get lostI did all the possible checks, but they seems really lost - I know is
absurd, but it seems soit has been noticed by two users on my server: intially I tought that
was their mistake (mail deleted, mail into spam, ecc), but it wasn't
Enable mail_log plugin to make sure of this. http://wiki2.dovecot.org/Plugins/MailLog
Oct 27 11:20:34 srv001 dovecot: lda(user3): msgid=<e9447410-51fe-45ff-b624-197840b9a862@usstlz-pinfez02.emrsn.org
: saved mail to INBOX
If Dovecot logs this, then the message definitely was saved to INBOX.
maybe is there some kind of bug in the maildrop version I use? by the
way, I had this issue also before installing amavisd-new
Maildrop?
Hello Timo, and thanks for your reply
I waited to reply until got it another time
as I already said, it does not happen very often, for example it
happened on 12 november - the log is at the end of this mail
Enable mail_log plugin to make sure of this. http://wiki2.dovecot.org/Plugins/MailLog
I already did, but just for a few days: it does not happen very often
that we loose mails, so I'm afraid I can damage the disks of the
production server if I keep logging enabled for too much time - it
will be a pain, years ago I had a server damaged because of logging
enabled for too much time. I do not want to repeat such a painfull
experience
Oct 27 11:20:34 srv001 dovecot: lda(user3): msgid=<e9447410-51fe-45ff-b624-197840b9a862@usstlz-pinfez02.emrsn.org
: saved mail to INBOX
If Dovecot logs this, then the message definitely was saved to INBOX.
it is exactly what I told to my colleagues, but belive me, sometime
some mail get lost - I suspect however that could be mine
misconfiguration somewhere, so that lda sometimes write the email not
in the right place, but elsewhere, and just write the phrase " saved
mail to INBOX in the logs (however I'm wondering why sometimes?!?)
I tried to find the missed email in the Maildir, but have not been
able to get it - the commands used are
cd /home/mailboxstore/theuser/Maildir
grep "6000029222" */* |grep "RE:" grep "6000029222" .Drafts/* |grep "RE:" grep "6000029222" .Drafts/*/* |grep "RE:" grep "6000029222" .Junk/* |grep "RE:" grep "6000029222" .Posta\ eliminata/* |grep "RE:" grep "6000029222" .Posta\ indesiderata/* |grep "RE:" grep "6000029222" .Posta\ inviata/* |grep "RE:" grep "6000029222" .Sent/* |grep "RE:" grep "6000029222" .Templates/* |grep "RE:" grep "6000029222" .Trash/* |grep "RE:"
and never got anything
here is the log instead
Nov 12 08:48:01 srv001 postfix/smtpd[1430]: connect from
mail.tasnee.com[62.3.52.58]
Nov 12 08:48:02 srv001 postfix/smtpd[1430]: 6C3874E4A9F:
client=mail.tasnee.com[62.3.52.58]
Nov 12 08:48:03 srv001 postfix/cleanup[1434]: 6C3874E4A9F: warning:
header Subject: RE: RFQ NO. 6000029222 - OUR OFFER NO. 2111221 from
mail.tasnee.com[62.3.52.58]; from=<sender@tasnee.com> to=<theuser@ourdomain.ch
proto=ESMTP helo=<mail.tasnee.com> Nov 12 08:48:03 srv001 postfix/cleanup[1434]: 6C3874E4A9F: message-id=<899EAB831EA7414F994704DB43677A140450EE74@NPICMAIL.npic.com.sa
Nov 12 08:48:03 srv001 postfix/qmgr[4876]: 6C3874E4A9F: from=<sender@tasnee.com
, size=9920, nrcpt=4 (queue active) Nov 12 08:48:06 srv001 postfix/smtpd[1442]: connect from
localhost.localdomain[127.0.0.1] Nov 12 08:48:06 srv001 postfix/smtpd[1442]: 244774E4AA2:
client=localhost.localdomain[127.0.0.1] Nov 12 08:48:06 srv001 postfix/cleanup[1434]: 244774E4AA2: message-id=<899EAB831EA7414F994704DB43677A140450EE74@NPICMAIL.npic.com.sa
Nov 12 08:48:06 srv001 postfix/qmgr[4876]: 244774E4AA2: from=<sender@tasnee.com
, size=10323, nrcpt=4 (queue active) Nov 12 08:48:06 srv001 postfix/smtpd[1442]: disconnect from
localhost.localdomain[127.0.0.1] Nov 12 08:48:06 srv001 amavis[8902]: (08902-05) Passed CLEAN,
[62.3.52.58] [62.3.52.58] <sender@tasnee.com> ->
< user2 @ourdomain.local>,<theuser@ourdomain.local>,<user4@ourdomain.local>,<user3@ourdomain.local , Message-ID: <899EAB831EA7414F994704DB43677A140450EE74@NPICMAIL.npic.com.sa , mail_id: z4aAgl2gBrfV, Hits: -0.592, size: 9919, queued_as:
244774E4AA2, 2632 ms Nov 12 08:48:06 srv001 postfix/lmtp[1438]: 6C3874E4A9F: to=<user2@ourdomain.local , orig_to=<user2@ourdomain.ch>, relay=127.0.0.1[127.0.0.1]:10024,
delay=3.9, delays=1.2/0.01/0/2.6, dsn=2.0.0, status=sent (250 2.0.0
from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 244774E4AA2) Nov 12 08:48:06 srv001 postfix/lmtp[1438]: 6C3874E4A9F: to=<theuser@ourdomain.local , orig_to=<theuser@ourdomain.ch>, relay=127.0.0.1[127.0.0.1]:10024,
delay=3.9, delays=1.2/0.01/0/2.6, dsn=2.0.0, status=sent (250 2.0.0
from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 244774E4AA2) Nov 12 08:48:06 srv001 postfix/lmtp[1438]: 6C3874E4A9F: to=<user4@ourdomain.local , orig_to=<user4@ourdomain.ch>, relay=127.0.0.1[127.0.0.1]:10024,
delay=3.9, delays=1.2/0.01/0/2.6, dsn=2.0.0, status=sent (250 2.0.0
from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 244774E4AA2) Nov 12 08:48:06 srv001 postfix/lmtp[1438]: 6C3874E4A9F: to=<user3@ourdomain.local , orig_to=<user3@ourdomain.ch>, relay=127.0.0.1[127.0.0.1]:10024,
delay=3.9, delays=1.2/0.01/0/2.6, dsn=2.0.0, status=sent (250 2.0.0
from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 244774E4AA2) Nov 12 08:48:06 srv001 postfix/qmgr[4876]: 6C3874E4A9F: removed Nov 12 08:48:06 srv001 dovecot: lda(user3): msgid=<899EAB831EA7414F994704DB43677A140450EE74@NPICMAIL.npic.com.sa : saved mail to INBOX Nov 12 08:48:06 srv001 dovecot: lda(user2): msgid=<899EAB831EA7414F994704DB43677A140450EE74@NPICMAIL.npic.com.sa : saved mail to INBOX Nov 12 08:48:06 srv001 postfix/pipe[1452]: 244774E4AA2: to=<user3@ourdomain.local , relay=dovecot, delay=0.08, delays=0.01/0.02/0/0.05, dsn=2.0.0,
status=sent (delivered via dovecot service) Nov 12 08:48:06 srv001 postfix/pipe[1445]: 244774E4AA2: to=<user2@ourdomain.local , relay=dovecot, delay=0.08, delays=0.01/0.01/0/0.06, dsn=2.0.0,
status=sent (delivered via dovecot service) Nov 12 08:48:06 srv001 dovecot: lda(theuser): msgid=<899EAB831EA7414F994704DB43677A140450EE74@NPICMAIL.npic.com.sa : saved mail to INBOX Nov 12 08:48:06 srv001 postfix/pipe[1447]: 244774E4AA2: to=<theuser@ourdomain.local , relay=dovecot, delay=0.09, delays=0.01/0.01/0/0.07, dsn=2.0.0,
status=sent (delivered via dovecot service) Nov 12 08:48:06 srv001 dovecot: lda(user4): msgid=<899EAB831EA7414F994704DB43677A140450EE74@NPICMAIL.npic.com.sa : saved mail to INBOX Nov 12 08:48:06 srv001 postfix/pipe[1450]: 244774E4AA2: to=<user4@ourdomain.local , relay=dovecot, delay=0.26, delays=0.01/0.02/0/0.23, dsn=2.0.0,
status=sent (delivered via dovecot service) Nov 12 08:48:06 srv001 postfix/qmgr[4876]: 244774E4AA2: removed Nov 12 08:48:08 srv001 postfix/smtpd[1430]: disconnect from
mail.tasnee.com[62.3.52.58]
as you can see again, the mail seems delivered, but is not
I really think is some kind of misconfiguration of mine, may you help
me, please? Just tell me what pieces of config to show (just not to
flood the whole config)
thank you
Marco Carcano
Hi,
On 17.11.2011 17:47, Marco Carcano wrote:
Hello Timo, and thanks for your reply
I waited to reply until got it another time
as I already said, it does not happen very often, for example it happened on 12 november - the log is at the end of this mail
Enable mail_log plugin to make sure of this. http://wiki2.dovecot.org/Plugins/MailLog
I already did, but just for a few days: it does not happen very often that we loose mails, so I'm afraid I can damage the disks of the production server if I keep logging enabled for too much time - it will be a pain, years ago I had a server damaged because of logging enabled for too much time. I do not want to repeat such a painfull experience
I think logging is not a main reason for damaging disks. I have enabled mail_log plugin since march 2011 without problems and it helps me very often in such cases.
Oct 27 11:20:34 srv001 dovecot: lda(user3): msgid=<e9447410-51fe-45ff-b624-197840b9a862@usstlz-pinfez02.emrsn.org
: saved mail to INBOX
If Dovecot logs this, then the message definitely was saved to INBOX.
it is exactly what I told to my colleagues, but belive me, sometime some mail get lost - I suspect however that could be mine misconfiguration somewhere, so that lda sometimes write the email not in the right place, but elsewhere, and just write the phrase " saved mail to INBOX in the logs (however I'm wondering why sometimes?!?)
Could it be that some other person is downloading the mail via pop3 and then the client is deleting it from the server? This happens to me sometimes when a customer is accessing his account with a new client but forgot to disable the same account on his old PC. So it happens, that the old pc downloads all new mails, delete it then and the customer never see new mails on his new client.
Regards Urban
I tried to find the missed email in the Maildir, but have not been able to get it - the commands used are
cd /home/mailboxstore/theuser/Maildir
grep "6000029222" */* |grep "RE:" grep "6000029222" .Drafts/* |grep "RE:" grep "6000029222" .Drafts/*/* |grep "RE:" grep "6000029222" .Junk/* |grep "RE:" grep "6000029222" .Posta\ eliminata/* |grep "RE:" grep "6000029222" .Posta\ indesiderata/* |grep "RE:" grep "6000029222" .Posta\ inviata/* |grep "RE:" grep "6000029222" .Sent/* |grep "RE:" grep "6000029222" .Templates/* |grep "RE:" grep "6000029222" .Trash/* |grep "RE:"
and never got anything
here is the log instead
Nov 12 08:48:01 srv001 postfix/smtpd[1430]: connect from mail.tasnee.com[62.3.52.58] Nov 12 08:48:02 srv001 postfix/smtpd[1430]: 6C3874E4A9F: client=mail.tasnee.com[62.3.52.58] Nov 12 08:48:03 srv001 postfix/cleanup[1434]: 6C3874E4A9F: warning: header Subject: RE: RFQ NO. 6000029222 - OUR OFFER NO. 2111221 from mail.tasnee.com[62.3.52.58]; from=<sender@tasnee.com> to=<theuser@ourdomain.ch> proto=ESMTP helo=<mail.tasnee.com> Nov 12 08:48:03 srv001 postfix/cleanup[1434]: 6C3874E4A9F: message-id=<899EAB831EA7414F994704DB43677A140450EE74@NPICMAIL.npic.com.sa> Nov 12 08:48:03 srv001 postfix/qmgr[4876]: 6C3874E4A9F: from=<sender@tasnee.com>, size=9920, nrcpt=4 (queue active) Nov 12 08:48:06 srv001 postfix/smtpd[1442]: connect from localhost.localdomain[127.0.0.1] Nov 12 08:48:06 srv001 postfix/smtpd[1442]: 244774E4AA2: client=localhost.localdomain[127.0.0.1] Nov 12 08:48:06 srv001 postfix/cleanup[1434]: 244774E4AA2: message-id=<899EAB831EA7414F994704DB43677A140450EE74@NPICMAIL.npic.com.sa> Nov 12 08:48:06 srv001 postfix/qmgr[4876]: 244774E4AA2: from=<sender@tasnee.com>, size=10323, nrcpt=4 (queue active) Nov 12 08:48:06 srv001 postfix/smtpd[1442]: disconnect from localhost.localdomain[127.0.0.1] Nov 12 08:48:06 srv001 amavis[8902]: (08902-05) Passed CLEAN, [62.3.52.58] [62.3.52.58] <sender@tasnee.com> -> <user2@ourdomain.local>,<theuser@ourdomain.local>,<user4@ourdomain.local>,<user3@ourdomain.local>, Message-ID: <899EAB831EA7414F994704DB43677A140450EE74@NPICMAIL.npic.com.sa>, mail_id: z4aAgl2gBrfV, Hits: -0.592, size: 9919, queued_as: 244774E4AA2, 2632 ms Nov 12 08:48:06 srv001 postfix/lmtp[1438]: 6C3874E4A9F: to=<user2@ourdomain.local>, orig_to=<user2@ourdomain.ch>, relay=127.0.0.1[127.0.0.1]:10024, delay=3.9, delays=1.2/0.01/0/2.6, dsn=2.0.0, status=sent (250 2.0.0 from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 244774E4AA2) Nov 12 08:48:06 srv001 postfix/lmtp[1438]: 6C3874E4A9F: to=<theuser@ourdomain.local>, orig_to=<theuser@ourdomain.ch>, relay=127.0.0.1[127.0.0.1]:10024, delay=3.9, delays=1.2/0.01/0/2.6, dsn=2.0.0, status=sent (250 2.0.0 from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 244774E4AA2) Nov 12 08:48:06 srv001 postfix/lmtp[1438]: 6C3874E4A9F: to=<user4@ourdomain.local>, orig_to=<user4@ourdomain.ch>, relay=127.0.0.1[127.0.0.1]:10024, delay=3.9, delays=1.2/0.01/0/2.6, dsn=2.0.0, status=sent (250 2.0.0 from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 244774E4AA2) Nov 12 08:48:06 srv001 postfix/lmtp[1438]: 6C3874E4A9F: to=<user3@ourdomain.local>, orig_to=<user3@ourdomain.ch>, relay=127.0.0.1[127.0.0.1]:10024, delay=3.9, delays=1.2/0.01/0/2.6, dsn=2.0.0, status=sent (250 2.0.0 from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 244774E4AA2) Nov 12 08:48:06 srv001 postfix/qmgr[4876]: 6C3874E4A9F: removed Nov 12 08:48:06 srv001 dovecot: lda(user3): msgid=<899EAB831EA7414F994704DB43677A140450EE74@NPICMAIL.npic.com.sa>: saved mail to INBOX Nov 12 08:48:06 srv001 dovecot: lda(user2): msgid=<899EAB831EA7414F994704DB43677A140450EE74@NPICMAIL.npic.com.sa>: saved mail to INBOX Nov 12 08:48:06 srv001 postfix/pipe[1452]: 244774E4AA2: to=<user3@ourdomain.local>, relay=dovecot, delay=0.08, delays=0.01/0.02/0/0.05, dsn=2.0.0, status=sent (delivered via dovecot service) Nov 12 08:48:06 srv001 postfix/pipe[1445]: 244774E4AA2: to=<user2@ourdomain.local>, relay=dovecot, delay=0.08, delays=0.01/0.01/0/0.06, dsn=2.0.0, status=sent (delivered via dovecot service) Nov 12 08:48:06 srv001 dovecot: lda(theuser): msgid=<899EAB831EA7414F994704DB43677A140450EE74@NPICMAIL.npic.com.sa>: saved mail to INBOX Nov 12 08:48:06 srv001 postfix/pipe[1447]: 244774E4AA2: to=<theuser@ourdomain.local>, relay=dovecot, delay=0.09, delays=0.01/0.01/0/0.07, dsn=2.0.0, status=sent (delivered via dovecot service) Nov 12 08:48:06 srv001 dovecot: lda(user4): msgid=<899EAB831EA7414F994704DB43677A140450EE74@NPICMAIL.npic.com.sa>: saved mail to INBOX Nov 12 08:48:06 srv001 postfix/pipe[1450]: 244774E4AA2: to=<user4@ourdomain.local>, relay=dovecot, delay=0.26, delays=0.01/0.02/0/0.23, dsn=2.0.0, status=sent (delivered via dovecot service) Nov 12 08:48:06 srv001 postfix/qmgr[4876]: 244774E4AA2: removed Nov 12 08:48:08 srv001 postfix/smtpd[1430]: disconnect from mail.tasnee.com[62.3.52.58]
as you can see again, the mail seems delivered, but is not
I really think is some kind of misconfiguration of mine, may you help me, please? Just tell me what pieces of config to show (just not to flood the whole config)
thank you
Marco Carcano
On 17.11.2011, at 18.47, Marco Carcano wrote:
Oct 27 11:20:34 srv001 dovecot: lda(user3): msgid=<e9447410-51fe-45ff-b624-197840b9a862@usstlz-pinfez02.emrsn.org
: saved mail to INBOX
If Dovecot logs this, then the message definitely was saved to INBOX.
it is exactly what I told to my colleagues, but belive me, sometime some mail get lost -
Most likely reason for this is that the user's client deletes the message. Possibly an automatic client side filter or some UI issue that causes user to accidentally delete a mail. The mail_log plugin's logging would have showed if this was the case.
I suspect however that could be mine misconfiguration somewhere, so that lda sometimes write the email not in the right place, but elsewhere, and just write the phrase " saved mail to INBOX in the logs (however I'm wondering why sometimes?!?)
I can't think of any reason why it would randomly write to a wrong place.
I tried to find the missed email in the Maildir, but have not been able to get it - the commands used are
cd /home/mailboxstore/theuser/Maildir
grep "6000029222" */* |grep "RE:" grep "6000029222" .Drafts/* |grep "RE:" grep "6000029222" .Drafts/*/* |grep "RE:" grep "6000029222" .Junk/* |grep "RE:" grep "6000029222" .Posta\ eliminata/* |grep "RE:" grep "6000029222" .Posta\ indesiderata/* |grep "RE:" grep "6000029222" .Posta\ inviata/* |grep "RE:" grep "6000029222" .Sent/* |grep "RE:" grep "6000029222" .Templates/* |grep "RE:" grep "6000029222" .Trash/* |grep "RE:"
Only the grep "6000029222" .Drafts/*/* |grep "RE:" was grepping from mail files. Easier would be just:
grep -r "RE:.*6000029222" .
I really think is some kind of misconfiguration of mine, may you help me, please? Just tell me what pieces of config to show (just not to flood the whole config)
I doubt this is related to configuration.
But you could enable http://wiki2.dovecot.org/Plugins/Lazyexpunge so that messages won't be lost if they are expunged. The next time a message is lost, you would most likely find it from the lazy-expunge namespace. (Then you could write a script that deletes e.g. >1 week old files nightly.)
Hello Timo and Urban, and thank you for the very quick reply
I have already thought about these things: I have already disabled
mailbox deletion from POP3 clients, that actually just leave the
messages on the server
however, this time noone of the 4 recipients got the email - so it is
really strange that all che clients deleted the same message and left
all the others
we can notice this only a few days after the issue, because customers
send us a reminder forwarding the lost mail
Il giorno 17/nov/11, alle ore 18:34, Timo Sirainen ha scritto:
On 17.11.2011, at 18.47, Marco Carcano wrote:
Oct 27 11:20:34 srv001 dovecot: lda(user3): msgid=<e9447410-51fe-45ff-b624-197840b9a862@usstlz-pinfez02.emrsn.org
: saved mail to INBOX
If Dovecot logs this, then the message definitely was saved to
INBOX.it is exactly what I told to my colleagues, but belive me, sometime
some mail get lost -Most likely reason for this is that the user's client deletes the
message. Possibly an automatic client side filter or some UI issue
that causes user to accidentally delete a mail. The mail_log
plugin's logging would have showed if this was the case.I suspect however that could be mine misconfiguration somewhere, so
that lda sometimes write the email not in the right place, but
elsewhere, and just write the phrase " saved mail to INBOX in the
logs (however I'm wondering why sometimes?!?)I can't think of any reason why it would randomly write to a wrong
place.
maybe something related to LDAP lookups? what can happen if for some
reason the LDAP server does not reply to the lookup?
Timo, belive to me, I use dovecot since 3 years, and I am one of the
thousands of happy user, I really can't explain what is happening on
this server
I'll do this trial: I'll enable lda debug logging ont a file on a USB
hard disk - in order to know where exactly messages are stored, and
enable also maillog too
I'll keep you informed on what I'll find - maybe it will take some
days, as I told it happens quite seldom
thank you
I tried to find the missed email in the Maildir, but have not been
able to get it - the commands used arecd /home/mailboxstore/theuser/Maildir
grep "6000029222" */* |grep "RE:" grep "6000029222" .Drafts/* |grep "RE:" grep "6000029222" .Drafts/*/* |grep "RE:" grep "6000029222" .Junk/* |grep "RE:" grep "6000029222" .Posta\ eliminata/* |grep "RE:" grep "6000029222" .Posta\ indesiderata/* |grep "RE:" grep "6000029222" .Posta\ inviata/* |grep "RE:" grep "6000029222" .Sent/* |grep "RE:" grep "6000029222" .Templates/* |grep "RE:" grep "6000029222" .Trash/* |grep "RE:"
Only the grep "6000029222" .Drafts/*/* |grep "RE:" was grepping from
mail files. Easier would be just:grep -r "RE:.*6000029222" .
I really think is some kind of misconfiguration of mine, may you
help me, please? Just tell me what pieces of config to show (just
not to flood the whole config)I doubt this is related to configuration.
But you could enable http://wiki2.dovecot.org/Plugins/Lazyexpunge so
that messages won't be lost if they are expunged. The next time a
message is lost, you would most likely find it from the lazy-expunge
namespace. (Then you could write a script that deletes e.g. >1 week
old files nightly.)
Hello Timo and Urban
I took quite a long time to reply, but as I told you this issue does
not verify very often, so I had enabled verbose logging and just
waited ..
I summarize the situation - user mmanzoni sometimes does not receive a
message - it does not matter if he is the only recipient or if there
are others
its outlook 2010 is configured for POP3 mail and to leave all messages
on the server, and setup to never delete them (neither after a few
days, neither when he deletes from his trash folder). There are not
any other client that log to that mail account: this is the only one
client that download messages
the following extract of the LDA log shows what happened: the message
was sent to 4 users (I report just 2 of them: criva, that received it,
and mmanzoni, who didn't)
################CRIVA#####################
Dec 12 10:51:24 srv001 dovecot: lda: Debug: Loading modules from
directory: /usr/lib64/dovecot
Dec 12 10:51:24 srv001 dovecot: lda: Debug: Module loaded: /usr/lib64/
dovecot/lib10_quota_plugin.so
Dec 12 10:51:24 srv001 dovecot: lda: Debug: Module loaded: /usr/lib64/
dovecot/lib90_sieve_plugin.so
Dec 12 10:51:24 srv001 dovecot: lda: Debug: auth input: criva home=/
home/criva 499=criva quota_rule=*:storage=8192M
Dec 12 10:51:24 srv001 dovecot: lda: Debug: Added userdb setting:
plugin/499=criva
Dec 12 10:51:24 srv001 dovecot: lda: Debug: Added userdb setting:
plugin/quota_rule=*:storage=8192M
Dec 12 10:51:24 srv001 dovecot: lda(criva): Debug: Effective uid=499,
gid=499, home=/home/criva
Dec 12 10:51:24 srv001 dovecot: lda(criva): Debug: Quota root:
name=User quota backend=maildir args=
Dec 12 10:51:24 srv001 dovecot: lda(criva): Debug: Quota rule:
root=User quota mailbox=* bytes=8589934592 messages=0
Dec 12 10:51:24 srv001 dovecot: lda(criva): Debug: Quota rule:
root=User quota mailbox=Trash bytes=+1048576000 messages=0
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: Quota warning:
bytes=6871947673 (80%) messages=0 reverse=no command=quota-warning 80
criva
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: Quota warning:
bytes=7730941132 (90%) messages=0 reverse=no command=quota-warning 90
criva
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: Quota warning:
bytes=8160437862 (95%) messages=0 reverse=no command=quota-warning 95
criva
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: Quota root:
name=Shared quota backend=maildir args=ns=Public/
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: Quota rule:
root=Shared quota mailbox=* bytes=20971520000 messages=0
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: Namespace :
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:/home/mailboxstore/criva/Maildir
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: maildir++: root=/
home/mailboxstore/criva/Maildir, index=, control=, inbox=/home/
mailboxstore/criva/Maildir
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: Namespace :
type=shared, prefix=shared/%u/, sep=/, inbox=no, hidden=no,
list=children, subscriptions=no location=maildir:/home/mailboxstore/
%Lu/Maildir:INDEX=/home/mailboxstore/criva/Maildir/shared/%Lu
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: shared: root=/var/
run/dovecot, index=, control=, inbox=
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: Namespace :
type=public, prefix=Public/, sep=/, inbox=no, hidden=no, list=yes,
subscriptions=no location=maildir:/home/mailboxstore/public
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: maildir++: root=/
home/mailboxstore/public, index=, control=, inbox=
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: Quota root:
name=User quota backend=maildir args=
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: Quota rule:
root=User quota mailbox=* bytes=14680064000 messages=0
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: Quota rule:
root=User quota mailbox=Trash bytes=+1048576000 messages=0
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: Quota warning:
bytes=11744051200 (80%) messages=0 reverse=no command=quota-warning 80
criva
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: Quota warning:
bytes=13212057600 (90%) messages=0 reverse=no command=quota-warning 90
criva
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: Quota warning:
bytes=13946060800 (95%) messages=0 reverse=no command=quota-warning 95
criva
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: Quota root:
name=Shared quota backend=maildir args=ns=Public/
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: Quota rule:
root=Shared quota mailbox=* bytes=20971520000 messages=0
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: none: root=,
index=, control=, inbox=
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: sieve: user's
script path /home/mailboxstore/criva/.dovecot.sieve doesn't exist
(using global script path in stead)
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: sieve: user has no
valid personal script
Dec 12 10:51:27 srv001 dovecot: lda(criva): Debug: sieve: no scripts
to execute: reverting to default delivery.
Dec 12 10:51:27 srv001 dovecot: lda(criva): msgid=<1888520041-1323683477-cardhu_decombobulator_blackberry.rim.net-2066152169-@b12.c13.bise7.blackberry
: saved mail to INBOX
#################MMANZONI###############
Dec 12 10:51:28 srv001 dovecot: lda: Debug: Loading modules from
directory: /usr/lib64/dovecot
Dec 12 10:51:28 srv001 dovecot: lda: Debug: Module loaded: /usr/lib64/
dovecot/lib10_quota_plugin.so
Dec 12 10:51:28 srv001 dovecot: lda: Debug: Module loaded: /usr/lib64/
dovecot/lib90_sieve_plugin.so
Dec 12 10:51:28 srv001 dovecot: lda: Debug: auth input: mmanzoni home=/
home/mmanzoni 499=mmanzoni quota_rule=*:storage=8192M
Dec 12 10:51:28 srv001 dovecot: lda: Debug: Added userdb setting:
plugin/499=mmanzoni
Dec 12 10:51:28 srv001 dovecot: lda: Debug: Added userdb setting:
plugin/quota_rule=*:storage=8192M
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: Effective
uid=499, gid=499, home=/home/mmanzoni
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: Quota root:
name=User quota backend=maildir args=
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: Quota rule:
root=User quota mailbox=* bytes=8589934592 messages=0
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: Quota rule:
root=User quota mailbox=Trash bytes=+1048576000 messages=0
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: Quota warning:
bytes=6871947673 (80%) messages=0 reverse=no command=quota-warning 80
mmanzoni
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: Quota warning:
bytes=7730941132 (90%) messages=0 reverse=no command=quota-warning 90
mmanzoni
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: Quota warning:
bytes=8160437862 (95%) messages=0 reverse=no command=quota-warning 95
mmanzoni
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: Quota root:
name=Shared quota backend=maildir args=ns=Public/
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: Quota rule:
root=Shared quota mailbox=* bytes=20971520000 messages=0
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: Namespace :
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:/home/mailboxstore/mmanzoni/Maildir
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: maildir++: root=/
home/mailboxstore/mmanzoni/Maildir, index=, control=, inbox=/home/
mailboxstore/mmanzoni/Maildir
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: Namespace :
type=shared, prefix=shared/%u/, sep=/, inbox=no, hidden=no,
list=children, subscriptions=no location=maildir:/home/mailboxstore/
%Lu/Maildir:INDEX=/home/mailboxstore/mmanzoni/Maildir/shared/%Lu
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: shared: root=/
var/run/dovecot, index=, control=, inbox=
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: Namespace :
type=public, prefix=Public/, sep=/, inbox=no, hidden=no, list=yes,
subscriptions=no location=maildir:/home/mailboxstore/public
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: maildir++: root=/
home/mailboxstore/public, index=, control=, inbox=
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: Quota root:
name=User quota backend=maildir args=
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: Quota rule:
root=User quota mailbox=* bytes=14680064000 messages=0
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: Quota rule:
root=User quota mailbox=Trash bytes=+1048576000 messages=0
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: Quota warning:
bytes=11744051200 (80%) messages=0 reverse=no command=quota-warning 80
mmanzoni
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: Quota warning:
bytes=13212057600 (90%) messages=0 reverse=no command=quota-warning 90
mmanzoni
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: Quota warning:
bytes=13946060800 (95%) messages=0 reverse=no command=quota-warning 95
mmanzoni
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: Quota root:
name=Shared quota backend=maildir args=ns=Public/
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: Quota rule:
root=Shared quota mailbox=* bytes=20971520000 messages=0
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: none: root=,
index=, control=, inbox=
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: sieve: user's
script path /home/mailboxstore/mmanzoni/.dovecot.sieve doesn't exist
(using global script path in stead)
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: sieve: user has
no valid personal script
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): Debug: sieve: no
scripts to execute: reverting to default delivery.
Dec 12 10:51:28 srv001 dovecot: lda(mmanzoni): msgid=<1888520041-1323683477-cardhu_decombobulator_blackberry.rim.net-2066152169-@b12.c13.bise7.blackberry
: saved mail to INBOX
#########################################
I know it seems absurd, but mmanzoni has not received the message - I
tried also "grepping" for the object in the maildir, but haven't been
able to get it
what do you think about this?
I really do not know where this issue can be - the only componet I
suppose could have some kind of problem is in the LDA phase, but I'm
just supposing
do you want to give a look to my config files? If so, which one could
be interesting to post?
kind regards
Marco Carcano
Il giorno 17/nov/11, alle ore 18:34, Timo Sirainen ha scritto:
On 17.11.2011, at 18.47, Marco Carcano wrote:
Oct 27 11:20:34 srv001 dovecot: lda(user3): msgid=<e9447410-51fe-45ff-b624-197840b9a862@usstlz-pinfez02.emrsn.org
: saved mail to INBOX
If Dovecot logs this, then the message definitely was saved to
INBOX.it is exactly what I told to my colleagues, but belive me, sometime
some mail get lost -Most likely reason for this is that the user's client deletes the
message. Possibly an automatic client side filter or some UI issue
that causes user to accidentally delete a mail. The mail_log
plugin's logging would have showed if this was the case.I suspect however that could be mine misconfiguration somewhere, so
that lda sometimes write the email not in the right place, but
elsewhere, and just write the phrase " saved mail to INBOX in the
logs (however I'm wondering why sometimes?!?)I can't think of any reason why it would randomly write to a wrong
place.I tried to find the missed email in the Maildir, but have not been
able to get it - the commands used arecd /home/mailboxstore/theuser/Maildir
grep "6000029222" */* |grep "RE:" grep "6000029222" .Drafts/* |grep "RE:" grep "6000029222" .Drafts/*/* |grep "RE:" grep "6000029222" .Junk/* |grep "RE:" grep "6000029222" .Posta\ eliminata/* |grep "RE:" grep "6000029222" .Posta\ indesiderata/* |grep "RE:" grep "6000029222" .Posta\ inviata/* |grep "RE:" grep "6000029222" .Sent/* |grep "RE:" grep "6000029222" .Templates/* |grep "RE:" grep "6000029222" .Trash/* |grep "RE:"
Only the grep "6000029222" .Drafts/*/* |grep "RE:" was grepping from
mail files. Easier would be just:grep -r "RE:.*6000029222" .
I really think is some kind of misconfiguration of mine, may you
help me, please? Just tell me what pieces of config to show (just
not to flood the whole config)I doubt this is related to configuration.
But you could enable http://wiki2.dovecot.org/Plugins/Lazyexpunge so
that messages won't be lost if they are expunged. The next time a
message is lost, you would most likely find it from the lazy-expunge
namespace. (Then you could write a script that deletes e.g. >1 week
old files nightly.)
On Tue, 2011-12-20 at 12:46 +0100, Marco Carcano wrote:
Hello Timo and Urban
I took quite a long time to reply, but as I told you this issue does
not verify very often, so I had enabled verbose logging and just
waited ..
Enabling mail_log plugin and/or lazy_expunge plugin would have helped more (both mentioned in my previous mail).
I summarize the situation - user mmanzoni sometimes does not receive a
message - it does not matter if he is the only recipient or if there
are othersits outlook 2010 is configured for POP3 mail and to leave all messages
on the server, and setup to never delete them (neither after a few
days, neither when he deletes from his trash folder). There are not
any other client that log to that mail account: this is the only one
client that download messagesthe following extract of the LDA log shows what happened: the message
was sent to 4 users (I report just 2 of them: criva, that received it,
and mmanzoni, who didn't)
There's really nothing in the LDA log that could explain why the message gets lost. It most likely was successfully delivered by LDA, but got deleted afterwards for some reason.
You mean that this user's mails are never supposed to be deleted via POP3? Verify that with:
grep 'pop3.*mmanzoni.*del=[^0]' /var/log/dovecot.log
or wherever those POP3 disconnection messages are logged, i.e. you should find lots of messages with:
grep 'pop3.*mmanzoni.*del=0' /var/log/dovecot.log
Hello Timo
and thanks again for the ultra quick reply!
Enabling mail_log plugin and/or lazy_expunge plugin would have helped more (both mentioned in my previous mail).
Sorry - I thought I have enabled it, but maybe I did something wrong
with the configuration and it was not enabled:
here is what I did in order to enable mail_log:
syslog_facility = local5
mail_debug = yes
plugin {
Events to log. Also available: flag_change append
mail_log_events = delete undelete expunge copy mailbox_delete
mailbox_rename
Group events within a transaction to one line.
#mail_log_group_events = no
Available fields: uid, box, msgid, from, subject, size, vsize,
flags
size and vsize are available only for expunge and copy events.
#mail_log_fields = uid box msgid size }
There's really nothing in the LDA log that could explain why the
message gets lost. It most likely was successfully delivered by LDA, but got deleted afterwards for some reason.You mean that this user's mails are never supposed to be deleted via POP3? Verify that with:
yes, you got it - it is never supposed only because we are debugging ;O)
grep 'pop3.*mmanzoni.*del=[^0]' /var/log/dovecot.log
or wherever those POP3 disconnection messages are logged, i.e. you should find lots of messages with:
grep 'pop3.*mmanzoni.*del=0' /var/log/dovecot.log
OK, tried the following - I have varoius log files
grep 'pop3.*mmanzoni.*del=[^0]' deliver.log*
and got nothing
grep 'pop3.*criva.*del=[^0]' deliver.log*
and got
deliver.log.1:Dec 15 12:26:16 srv001 dovecot: pop3(criva):
Disconnected: Logged out top=0/0, retr=1/8147, del=1613/1613,
size=619997598
deliver.log.1:Dec 15 12:27:39 srv001 dovecot: pop3(criva):
Disconnected: Logged out top=0/0, retr=200/50212479, del=200/200,
size=50208702
deliver.log.1:Dec 15 12:29:08 srv001 dovecot: pop3(criva):
Disconnected: Logged out top=0/0, retr=600/203527129, del=600/600,
size=203515938
deliver.log.1:Dec 15 12:30:49 srv001 dovecot: pop3(criva):
Disconnected: Logged out top=0/0, retr=1000/310592896, del=1000/1000,
size=310574037
deliver.log.1:Dec 15 12:31:10 srv001 dovecot: pop3(criva):
Disconnected: Logged out top=0/0, retr=399/44426198, del=399/399,
size=44418942
deliver.log.2:Dec 15 00:11:09 srv001 dovecot: pop3(criva):
Disconnected: Logged out top=0/0, retr=10530/1684049964,
del=10530/10530, size=1683854308
so yes, I'm pretty sure that mmanzoni never deletes messages
belive to me - usually I try to solve problems myself without
disturbing anyone else, but this time is really hard and I do not know
if I could face it alone
I hope you can help
kind regards
Marco Carcano
On 20.12.2011, at 16.52, Marco Carcano wrote:
Enabling mail_log plugin and/or lazy_expunge plugin would have helped more (both mentioned in my previous mail).
Sorry - I thought I have enabled it, but maybe I did something wrong with the configuration and it was not enabled:
here is what I did in order to enable mail_log:
syslog_facility = local5
mail_debug = yes
plugin {
Events to log. Also available: flag_change append
mail_log_events = delete undelete expunge copy mailbox_delete mailbox_rename
Group events within a transaction to one line.
#mail_log_group_events = no
Available fields: uid, box, msgid, from, subject, size, vsize, flags
size and vsize are available only for expunge and copy events.
#mail_log_fields = uid box msgid size }
You're missing: mail_plugins = mail_log
grep 'pop3.*mmanzoni.*del=[^0]' /var/log/dovecot.log
or wherever those POP3 disconnection messages are logged, i.e. you should find lots of messages with:
grep 'pop3.*mmanzoni.*del=0' /var/log/dovecot.log
OK, tried the following - I have varoius log files
grep 'pop3.*mmanzoni.*del=[^0]' deliver.log*
and got nothing
But with:
grep 'pop3.*mmanzoni.*del=0' deliver.log*
There are log entries listed since December 12? (So they haven't gotten deleted from the logs already?)
Also what kind of tools are ever accessing mails? Is it just Dovecot LDA + IMAP + POP3? No doveadm or any external tools?
Hello Timo
of course we have entries:
grep 'pop3.*mmanzoni.*del=0.*' deliver.log* |grep "Dec 12"
deliver.log.2:Dec 12 13:13:19 srv001 dovecot: pop3(mmanzoni): Disconnected: Logged out top=0/0, retr=23/2025701, del=0/3920, size=700800292 deliver.log.2:Dec 12 13:46:02 srv001 dovecot: pop3(mmanzoni): Disconnected: Logged out top=0/0, retr=1/475746, del=0/3921, size=701276018 deliver.log.2:Dec 12 14:58:08 srv001 dovecot: pop3(mmanzoni): Disconnected: Logged out top=0/0, retr=8/911587, del=0/3929, size=702187446 deliver.log.2:Dec 12 14:58:09 srv001 dovecot: pop3(mmanzoni): Disconnected: Logged out top=0/0, retr=0/0, del=0/3929, size=702187446 deliver.log.2:Dec 12 15:55:24 srv001 dovecot: pop3(mmanzoni): Disconnected: Logged out top=0/0, retr=1/936418, del=0/3930, size=703123844 deliver.log.2:Dec 12 16:40:59 srv001 dovecot: pop3(mmanzoni): Disconnected: Logged out top=0/0, retr=1/421415, del=0/3931, size=703545240 deliver.log.2:Dec 12 16:43:23 srv001 dovecot: pop3(mmanzoni): Disconnected: Logged out top=0/0, retr=0/0, del=0/3931, size=703545240 deliver.log.2:Dec 12 17:37:21 srv001 dovecot: pop3(mmanzoni): Disconnected: Logged out top=0/0, retr=0/0, del=0/3931, size=703545240 deliver.log.2:Dec 12 17:44:38 srv001 dovecot: pop3(mmanzoni): Disconnected: Logged out top=0/0, retr=0/0, del=0/3931, size=703545240 deliver.log.2:Dec 12 18:14:29 srv001 dovecot: pop3(mmanzoni): Disconnected: Logged out top=0/0, retr=0/0, del=0/3931, size=703545240 deliver.log.2:Dec 12 18:17:50 srv001 dovecot: pop3(mmanzoni): Disconnected: Logged out top=0/0, retr=0/0, del=0/3931, size=703545240
Also what kind of tools are ever accessing mails? Is it just Dovecot LDA + IMAP + POP3? No doveadm or any external tools?
yes, only LDA + IMAP + POP3, no external tools
I hope you have some ideas
Kind regards
Marco carcano
participants (4)
-
Marco Carcano
-
marco＠carcano.ch
-
Timo Sirainen
-
Urban Loesch