-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1

On Thu, 25 Jul 2013, Kavish Karkera wrote:

Thanks Steffen for the valuable knowledge. Need to know futher that, how could this lead to mails to get re-downloaded. ??

Because Dovecot detects that the UID list is erroreous and therefore rebuilts it. To prevent data loss, either the complete list of messages or just the conflicting ones [the messages that had been delivered in parallel and caused the while problem] do appear as new to the clients.

---

From: Steffen Kaiser skdovecot@smail.inf.fh-brs.de To: Kavish Karkera kavish.karkera@yahoo.com Cc: "dovecot@dovecot.org" dovecot@dovecot.org Sent: Thursday, 25 July 2013 5:54 PM Subject: Re: [Dovecot] Duplicate Mails downloding issue

-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1

On Thu, 25 Jul 2013, Kavish Karkera wrote:

...

---

Jul 23 15:34:51 popserver dovecot: pop3(14949_kavish): Warning: Locking transaction log file /indexes//mail/v3store/example.com/14949_kavish/.INBOX/dovecot.index.log took 133 seconds

some process keeps the INBOX locked, but does not touch the file, so it looks like a stale lock.

...

Jul 23 15:34:51 popserver dovecot: pop3(kavish@example.com): Error: Broken file /indexes//mail/v3store/example.com/14949_kavish/.INBOX/dovecot-uidlist line 180: UIDs not ordered (10156 >= 10156)

Therefore some other process had broken the lock and had appended a message.

...

Jul 23 15:35:01 popserver dovecot: pop3(kavish@example.com): Error: utime(/indexes//mail/v3store/example.com/kavish/.INBOX/dovecot-uidlist.lock) failed: No such file or directory

Jul 23 15:35:11 popserver dovecot: pop3(kavish@example.com): Error: utime(/indexes//mail/v3store/example.com/kavish/.INBOX/dovecot-uidlist.lock) failed: No such file or directory

then the former process(es) finish and try to clean up, but the "some other process" already deleted the lock file.

...

Jul 23 15:35:21 popserver dovecot: pop3(kavish@example.com): Warning: Our dotlock file /indexes//mail/v3store/example.com/kavish/.INBOX/dovecot-uidlist.lock was deleted (kept it 30 secs)

So you have to check your system why a process, that as locked INBOX, is stalled for more than 120min.

---

Steffen Kaiser -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.11 (GNU/Linux)

iQEVAwUBUfEY6F3r2wJMiz2NAQICHwf9HJG66UAHGJp1nT8Ql31n1Bk1KWb+wAhA p2nReYZVSbzZOJM84Dkw8xLu3WoHzFxFEIS+CJc7xGtaeWGrwrTik6d7LKjwI9gf HCun1rq9VzfS85sHvn1owVJxMnUrA3YcY90aQZ6SWHNwvrdmmqqIPhQdGx7xc3En N1jJ0wPEd9hbJyi+2MScZt0WxKuRR+Wpkl14gO6ZPcX95uONGzLcSTs071rAXT+c 6RWLxn2jhruk4qUIm+PGnHkwXTnKL2Dqfladj4/ybxTRn2hgNldK8w4piUwwPWIn HW/hN+sDM/hlRtyu0zHVfiFC7MES6s0JonzwDlOKAFt9dUUG4Mcr9Q== =mar+ -----END PGP SIGNATURE-----

Steffen Kaiser -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.11 (GNU/Linux)

iQEVAwUBUfE3PV3r2wJMiz2NAQKdzAf9HY90QTSszIhaz7pMHYbQBMMU4XEiNBFU 3beZQLuZpYrw1aKr8xJB87DWcfyeULRgiEdWs6uSWgpYnmXYSBjDWV16HYW6+pY8 LTWr1tSY6AzUOxypx8GZfwQFhAmntwfFpoi/JiU8tDnEx2e1W44+V9hzDS4Kfy9i MQDDHRCOZL0cArAQ1DleXrQGnKY/Haa3clBfR72E/UdnGWzuGYxpORbHe9VUK8IP XrNUX1vV6RuS/cxg0/kLoVHk+0YAJCOk9kT2r2t9ZRSxSFHdzm8L/nTnQAgB+ZCR H9lNQxzi6UsRV8hT5mazMmIctW4BQsrJELV/5iWNoMDNxrYVH3Cqlg== =i01T -----END PGP SIGNATURE-----

Steffen ,

Cant understand what's happening here.

Jul 26 12:25:37 popserver dovecot: pop3(kavish.karkera@example.com): Error: Couldn't open INBOX: Timeout while waiting for lock

Jul 26 12:25:37 popserver dovecot: pop3(kavish.karkera@example.com): Couldn't open INBOX top=0/0, retr=0/0, del=0/0, size=0

Jul 26 12:39:02 popserver dovecot: imap-login: Login: user=kavish.karkera@example.com, method=PLAIN, rip=1.38.25.83, lip=121.241.242.35, mpid=27197, TLS, session=<L9JM0WTiPgABJhlT>

Jul 26 12:42:12 popserver dovecot: imap(kavish.karkera@example.com): Error: Timeout (180s) while waiting for lock for transaction log file /indexes//mail/v3store/example.com/kavish.karkera@example.com/.INBOX/dovecot.index.log

Jul 26 12:42:12 popserver dovecot: imap(kavish.karkera@example.com): Warning: Our dotlock file /indexes//mail/v3store/example.com/kavish.karkera@example.com/.INBOX/dovecot-uidlist.lock was modified (1374822548 vs 1374822714), assuming it wasn't overridden (kept it 180 secs)

Jul 26 12:42:12 popserver dovecot: imap(kavish.karkera@example.com): Connection closed bytes=122/1222

Jul 26 12:45:53 popserver dovecot: imap(kavish.karkera@example.com): Warning: Maildir: Scanning /mail/v3store/example.com/kavish.karkera@example.com/Maildir/new took 1543 seconds (13 readdir()s, 13 rename()s to cur/, why=0x10)

Jul 26 12:49:11 popserver dovecot: imap-login: Login: user=kavish.karkera@example.com, method=PLAIN, rip=1.38.25.83, lip=121.241.242.35, mpid=26747, TLS, session=<tqCL9WTiOgABJhlT>

Jul 26 12:52:53 popserver dovecot: imap(kavish.karkera@example.com): Error: Timeout (180s) while waiting for lock for transaction log file /indexes//mail/v3store/example.com/kavish.karkera@example.com/.INBOX/dovecot.index.log

ul 26 12:52:53 popserver dovecot: imap(kavish.karkera@example.com): Warning: Our dotlock file /indexes//mail/v3store/example.com/kavish.karkera@example.com/.INBOX/dovecot-uidlist.lock was modified (1374823189 vs 1374823271), assuming it wasn't overridden (kept it 180 secs)

Jul 26 12:52:53 popserver dovecot: imap(kavish.karkera@example.com): Connection closed bytes=122/1341

Jul 26 12:52:58 popserver dovecot: imap(kavish.karkera@example.com): Warning: Maildir: Scanning /mail/v3store/example.com/kavish.karkera@example.com/Maildir/new took 425 seconds (14 readdir()s, 14 rename()s to cur/, why=0x10)

Jul 26 12:53:18 popserver dovecot: imap(kavish.karkera@example.com): Warning: Maildir /mail/v3store/example.com/kavish.karkera@example.com/Maildir: Synchronization took 1988 seconds (0 new msgs, 0 flag change attempts, 0 expunge attempts)

Jul 26 12:53:18 popserver dovecot: imap(kavish.karkera@example.com): Warning: Transaction log file /indexes//mail/v3store/example.com/kavish.karkera@example.com/.INBOX/dovecot.index.log was locked for 1988 seconds

Jul 26 12:53:18 popserver dovecot: imap(kavish.karkera@example.com): Warning: Our dotlock file /indexes//mail/v3store/example.com/kavish.karkera@example.com/.INBOX/dovecot-uidlist.lock was modified (1374821406 vs 1374823373), assuming it wasn't overridden (kept it 1988 secs)

AND MAILS HAVE DOWNLOADED AGAIN. 

it wouls be helpfull if you eloborate thsi logs in more detail. so we coluld resolve this ongoing issue.

We have 3 POP/IMAP Servers, running as load balancers through DNS round robin.

Dovecot version server 1 = 2.1.12 Dovecot version server 2 = 2.1.15 Dovecot version server 3 = 2.1.13

Mails and Indexes are stored over NFS  and we do have these setting enabled

mail_nfs_storage = yes # Mail index files also exist in NFS. Setting this to yes requires # mmap_disable=yes and fsync_disable=no. mail_nfs_index = yes

Regards, Kavish Karkera

From: Kavish Karkera kavish.karkera@yahoo.com To: "dovecot@dovecot.org" dovecot@dovecot.org Sent: Thursday, 25 July 2013 9:18 PM Subject: Re: [Dovecot] Duplicate Mails downloding issue

Got it ...Thanks a ton Steffen. :)

Regards, Kavish Karkera

From: Steffen Kaiser skdovecot@smail.inf.fh-brs.de To: Kavish Karkera kavish.karkera@yahoo.com Cc: "dovecot@dovecot.org" dovecot@dovecot.org Sent: Thursday, 25 July 2013 8:03 PM Subject: Re: [Dovecot] Duplicate Mails downloding issue

-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1

On Thu, 25 Jul 2013, Kavish Karkera wrote:

Thanks Steffen for the valuable knowledge. Need to know futher that, how could this lead to mails to get re-downloaded. ??

Because Dovecot detects that the UID list is erroreous and therefore rebuilts it. To prevent data loss, either the complete list of messages or just the conflicting ones [the messages that had been delivered in parallel and caused the while problem] do appear as new to the clients.

From: Steffen Kaiser skdovecot@smail.inf.fh-brs.de To: Kavish Karkera kavish.karkera@yahoo.com Cc: "dovecot@dovecot.org" dovecot@dovecot.org Sent: Thursday, 25 July 2013 5:54 PM Subject: Re: [Dovecot] Duplicate Mails downloding issue

-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1

On Thu, 25 Jul 2013, Kavish Karkera wrote:

...

...

Jul 23 15:34:51 popserver dovecot: pop3(14949_kavish): Warning: Locking transaction log file /indexes//mail/v3store/example.com/14949_kavish/.INBOX/dovecot.index.log took 133 seconds

some process keeps the INBOX locked, but does not touch the file, so it looks like a stale lock.

...

Jul 23 15:34:51 popserver dovecot: pop3(kavish@example.com): Error: Broken file /indexes//mail/v3store/example.com/14949_kavish/.INBOX/dovecot-uidlist line 180: UIDs not ordered (10156 >= 10156)

Therefore some other process had broken the lock and had appended a message.

...

Jul 23 15:35:01 popserver dovecot: pop3(kavish@example.com): Error: utime(/indexes//mail/v3store/example.com/kavish/.INBOX/dovecot-uidlist.lock) failed: No such file or directory

Jul 23 15:35:11 popserver dovecot: pop3(kavish@example.com): Error: utime(/indexes//mail/v3store/example.com/kavish/.INBOX/dovecot-uidlist.lock) failed: No such file or directory

then the former process(es) finish and try to clean up, but the "some other process" already deleted the lock file.

...

Jul 23 15:35:21 popserver dovecot: pop3(kavish@example.com): Warning: Our dotlock file /indexes//mail/v3store/example.com/kavish/.INBOX/dovecot-uidlist.lock was deleted (kept it 30 secs)

So you have to check your system why a process, that as locked INBOX, is stalled for more than 120min.

---

Steffen Kaiser -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.11 (GNU/Linux)

iQEVAwUBUfEY6F3r2wJMiz2NAQICHwf9HJG66UAHGJp1nT8Ql31n1Bk1KWb+wAhA p2nReYZVSbzZOJM84Dkw8xLu3WoHzFxFEIS+CJc7xGtaeWGrwrTik6d7LKjwI9gf HCun1rq9VzfS85sHvn1owVJxMnUrA3YcY90aQZ6SWHNwvrdmmqqIPhQdGx7xc3En N1jJ0wPEd9hbJyi+2MScZt0WxKuRR+Wpkl14gO6ZPcX95uONGzLcSTs071rAXT+c 6RWLxn2jhruk4qUIm+PGnHkwXTnKL2Dqfladj4/ybxTRn2hgNldK8w4piUwwPWIn HW/hN+sDM/hlRtyu0zHVfiFC7MES6s0JonzwDlOKAFt9dUUG4Mcr9Q== =mar+ -----END PGP SIGNATURE-----

Steffen Kaiser -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.11 (GNU/Linux)

iQEVAwUBUfE3PV3r2wJMiz2NAQKdzAf9HY90QTSszIhaz7pMHYbQBMMU4XEiNBFU 3beZQLuZpYrw1aKr8xJB87DWcfyeULRgiEdWs6uSWgpYnmXYSBjDWV16HYW6+pY8 LTWr1tSY6AzUOxypx8GZfwQFhAmntwfFpoi/JiU8tDnEx2e1W44+V9hzDS4Kfy9i MQDDHRCOZL0cArAQ1DleXrQGnKY/Haa3clBfR72E/UdnGWzuGYxpORbHe9VUK8IP XrNUX1vV6RuS/cxg0/kLoVHk+0YAJCOk9kT2r2t9ZRSxSFHdzm8L/nTnQAgB+ZCR H9lNQxzi6UsRV8hT5mazMmIctW4BQsrJELV/5iWNoMDNxrYVH3Cqlg== =i01T -----END PGP SIGNATURE-----

Yes, Thanks Charles,

Working with Director is in process, we will soon implement this, I hope it would help to solve this ongoing  issue.

But, i want to  know the cause . why is it happening

Regards, Kavish Karkera

From: Charles Marcus CMarcus@Media-Brokers.com To: dovecot@dovecot.org Sent: Friday, 26 July 2013 6:38 PM Subject: Re: [Dovecot] Duplicate Mails downloding issue

On 2013-07-26 8:28 AM, Kavish Karkera kavish.karkera@yahoo.com wrote:

We have 3 POP/IMAP Servers, running as load balancers through DNS round robin.

Dovecot version server 1 = 2.1.12 Dovecot version server 2 = 2.1.15 Dovecot version server 3 = 2.1.13

Mails and Indexes are stored over NFS  and we do have these setting enabled

mail_nfs_storage = yes # Mail index files also exist in NFS. Setting this to yes requires # mmap_disable=yes and fsync_disable=no. mail_nfs_index = yes

There';s your problem.

You need to implement the Dovecot Director, which was created specifically to address this kind of issue...

http://wiki2.dovecot.org/Director

--

Best regards,

Charles

-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1

On Fri, 26 Jul 2013, Kavish Karkera wrote:

Jul 26 12:25:37 popserver dovecot: pop3(kavish.karkera@example.com): Error: Couldn't open INBOX: Timeout while waiting for lock Jul 26 12:42:12 popserver dovecot: imap(kavish.karkera@example.com): Error: Timeout (180s) while waiting for lock for transaction log file /indexes//mail/v3store/example.com/kavish.karkera@example.com/.INBOX/dovecot.index.log

it wouls be helpfull if you eloborate thsi logs in more detail. so we coluld resolve this ongoing issue.

We have 3 POP/IMAP Servers, running as load balancers through DNS round robin.

Dovecot version server 1 = 2.1.12 Dovecot version server 2 = 2.1.15 Dovecot version server 3 = 2.1.13

Mails and Indexes are stored over NFS  and we do have these setting enabled

mail_nfs_storage = yes # Mail index files also exist in NFS. Setting this to yes requires # mmap_disable=yes and fsync_disable=no. mail_nfs_index = yes

you have three servers, into which the same user logs in simultaneously, but they share the same storage area.

Say, kavish.karkera@example.com logs into server2 with IMAP and keeps the mailbox locked, because it IDLEs there. Now kavish.karkera@example.com logs into server1 and wants to access INBOX a second time in parallel to server2, which has the lock still. Because both servers do not communicating with each other, server2 do not give up the lock, in order to let server1 proceed.

If kavish.karkera@example.com would only log into server2 (or server1, it does not matter which server, as long as kavish.karkera@example.com do not log into two servers the same time), Dovecot would handle it. But because you use DNS round robin as load balancer, you cannot ensure this.

Steffen Kaiser -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.11 (GNU/Linux)

iQEVAwUBUfJ/m13r2wJMiz2NAQIWzAf7Bjyx8WarthCZLeSmLb1qGOxCrqmtzlmU qrq2b3+ccpo3/0H5czgfRhX4+bedzV+M0DPH9KzyOtwD7AZrQ8EdarrmG2g8vzZZ GP5vw+6NTZS/PCR+kj2wGgcF0qyPgyrcGp3cmUbCENwujAFwHXo2N+NRrqqEXuR1 l7zVVR7vWp3afQRtNBgyxeFeWI+Zd/MNKuEv6PoqQvfWu4y0KXl03aiImbrAx3eR ZKvpN26rQvRE0P5AIyoGy2n6xuh7V+itZf1UlydONVEE4nC1LFvM6eD9n3bPp3Dc JQmNvefv0OUVaNWxBSpafSN4uk4whZ+zwDNOyzhnDTO09Rdw+4rotw== =vHAq -----END PGP SIGNATURE-----