Description of problem: After futher investigation, it seems selinux were deying the read/write permission of /var/tmp/host_0 file to saslauthd and thus deamon had no way to verify the users and failed their authentication. type=AVC msg=audit(1307624494.176:365247): avc: denied { getattr } for pid=8577 comm="saslauthd" path="/var/tmp/host_0" dev=dm-2 ino=2998276 scontext=user_u:system_r:saslauthd_t:s0 tcontext=system_u:object_r:tmp_t:s0 tclass=file type=AVC msg=audit(1307624494.176:365248): avc: denied { read write } for pid=8577 comm="saslauthd" name="host_0" dev=dm-2 ino=2998276 scontext=user_u:system_r:saslauthd_t:s0 tcontext=system_u:object_r:tmp_t:s0 tclass=file This was due to wrong selinux content on the file. # ls -Z /var/tmp/host_0 -rw------- root root user_u:object_r:saslauthd_tmp_t /var/tmp/host_0 # restorecon -v /var/tmp/host_0 restorecon reset /var/tmp/host_0 context user_u:object_r:saslauthd_tmp_t:s0->system_u:object_r:krb5_host_rcache_t:s0 # sesearch -A -s saslauthd_t -t krb5_host_rcache_t -C Found 1 av rules: ET allow saslauthd_t krb5_host_rcache_t : file { ioctl read write create getattr setattr lock append unlink link rename }; [ allow_kerberos ] After this, I found a Fedora bug Bug 650819 that refects this problem, but this is only fixed in futher version of selinux-policy that is not yet in RHEL5.6. http://git.fedorahosted.org/git/?p=selinux-policy.git;a=commitdiff;h=c56e4a6d3fd24a19dce1c4e20a832b54c92ed8e8 diff --git a/policy/modules/services/sasl.te b/policy/modules/services/sasl.te index 87810ec..687f9ae 100644 (file) --- a/policy/modules/services/sasl.te +++ b/policy/modules/services/sasl.te @@ -98,6 +98,7 @@ tunable_policy(`allow_saslauthd_read_shadow',` optional_policy(` kerberos_keytab_template(saslauthd, saslauthd_t) + kerberos_manage_host_rcache(saslauthd_t) ') However, this is just a workaround from selinux. After some time I noticed something strange - something on the system is changing the selinux context of the file back to sasl after few minutes. Thu Jun 9 11:43:15 EDT 2011 -rw------- root root system_u:object_r:krb5_host_rcache_t /var/tmp/host_0 Thu Jun 9 11:43:25 EDT 2011 -rw------- root root system_u:object_r:krb5_host_rcache_t /var/tmp/host_0 Thu Jun 9 11:43:35 EDT 2011 -rw------- root root system_u:object_r:krb5_host_rcache_t /var/tmp/host_0 Thu Jun 9 11:43:45 EDT 2011 -rw------- root root system_u:object_r:krb5_host_rcache_t /var/tmp/host_0 Thu Jun 9 11:43:55 EDT 2011 -rw------- root root system_u:object_r:krb5_host_rcache_t /var/tmp/host_0 Thu Jun 9 11:44:05 EDT 2011 -rw------- root root system_u:object_r:krb5_host_rcache_t /var/tmp/host_0 Thu Jun 9 11:44:15 EDT 2011 -rw------- root root system_u:object_r:krb5_host_rcache_t /var/tmp/host_0 Thu Jun 9 11:44:25 EDT 2011 -rw------- root root system_u:object_r:krb5_host_rcache_t /var/tmp/host_0 Thu Jun 9 11:44:35 EDT 2011 -rw------- root root user_u:object_r:saslauthd_tmp_t /var/tmp/host_0 Thu Jun 9 11:44:45 EDT 2011 -rw------- root root user_u:object_r:saslauthd_tmp_t /var/tmp/host_0 Thu Jun 9 11:44:55 EDT 2011 -rw------- root root user_u:object_r:saslauthd_tmp_t /var/tmp/host_0 ==> /tmp/PostmortemSharedFolderOutage20110609.log <== Thu Jun 9 12:16:56 EDT 2011 -rw------- root root system_u:object_r:krb5_host_rcache_t /var/tmp/host_0 Thu Jun 9 12:17:06 EDT 2011 -rw------- root root system_u:object_r:krb5_host_rcache_t /var/tmp/host_0 ==> /var/log/audit/audit.log <== type=AVC msg=audit(1307636232.970:367728): avc: denied { search } for pid=5269 comm="saslauthd" name="home" dev=sda3 ino=1470241 scontext=user_u:system_r:saslauthd_t:s0 tco ntext=system_u:object_r:home_root_t:s0 tclass=dir type=SYSCALL msg=audit(1307636232.970:367728): arch=c000003e syscall=21 success=no exit=-2 a0=1bc5c3c0 a1=0 a2=323db53a38 a3=6a722f7564722f65 items=0 ppid=2375 pid=5269 auid=1 1675 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4577 comm="saslauthd" exe="/usr/sbin/saslauthd" subj=user_u:system_r:saslauthd_t:s0 key=(null) type=USER_AUTH msg=audit(1307636232.970:367729): user pid=5269 uid=0 auid=11675 subj=user_u:system_r:saslauthd_t:s0 msg='PAM: authentication acct="rjaswal" : exe="/usr/sbin/sa slauthd" (hostname=?, addr=?, terminal=? res=success)' type=USER_ACCT msg=audit(1307636232.971:367730): user pid=5269 uid=0 auid=11675 subj=user_u:system_r:saslauthd_t:s0 msg='PAM: accounting acct="rjaswal" : exe="/usr/sbin/saslau thd" (hostname=?, addr=?, terminal=? res=success)' type=ANOM_ABEND msg=audit(1307636232.972:367731): auid=11675 uid=76 gid=12 ses=4575 subj=user_u:system_r:cyrus_t:s0 pid=28671 comm="imapd" sig=6 type=USER_AUTH msg=audit(1307636233.566:367732): user pid=5273 uid=0 auid=11675 subj=user_u:system_r:saslauthd_t:s0 msg='PAM: authentication acct="docushare" : exe="/usr/sbin/ saslauthd" (hostname=?, addr=?, terminal=? res=success)' type=USER_ACCT msg=audit(1307636233.567:367733): user pid=5273 uid=0 auid=11675 subj=user_u:system_r:saslauthd_t:s0 msg='PAM: accounting acct="docushare" : exe="/usr/sbin/sasl authd" (hostname=?, addr=?, terminal=? res=success)' ==> /tmp/PostmortemSharedFolderOutage20110609.log <== Thu Jun 9 12:17:16 EDT 2011 -rw------- root root user_u:object_r:saslauthd_tmp_t /var/tmp/host_0 The line that is responsible for this type change is: type=SYSCALL msg=audit(1307637874.187:368070): arch=c000003e syscall=21 success=no exit=-2 a0=1bf2b400 a1=0 a2=323db53a38 a3=6b726f2f656d6f68 items=0 ppid=2375 pid=13307 auid=11675 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4577 comm="saslauthd" exe="/usr/sbin/saslauthd" subj=user_u:system_r:saslauthd_t:s0 key=(null) $ grep "21$" /usr/include/asm/unistd_64.h #define __NR_access 21 Strace from saslauthd shows, it's using a function from krb5 libs. 04:15:02 write(7, "\24\0\0\0jrigsbee\0@\0\0\0host"..., 100) = 100 04:15:02 write(7, "\24\0\0\0gciraudo\0@\0\0\0host"..., 100) = 100 04:15:02 write(7, "\24\0\0\0pnavadgi\0@\0\0\0host"..., 100) = 100 04:15:02 fsync(7) = 0 04:15:02 fsync(5) = 0 04:15:02 rename("/var/tmp/krb5_RC9705aaa", "/var/tmp/host_0") = 0 04:15:02 close(5) = 0 04:15:02 dup(7) = 5 04:15:02 close(7) = 0 After more investigation, I've found the function in question is krb5_rc_dfl_expunge_locked , when it finds out the cache contains too many obsolete entries it creates a temporary file with current principals and move it to /var/tmp/host_0 destroying the selinux context. This is a bug in krb5. http://opengrok.brq.redhat.com/source/xref/RHEL-5/krb5/1.6.1/55.el5_6.1/krb5-1.6.1/src/lib/krb5/rcache/rc_dfl.c#krb5_rc_dfl_expunge_locked Version-Release number of selected component (if applicable): krb5-libs-1.6.1-55.el5 How reproducible: always
Technical note added. If any revisions are required, please edit the "Technical Notes" field accordingly. All revisions will be proofread by the Engineering Content Services team. New Contents: When expired entries are being expunged from cache, Kerberos creates a temporary file, copies valid entries into it and then renames it back to set it as a new cache file. Prior to this update, the SELinux label was not set correctly for the temporary file. Subsequently, user identities could not be properly verified. With this update, a newer version of the patch addressing this issue has been provided, the temporary file now gets the correct SELinux label and applications that modify the replay cache file continue to work properly in the described scenario.
An advisory has been issued which should help the problem described in this bug report. This report is therefore being closed with a resolution of ERRATA. For more information on therefore solution and/or where to find the updated files, please follow the link below. You may reopen this bug report if the solution does not work for you. http://rhn.redhat.com/errata/RHBA-2011-1031.html