Re: [Dovecot] Mail lost - maybe a bug???
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
Re: [Dovecot] Mail lost - maybe a bug???
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?
Re: [Dovecot] Mail lost - maybe a bug???
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
Re: [Dovecot] Mail lost - maybe a bug???
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 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) 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
Re: [Dovecot] Mail lost - maybe a bug???
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=2097152 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=2097152 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 perso
Re: [Dovecot] Mail lost - maybe a bug???
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= : 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 are cd /home/mailboxstore/theuser/Maildir grep "629222" */* |grep "RE:" grep "629222" .Drafts/* |grep "RE:" grep "629222" .Drafts/*/* |grep "RE:" grep "629222" .Junk/* |grep "RE:" grep "629222" .Posta\ eliminata/* |grep "RE:" grep "629222" .Posta\ indesiderata/* |grep "RE:" grep "629222" .Posta\ inviata/* |grep "RE:" grep "629222" .Sent/* |grep "RE:" grep "629222" .Templates/* |grep "RE:" grep "629222" .Trash/* |grep "RE:" Only the grep "629222" .Drafts/*/* |grep "RE:" was grepping from mail files. Easier would be just: grep -r "RE:.*629222" . 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.)
Re: [Dovecot] Mail lost - maybe a bug???
On 17.11.2011, at 18.47, Marco Carcano wrote: >>> Oct 27 11:20:34 srv001 dovecot: lda(user3): >>> msgid=>>> : 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 "629222" */* |grep "RE:" > grep "629222" .Drafts/* |grep "RE:" > grep "629222" .Drafts/*/* |grep "RE:" > grep "629222" .Junk/* |grep "RE:" > grep "629222" .Posta\ eliminata/* |grep "RE:" > grep "629222" .Posta\ indesiderata/* |grep "RE:" > grep "629222" .Posta\ inviata/* |grep "RE:" > grep "629222" .Sent/* |grep "RE:" > grep "629222" .Templates/* |grep "RE:" > grep "629222" .Trash/* |grep "RE:" Only the grep "629222" .Drafts/*/* |grep "RE:" was grepping from mail files. Easier would be just: grep -r "RE:.*629222" . > 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.)
Re: [Dovecot] Mail lost - maybe a bug???
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= : 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 "629222" */* |grep "RE:" grep "629222" .Drafts/* |grep "RE:" grep "629222" .Drafts/*/* |grep "RE:" grep "629222" .Junk/* |grep "RE:" grep "629222" .Posta\ eliminata/* |grep "RE:" grep "629222" .Posta\ indesiderata/* |grep "RE:" grep "629222" .Posta\ inviata/* |grep "RE:" grep "629222" .Sent/* |grep "RE:" grep "629222" .Templates/* |grep "RE:" grep "629222" .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. 629222 - OUR OFFER NO. 2111221 from mail.tasnee.com[62.3.52.58]; from= to= proto=ESMTP helo= Nov 12 08:48:03 srv001 postfix/cleanup[1434]: 6C3874E4A9F: message-id=<899eab831ea7414f994704db43677a140450e...@npicmail.npic.com.sa> Nov 12 08:48:03 srv001 postfix/qmgr[4876]: 6C3874E4A9F: from=, 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=<899eab831ea7414f994704db43677a140450e...@npicmail.npic.com.sa> Nov 12 08:48:06 srv001 postfix/qmgr[4876]: 244774E4AA2: from=, 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] -> Message-ID: <899eab831ea7414f994704db43677a140450e...@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=, orig_to=, 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=, orig_to=, 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=, orig_to=, 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=, orig_to=, 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=<899eab831ea7414f994704db43677a140450e...@npicmail.npic.com.sa>: saved mail to INBOX Nov 12 08:48:06 srv001 dovecot: lda(user2): msgid=<899eab83
Re: [Dovecot] Mail lost - maybe a bug???
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= : 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 "629222" */* |grep "RE:" grep "629222" .Drafts/* |grep "RE:" grep "629222" .Drafts/*/* |grep "RE:" grep "629222" .Junk/* |grep "RE:" grep "629222" .Posta\ eliminata/* |grep "RE:" grep "629222" .Posta\ indesiderata/* |grep "RE:" grep "629222" .Posta\ inviata/* |grep "RE:" grep "629222" .Sent/* |grep "RE:" grep "629222" .Templates/* |grep "RE:" grep "629222" .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. 629222 - OUR OFFER NO. 2111221 from mail.tasnee.com[62.3.52.58]; from= to=> proto=ESMTP helo= Nov 12 08:48:03 srv001 postfix/cleanup[1434]: 6C3874E4A9F: message-id=<899eab831ea7414f994704db43677a140450e...@npicmail.npic.com.sa > Nov 12 08:48:03 srv001 postfix/qmgr[4876]: 6C3874E4A9F: from=>, 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=<899eab831ea7414f994704db43677a140450e...@npicmail.npic.com.sa > Nov 12 08:48:06 srv001 postfix/qmgr[4876]: 244774E4AA2: from=>, 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] -> < user2 @ourdomain.local>,,,>, Message-ID: <899eab831ea7414f994704db43677a140450e...@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=>, orig_to=, 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=>, orig_to=, 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=>, orig_to=, 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=>, orig_to=, 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=<899eab831ea7414f994704db43677a140450e...@npicmail.npic.com.sa >: saved mail to INBOX Nov 12 08:48:06 srv001 dovecot: lda(user2): msgid=<899eab831ea7414f994704db43677a140450e...@npicmail.npic.com.sa >: saved mail to INBOX Nov 12 08:48:06 srv001 postfix/pipe[1452]: 244774E4AA2: to=>, 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=>, 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=<899eab831ea7414f994704db43677a140450e...@npicmail.npic.com.sa >: saved mail to
Re: [Dovecot] Mail lost - maybe a bug???
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 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 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= >: 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?
