Bug 1456037 - SELinux denies execute_no_trans for ipa-dnskeysyncd during upgrade from Fedora 25 to Fedora 26 (crashes in enforcing mode)
Summary: SELinux denies execute_no_trans for ipa-dnskeysyncd during upgrade from Fedor...
Keywords:
Status: CLOSED EOL
Alias: None
Product: Fedora
Classification: Fedora
Component: selinux-policy-targeted
Version: 26
Hardware: x86_64
OS: Linux
unspecified
high
Target Milestone: ---
Assignee: Lukas Vrabec
QA Contact: Ben Levenson
URL:
Whiteboard:
Depends On:
Blocks: 1456038
TreeView+ depends on / blocked
 
Reported: 2017-05-26 19:33 UTC by Adam Williamson
Modified: 2018-05-29 12:31 UTC (History)
6 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2018-05-29 12:31:50 UTC
Type: Bug
Embargoed:

Attachments (Terms of Use)

Description Adam Williamson 2017-05-26 19:33:05 UTC 
I'm currently testing upgrades of Fedora 25 FreeIPA servers to Fedora 26, and noticing several problems, including several different AVCs from SELinux. There are two identical denials for ipa-dnskeysyncd:

time->Fri May 26 11:42:21 2017
type=AVC msg=audit(1495824141.019:171): avc:  denied  { execute_no_trans } for  pid=17134 comm="ipa-dnskeysyncd" path="/usr/libexec/ipa/ipa-dnskeysync-replica" dev="dm-0" ino=825153 scontext=system_u:system_r:ipa_dnskey_t:s0 tcontext=system_u:object_r:ipa_dnskey_exec_t:s0 tclass=file permissive=1

time->Fri May 26 11:44:30 2017
type=AVC msg=audit(1495824270.708:223): avc:  denied  { execute_no_trans } for  pid=1783 comm="ipa-dnskeysyncd" path="/usr/libexec/ipa/ipa-dnskeysync-replica" dev="dm-0" ino=825153 scontext=system_u:system_r:ipa_dnskey_t:s0 tcontext=system_u:object_r:ipa_dnskey_exec_t:s0 tclass=file permissive=1

When running in enforcing mode, this seems to cause ipa-dnskeysyncd to crash, again twice, once during the 'cleanup' phase of the upgrade:

May 25 15:35:15 ipa001.domain.local dnf[890]:   Cleanup     : libgcc-6.3.1-1.fc25.x86_64                            1597/1597
May 25 15:35:15 ipa001.domain.local dnf[890]: unable to resolve host name ipa001.domain.local. to IP address, ipa-ca DNS record will be incomplete
May 25 15:35:16 ipa001.domain.local systemd[1]: Stopping The Apache HTTP Server...
May 25 15:35:17 ipa001.domain.local systemd[1]: Stopped The Apache HTTP Server.
May 25 15:35:17 ipa001.domain.local audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=httpd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
May 25 15:35:17 ipa001.domain.local audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=httpd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
May 25 15:35:17 ipa001.domain.local systemd[1]: Starting The Apache HTTP Server...
May 25 15:35:17 ipa001.domain.local ipa-httpd-kdcproxy[17122]: ipa         : INFO     KDC proxy enabled
May 25 15:35:18 ipa001.domain.local ipa-dnskeysyncd[17101]: ipa         : INFO     LDAP bind...
May 25 15:35:18 ipa001.domain.local python2[17101]: GSSAPI client step 1
May 25 15:35:18 ipa001.domain.local python2[17101]: GSSAPI client step 1
May 25 15:35:18 ipa001.domain.local python2[17101]: GSSAPI client step 1
May 25 15:35:18 ipa001.domain.local python2[17101]: GSSAPI client step 2
May 25 15:35:18 ipa001.domain.local ipa-dnskeysyncd[17101]: ipa         : INFO     Commencing sync process
May 25 15:35:18 ipa001.domain.local ns-slapd[16733]: [25/May/2017:18:35:18.076779944 -0400] - ERR - cos-plugin - cos_cache_query_attr - cos attribute krbPwdPolicyReference failed schema check on dn: idnsname=domain.local.,cn=dns,dc=domain,dc=local
May 25 15:35:18 ipa001.domain.local ns-slapd[16733]: [25/May/2017:18:35:18.079727812 -0400] - ERR - cos-plugin - cos_cache_query_attr - cos attribute krbPwdPolicyReference failed schema check on dn: ipk11UniqueID=57200516-4198-11e7-9626-525400120015,cn=keys,cn=sec,cn=dns,dc=domain,dc=local
May 25 15:35:18 ipa001.domain.local ipa-dnskeysyncd[17101]: ipa.ipapython.dnssec.keysyncer.KeySyncer: INFO     Initial LDAP dump is done, sychronizing with ODS and BIND
May 25 15:35:18 ipa001.domain.local audit[17127]: AVC avc:  denied  { execute_no_trans } for  pid=17127 comm="ipa-dnskeysyncd" path="/usr/libexec/ipa/ipa-dnskeysync-replica" dev="dm-0" ino=834741 scontext=system_u:system_r:ipa_dnskey_t:s0 tcontext=system_u:object_r:ipa_dnskey_exec_t:s0 tclass=file permissive=0
May 25 15:35:18 ipa001.domain.local ipa-dnskeysyncd[17101]: Traceback (most recent call last):
May 25 15:35:18 ipa001.domain.local ipa-dnskeysyncd[17101]:   File "/usr/libexec/ipa/ipa-dnskeysyncd", line 110, in <module>
May 25 15:35:18 ipa001.domain.local ipa-dnskeysyncd[17101]:     while ldap_connection.syncrepl_poll(all=1, msgid=ldap_search):
May 25 15:35:18 ipa001.domain.local ipa-dnskeysyncd[17101]:   File "/usr/lib64/python2.7/site-packages/ldap/syncrepl.py", line 409, in syncrepl_poll
May 25 15:35:18 ipa001.domain.local ipa-dnskeysyncd[17101]:     self.syncrepl_refreshdone()
May 25 15:35:18 ipa001.domain.local ipa-dnskeysyncd[17101]:   File "/usr/lib/python2.7/site-packages/ipapython/dnssec/keysyncer.py", line 115, in syncrepl_refreshdone
May 25 15:35:18 ipa001.domain.local ipa-dnskeysyncd[17101]:     self.hsm_replica_sync()
May 25 15:35:18 ipa001.domain.local ipa-dnskeysyncd[17101]:   File "/usr/lib/python2.7/site-packages/ipapython/dnssec/keysyncer.py", line 181, in hsm_replica_sync
May 25 15:35:18 ipa001.domain.local ipa-dnskeysyncd[17101]:     ipautil.run([paths.IPA_DNSKEYSYNCD_REPLICA])
May 25 15:35:18 ipa001.domain.local ipa-dnskeysyncd[17101]:   File "/usr/lib/python2.7/site-packages/ipapython/ipautil.py", line 459, in run
May 25 15:35:18 ipa001.domain.local ipa-dnskeysyncd[17101]:     preexec_fn=preexec_fn)
May 25 15:35:18 ipa001.domain.local ipa-dnskeysyncd[17101]:   File "/usr/lib64/python2.7/subprocess.py", line 390, in __init__
May 25 15:35:18 ipa001.domain.local ipa-dnskeysyncd[17101]:     errread, errwrite)
May 25 15:35:18 ipa001.domain.local ipa-dnskeysyncd[17101]:   File "/usr/lib64/python2.7/subprocess.py", line 1024, in _execute_child
May 25 15:35:18 ipa001.domain.local ipa-dnskeysyncd[17101]:     raise child_exception
May 25 15:35:18 ipa001.domain.local ipa-dnskeysyncd[17101]: OSError: [Errno 13] Permission denied
May 25 15:35:18 ipa001.domain.local systemd[1]: ipa-dnskeysyncd.service: Main process exited, code=exited, status=1/FAILURE
May 25 15:35:18 ipa001.domain.local systemd[1]: ipa-dnskeysyncd.service: Unit entered failed state.
May 25 15:35:18 ipa001.domain.local systemd[1]: ipa-dnskeysyncd.service: Failed with result 'exit-code'.
May 25 15:35:18 ipa001.domain.local audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=ipa-dnskeysyncd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'

and once during the 'verifying' phase of the upgrade process:

May 25 15:36:21 ipa001.domain.local dnf[890]:   Verifying   : libutempter-1.1.6-8.fc24.x86_64                       1221/1597
May 25 15:36:21 ipa001.domain.local dnf[890]:   Verifying   : libuuid-2.28.2-2.fc25.x86_64                          1222/1597
May 25 15:36:21 ipa001.domain.local ipa-dnskeysyncd[12493]: ipa         : INFO     LDAP bind...
May 25 15:36:21 ipa001.domain.local python2[12493]: GSSAPI client step 1
May 25 15:36:21 ipa001.domain.local python2[12493]: GSSAPI client step 1
May 25 15:36:21 ipa001.domain.local python2[12493]: GSSAPI client step 1
May 25 15:36:21 ipa001.domain.local python2[12493]: GSSAPI client step 2
May 25 15:36:21 ipa001.domain.local ipa-dnskeysyncd[12493]: ipa         : INFO     Commencing sync process
May 25 15:36:21 ipa001.domain.local ns-slapd[16733]: [25/May/2017:18:36:21.222451400 -0400] - ERR - cos-plugin - cos_cache_query_attr - cos attribute krbPwdPolicyReference failed schema check on dn: idnsname=domain.local.,cn=dns,dc=domain,dc=local
May 25 15:36:21 ipa001.domain.local ns-slapd[16733]: [25/May/2017:18:36:21.225463617 -0400] - ERR - cos-plugin - cos_cache_query_attr - cos attribute krbPwdPolicyReference failed schema check on dn: ipk11UniqueID=57200516-4198-11e7-9626-525400120015,cn=keys,cn=sec,cn=dns,dc=domain,dc=local
May 25 15:36:21 ipa001.domain.local ipa-dnskeysyncd[12493]: ipa.ipapython.dnssec.keysyncer.KeySyncer: INFO     Initial LDAP dump is done, sychronizing with ODS and BIND
May 25 15:36:21 ipa001.domain.local audit[12683]: AVC avc:  denied  { execute_no_trans } for  pid=12683 comm="ipa-dnskeysyncd" path="/usr/libexec/ipa/ipa-dnskeysync-replica" dev="dm-0" ino=834741 scontext=system_u:system_r:ipa_dnskey_t:s0 tcontext=system_u:object_r:ipa_dnskey_exec_t:s0 tclass=file permissive=0
May 25 15:36:21 ipa001.domain.local dnf[890]:   Verifying   : libverto-0.2.6-6.fc24.x86_64                          1223/1597
May 25 15:36:21 ipa001.domain.local ipa-dnskeysyncd[12493]: Traceback (most recent call last):
May 25 15:36:21 ipa001.domain.local ipa-dnskeysyncd[12493]:   File "/usr/libexec/ipa/ipa-dnskeysyncd", line 110, in <module>
May 25 15:36:21 ipa001.domain.local ipa-dnskeysyncd[12493]:     while ldap_connection.syncrepl_poll(all=1, msgid=ldap_search):
May 25 15:36:21 ipa001.domain.local ipa-dnskeysyncd[12493]:   File "/usr/lib64/python2.7/site-packages/ldap/syncrepl.py", line 409, in syncrepl_poll
May 25 15:36:21 ipa001.domain.local ipa-dnskeysyncd[12493]:     self.syncrepl_refreshdone()
May 25 15:36:21 ipa001.domain.local ipa-dnskeysyncd[12493]:   File "/usr/lib/python2.7/site-packages/ipapython/dnssec/keysyncer.py", line 115, in syncrepl_refreshdone
May 25 15:36:21 ipa001.domain.local ipa-dnskeysyncd[12493]:     self.hsm_replica_sync()
May 25 15:36:21 ipa001.domain.local ipa-dnskeysyncd[12493]:   File "/usr/lib/python2.7/site-packages/ipapython/dnssec/keysyncer.py", line 181, in hsm_replica_sync
May 25 15:36:21 ipa001.domain.local ipa-dnskeysyncd[12493]:     ipautil.run([paths.IPA_DNSKEYSYNCD_REPLICA])
May 25 15:36:21 ipa001.domain.local ipa-dnskeysyncd[12493]:   File "/usr/lib/python2.7/site-packages/ipapython/ipautil.py", line 459, in run
May 25 15:36:21 ipa001.domain.local ipa-dnskeysyncd[12493]:     preexec_fn=preexec_fn)
May 25 15:36:21 ipa001.domain.local ipa-dnskeysyncd[12493]:   File "/usr/lib64/python2.7/subprocess.py", line 390, in __init__
May 25 15:36:21 ipa001.domain.local ipa-dnskeysyncd[12493]:     errread, errwrite)
May 25 15:36:21 ipa001.domain.local ipa-dnskeysyncd[12493]:   File "/usr/lib64/python2.7/subprocess.py", line 1024, in _execute_child
May 25 15:36:21 ipa001.domain.local ipa-dnskeysyncd[12493]:     raise child_exception
May 25 15:36:21 ipa001.domain.local ipa-dnskeysyncd[12493]: OSError: [Errno 13] Permission denied
May 25 15:36:21 ipa001.domain.local dnf[890]:   Verifying   : libverto-libev-0.2.6-6.fc24.x86_64                    1224/1597
May 25 15:36:21 ipa001.domain.local dnf[890]:   Verifying   : libwbclient-2:4.5.8-1.fc25.x86_64                     1225/1597
May 25 15:36:21 ipa001.domain.local dnf[890]:   Verifying   : libxkbcommon-0.7.1-1.fc25.x86_64                      1226/1597
May 25 15:36:21 ipa001.domain.local systemd[1]: ipa-dnskeysyncd.service: Main process exited, code=exited, status=1/FAILURE
May 25 15:36:21 ipa001.domain.local systemd[1]: ipa-dnskeysyncd.service: Unit entered failed state.
May 25 15:36:21 ipa001.domain.local audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=ipa-dnskeysyncd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
May 25 15:36:21 ipa001.domain.local systemd[1]: ipa-dnskeysyncd.service: Failed with result 'exit-code'.

There are so many different problems and errors with the upgrade process that I'm not sure which ones are critical, so I'm just listing them all as 'high' severity for now.
Comment 1 Standa Laznicka 2017-06-13 08:15:48 UTC 
Just for the record: there was no change in this part of FreeIPA (dnskeysyncd) that I am aware of so it should be purely a SELinux issue.
Comment 2 Daniel Walsh 2017-06-14 14:52:04 UTC 
It looks like a code path is being traversed that we did not hit before.  Basically the tool is executing itself.   This should be allowed.
Comment 3 Fedora End Of Life 2018-05-03 08:12:54 UTC 
This message is a reminder that Fedora 26 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 26. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as EOL if it remains open with a Fedora  'version'
of '26'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version'
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not
able to fix it before Fedora 26 is end of life. If you would still like
to see this bug fixed and are able to reproduce it against a later version
of Fedora, you are encouraged  change the 'version' to a later Fedora
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's
lifetime, sometimes those efforts are overtaken by events. Often a
more recent Fedora release includes newer upstream software that fixes
bugs or makes them obsolete.
Comment 4 Fedora End Of Life 2018-05-29 12:31:50 UTC 
Fedora 26 changed to end-of-life (EOL) status on 2018-05-29. Fedora 26
is no longer maintained, which means that it will not receive any
further security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.
Note You need to log in before you can comment on or make changes to this bug.