Dovecot: 2.3.4
Hi,
i am debugging a problem where after a force-resync removed all cache
files (All files are 44 byte). Trying to open a folder takes literally minutes
(Huge mailbox - 220K folder, 45GByte compressed storage)
After i straced the imap process i can see the imap process accesses
hundrets of other completely unrelated folders:
Thats from the logfile - You can see mutt selecting the mailbox
"zzzzzzt":
May 07 18:05:19 imap(inbox at
wasteland)<20381><hlkrmL/B5qwgAwDvnxMdAGcc/5MSpYxQ>: Debug: fts: No
fts setting - plugin disabled
May 07 18:05:19 imap(inbox at
wasteland)<20381><hlkrmL/B5qwgAwDvnxMdAGcc/5MSpYxQ>: Debug: quota:
quota_over_flag check: quota_over_script unset - skipping
May 07 18:05:19 imap(inbox at
wasteland)<20381><hlkrmL/B5qwgAwDvnxMdAGcc/5MSpYxQ>: Debug: Mailbox
zzzzzzt: Mailbox opened because: SELECT
From strace -p 20381 - This goes on for minutes opening thousands of unrelated
folders. It is noteworthy
that it mostly opens nested folders which are rare here:
[...]
open("/var/vmail/wasteland/inbox/mdbox/mailboxes/gerries/are/hawt",
O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 15
fstat(15, {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
getdents(15, /* 3 entries */, 32768) = 72
stat("/var/vmail/wasteland/inbox/mdbox/mailboxes/gerries/are/hawt/yeah",
{st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
stat("/var/vmail/wasteland/inbox/mdbox/mailboxes/gerries/are/hawt/yeah/dbox-Mails",
{st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
getdents(15, /* 0 entries */, 32768) = 0
close(15) = 0
open("/var/vmail/wasteland/inbox/mdbox/mailboxes/karl588594",
O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 15
fstat(15, {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
getdents(15, /* 3 entries */, 32768) = 80
stat("/var/vmail/wasteland/inbox/mdbox/mailboxes/karl588594/b3914",
{st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
stat("/var/vmail/wasteland/inbox/mdbox/mailboxes/karl588594/b3914/dbox-Mails",
{st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
getdents(15, /* 0 entries */, 32768) = 0
close(15) = 0
open("/var/vmail/wasteland/inbox/mdbox/mailboxes/ben",
O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 15
fstat(15, {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
getdents(15, /* 4 entries */, 32768) = 104
stat("/var/vmail/wasteland/inbox/mdbox/mailboxes/ben/gang",
{st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
stat("/var/vmail/wasteland/inbox/mdbox/mailboxes/ben/gang/dbox-Mails",
{st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
Reopening the same folder again is quick and seamless. So it seems this is some
cache recreation code looking into other folders.
I am bit puzzled on why it does this. mail_debug=yes did now show anything.
Any more debug options for mdbox i might set to find out about its decisions?
Flo
--
Florian Lohoff f at zz.de
Any sufficiently advanced technology is indistinguishable from magic.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 833 bytes
Desc: not available
URL:
<https://dovecot.org/pipermail/dovecot/attachments/20210507/a2bc654a/attachment.sig>
On Fri, May 07, 2021 at 06:15:55PM +0200, Florian Lohoff wrote:> > Dovecot: 2.3.4 > > Hi, > i am debugging a problem where after a force-resync removed all cache > files (All files are 44 byte). Trying to open a folder takes literally minutes > (Huge mailbox - 220K folder, 45GByte compressed storage)As i am running out of options i upgraded to 2.3.14-5+debian9 though no success. Between Debian/Stretch 2.2.27 and 2.3.4 something broke horribly for huge mdboxes. Opening the mailbox takes (on an otherwise idle machine, 32GByte RAM, RAID1 spinning rust) root at pax:~# time doveadm mailbox list -u inbox at wasteland.rfc822.org >/var/tmp/list doveadm(inbox at wasteland.rfc822.org): Warning: Transaction log file /var/vmail/wasteland.rfc822.org/inbox/mdbox/dovecot.list.index.log was locked for 107 seconds (Mailbox was synchronized) real 1m47.508s user 1m46.856s sys 0m0.480s We see the ~220K folders in this mailbox: root at pax:~# wc -l /var/tmp/list 213922 /var/tmp/list Looking at an strace on this command we see: root at pax:~# grep stat /var/tmp/strace.doveadm.list | wc -l 428696 So every folder will at least get 2 stat calls - Okay - may be because of the mailbox list command - lets try deleting a folder. root at pax:~# strace -f -o /var/tmp/strace.doveadm.mailbox.delete doveadm mailbox delete -e -u inbox at wasteland.rfc822.org bernd.bottich doveadm(inbox at wasteland.rfc822.org): Warning: Transaction log file /var/vmail/wasteland.rfc822.org/inbox/mdbox/dovecot.list.index.log was locked for 115 seconds (Mailbox was synchronized) doveadm(inbox at wasteland.rfc822.org): Error: Can't delete mailbox bernd.bottich: Mailbox doesn't exist: bernd.bottich root at pax:~# grep stat /var/tmp/strace.doveadm.mailbox.delete | wc -l 428702 Okay - so we opened the mailbox, stattet all folders to tell me my mailbox is not existent. Took again around 90 seconds. And this happens every, single, time. root at pax:~# time doveadm mailbox delete -e -u inbox at wasteland.rfc822.org bernd.bottich doveadm(inbox at wasteland.rfc822.org): Warning: Transaction log file /var/vmail/wasteland.rfc822.org/inbox/mdbox/dovecot.list.index.log was locked for 108 seconds (Mailbox was synchronized) doveadm(inbox at wasteland.rfc822.org): Error: Can't delete mailbox bernd.bottich: Mailbox doesn't exist: bernd.bottich real 1m48.232s user 1m47.472s sys 0m0.580s So logging is broken (Yes i had a look at the code. It complains about its own lock been taken to long on unlocking) So i am in a deadend. 2.2.27 eats mdboxes for breakfast and cant repair them 2.3.4+ is unusuable with this mailbox. All these operations were in the sub-second range with 2.2.27 ... Guess i need to find something else to store mails ... Flo -- Florian Lohoff f at zz.de Any sufficiently advanced technology is indistinguishable from magic. -------------- next part -------------- A non-text attachment was scrubbed... Name: signature.asc Type: application/pgp-signature Size: 833 bytes Desc: not available URL: <https://dovecot.org/pipermail/dovecot/attachments/20210508/a084f684/attachment.sig>