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