mailboxes.db inconsistency caused by simultaneous renames

Sebastian Hagedorn Hagedorn at uni-koeln.de
Tue Jan 29 03:51:49 EST 2013


Hi,

running 2.4.16 we noticed something that clearly isn't right. Somehow a 
user managed to rename (or rather move) a folder twice at the same time. 
The result is an invalid entry in mailboxes.db without the corresponding 
folder in the file system. Here's what happened:

Jan 24 18:07:36 clotho imap[3419]: login: [134.95.xxx.xxx] redacted 
CRAM-MD5+TLS User logged in 
SESSIONID=<cyrus.rrz.uni-koeln.de-3419-1359047255-1>
Jan 24 18:07:36 clotho imap[2153]: login: [134.95.xxx.xxx] redacted 
CRAM-MD5+TLS User logged in 
SESSIONID=<cyrus.rrz.uni-koeln.de-2153-1359047250-1>
Jan 24 18:07:37 clotho imap[2153]: open: user redacted opened INBOX
Jan 24 18:07:38 clotho imap[3419]: open: user redacted opened 
Archives/Kollegen
Jan 24 18:07:45 clotho imap[3419]: Rename: user.redacted.Archives.Kollegen 
-> user.redacted.Lehre.1_unerledigt Studies.Kollegen
Jan 24 18:07:45 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen
Jan 24 18:07:45 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.K&ANY-LN -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.K&ANY-LN
Jan 24 18:07:46 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.K&ANY-LN
Jan 24 18:07:46 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.K&ANY-LN.Andrej -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.K&ANY-LN.Andrej
Jan 24 18:07:46 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.K&ANY-LN.Andrej
Jan 24 18:07:46 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.K&ANY-LN.Anne -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.K&ANY-LN.Anne
Jan 24 18:07:47 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.K&ANY-LN.Anne
Jan 24 18:07:47 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.K&ANY-LN.Aschermann -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.K&ANY-LN.Aschermann
Jan 24 18:07:47 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.K&ANY-LN.Aschermann
Jan 24 18:07:47 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.K&ANY-LN.Bernd -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.K&ANY-LN.Bernd
Jan 24 18:07:47 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.K&ANY-LN.Bernd
Jan 24 18:07:47 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.K&ANY-LN.Christoph -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.K&ANY-LN.Christoph
Jan 24 18:07:48 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.K&ANY-LN.Christoph
Jan 24 18:07:48 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.K&ANY-LN.Gerhard -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.K&ANY-LN.Gerhard
Jan 24 18:07:48 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.K&ANY-LN.Gerhard
Jan 24 18:07:48 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.K&ANY-LN.Hilde -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.K&ANY-LN.Hilde
Jan 24 18:07:49 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.K&ANY-LN.Hilde
Jan 24 18:07:49 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.K&ANY-LN.Isabell -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.K&ANY-LN.Isabell
Jan 24 18:07:49 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.K&ANY-LN.Isabell
Jan 24 18:07:49 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.K&ANY-LN.Thomas -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.K&ANY-LN.Thomas
Jan 24 18:07:50 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.K&ANY-LN.Thomas
Jan 24 18:07:50 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.K&ANY-LN.Ursula -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.K&ANY-LN.Ursula
Jan 24 18:07:51 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.K&ANY-LN.Ursula
Jan 24 18:07:51 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.K&ANY-LN.Wilfried -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.K&ANY-LN.Wilfried
Jan 24 18:07:51 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.K&ANY-LN.Wilfried
Jan 24 18:07:51 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.Kollegen G&APY- -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.Kollegen G&APY-
Jan 24 18:07:51 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.Kollegen G&APY-
Jan 24 18:07:51 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.Kollegen G&APY-.AnnaSF -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.Kollegen G&APY-.AnnaSF
Jan 24 18:07:52 clotho imap[29016]: login: [134.95.xxx.xxx] redacted 
CRAM-MD5+TLS User logged in 
SESSIONID=<cyrus.rrz.uni-koeln.de-29016-1359047271-1>
Jan 24 18:07:52 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.Kollegen G&APY-.AnnaSF
Jan 24 18:07:52 clotho imap[29016]: Rename: 
user.redacted.Archives.Kollegen.Kollegen G&APY-.Antonia -> 
user.redacted.Kollegen.Kollegen G&APY-.Antonia
Jan 24 18:07:52 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.Kollegen G&APY-.Antonia -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.Kollegen G&APY-.Antonia
Jan 24 18:07:53 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.Kollegen G&APY-.Antonia
Jan 24 18:07:53 clotho imap[29016]: Deleted mailbox 
user.redacted.Archives.Kollegen.Kollegen G&APY-.Antonia
Jan 24 18:07:53 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.Kollegen G&APY-.Henning -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.Kollegen G&APY-.Henning
Jan 24 18:07:53 clotho imap[29016]: Rename: 
user.redacted.Archives.Kollegen.Kollegen G&APY-.Henning -> 
user.redacted.Kollegen.Kollegen G&APY-.Henning
Jan 24 18:07:53 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.Kollegen G&APY-.Henning
Jan 24 18:07:53 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.andere Kollegen -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.andere Kollegen
Jan 24 18:07:53 clotho imap[29016]: Deleted mailbox 
user.redacted.Archives.Kollegen.Kollegen G&APY-.Henning
Jan 24 18:07:53 clotho imap[29016]: Rename: 
user.redacted.Archives.Kollegen.andere Kollegen -> 
user.redacted.Kollegen.andere Kollegen
Jan 24 18:07:53 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.andere Kollegen
Jan 24 18:07:53 clotho imap[29016]: Deleted mailbox 
user.redacted.Archives.Kollegen.andere Kollegen
Jan 24 18:07:53 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.andere Kollegen.GerhardRinkenauer -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.andere 
Kollegen.GerhardRinkenauer
Jan 24 18:07:54 clotho imap[29016]: Rename: 
user.redacted.Archives.Kollegen.andere Kollegen.GerhardRinkenauer -> 
user.redacted.Kollegen.andere Kollegen.GerhardRinkenauer
Jan 24 18:07:54 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.andere Kollegen.GerhardRinkenauer
Jan 24 18:07:54 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.andere Kollegen.JM -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.andere Kollegen.JM
Jan 24 18:07:54 clotho imap[29016]: Deleted mailbox 
user.redacted.Archives.Kollegen.andere Kollegen.GerhardRinkenauer
Jan 24 18:07:54 clotho imap[29016]: Rename: 
user.redacted.Archives.Kollegen.andere Kollegen.JM -> 
user.redacted.Kollegen.andere Kollegen.JM
Jan 24 18:07:54 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.andere Kollegen.JM
Jan 24 18:07:54 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.andere Kollegen.PW -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.andere Kollegen.PW
Jan 24 18:07:54 clotho imap[29016]: Deleted mailbox 
user.redacted.Archives.Kollegen.andere Kollegen.JM
Jan 24 18:07:54 clotho imap[29016]: Rename: 
user.redacted.Archives.Kollegen.andere Kollegen.PW -> 
user.redacted.Kollegen.andere Kollegen.PW
Jan 24 18:07:54 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.andere Kollegen.PW
Jan 24 18:07:54 clotho imap[29016]: Deleted mailbox 
user.redacted.Archives.Kollegen.andere Kollegen.PW
Jan 24 18:07:54 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.andere Kollegen.RU -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.andere Kollegen.RU
Jan 24 18:07:54 clotho imap[29016]: Rename: 
user.redacted.Archives.Kollegen.andere Kollegen.RU -> 
user.redacted.Kollegen.andere Kollegen.RU
Jan 24 18:07:54 clotho imap[29016]: Deleted mailbox 
user.redacted.Archives.Kollegen.andere Kollegen.RU
Jan 24 18:07:54 clotho imap[29016]: Rename: 
user.redacted.Archives.Kollegen.andere Kollegen.StefanBode -> 
user.redacted.Kollegen.andere Kollegen.StefanBode
Jan 24 18:07:54 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.andere Kollegen.RU
Jan 24 18:07:54 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.andere Kollegen.StefanBode -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.andere Kollegen.StefanBode
Jan 24 18:07:58 clotho imap[29016]: Deleted mailbox 
user.redacted.Archives.Kollegen.andere Kollegen.StefanBode
Jan 24 18:07:58 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.andere Kollegen.StefanBode

The relevant part is that one mailbox is renamed twice:

Jan 24 18:07:53 clotho imap[3419]: Rename: 
user.redacted.Archives.Kollegen.Kollegen G&APY-.Henning -> 
user.redacted.Lehre.1_unerledigt Studies.Kollegen.Kollegen G&APY-.Henning
Jan 24 18:07:53 clotho imap[29016]: Rename: 
user.redacted.Archives.Kollegen.Kollegen G&APY-.Henning -> 
user.redacted.Kollegen.Kollegen G&APY-.Henning
Jan 24 18:07:53 clotho imap[3419]: Deleted mailbox 
user.redacted.Archives.Kollegen.Kollegen G&APY-.Henning
Jan 24 18:07:53 clotho imap[29016]: Deleted mailbox 
user.redacted.Archives.Kollegen.Kollegen G&APY-.Henning

The first operation succeeded, i.e. the new mailbox exists both in 
mailboxes.db and in the file system, the second only succeeded partially. 
So it looks as though there's a locking bug. The client that was used is 
Thunderbird 17.0.2.

I've also filed a bug report:

<https://bugzilla.cyrusimap.org/show_bug.cgi?id=3766>
--
Sebastian Hagedorn - Weyertal 121, Zimmer 2.02
Regionales Rechenzentrum (RRZK)
Universität zu Köln / Cologne University - Tel. +49-221-470-89578
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pkcs7-signature
Size: 5313 bytes
Desc: not available
Url : http://lists.andrew.cmu.edu/pipermail/info-cyrus/attachments/20130129/2706df31/attachment-0001.bin 


More information about the Info-cyrus mailing list