extremely poor performance with many maiboxes for 'list "" *'

[Greg A. Woods]

I manage a single-instance server running v2.2.12 with a reasonably
large number of mailboxes, using "mboxlist_db: flat":

# wc -l /var/imap/mailboxes.db                                                                
   40190 /var/imap/mailboxes.db

On the hardware it runs on a grep through the mailboxes file using a
non-trivial RE to match the user and ACL (in a manner I suspect is
similar to 'list "" *') will complete in less than a second of CPU time.

However imapd takes well over two minutes of CPU time to do the same
thing -- an unbelievable, impossibly, long time for what should be a
very trivial operation on so few records, relatively speaking.  I would
have expected that hardware to be able to process several tens of
millions of records in two minutes of CPU time.  I.e. whatever is being
done is being done with three or four orders of magnitude too many
instructions per record!  This is a "flat" DB, but still!

Unfortunately some clients, despite the advice of RFC 2683 Section
3.2.1.1, e.g. pine, frequently do things like this (or seem to),
sometimes putting extraordinarily excessive load on the system when
several do so at the same time (it's only a 4-CPU system :-)).


$ imtest
WARNING: no hostname supplied, assuming localhost

S: * OK public Cyrus IMAP4 v2.2.12 server ready
C: C01 CAPABILITY
S: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE STARTTLS LISTEXT LIST-SUBSCRIBED
S: C01 OK Completed
Please enter your password: 
C: L01 LOGIN woods {9}
S: + go ahead
C: <omitted>
S: L01 OK User logged in
Authenticated.
Security strength factor: 0
. list inbox *
* LIST (\HasChildren) "/" "inbox"
* LIST (\HasNoChildren) "/" "inbox/Trash"
. OK Completed (0.000 secs 3 calls)
. list "" *
* LIST (\HasChildren) "/" "INBOX"
* LIST (\HasNoChildren) "/" "INBOX/Trash"
* LIST (\HasNoChildren) "/" "notice/network/news"
* LIST (\HasNoChildren) "/" "user/cyrus"
* LIST (\HasChildren) "/" "user/gwoods"
* LIST (\HasNoChildren) "/" "user/gwoods/This is a new folder"
* LIST (\HasNoChildren) "/" "user/gwoods/Trash"
* LIST (\HasChildren) "/" "user/gwoods/a folder with spaces"
* LIST (\HasNoChildren) "/" "user/gwoods/a folder with spaces/a sub-folder within a folder"
* LIST (\HasNoChildren) "/" "user/gwoods/a-new-folder-by-wl"
. OK Completed (160.650 secs 11 calls)
C: Q01 LOGOUT
* BYE LOGOUT received
Q01 OK Completed
Connection closed.


$ ps -lp 15991 
UID   PID PPID CPU PRI NI  VSZ  RSS WCHAN  STAT TT    TIME COMMAND
120 15991  253  34   2  4 3720 4576 select IN   ?? 2:41.49 imapd: imapd: localhost [127.0.0.1]   


I haven't tried profiling the code yet (I'll have to replicate the
config on a test server that I'll have to build first).

I'm wondering if anyone else has seen this kind of problem and whether
or not anyone has looked into possible causes yet or not.

-- 
						Greg A. Woods

H:+1 416 218-0098 W:+1 416 489-5852 x122 VE3TCP RoboHack <woods at robohack.ca>
Planix, Inc. <woods at planix.com>       Secrets of the Weird <woods at weird.com>