Ticket was cloned from Red Hat Bugzilla (product Fedora): Bug 1452866
I've been adjusting openQA to test FreeIPA upgrades recently. I *think* I've now got it to the point where the test is valid, but it's failing because of a genuine bug (but this is all new stuff, so it's possible I got something wrong). Anyway, the test does this: * A server VM boots from a clean Fedora 25 image and deploys itself as a FreeIPA server (using rolectl) * A client VM boots from the same image and enrols into the domain (using realmd) * The server upgrades itself to Fedora 26 (using dnf system-upgrade), then reboots and sits there until the client is done * The client waits for the server to be done upgrading, then also upgrades to Fedora 26 * The client runs some client-side tests to see if things are working correctly * Once the client is done, the server tries to cleanly decommission itself, then the test ends What I see happening is that one of the client side tests fails - when it runs `kinit -k host/client003.domain.local@DOMAIN.LOCAL`, expecting success, it fails with the error "kinit: Cannot contact any KDC for realm 'DOMAIN.LOCAL' while getting initial credentials". Some earlier tests pass, but I don't think any of those actually *contact* the server, they're just checking local configuration on the client side. When I look at the server logs, I see several failures from ns-slapd, including one which recurs over and over: May 19 11:26:43 ipa001.domain.local ns-slapd[1205]: [19/May/2017:14:26:43.033212238 -0400] - ERR - cos-plugin - cos_cache_query_attr - cos attribute krbPwdPolicyReference failed schema check on dn: cn=dns,dc=domain,dc=local there are various other errors, and ipa-dnskeysyncd.service keeps trying to start up and failing, with these messages: May 19 11:28:12 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=ipa-dnskeysyncd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' May 19 11:28:14 ipa001.domain.local ipa-dnskeysyncd[1823]: ipa : INFO LDAP bind... May 19 11:28:14 ipa001.domain.local python2[1823]: GSSAPI client step 1 May 19 11:28:14 ipa001.domain.local python2[1823]: GSSAPI client step 1 May 19 11:28:14 ipa001.domain.local python2[1823]: GSSAPI client step 1 May 19 11:28:14 ipa001.domain.local python2[1823]: GSSAPI client step 2 May 19 11:28:14 ipa001.domain.local ipa-dnskeysyncd[1823]: ipa : INFO Commencing sync process May 19 11:28:14 ipa001.domain.local ns-slapd[1205]: [19/May/2017:14:28:14.803715502 -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 19 11:28:14 ipa001.domain.local ns-slapd[1205]: [19/May/2017:14:28:14.806331783 -0400] - ERR - cos-plugin - cos_cache_query_attr - cos attribute krbPwdPolicyReference failed schema check on dn: ipk11UniqueID=562d1e30-3cbd-11e7-b9ff-525400120019,cn=keys,cn=sec,cn=dns ,dc=domain,dc=local May 19 11:28:14 ipa001.domain.local ipa-dnskeysyncd[1823]: ipa.ipapython.dnssec.keysyncer.KeySyncer: INFO Initial LDAP dump is done, sychronizing with ODS and BIND May 19 11:28:14 ipa001.domain.local audit[1829]: AVC avc: denied { execute_no_trans } for pid=1829 comm="ipa-dnskeysyncd" path="/usr/libexec/ipa/ipa-dnskeysync-replica" dev="dm-0" ino=812860 scontext=system_u:system_r:ipa_dnskey_t:s0 tcontext=system_u:object_r:ipa_dnskey_exec_t:s0 tclass=file permissive=0 May 19 11:28:14 ipa001.domain.local ipa-dnskeysyncd[1823]: Traceback (most recent call last): May 19 11:28:14 ipa001.domain.local ipa-dnskeysyncd[1823]: File "/usr/libexec/ipa/ipa-dnskeysyncd", line 110, in <module> May 19 11:28:14 ipa001.domain.local ipa-dnskeysyncd[1823]: while ldap_connection.syncrepl_poll(all=1, msgid=ldap_search): May 19 11:28:14 ipa001.domain.local ipa-dnskeysyncd[1823]: File "/usr/lib64/python2.7/site-packages/ldap/syncrepl.py", line 409, in syncrepl_poll May 19 11:28:14 ipa001.domain.local ipa-dnskeysyncd[1823]: self.syncrepl_refreshdone() May 19 11:28:14 ipa001.domain.local ipa-dnskeysyncd[1823]: File "/usr/lib/python2.7/site-packages/ipapython/dnssec/keysyncer.py", line 115, in syncrepl_refreshdone May 19 11:28:14 ipa001.domain.local ipa-dnskeysyncd[1823]: self.hsm_replica_sync() May 19 11:28:14 ipa001.domain.local ipa-dnskeysyncd[1823]: File "/usr/lib/python2.7/site-packages/ipapython/dnssec/keysyncer.py", line 181, in hsm_replica_sync May 19 11:28:14 ipa001.domain.local ipa-dnskeysyncd[1823]: ipautil.run([paths.IPA_DNSKEYSYNCD_REPLICA]) May 19 11:28:14 ipa001.domain.local ipa-dnskeysyncd[1823]: File "/usr/lib/python2.7/site-packages/ipapython/ipautil.py", line 459, in run May 19 11:28:14 ipa001.domain.local ipa-dnskeysyncd[1823]: preexec_fn=preexec_fn) May 19 11:28:14 ipa001.domain.local ipa-dnskeysyncd[1823]: File "/usr/lib64/python2.7/subprocess.py", line 390, in __init__ May 19 11:28:14 ipa001.domain.local ipa-dnskeysyncd[1823]: errread, errwrite) May 19 11:28:14 ipa001.domain.local ipa-dnskeysyncd[1823]: File "/usr/lib64/python2.7/subprocess.py", line 1024, in _execute_child May 19 11:28:14 ipa001.domain.local ipa-dnskeysyncd[1823]: raise child_exception May 19 11:28:14 ipa001.domain.local ipa-dnskeysyncd[1823]: OSError: [Errno 13] Permission denied May 19 11:28:14 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 19 11:28:14 ipa001.domain.local systemd[1]: ipa-dnskeysyncd.service: Main process exited, code=exited, status=1/FAILURE May 19 11:28:14 ipa001.domain.local systemd[1]: ipa-dnskeysyncd.service: Unit entered failed state. May 19 11:28:14 ipa001.domain.local systemd[1]: ipa-dnskeysyncd.service: Failed with result 'exit-code'. I will attach tarballs containing the whole contents of /var/log from both server and client ends; there are rather a lot of errors, and I'm not sure which are significant. Proposing as an F26 Beta blocker, as a violation of "For each one of the release-blocking package sets, it must be possible to successfully complete a direct upgrade from fully updated installations of the last two stable Fedora releases with that package set installed. ... The upgraded system must meet all release criteria." - an upgraded Server system deployed as a FreeIPA server doesn't meet the Alpha criterion "Release-blocking roles and the supported role configuration interfaces must meet the core functional Role Definition Requirements to the extent that supported roles can be successfully deployed, started, stopped, brought to a working configuration, and queried.", as the domain controller role does not meet its core requirements. Now I read the criteria again, it's arguable whether this applies (I don't think FreeIPA is actually part of the *default* Server install), but I think it's worth considering at least.
Metadata Update from @stlaz: - Custom field rhbz adjusted to https://bugzilla.redhat.com/show_bug.cgi?id=1452866 - Issue set to the milestone: None
Regarding DS cos plugin errors:
[19/May/2017:14:28:14.803715502 -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
This is tracked with https://pagure.io/389-ds-base/issue/49249 (bz 1437492) that is supposed to be fixed in
Fedora 26 389-ds-base-1.3.6.6-1.fc26 - https://koji.fedoraproject.org/koji/buildinfo?buildID=896118
RHEL 7.4 389-ds-base-1.3.6.1-14.el7
Metadata Update from @tbordaz: - Custom field rhbz reset (from https://bugzilla.redhat.com/show_bug.cgi?id=1452866)
Metadata Update from @stlaz: - Issue assigned to stlaz
Metadata Update from @stlaz: - Custom field rhbz adjusted to https://bugzilla.redhat.com/show_bug.cgi?id=1452866
Metadata Update from @tkrizek: - Issue priority set to: major - Issue set to the milestone: FreeIPA 4.5.3
master:
ipa-4-5:
Metadata Update from @tkrizek: - Issue close_status updated to: fixed - Issue status updated to: Closed (was: Open)
Please ignore the commits above, I accidentally pushed the code into a mirror repo instead of upstream. Sorry about that.
Metadata Update from @tkrizek: - Issue status updated to: Open (was: Closed)
Log in to comment on this ticket.