Bug 1350957

Summary: ipa named-pkcs11 failed to enumerate object store
Product: Red Hat Enterprise Linux 7 Reporter: Scott Poore <spoore>
Component: selinux-policyAssignee: Lukas Vrabec <lvrabec>
Status: CLOSED ERRATA QA Contact: Milos Malik <mmalik>
Severity: urgent Docs Contact:
Priority: urgent    
Version: 7.3CC: jgalipea, lvrabec, mgrepl, mmalik, plautrba, pspacek, pvoborni, pvrabec, rcritten, spoore, ssekidde, tdudlak
Target Milestone: rcKeywords: Regression, TestBlocker
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: selinux-policy-3.13.1-91.el7 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-11-04 02:33:22 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
ausearch output after update
none
ausearch output after update to 89 release
none
ausearch output after update to 89 release in permissive mode none

Description Scott Poore 2016-06-28 20:15:02 UTC
Description of problem:

IPA fails to start with named error (listed below).  If I make SELinux permissive, I'm able to start. However, I am not able to consistently see AVC denials.

[root@cloud-qe-21 ~]# ipactl start
ipa: WARNING: session memcached servers not running
Existing service file detected!
Assuming stale, cleaning and proceeding
Starting Directory Service
Starting krb5kdc Service
Starting kadmin Service
Starting named Service
Failed to start named Service
Shutting down
Hint: You can use --ignore-service-failure option for forced start in case that a non-critical service failed
Aborting ipactl

[root@cloud-qe-21 ~]# ausearch -m avc -ts 15:56
<no matches>

When I put it in permissive mode though, I get AVCs that look like named_t can't access ipa_var_lib_t.


Version-Release number of selected component (if applicable):
bind-9.9.4-36.el7.x86_64
bind-pkcs11-9.9.4-36.el7.x86_64
selinux-policy-3.13.1-82.el7.noarch
selinux-policy-targeted-3.13.1-82.el7.noarch
ipa-server-4.4.0-0.el7.2.alpha1.x86_64


How reproducible:
always

Steps to Reproduce:
1.  use repo with latest rpms
2.  yum -y install ipa-server-dns
3.  ipa-server-install --setup-dns --forwarder=$DNSFORWARDER --hostname=$HOSTNAME --ip-address=$IP -n $DNSDOMAIN -r $REALM -a $PASSWORD -p $PASSWORD -U
4.  ipactl restart

Actual results:
ipa-server-install actually fails because of named issue mentioned.  Able to reproduce afterwards with ipactl as in step 4.

Expected results:
no failures

Additional info:

From /var/log/messages:

Jun 28 15:41:57 localhost named-pkcs11[25696]: ObjectStore.cpp(59): Failed to enumerate object store in /var/lib/ipa/dnssec/tokens
Jun 28 15:41:57 localhost named-pkcs11[25696]: SoftHSM.cpp(476): Could not load the object store
Jun 28 15:41:57 localhost named-pkcs11[25696]: initializing DST: PKCS#11 initialization failed
Jun 28 15:41:57 localhost named-pkcs11[25696]: exiting (due to fatal error)

AVC seen when in permissive mode:
time->Tue Jun 28 15:58:55 2016
type=SYSCALL msg=audit(1467143935.025:348): arch=c000003e syscall=257 success=yes exit=9 a0=ffffffffffffff9c a1=7fb92eba7a08 a2=90800 a3=0 items=0 ppid=27053 pid=27055 auid=4294967295 uid=25 gid=25 euid=25 suid=25 fsuid=25 egid=25 sgid=25 fsgid=25 tty=(none) ses=4294967295 comm="named-pkcs11" exe="/usr/sbin/named-pkcs11" subj=system_u:system_r:named_t:s0 key=(null)
type=AVC msg=audit(1467143935.025:348): avc:  denied  { read } for  pid=27055 comm="named-pkcs11" name="tokens" dev="dm-0" ino=33565592 scontext=system_u:system_r:named_t:s0 tcontext=unconfined_u:object_r:ipa_var_lib_t:s0 tclass=dir
----
time->Tue Jun 28 15:58:55 2016
type=SYSCALL msg=audit(1467143935.025:349): arch=c000003e syscall=2 success=yes exit=9 a0=7fb92eba80b8 a1=42 a2=180 a3=ffffe000 items=0 ppid=27053 pid=27055 auid=4294967295 uid=25 gid=25 euid=25 suid=25 fsuid=25 egid=25 sgid=25 fsgid=25 tty=(none) ses=4294967295 comm="named-pkcs11" exe="/usr/sbin/named-pkcs11" subj=system_u:system_r:named_t:s0 key=(null)
type=AVC msg=audit(1467143935.025:349): avc:  denied  { open } for  pid=27055 comm="named-pkcs11" path="/var/lib/ipa/dnssec/tokens/67565689-8135-6d50-0a6d-1c5e3a2143e5/generation" dev="dm-0" ino=68045545 scontext=system_u:system_r:named_t:s0 tcontext=unconfined_u:object_r:ipa_var_lib_t:s0 tclass=file
type=AVC msg=audit(1467143935.025:349): avc:  denied  { read write } for  pid=27055 comm="named-pkcs11" name="generation" dev="dm-0" ino=68045545 scontext=system_u:system_r:named_t:s0 tcontext=unconfined_u:object_r:ipa_var_lib_t:s0 tclass=file
----
time->Tue Jun 28 15:58:55 2016
type=SYSCALL msg=audit(1467143935.025:350): arch=c000003e syscall=72 success=yes exit=0 a0=9 a1=7 a2=7ffdd60180d0 a3=24 items=0 ppid=27053 pid=27055 auid=4294967295 uid=25 gid=25 euid=25 suid=25 fsuid=25 egid=25 sgid=25 fsgid=25 tty=(none) ses=4294967295 comm="named-pkcs11" exe="/usr/sbin/named-pkcs11" subj=system_u:system_r:named_t:s0 key=(null)
type=AVC msg=audit(1467143935.025:350): avc:  denied  { lock } for  pid=27055 comm="named-pkcs11" path="/var/lib/ipa/dnssec/tokens/67565689-8135-6d50-0a6d-1c5e3a2143e5/generation" dev="dm-0" ino=68045545 scontext=system_u:system_r:named_t:s0 tcontext=unconfined_u:object_r:ipa_var_lib_t:s0 tclass=file
----
time->Tue Jun 28 15:58:55 2016
type=SYSCALL msg=audit(1467143935.025:351): arch=c000003e syscall=5 success=yes exit=0 a0=9 a1=7ffdd6018070 a2=7ffdd6018070 a3=24 items=0 ppid=27053 pid=27055 auid=4294967295 uid=25 gid=25 euid=25 suid=25 fsuid=25 egid=25 sgid=25 fsgid=25 tty=(none) ses=4294967295 comm="named-pkcs11" exe="/usr/sbin/named-pkcs11" subj=system_u:system_r:named_t:s0 key=(null)
type=AVC msg=audit(1467143935.025:351): avc:  denied  { getattr } for  pid=27055 comm="named-pkcs11" path="/var/lib/ipa/dnssec/tokens/67565689-8135-6d50-0a6d-1c5e3a2143e5/generation" dev="dm-0" ino=68045545 scontext=system_u:system_r:named_t:s0 tcontext=unconfined_u:object_r:ipa_var_lib_t:s0 tclass=file

Comment 1 Scott Poore 2016-06-28 20:43:55 UTC
This appears to be similar to Fedora bug #1333106

Changing component to selinux-policy.

Comment 4 Petr Spacek 2016-07-08 08:08:00 UTC
*** Bug 1353631 has been marked as a duplicate of this bug. ***

Comment 5 Petr Spacek 2016-07-08 11:30:17 UTC
*** Bug 1353631 has been marked as a duplicate of this bug. ***

Comment 7 Scott Poore 2016-07-14 22:07:19 UTC
OK, I'm seeing IPA install and restart without failure now.

I'm now seeing quite a few other AVC denials.  I'll post the actual AVCs as an attachment.

This is what I see from audit2allow for the failures:

[root@rhel7-1 ~]# cat /var/log/audit/audit.log | audit2allow
libsepol.sepol_string_to_security_class: unrecognized class (null)


#============= certmonger_t ==============
allow certmonger_t var_log_t:dir write;

#============= ipa_dnskey_t ==============
allow ipa_dnskey_t named_cache_t:dir search;
allow ipa_dnskey_t proc_t:file read;

#============= policykit_t ==============
allow policykit_t tuned_t:(null) 0x2;

#============= sssd_t ==============
allow sssd_t fs_t:filesystem getattr;

Comment 8 Scott Poore 2016-07-14 22:08:58 UTC
Created attachment 1179966 [details]
ausearch output after update

This is a listing of the AVC denials I see after ipa-server-install and ipactl stop/start.

selinux-policy-3.13.1-88.el7.noarch
ipa-server-4.4.0-2.1.el7.x86_64

Comment 15 Scott Poore 2016-07-18 13:51:15 UTC
Hi Lukas,

I am still seeing most of the AVC denials I saw previously in the attachment.

Here are a couple examples:

----
time->Mon Jul 18 08:36:13 2016
type=SYSCALL msg=audit(1468848973.979:169): arch=c000003e syscall=83 success=no exit=-13 a0=19a7140 a1=1ff a2=1 a3=7ffdfb090fd0 items=0 ppid=2689 pid=2725 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="dogtag-ipa-ca-r" exe="/usr/bin/python2.7" subj=system_u:system_r:certmonger_t:s0 key=(null)
type=AVC msg=audit(1468848973.979:169): avc:  denied  { write } for  pid=2725 comm="dogtag-ipa-ca-r" name="log" dev="dm-0" ino=93 scontext=system_u:system_r:certmonger_t:s0 tcontext=system_u:object_r:var_log_t:s0 tclass=dir
----
time->Mon Jul 18 08:38:58 2016
type=SYSCALL msg=audit(1468849138.745:226): arch=c000003e syscall=2 success=no exit=-13 a0=7fe617122a1d a1=80000 a2=1b6 a3=24 items=0 ppid=4510 pid=4517 auid=4294967295 uid=995 gid=25 euid=995 suid=995 fsuid=995 egid=25 sgid=25 fsgid=25 tty=(none) ses=4294967295 comm="sh" exe="/usr/bin/bash" subj=system_u:system_r:ipa_dnskey_t:s0 key=(null)
type=AVC msg=audit(1468849138.745:226): avc:  denied  { read } for  pid=4517 comm="sh" name="meminfo" dev="proc" ino=4026532028 scontext=system_u:system_r:ipa_dnskey_t:s0 tcontext=system_u:object_r:proc_t:s0 tclass=file
----

These are occurring during ipa-server-install.  And are just a couple examples of many that are like the ones from previous attachment.  I'll include a new attachment showing the current ones.

Can these be addressed as well?

Thanks,
Scott

Comment 16 Scott Poore 2016-07-18 13:52:18 UTC
Created attachment 1181107 [details]
ausearch output after update to 89 release

These are the AVC denials I'm now seeing with this version of selinux-policy:

selinux-policy-3.13.1-89.el7.noarch

Comment 17 Lukas Vrabec 2016-07-18 15:34:53 UTC
Scott, 
yes, it can be addressed but could you test it in permissive mode to collect all AVCs and attahc them? Then I fix policy. 

Thank you for testing.

Comment 18 Scott Poore 2016-07-18 18:01:27 UTC
Created attachment 1181224 [details]
ausearch output after update to 89 release in permissive mode

This is the list of AVC denials from ipa-server-install with SELinux in permissive mode.

Comment 22 Scott Poore 2016-07-19 14:07:11 UTC
selinux-policy-3.13.1-90.el7.noarch

Not sure why we didn't see these until now but, now I'm seeing this:


[root@rhel7-4 ~]# ausearch -m avc
----
time->Tue Jul 19 08:57:06 2016
type=SYSCALL msg=audit(1468936626.889:216): arch=c000003e syscall=4 success=no exit=-2 a0=12cd0a0 a1=7ffff4ad7700 a2=7ffff4ad7700 a3=0 items=0 ppid=1 pid=4560 auid=4294967295 uid=995 gid=25 euid=995 suid=995 fsuid=995 egid=25 sgid=25 fsgid=25 tty=(none) ses=4294967295 comm="ipa-dnskeysyncd" exe="/usr/bin/python2.7" subj=system_u:system_r:ipa_dnskey_t:s0 key=(null)
type=AVC msg=audit(1468936626.889:216): avc:  denied  { search } for  pid=4560 comm="ipa-dnskeysyncd" name="softhsm" dev="dm-0" ino=8415058 scontext=system_u:system_r:ipa_dnskey_t:s0 tcontext=system_u:object_r:named_cache_t:s0 tclass=dir
----
time->Tue Jul 19 08:57:08 2016
type=SYSCALL msg=audit(1468936628.858:218): arch=c000003e syscall=2 success=no exit=-2 a0=4eff1c0 a1=0 a2=1b6 a3=24 items=0 ppid=1 pid=4560 auid=4294967295 uid=995 gid=25 euid=995 suid=995 fsuid=995 egid=25 sgid=25 fsgid=25 tty=(none) ses=4294967295 comm="ipa-dnskeysyncd" exe="/usr/bin/python2.7" subj=system_u:system_r:ipa_dnskey_t:s0 key=(null)
type=AVC msg=audit(1468936628.858:218): avc:  denied  { search } for  pid=4560 comm="ipa-dnskeysyncd" name="softhsm" dev="dm-0" ino=8415058 scontext=system_u:system_r:ipa_dnskey_t:s0 tcontext=system_u:object_r:named_cache_t:s0 tclass=dir

Comment 23 Lukas Vrabec 2016-07-19 14:08:29 UTC
Could you please test it in permissive mode? We need to catch all AVCs. 

Thank you.

Comment 25 Scott Poore 2016-07-19 14:10:49 UTC
Hi Lukas,

In my test from comment #22, that was in permissive mode:

[root@rhel7-4 ~]# getenforce
Permissive

I'm not sure what changed that this wasn't caught before but, that's what we're seeing now.

Comment 33 errata-xmlrpc 2016-11-04 02:33:22 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHBA-2016-2283.html