Steffen , Cant understand what's happening here.
------------------------------------------------------------------------------------------------------------------------------------------------------- Jul 26 12:25:37 popserver dovecot: pop3(kavish.kark...@example.com): Error: Couldn't open INBOX: Timeout while waiting for lock Jul 26 12:25:37 popserver dovecot: pop3(kavish.kark...@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.kark...@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.kark...@example.com): Error: Timeout (180s) while waiting for lock for transaction log file /indexes//mail/v3store/example.com/kavish.kark...@example.com/.INBOX/dovecot.index.log Jul 26 12:42:12 popserver dovecot: imap(kavish.kark...@example.com): Warning: Our dotlock file /indexes//mail/v3store/example.com/kavish.kark...@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.kark...@example.com): Connection closed bytes=122/1222 Jul 26 12:45:53 popserver dovecot: imap(kavish.kark...@example.com): Warning: Maildir: Scanning /mail/v3store/example.com/kavish.kark...@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.kark...@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.kark...@example.com): Error: Timeout (180s) while waiting for lock for transaction log file /indexes//mail/v3store/example.com/kavish.kark...@example.com/.INBOX/dovecot.index.log ul 26 12:52:53 popserver dovecot: imap(kavish.kark...@example.com): Warning: Our dotlock file /indexes//mail/v3store/example.com/kavish.kark...@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.kark...@example.com): Connection closed bytes=122/1341 Jul 26 12:52:58 popserver dovecot: imap(kavish.kark...@example.com): Warning: Maildir: Scanning /mail/v3store/example.com/kavish.kark...@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.kark...@example.com): Warning: Maildir /mail/v3store/example.com/kavish.kark...@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.kark...@example.com): Warning: Transaction log file /indexes//mail/v3store/example.com/kavish.kark...@example.com/.INBOX/dovecot.index.log was locked for 1988 seconds Jul 26 12:53:18 popserver dovecot: imap(kavish.kark...@example.com): Warning: Our dotlock file /indexes//mail/v3store/example.com/kavish.kark...@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.kark...@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 <skdove...@smail.inf.fh-brs.de> To: Kavish Karkera <kavish.kark...@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 <skdove...@smail.inf.fh-brs.de> > To: Kavish Karkera <kavish.kark...@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(kav...@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(kav...@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(kav...@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(kav...@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-----
