Andi Meier
2011-Jan-10 15:08 UTC
[Dovecot] Urgent problem: Dovecot fetches the same mails multiple times per POP
I have a problem since a couple of hours: I manage several mboxes on a virtual server using Dovecot (over POP3). Until a few hours ago, it worked well, but since 11:50, the e-mail clients which access Dovecot's mailboxes, receive all e-mails new each time the mailbox is queried. For example: 15:40 fetches 22 new mails 15:41 fetches the same 22 mails again as new 15:42 fetches the same 22 mails again as new etc. Dovecot version is 1.0.15 on Debian Lenny. How can I fix this? How can I diagnose what's wrong? The mailbox files themselves seem ok, no dupe messages. I noticed that in the /var/log/mail.log Dovecot says: ------- START --------- Jan 10 15:27:08 lvps87-230-81-99 dovecot: POP3(office): Disconnected: Logged out top=0/0, retr=23/6273313, del=23/23, size=6272894 Jan 10 15:40:02 lvps87-230-81-99 dovecot: POP3(office): Effective uid=1002, gid=1002 Jan 10 15:40:02 lvps87-230-81-99 dovecot: POP3(office): mbox: data=/var/mail:INBOX=/var/mail/office Jan 10 15:40:02 lvps87-230-81-99 dovecot: POP3(office): mbox: root=/var/mail, index=/var/mail, inbox=/var/mail/office Jan 10 15:40:02 lvps87-230-81-99 dovecot: POP3(office): mbox sync: Expunged message reappeared in mailbox /var/mail/office (UID 3234 < 3261, seq=2, idx_msgs=0) Jan 10 15:40:02 lvps87-230-81-99 dovecot: pop3-login: Login: user=<office>, method=PLAIN, rip=80.122.113.70, lip=87.230.81.99 Jan 10 15:40:02 lvps87-230-81-99 dovecot: POP3(office): mbox sync: UID inserted in the middle of mailbox /var/mail/office (3261 > 3234, seq=2, idx_msgs=24) Jan 10 15:40:02 lvps87-230-81-99 dovecot: POP3(office): mbox sync: UID inserted in the middle of mailbox /var/mail/office (3285 > 3234, seq=2, idx_msgs=24) Jan 10 15:40:22 lvps87-230-81-99 dovecot: POP3(office): mbox sync: UID inserted in the middle of mailbox /var/mail/office (3309 > 3234, seq=2, idx_msgs=24) Jan 10 15:40:22 lvps87-230-81-99 dovecot: POP3(office): Disconnected: Logged out top=2/0, retr=24/6274745, del=24/24, size=6274309 ------- END --------- What puzzles me: Each time the retr=XX value is never decreasing. Shouldn't it be 0/xxxxx the next time when the mails are not kept on the server? Apparently Dovecot does not manage to remove the mails form the mbox, although the email client tells it so (=> del=24/24) Is this the problem? How can I check this? I am very thankful for any hints! Cheers, Andi
Andi Meier
2011-Jan-10 16:28 UTC
[Dovecot] mbox sync problem [was: Urgent problem: Dovecot fetches the same mails multiple times per POP]
The problem in my OP seems to be this log message: mbox sync: UID inserted in the middle of mailbox /var/mail/office (3938 > 3918, seq=2, idx_msgs=10) which appears from time to time. Every time it occurs, all mails are fetches again. I guess that's because all X-UID have now been replaced and the E-Mail Client (or Dovecot itself??) thinks they are all new. Am I right? What can I do about this? How can I diagnose this? Many thanks, Andi On 10.01.2011 16:08, Andi Meier wrote:> I have a problem since a couple of hours: > I manage several mboxes on a virtual server using Dovecot (over POP3). > > Until a few hours ago, it worked well, but since 11:50, the e-mail clients which access Dovecot's mailboxes, receive all e-mails new each > time the mailbox is queried. > > For example: > 15:40 fetches 22 new mails > 15:41 fetches the same 22 mails again as new > 15:42 fetches the same 22 mails again as new > etc. > > > Dovecot version is 1.0.15 on Debian Lenny. > > How can I fix this? How can I diagnose what's wrong? The mailbox files themselves seem ok, no dupe messages. > > I noticed that in the /var/log/mail.log Dovecot says: > > ------- START --------- > Jan 10 15:27:08 lvps87-230-81-99 dovecot: POP3(office): Disconnected: Logged out top=0/0, retr=23/6273313, del=23/23, size=6272894 > Jan 10 15:40:02 lvps87-230-81-99 dovecot: POP3(office): Effective uid=1002, gid=1002 > Jan 10 15:40:02 lvps87-230-81-99 dovecot: POP3(office): mbox: data=/var/mail:INBOX=/var/mail/office > Jan 10 15:40:02 lvps87-230-81-99 dovecot: POP3(office): mbox: root=/var/mail, index=/var/mail, inbox=/var/mail/office > Jan 10 15:40:02 lvps87-230-81-99 dovecot: POP3(office): mbox sync: Expunged message reappeared in mailbox /var/mail/office (UID 3234 < 3261, > seq=2, idx_msgs=0) > Jan 10 15:40:02 lvps87-230-81-99 dovecot: pop3-login: Login: user=<office>, method=PLAIN, rip=80.122.113.70, lip=87.230.81.99 > Jan 10 15:40:02 lvps87-230-81-99 dovecot: POP3(office): mbox sync: UID inserted in the middle of mailbox /var/mail/office (3261 > 3234, > seq=2, idx_msgs=24) > Jan 10 15:40:02 lvps87-230-81-99 dovecot: POP3(office): mbox sync: UID inserted in the middle of mailbox /var/mail/office (3285 > 3234, > seq=2, idx_msgs=24) > Jan 10 15:40:22 lvps87-230-81-99 dovecot: POP3(office): mbox sync: UID inserted in the middle of mailbox /var/mail/office (3309 > 3234, > seq=2, idx_msgs=24) > Jan 10 15:40:22 lvps87-230-81-99 dovecot: POP3(office): Disconnected: Logged out top=2/0, retr=24/6274745, del=24/24, size=6274309 > ------- END --------- > > What puzzles me: Each time the retr=XX value is never decreasing. Shouldn't it be 0/xxxxx the next time when the mails are not kept on the > server? Apparently Dovecot does not manage to remove the mails form the mbox, although the email client tells it so (=> del=24/24) > Is this the problem? How can I check this? > > > I am very thankful for any hints! > > Cheers, > Andi >