<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.0 TRANSITIONAL//EN">
<HTML>
<HEAD>
<META HTTP-EQUIV="Content-Type" CONTENT="text/html; CHARSET=UTF-8">
<META NAME="GENERATOR" CONTENT="GtkHTML/3.16.3">
</HEAD>
<BODY>
It seems that sasl_server_start() takes 0.17 seconds to run with selinux is disabled and takes 1.28 seconds to run when selinux is enabled.<BR>
<BR>
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.<BR>
<BR>
Does any one have any idea why this happens and how to fix it?<BR>
<BR>
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.<BR>
<BR>
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.<BR>
<BR>
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:
<PRE>
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
</PRE>
There are also many repeated calls to read, mmap, brk, and others that repeat 9 times while sasl_server_start() is running.<BR>
<BR>
So far, I have only tinkered with the sample/server.c code and tracked the slowness to sasl_server_start().<BR>
<BR>
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.<BR>
<BR>
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.<BR>
<BR>
I appreciate any ideas you may have.<BR>
<BR>
Thanks<BR>
<BR>
Matt<BR>
<A HREF="mailto:mbrookov@mines.edu">mbrookov@mines.edu</A><BR>
<BR>
<BR>
</BODY>
</HTML>