The SASL mechanism is set to Kerberos 5. The user is correctly authorized, and except for sasl_server_start() being really slow, things seem to work.
Does any one have any idea why this happens and how to fix it?
Some more details, the test system is running CentOS 6.3, which came with Cyrus SASL 2.1.23 and MIT Kerberos 1.9 libraries. I first noticed the problem with OpenLDAP 2.4.28. I have since compiled SASL 2.1.25 and confirmed the problem using the sample client and sample server.
Running the sample client and sample server under strace, it looks like sasl_server_start() opens and processes the same set of files 9 times. Not sure why 9 times or why it would need to look at any of them more then one time.
I grepped for open in the strace output collected while sasl_server_start() was running and copied the last group of open calls to get this list of files that are processed 9 times:
15:35:30.739312 open("/var/tmp/ldap_0", O_RDWR) = 12
15:35:30.748931 open("/etc/krb5.conf", O_RDONLY) = 13
15:35:30.749320 open("/dev/urandom", O_RDONLY) = 13
15:35:30.749664 open("/etc/krb5.conf", O_RDONLY) = 13
15:35:30.750056 open("/dev/urandom", O_RDONLY) = 13
15:35:30.750365 open("/dev/urandom", O_RDONLY) = 13
15:35:30.750700 open("/proc/self/task/4798/attr/current", O_RDONLY) = 13
15:35:30.750907 open("/proc/self/task/4798/attr/fscreate", O_RDONLY) = 13
15:35:30.751042 open("/etc/selinux/targeted/contexts/files/file_contexts.subs", O_RDONLY) = -1 ENOENT (No such file or directory)
15:35:30.751095 open("/etc/selinux/targeted/contexts/files/file_contexts", O_RDONLY) = 13
15:35:30.751199 open("/etc/selinux/targeted/contexts/files/file_contexts.homedirs", O_RDONLY) = 14
15:35:30.751251 open("/etc/selinux/targeted/contexts/files/file_contexts.local", O_RDONLY) = -1 ENOENT (No such file or directory)
15:35:30.873405 open("/proc/self/task/4798/attr/current", O_RDONLY) = 13
15:35:30.873964 open("/proc/self/task/4798/attr/fscreate", O_RDWR) = 13
15:35:30.874148 open("/usr/local/etc/openldap/ldap-infinite-temp.keytab", O_RDONLY) = 13
15:35:30.874228 open("/proc/self/task/4798/attr/current", O_RDONLY) = 14
15:35:30.875398 open("/proc/self/task/4798/attr/fscreate", O_RDWR) = 14
There are also many repeated calls to read, mmap, brk, and others that repeat 9 times while sasl_server_start() is running.So far, I have only tinkered with the sample/server.c code and tracked the slowness to sasl_server_start().
With selinux disabled, it seems that sasl_server_start() does similar looping with krb5.conf, /etc/hosts, etc. The loop is still there, but, it does not take long because selinux is not slowing things way down.
Kinit, ksu, ssh, and other "kerberized" programs do not seem to have any performance problems on CentOS 6.3. I have only noticed the slow down on programs that use SASL with saslauthd running on a system with selinux enabled.
I appreciate any ideas you may have.
Thanks
Matt
mbrookov@xxxxxxxxx
