Re: LIST is slow for 35K mailboxes

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



On 09 Oct 07, at 1550, Wesley Craig wrote:

> What's your authentication & authorization infrastructure look like?

sasl into yellow pages.

> Every mailbox has an associated ACL, which must be canonicalized to  
> determine whether the user in question gets to see it.   
> ctl_mboxlist just lists whatever it finds.  I've seen Kerberos  
> cause LIST * to take a long time -- and I have patches to fix the  
> problem.  Your high CPU load suggests a similar problem.  Try  
> sampling (Solaris: truss, dtrace?) a process that is spinning like  
> this, to see what kinds of actions it's taking.  In the case of  
> Kerberos, the stock Cyrus distribution will repeatedly open the  
> krb5.conf file once for each mailbox it examines, i.e., 35K times  
> in your case.

Well, in system call terms it's just jumping up and down on mailboxes.db

stat("/var/imap/mailboxes.db", 0xFFBFC838)      = 0
stat("/var/imap/mailboxes.db", 0xFFBFC838)      = 0
stat("/var/imap/mailboxes.db", 0xFFBFC838)      = 0
stat("/var/imap/mailboxes.db", 0xFFBFC838)      = 0
stat("/var/imap/mailboxes.db", 0xFFBFC838)      = 0
stat("/var/imap/mailboxes.db", 0xFFBFC838)      = 0
stat("/var/imap/mailboxes.db", 0xFFBFC838)      = 0
stat("/var/imap/mailboxes.db", 0xFFBFC838)      = 0
stat("/var/imap/mailboxes.db", 0xFFBFC838)      = 0
stat("/var/imap/mailboxes.db", 0xFFBFC838)      = 0
stat("/var/imap/mailboxes.db", 0xFFBFC838)      = 0
write(1, " . j u n k s t u f f "\r".., 4096)    = 4096
stat("/var/imap/mailboxes.db", 0xFFBFC838)      = 0
stat("/var/imap/mailboxes.db", 0xFFBFC838)      = 0
stat("/var/imap/mailboxes.db", 0xFFBFC838)      = 0
stat("/var/imap/mailboxes.db", 0xFFBFC838)      = 0
stat("/var/imap/mailboxes.db", 0xFFBFC838)      = 0
stat("/var/imap/mailboxes.db", 0xFFBFC838)      = 0
stat("/var/imap/mailboxes.db", 0xFFBFC838)      = 0
stat("/var/imap/mailboxes.db", 0xFFBFC838)      = 0
stat("/var/imap/mailboxes.db", 0xFFBFC838)      = 0

So it's not talking to the authentication infrastructure, as that  
would require system calls.

But in userspace (thanks for the prod to make me look at this) it's a  
lot messier, and looks like, as you say, it's doing a lot of  
authentication stuff: assuming that the stat()s of mailboxes.db are  
one per mailbox, and using truss -u to get the calls made by imapd  
and by libsasl, we see the below.  35K in 243s is about 144/sec, so  
it's not unreasonable that a lot of userspace calls are enough to  
slow things down.   So I can see where the time's going, but I'd  
rather it came back...

ian

1:     stat("/var/imap/mailboxes.db", 0xFFBFC838)      = 0
/1@1:                       -> map_refresh(0x6, 0x0, 0x1f2304, 0x1f230c)
/1@1:                     -> bsearch_mem(0xffbfca38, 0x1, 0xfd580000,  
0x25a510)
/1@1:           -> find_p(0xffbfe208, 0xfd3beaec, 0x1b, 0xfd3beb08)
/1@1:             -> glob_test(0x1f9560, 0xffbfdb2b, 0x18, 0xffbfdb24)
/1@1:             -> cyrus_acl_myrights(0x1f94f8, 0x21c318,  
0xffffffff, 0x0)
/1@1:               -> auth_memberof(0x1f94f8, 0x21c318, 0x66ff6367,  
0x80808080)
/1@1:                 -> auth_fromname(0x1f94f8, 0x21c318,  
0xffffffff, 0x0)
/1@1:                   -> libcyrus_config_getstring(0xd, 0x21c318,  
0x66ff6367, 0x80808080)
/1@1:                 -> mymemberof(0x1f94f8, 0x21c318, 0xffffffff, 0x0)
/1@1:               -> cyrus_acl_strtomask(0x21c31c, 0x21c318,  
0x66ff6367, 0x80808080)
/1@1:                 -> libcyrus_config_getstring(0x10, 0x21c326,  
0xffffffff, 0x0)
/1@1:               -> auth_memberof(0x1f94f8, 0x21c326, 0x696c66ff,  
0x80808080)
/1@1:                 -> auth_fromname(0x1f94f8, 0x21c326,  
0xffffffff, 0x0)
/1@1:                   -> libcyrus_config_getstring(0xd, 0x21c326,  
0x696c66ff, 0x80808080)
/1@1:                 -> mymemberof(0x1f94f8, 0x21c326, 0xffffffff, 0x0)
/1@1:           -> find_cb(0xffbfe208, 0xfd3beaec, 0x1b, 0xfd3beb08)
/1@1:             -> glob_test(0x1f9560, 0xffbfdb2b, 0x18, 0xffbfdb24)
/1@1:             -> listdata(0xffbfdb2b, 0x18, 0x1, 0xffbfe378)
/1@1:               -> mstringdata(0x1b1ab8, 0xffbfdb2b, 0x18, 0x1)
/1@1:                 -> prot_printf(0x1f72e8, 0x1b19f8, 0x1b1ab8,  
0x672e5365)
/1@1:                   -> prot_write(0x1f72e8, 0x1b19f8, 0x2,  
0x80808080)
/1@1:                   -> prot_write(0x1f72e8, 0x1b1ab8, 0x4,  
0x80808080)
/1@1:                   -> prot_write(0x1f72e8, 0x1b19fc, 0x2,  
0x80808080)
/1@1:                 -> prot_printf(0x1f72e8, 0x1b1a78, 0x1aed00,  
0x1b1a68)
/1@1:                   -> prot_write(0x1f72e8, 0x1b1a78, 0x0,  
0x80808080)
/1@1:                   -> prot_write(0x1f72e8, 0x1aed00, 0x0,  
0x80808080)
/1@1:                   -> prot_write(0x1f72e8, 0x1b1a7a, 0x0,  
0x80808080)
/1@1:                   -> prot_write(0x1f72e8, 0x1b1a68, 0xe,  
0x80808080)
/1@1:                   -> prot_write(0x1f72e8, 0x1b1a7c, 0x0,  
0x80808080)
/1@1:                 -> prot_printf(0x1f72e8, 0x1b1a30, 0x2e,  
0xffbfc998)
/1@1:                   -> prot_write(0x1f72e8, 0x1b1a30, 0x3,  
0x80808080)
/1@1:                   -> prot_write(0x1f72e8, 0x1b1a35, 0x2,  
0x80808080)
/1@1:                 -> mboxname_toexternal(0x1efe7c, 0x1dfb40,  
0x1f02d0, 0xffbfca38)
/1@1:                   -> mboxname_hiersep_toexternal(0x1efe7c,  
0xffbfca38, 0x0, 0x7300)
/1@1:                 -> printstring(0xffbfca38, 0x1dfb40, 0x1f02d0,  
0xffbfca38)
/1@1:                 -> prot_printf(0x1f72e8, 0x1af2a0, 0xffbfca38,  
0xffbfca38)
/1@1:                   -> prot_write(0x1f72e8, 0x1af2a0, 0x1,  
0x80808080)
/1@1:                   -> prot_write(0x1f72e8, 0xffbfca38, 0x11,  
0x80808080)
/1@1:                   -> prot_write(0x1f72e8, 0x1af2a3, 0x1,  
0x80808080)
/1@1:                 -> prot_printf(0x1f72e8, 0x1af918, 0xffbfca38,  
0xffbfc998)
/1@1:                   -> prot_write(0x1f72e8, 0x1af918, 0x2,  
0x80808080)
/1@1:                 -> mboxname_tointernal(0x1efe7c, 0x1b0218,  
0x1f02d0, 0xffbfca38)
/1@1:                   -> mboxname_hiersep_tointernal(0x1efe7c,  
0xffbfca40, 0x0, 0x1f02d0)
/1@1:                 -> mboxlist_detail(0xffbfca38, 0xffbfca34, 0x0,  
0x0)
/1@1:                 -> mboxlist_mylookup(0xffbfca38, 0xffbfca34,  
0x0, 0x0)
/1@1:                   -> fetch(0x1f22f8, 0xffbfca38, 0x1b, 0xffbfc9b4)
/1@1:                   -> myfetch(0x1f22f8, 0xffbfca38, 0x1b,  
0xffbfc9b4)
/1@1:                     -> starttxn_or_refetch(0x1f22f8, 0x0, 0x0,  
0x0)
/1:     stat("/var/imap/mailboxes.db", 0xFFBFC838)      = 0






>
> :wes
>
> On 09 Oct 2007, at 09:19, Ian G Batten wrote:
>> WeBut at root I don't understand why LIST "" * should take any
>> longer than, for example, ctl_mboxlist -d.

----
Cyrus Home Page: http://cyrusimap.web.cmu.edu/
Cyrus Wiki/FAQ: http://cyrusimap.web.cmu.edu/twiki
List Archives/Info: http://asg.web.cmu.edu/cyrus/mailing-list.html

[Index of Archives]     [Cyrus SASL]     [Squirrel Mail]     [Asterisk PBX]     [Video For Linux]     [Photo]     [Yosemite News]     [gtk]     [KDE]     [Gimp on Windows]     [Steve's Art]

  Powered by Linux