[Dovecot] dovecot-uidlist: Duplicate file entry at line
Hi All, we are experiencing another strange problem after upgrading to 2.0.1 from 1.2.
Many people's client aree-retrieving mail from server due to some problem with dovecot-uidlist file. Looking at log file seem that all file content is sometime duplicated and appended to the and of same file. It look as another process was accesing and trying to modify uidlist table. Our setup has a load balance (dovecot director) and three backend server. All of them use 2.0.1. MTA is a cluster of postfix that deliver mail to load balancer by LMTP.
How can I collect some more information? or, better, solve it?
Regards
Luca
PS: Backend configuration is: # 2.0.1: /etc/dovecot/dovecot.conf # OS: Linux 2.6.26-2-686-bigmem i686 Debian 5.0.5 auth_master_user_separator = * auth_verbose = yes disable_plaintext_auth = no mail_location = maildir:~/Maildir mail_plugins = $mail_plugins notify mail_log quota managesieve_notify_capability = mailto managesieve_sieve_capability = comparator-i;octet comparator-i;ascii-casemap fileinto reject envelope encoded-character vacation subaddress comparator-i;ascii-numeric relational regex imap4flags copy include variables body enotify environment mailbox date spamtest spamtestplus virustest passdb { args = /etc/dovecot/dovecot-sql.conf.ext driver = sql } plugin { mail_log_events = delete undelete expunge copy mailbox_delete mailbox_rename mail_log_fields = uid box msgid from size quota = maildir:User quota quota_warning = storage=95%% quota-warning.sh 95 %u quota_warning2 = storage=80%% quota-warning.sh 80 %u sieve = ~/.dovecot.sieve sieve_dir = ~/sieve sieve_global_dir = /etc/dovecot/sieve/global/ sieve_global_path = /etc/dovecot/sieve/default.sieve } protocols = imap pop3 lmtp sieve service auth { unix_listener auth-userdb { group = dovecot mode = 0600 user = dovecot } } service director { inet_listener { port = 8100 } } service lmtp { inet_listener lmtp { address = 10.194.1.31 127.0.0.1 ::1 port = 24 } } service managesieve-login { inet_listener sieve { address = 10.194.1.31 127.0.0.1 ::1 port = 4190 } process_min_avail = 0 service_count = 1 } service quota-warning { executable = script /virtual/shared/quota-warning.sh unix_listener quota-warning { user = vmail } user = dovecot } ssl_cert = </etc/ssl/certs/dovecot.pem ssl_key = </etc/ssl/private/dovecot.pem userdb { args = /etc/dovecot/dovecot-sql.conf.ext driver = sql } verbose_proctitle = yes protocol lmtp { mail_plugins = $mail_plugins quota sieve } protocol lda { mail_plugins = $mail_plugins quota } protocol imap { mail_plugins = $mail_plugins quota imap_quota } protocol pop3 { mail_plugins = $mail_plugins quota }
On Thu, 2010-09-02 at 19:21 +0200, Luca Palazzo wrote:
Hi All, we are experiencing another strange problem after upgrading to 2.0.1 from 1.2.
Many people's client aree-retrieving mail from server due to some problem with dovecot-uidlist file. Looking at log file seem that all file content is sometime duplicated and appended to the and of same file. It look as another process was accesing and trying to modify uidlist table.
I've heard of some dovecot-uidlist problems, but haven't really figured out anything that could be wrong.. I guess there's no way you can reproduce this? Does happen to same user more than once? How many users is "many"? Does this happen only/mainly to some specific mailboxes (INBOX, Trash)? Does this happen to more than one same user's mailbox at the same time? Does this happen to different users around the same time?
Our setup has a load balance (dovecot director) and three backend server. All of them use 2.0.1.
How did you do it before v2.0?
The maildir code hasn't changed much since v1.2. Hmm. Except that maildir filenames are now tried to be preserved when copying, so copying messages elsewhere and back does sound like it could cause this (although there is code to prevent it)..
Il giorno 03/set/2010, alle ore 16.44, Timo Sirainen ha scritto:
On Thu, 2010-09-02 at 19:21 +0200, Luca Palazzo wrote:
Hi All, we are experiencing another strange problem after upgrading to 2.0.1 from 1.2.
Many people's client aree-retrieving mail from server due to some problem with dovecot-uidlist file. Looking at log file seem that all file content is sometime duplicated and appended to the and of same file. It look as another process was accesing and trying to modify uidlist table.
I've heard of some dovecot-uidlist problems, but haven't really figured out anything that could be wrong.. I guess there's no way you can reproduce this? Does happen to same user more than once? How many users is "many"? Does this happen only/mainly to some specific mailboxes (INBOX, Trash)? Does this happen to more than one same user's mailbox at the same time? Does this happen to different users around the same time?
I have the same problem, since migration to 2.0. Mainly it happens on INBOX (well, I’ve only seen this happen on INBOX), but I did not found a way to reproduce it. It happened to the same user more than once. I have 15 users. Only one mailbox a time, well, as I said before it happens only on INBOX and yes, more than one user per time.
Our setup has a load balance (dovecot director) and three backend server. All of them use 2.0.1.
How did you do it before v2.0?
I have no load balance, no director.
The maildir code hasn't changed much since v1.2. Hmm. Except that maildir filenames are now tried to be preserved when copying, so copying messages elsewhere and back does sound like it could cause this (although there is code to prevent it)..
TIA Andrea Mistrali
On Fri, 2010-09-03 at 16:51 +0200, Andre wrote:
I've heard of some dovecot-uidlist problems, but haven't really figured out anything that could be wrong.. I guess there's no way you can reproduce this? Does happen to same user more than once? How many users is "many"? Does this happen only/mainly to some specific mailboxes (INBOX, Trash)? Does this happen to more than one same user's mailbox at the same time? Does this happen to different users around the same time?
I have the same problem, since migration to 2.0. Mainly it happens on INBOX (well, I’ve only seen this happen on INBOX), but I did not found a way to reproduce it. It happened to the same user more than once. I have 15 users.
Any idea if those users copy messages around? Or undelete from Trash?
Only one mailbox a time, well, as I said before it happens only on INBOX and yes, more than one user per time.
I mean does it happen to multiple users "at once", like within same second (or close to it)?
Il giorno 03/set/2010, alle ore 16.55, Timo Sirainen ha scritto:
On Fri, 2010-09-03 at 16:51 +0200, Andre wrote:
I've heard of some dovecot-uidlist problems, but haven't really figured out anything that could be wrong.. I guess there's no way you can reproduce this? Does happen to same user more than once? How many users is "many"? Does this happen only/mainly to some specific mailboxes (INBOX, Trash)? Does this happen to more than one same user's mailbox at the same time? Does this happen to different users around the same time?
I have the same problem, since migration to 2.0. Mainly it happens on INBOX (well, I’ve only seen this happen on INBOX), but I did not found a way to reproduce it. It happened to the same user more than once. I have 15 users.
Any idea if those users copy messages around? Or undelete from Trash?
No, they don’t
Only one mailbox a time, well, as I said before it happens only on INBOX and yes, more than one user per time.
I mean does it happen to multiple users "at once", like within same second (or close to it)?
No, it does not.
TIA A.
On Fri, 2010-09-03 at 15:44 +0100, Timo Sirainen wrote:
The maildir code hasn't changed much since v1.2. Hmm. Except that maildir filenames are now tried to be preserved when copying, so copying messages elsewhere and back does sound like it could cause this (although there is code to prevent it)..
You could try with attached patch to disable this feature and see if it helps.. dsync mirroring will break with it though.
On Fri, 2010-09-03 at 15:57 +0100, Timo Sirainen wrote:
On Fri, 2010-09-03 at 15:44 +0100, Timo Sirainen wrote:
The maildir code hasn't changed much since v1.2. Hmm. Except that maildir filenames are now tried to be preserved when copying, so copying messages elsewhere and back does sound like it could cause this (although there is code to prevent it)..
You could try with attached patch to disable this feature and see if it helps.. dsync mirroring will break with it though.
Whops, that patch wasn't enough. This one is. :)
Il giorno 03/set/2010, alle ore 16.59, Timo Sirainen ha scritto:
On Fri, 2010-09-03 at 15:57 +0100, Timo Sirainen wrote:
On Fri, 2010-09-03 at 15:44 +0100, Timo Sirainen wrote:
The maildir code hasn't changed much since v1.2. Hmm. Except that maildir filenames are now tried to be preserved when copying, so copying messages elsewhere and back does sound like it could cause this (although there is code to prevent it)..
You could try with attached patch to disable this feature and see if it helps.. dsync mirroring will break with it though.
Whops, that patch wasn't enough. This one is. :) <diff> Applied, I’ll make you know if there are other problems.
A.
Hi Timo, I tried the patch and duplicate uid are always there.
Look at this: Sep 6 10:51:30 10.97.1.33 dovecot: lmtp(29909, xxxxxx@unict.it): save: box=INBOX, uid=133197, msgid=<20100906104944.Q92185@>, size=7414, from= Sep 6 10:51:30 10.97.1.33 dovecot: lmtp(29909, xxxxxx@unict.it): T8gcJIyphEzVdAAA27qniQ: msgid=<20100906104944.Q92185@pongo.fi.infn.it>: saved mail to INBOX Sep 6 10:51:31 10.97.1.33 dovecot: imap(xxxxxx@unict.it): Warning: /virtual1/unict.it/g/xxxxxx//Maildir/dovecot-uidlist: Duplicate file entry at line 883: 1277948239.M332097P873 3.mailcl-mbox1,S=7903,W=8024:2,S (uid 132318 -> 133198) Sep 6 10:51:31 10.97.1.33 dovecot: imap(xxxxxx@unict.it): Warning: /virtual1/unict.it/g/xxxxxx//Maildir/dovecot-uidlist: Duplicate file entry at line 884: 1277952980.M167558P112 43.mailcl-mbox1,S=11228,W=11393:2,S (uid 132319 -> 133199) Sep 6 10:51:31 10.97.1.33 dovecot: imap(xxxxxx@unict.it): Warning: /virtual1/unict.it/g/xxxxxx//Maildir/dovecot-uidlist: Duplicate file entry at line 885: 1277966013.M655255P280 93.mailcl-mbox1,S=23709,W=24249:2,S (uid 132320 -> 133200) Sep 6 10:51:31 10.97.1.33 dovecot: imap(xxxxxx@unict.it): Warning: /virtual1/unict.it/g/xxxxxx//Maildir/dovecot-uidlist: Duplicate file entry at line 886: 1277969233.M852614P116 56.mailcl-mbox1,S=4496,W=4604:2,S (uid 132321 -> 133201) Sep 6 10:51:31 10.97.1.33 dovecot: imap(xxxxxx@unict.it): Warning: /virtual1/unict.it/g/xxxxxx//Maildir/dovecot-uidlist: Duplicate file entry at line 887: 1277970140.M285747P169 43.mailcl-mbox1,S=7601,W=7845:2,RS (uid 132322 -> 133202)
It seems that LMTP process duplicate UID or something related to it. But, duplicate occurs sometime during LMTP delivery and sometime after LMTP delivery with IMAP or POP3.
I hope this helps.
Luca On 09/03/2010 04:59 PM, Timo Sirainen wrote:
On Fri, 2010-09-03 at 15:57 +0100, Timo Sirainen wrote:
On Fri, 2010-09-03 at 15:44 +0100, Timo Sirainen wrote:
The maildir code hasn't changed much since v1.2. Hmm. Except that maildir filenames are now tried to be preserved when copying, so copying messages elsewhere and back does sound like it could cause this (although there is code to prevent it)..
You could try with attached patch to disable this feature and see if it helps.. dsync mirroring will break with it though.
Whops, that patch wasn't enough. This one is. :)
Il giorno 06/set/2010, alle ore 11.11, Luca Palazzo ha scritto:
Hi Timo, I tried the patch and duplicate uid are always there.
Look at this: Sep 6 10:51:30 10.97.1.33 dovecot: lmtp(29909, xxxxxx@unict.it): save: box=INBOX, uid=133197, msgid=<20100906104944.Q92185@>, size=7414, from= Sep 6 10:51:30 10.97.1.33 dovecot: lmtp(29909, xxxxxx@unict.it): T8gcJIyphEzVdAAA27qniQ: msgid=<20100906104944.Q92185@pongo.fi.infn.it>: saved mail to INBOX Sep 6 10:51:31 10.97.1.33 dovecot: imap(xxxxxx@unict.it): Warning: /virtual1/unict.it/g/xxxxxx//Maildir/dovecot-uidlist: Duplicate file entry at line 883: 1277948239.M332097P873 3.mailcl-mbox1,S=7903,W=8024:2,S (uid 132318 -> 133198) Sep 6 10:51:31 10.97.1.33 dovecot: imap(xxxxxx@unict.it): Warning: /virtual1/unict.it/g/xxxxxx//Maildir/dovecot-uidlist: Duplicate file entry at line 884: 1277952980.M167558P112 43.mailcl-mbox1,S=11228,W=11393:2,S (uid 132319 -> 133199) Sep 6 10:51:31 10.97.1.33 dovecot: imap(xxxxxx@unict.it): Warning: /virtual1/unict.it/g/xxxxxx//Maildir/dovecot-uidlist: Duplicate file entry at line 885: 1277966013.M655255P280 93.mailcl-mbox1,S=23709,W=24249:2,S (uid 132320 -> 133200) Sep 6 10:51:31 10.97.1.33 dovecot: imap(xxxxxx@unict.it): Warning: /virtual1/unict.it/g/xxxxxx//Maildir/dovecot-uidlist: Duplicate file entry at line 886: 1277969233.M852614P116 56.mailcl-mbox1,S=4496,W=4604:2,S (uid 132321 -> 133201) Sep 6 10:51:31 10.97.1.33 dovecot: imap(xxxxxx@unict.it): Warning: /virtual1/unict.it/g/xxxxxx//Maildir/dovecot-uidlist: Duplicate file entry at line 887: 1277970140.M285747P169 43.mailcl-mbox1,S=7601,W=7845:2,RS (uid 132322 -> 133202)
It seems that LMTP process duplicate UID or something related to it. But, duplicate occurs sometime during LMTP delivery and sometime after LMTP delivery with IMAP or POP3.
I hope this helps.
Luca Instead for me seems to have fixed the problem (2.0.1) Andre
On Mon, 2010-09-06 at 11:11 +0200, Luca Palazzo wrote:
Sep 6 10:51:31 10.97.1.33 dovecot: imap(xxxxxx@unict.it): Warning: /virtual1/unict.it/g/xxxxxx//Maildir/dovecot-uidlist: Duplicate file entry at line 883: 1277948239.M332097P873
Hmmh. See if http://hg.dovecot.org/dovecot-2.0/rev/e2a267b64619 changes the behavior?
Hi Timo and All, please take care of this trace. It seems that dovecot.uidlist's increase its size (8056 from stat and from read and then 14641 with stat) while delivering and then it tries to look for duplicates.
I hope this helps, duplicates problem is becoming big. Can I check or trace something else?
Luca
open("/virtual1/unict.it/a/account//Maildir/dovecot-uidlist", O_RDWR|O_LARGEFILE) = 17 _llseek(17, 0, [0], SEEK_SET) = 0 fstat64(17, {st_mode=S_IFREG|0644, st_size=8056, ...}) = 0 fstat64(17, {st_mode=S_IFREG|0644, st_size=8056, ...}) = 0 pread64(17, "3 V1264536006 N2107 Gc56f442c6771"..., 4096, 0) = 4096 pread64(17, "8340P4605.mailcl-mbox1,S=19935,W="..., 4076, 4096) = 3960 pread64(17, ""..., 116, 8056) = 0 time(NULL) = 1283846418 umask(0133) = 077 time(NULL) = 1283846418 lstat64("/virtual1/unict.it/a/account//Maildir/dovecot-uidlist.lock", 0xbfd07bcc) = -1 ENOENT (No such file or directory) umask(0666) = 0133 lstat64("/virtual1/unict.it/a/account//Maildir/temp.mailcl-mbox2.31697.74d7957105ba8895", 0xbfd07bc4) = -1 ENOENT (No such file or directory) umask(0133) = 0666 open("/virtual1/unict.it/a/account//Maildir/temp.mailcl-mbox2.31697.74d7957105ba8895", O_RDWR|O_CREAT|O_EXCL|O_LARGEFILE, 0666) = 20 umask(0666) = 0133 umask(0133) = 0666 write(20, "31697:mailcl-mbox2"..., 18) = 18 link("/virtual1/unict.it/a/account//Maildir/temp.mailcl-mbox2.31697.74d7957105ba8895", "/virtual1/unict.it/a/account//Maildir/dovecot-uidlist.lock") = 0 unlink("/virtual1/unict.it/a/account//Maildir/temp.mailcl-mbox2.31697.74d7957105ba8895") = 0 fstat64(20, {st_mode=S_IFREG|0644, st_size=18, ...}) = 0 close(20) = 0 lstat64("/virtual1/unict.it/a/account//Maildir/dovecot-uidlist.lock", {st_mode=S_IFREG|0644, st_size=18, ...}) = 0 umask(077) = 0133 stat64("/virtual1/unict.it/a/account//Maildir/dovecot-uidlist", {st_mode=S_IFREG|0644, st_size=8056, ...}) = 0 _llseek(17, 0, [0], SEEK_SET) = 0 fstat64(17, {st_mode=S_IFREG|0644, st_size=8056, ...}) = 0 fstat64(17, {st_mode=S_IFREG|0644, st_size=8056, ...}) = 0 pread64(17, ""..., 4096, 8056) = 0 alarm(180) = 0 fcntl64(15, F_SETLKW64, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0}, 0xbfd07c64) = 0 alarm(0) = 180 stat64("/virtual1/unict.it/a/account//Maildir/dovecot.index.log", {st_mode=S_IFREG|0644, st_size=2836, ...}) = 0 fstat64(15, {st_mode=S_IFREG|0644, st_size=2836, ...}) = 0 open("/virtual1/unict.it/a/account//Maildir/new", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|O_CLOEXEC) = 20 fstat64(20, {st_mode=S_IFDIR|0700, st_size=1848, ...}) = 0 fstat64(20, {st_mode=S_IFDIR|0700, st_size=1848, ...}) = 0 time(NULL) = 1283846418 getdents64(20, /* 3 entries */, 4096) = 120 getdents64(20, /* 0 entries */, 4096) = 0 close(20) = 0 open("/virtual1/unict.it/a/account//Maildir/cur", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|O_CLOEXEC) = 20 fstat64(20, {st_mode=S_IFDIR|0700, st_size=10240, ...}) = 0 fstat64(20, {st_mode=S_IFDIR|0700, st_size=10240, ...}) = 0 time(NULL) = 1283846418 getdents64(20, /* 29 entries */, 4096) = 2200 getdents64(20, /* 27 entries */, 4096) = 2160 getdents64(20, /* 24 entries */, 4096) = 1912 getdents64(20, /* 21 entries */, 4096) = 1680 getdents64(20, /* 6 entries */, 4096) = 480 getdents64(20, /* 0 entries */, 4096) = 0 close(20) = 0 _llseek(17, 0, [8056], SEEK_END) = 0 _llseek(17, 0, [8056], SEEK_CUR) = 0 fstat64(17, {st_mode=S_IFREG|0644, st_size=8056, ...}) = 0 write(17, "2145 :1268504260.V811I106f6056M46"..., 6585) = 6585 fdatasync(17) = 0 fstat64(17, {st_mode=S_IFREG|0644, st_size=14641, ...}) = 0 time(NULL) = 1283846418 stat64("/virtual1/unict.it/a/account//Maildir/dovecot-uidlist", {st_mode=S_IFREG|0644, st_size=14641, ...}) = 0 _llseek(17, 0, [0], SEEK_SET) = 0 fstat64(17, {st_mode=S_IFREG|0644, st_size=14641, ...}) = 0 fstat64(17, {st_mode=S_IFREG|0644, st_size=14641, ...}) = 0 pread64(17, ""..., 4096, 14641) = 0 stat64("/virtual1/unict.it/a/account//Maildir/dovecot-uidlist", {st_mode=S_IFREG|0644, st_size=14641, ...}) = 0 _llseek(17, 0, [0], SEEK_SET) = 0 fstat64(17, {st_mode=S_IFREG|0644, st_size=14641, ...}) = 0 fstat64(17, {st_mode=S_IFREG|0644, st_size=14641, ...}) = 0 pread64(17, ""..., 4096, 14641) = 0
On 09/06/2010 04:42 PM, Timo Sirainen wrote:
On Mon, 2010-09-06 at 11:11 +0200, Luca Palazzo wrote:
Sep 6 10:51:31 10.97.1.33 dovecot: imap(xxxxxx@unict.it): Warning: /virtual1/unict.it/g/xxxxxx//Maildir/dovecot-uidlist: Duplicate file entry at line 883: 1277948239.M332097P873
Hmmh. See if http://hg.dovecot.org/dovecot-2.0/rev/e2a267b64619 changes the behavior?
Il giorno 07/set/2010, alle ore 10.19, Luca Palazzo ha scritto:
Hi Timo and All, please take care of this trace. It seems that dovecot.uidlist's increase its size (8056 from stat and from read and then 14641 with stat) while delivering and then it tries to look for duplicates.
I hope this helps, duplicates problem is becoming big. Can I check or trace something else?
Luca
open("/virtual1/unict.it/a/account//Maildir/dovecot-uidlist", O_RDWR|O_LARGEFILE) = 17 _llseek(17, 0, [0], SEEK_SET) = 0 fstat64(17, {st_mode=S_IFREG|0644, st_size=8056, ...}) = 0 fstat64(17, {st_mode=S_IFREG|0644, st_size=8056, ...}) = 0 pread64(17, "3 V1264536006 N2107 Gc56f442c6771"..., 4096, 0) = 4096 pread64(17, "8340P4605.mailcl-mbox1,S=19935,W="..., 4076, 4096) = 3960 pread64(17, ""..., 116, 8056) = 0 time(NULL) = 1283846418 umask(0133) = 077 time(NULL) = 1283846418 lstat64("/virtual1/unict.it/a/account//Maildir/dovecot-uidlist.lock", 0xbfd07bcc) = -1 ENOENT (No such file or directory) umask(0666) = 0133 lstat64("/virtual1/unict.it/a/account//Maildir/temp.mailcl-mbox2.31697.74d7957105ba8895", 0xbfd07bc4) = -1 ENOENT (No such file or directory) umask(0133) = 0666 open("/virtual1/unict.it/a/account//Maildir/temp.mailcl-mbox2.31697.74d7957105ba8895", O_RDWR|O_CREAT|O_EXCL|O_LARGEFILE, 0666) = 20 umask(0666) = 0133 umask(0133) = 0666 write(20, "31697:mailcl-mbox2"..., 18) = 18 link("/virtual1/unict.it/a/account//Maildir/temp.mailcl-mbox2.31697.74d7957105ba8895", "/virtual1/unict.it/a/account//Maildir/dovecot-uidlist.lock") = 0 unlink("/virtual1/unict.it/a/account//Maildir/temp.mailcl-mbox2.31697.74d7957105ba8895") = 0 fstat64(20, {st_mode=S_IFREG|0644, st_size=18, ...}) = 0 close(20) = 0 lstat64("/virtual1/unict.it/a/account//Maildir/dovecot-uidlist.lock", {st_mode=S_IFREG|0644, st_size=18, ...}) = 0 umask(077) = 0133 stat64("/virtual1/unict.it/a/account//Maildir/dovecot-uidlist", {st_mode=S_IFREG|0644, st_size=8056, ...}) = 0 _llseek(17, 0, [0], SEEK_SET) = 0 fstat64(17, {st_mode=S_IFREG|0644, st_size=8056, ...}) = 0 fstat64(17, {st_mode=S_IFREG|0644, st_size=8056, ...}) = 0 pread64(17, ""..., 4096, 8056) = 0 alarm(180) = 0 fcntl64(15, F_SETLKW64, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0}, 0xbfd07c64) = 0 alarm(0) = 180 stat64("/virtual1/unict.it/a/account//Maildir/dovecot.index.log", {st_mode=S_IFREG|0644, st_size=2836, ...}) = 0 fstat64(15, {st_mode=S_IFREG|0644, st_size=2836, ...}) = 0 open("/virtual1/unict.it/a/account//Maildir/new", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|O_CLOEXEC) = 20 fstat64(20, {st_mode=S_IFDIR|0700, st_size=1848, ...}) = 0 fstat64(20, {st_mode=S_IFDIR|0700, st_size=1848, ...}) = 0 time(NULL) = 1283846418 getdents64(20, /* 3 entries */, 4096) = 120 getdents64(20, /* 0 entries */, 4096) = 0 close(20) = 0 open("/virtual1/unict.it/a/account//Maildir/cur", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|O_CLOEXEC) = 20 fstat64(20, {st_mode=S_IFDIR|0700, st_size=10240, ...}) = 0 fstat64(20, {st_mode=S_IFDIR|0700, st_size=10240, ...}) = 0 time(NULL) = 1283846418 getdents64(20, /* 29 entries */, 4096) = 2200 getdents64(20, /* 27 entries */, 4096) = 2160 getdents64(20, /* 24 entries */, 4096) = 1912 getdents64(20, /* 21 entries */, 4096) = 1680 getdents64(20, /* 6 entries */, 4096) = 480 getdents64(20, /* 0 entries */, 4096) = 0 close(20) = 0 _llseek(17, 0, [8056], SEEK_END) = 0 _llseek(17, 0, [8056], SEEK_CUR) = 0 fstat64(17, {st_mode=S_IFREG|0644, st_size=8056, ...}) = 0 write(17, "2145 :1268504260.V811I106f6056M46"..., 6585) = 6585 fdatasync(17) = 0 fstat64(17, {st_mode=S_IFREG|0644, st_size=14641, ...}) = 0 time(NULL) = 1283846418 stat64("/virtual1/unict.it/a/account//Maildir/dovecot-uidlist", {st_mode=S_IFREG|0644, st_size=14641, ...}) = 0 _llseek(17, 0, [0], SEEK_SET) = 0 fstat64(17, {st_mode=S_IFREG|0644, st_size=14641, ...}) = 0 fstat64(17, {st_mode=S_IFREG|0644, st_size=14641, ...}) = 0 pread64(17, ""..., 4096, 14641) = 0 stat64("/virtual1/unict.it/a/account//Maildir/dovecot-uidlist", {st_mode=S_IFREG|0644, st_size=14641, ...}) = 0 _llseek(17, 0, [0], SEEK_SET) = 0 fstat64(17, {st_mode=S_IFREG|0644, st_size=14641, ...}) = 0 fstat64(17, {st_mode=S_IFREG|0644, st_size=14641, ...}) = 0 pread64(17, ""..., 4096, 14641) = 0
This morning I have again the problem with duplicate uidlist. Unfortunately.
Andre
OK, I can reproduce this. It happens only with LMTP, because only then it can do a mailbox sync around the time of mail delivery. It probably also only happens when LMTP delivers the same mail to multiple recipients.
Now I'll just need to figure out how to fix this properly.. The maildir uidlist code is getting pretty ugly.
On Tue, 2010-09-07 at 15:59 +0100, Timo Sirainen wrote:
OK, I can reproduce this. It happens only with LMTP, because only then it can do a mailbox sync around the time of mail delivery. It probably also only happens when LMTP delivers the same mail to multiple recipients.
Now I'll just need to figure out how to fix this properly.. The maildir uidlist code is getting pretty ugly.
http://hg.dovecot.org/dovecot-2.0/rev/65b0e7b4eda9 should fix it. Although looks like it's still doing unnecessary extra work.
On Tue, 2010-09-07 at 16:24 +0100, Timo Sirainen wrote:
On Tue, 2010-09-07 at 15:59 +0100, Timo Sirainen wrote:
OK, I can reproduce this. It happens only with LMTP, because only then it can do a mailbox sync around the time of mail delivery. It probably also only happens when LMTP delivers the same mail to multiple recipients.
Now I'll just need to figure out how to fix this properly.. The maildir uidlist code is getting pretty ugly.
http://hg.dovecot.org/dovecot-2.0/rev/65b0e7b4eda9 should fix it. Although looks like it's still doing unnecessary extra work.
And http://hg.dovecot.org/dovecot-2.0/rev/c7e1c71c5ec5 fixes the extra work.
Timo, just put the path in all three servers. I'm yes getting duplicates. May be they are caused by existent files?
How may I check if patch is working fine?
I'll look at results tomorrow, anyway.
Luca
On 09/07/2010 05:32 PM, Timo Sirainen wrote:
On Tue, 2010-09-07 at 16:24 +0100, Timo Sirainen wrote:
On Tue, 2010-09-07 at 15:59 +0100, Timo Sirainen wrote:
OK, I can reproduce this. It happens only with LMTP, because only then it can do a mailbox sync around the time of mail delivery. It probably also only happens when LMTP delivers the same mail to multiple recipients.
Now I'll just need to figure out how to fix this properly.. The maildir uidlist code is getting pretty ugly.
http://hg.dovecot.org/dovecot-2.0/rev/65b0e7b4eda9 should fix it. Although looks like it's still doing unnecessary extra work.
And http://hg.dovecot.org/dovecot-2.0/rev/c7e1c71c5ec5 fixes the extra work.
Yeah, the patches fix the mail delivery stage. These duplicate errors happen during the next imap/pop3 login. So either wait for a while and in the meanwhile maybe check that the same mailbox won't get the error more than once.
On Tue, 2010-09-07 at 18:36 +0200, Luca Palazzo wrote:
Timo, just put the path in all three servers. I'm yes getting duplicates. May be they are caused by existent files?
How may I check if patch is working fine?
I'll look at results tomorrow, anyway.
Luca
On 09/07/2010 05:32 PM, Timo Sirainen wrote:
On Tue, 2010-09-07 at 16:24 +0100, Timo Sirainen wrote:
On Tue, 2010-09-07 at 15:59 +0100, Timo Sirainen wrote:
OK, I can reproduce this. It happens only with LMTP, because only then it can do a mailbox sync around the time of mail delivery. It probably also only happens when LMTP delivers the same mail to multiple recipients.
Now I'll just need to figure out how to fix this properly.. The maildir uidlist code is getting pretty ugly.
http://hg.dovecot.org/dovecot-2.0/rev/65b0e7b4eda9 should fix it. Although looks like it's still doing unnecessary extra work.
And http://hg.dovecot.org/dovecot-2.0/rev/c7e1c71c5ec5 fixes the extra work.
Timo, please also check this output of lmtp process:
stat64("/virtual1/unict.it/d/yyyyyyyy//Maildir/dovecot-uidlist", {st_mode=S_IFREG|0644, st_size=44628, ...}) = 0 _llseek(42, 0, [0], SEEK_SET) = 0 fstat64(42, {st_mode=S_IFREG|0644, st_size=44628, ...}) = 0 fstat64(42, {st_mode=S_IFREG|0644, st_size=44628, ...}) = 0 pread64(42, ""..., 4096, 44628) = 0
the same block is repeatead as time as entries in uidlist file.
Luca
On 09/03/2010 04:59 PM, Timo Sirainen wrote:
On Fri, 2010-09-03 at 15:57 +0100, Timo Sirainen wrote:
On Fri, 2010-09-03 at 15:44 +0100, Timo Sirainen wrote:
The maildir code hasn't changed much since v1.2. Hmm. Except that maildir filenames are now tried to be preserved when copying, so copying messages elsewhere and back does sound like it could cause this (although there is code to prevent it)..
You could try with attached patch to disable this feature and see if it helps.. dsync mirroring will break with it though.
Whops, that patch wasn't enough. This one is. :)
Hi Timo and All,
On 09/03/2010 04:44 PM, Timo Sirainen wrote:
On Thu, 2010-09-02 at 19:21 +0200, Luca Palazzo wrote:
Hi All, we are experiencing another strange problem after upgrading to 2.0.1 from 1.2.
Many people's client aree-retrieving mail from server due to some problem with dovecot-uidlist file. Looking at log file seem that all file content is sometime duplicated and appended to the and of same file. It look as another process was accesing and trying to modify uidlist table.
I've heard of some dovecot-uidlist problems, but haven't really figured out anything that could be wrong.. I guess there's no way you can reproduce this? Does happen to same user more than once? How many users is "many"? Does this happen only/mainly to some specific mailboxes (INBOX, Trash)? Does this happen to more than one same user's mailbox at the same time? Does this happen to different users around the same time? It's really difficult to understand how to reproduce it. We have about 6k maildirs and some of them, maybe about 200, are experiencing it more often. One this user has this problem accessing to mail by POP3 (so no other folder other than INBOX) from three different client. I'll try to figure if it's possible to have more info. One interesting information is that log file complain that duplicated UID line occur for all mails in uidlist file such as something is duplicating all mails UID at the end of file
Our setup has a load balance (dovecot director) and three backend server. All of them use 2.0.1.
How did you do it before v2.0? Pre-2.0 we were using a IPVS load balancing so we had no user affinity with server.
The maildir code hasn't changed much since v1.2. Hmm. Except that maildir filenames are now tried to be preserved when copying, so copying messages elsewhere and back does sound like it could cause this (although there is code to prevent it)..
I think it's not related to mail copy due to POP3 usage of user that experienced problem.
Luca
participants (4)
-
Andre
-
Andrea Mistrali
-
Luca Palazzo
-
Timo Sirainen