2016-12-19 18:53 GMT+01:00 Martin Basti <mba...@redhat.com>: > > > On 19.12.2016 17:51, Rob Verduijn wrote: > > 2016-12-19 17:06 GMT+01:00 Martin Basti <mba...@redhat.com>: > >> >> >> On 19.12.2016 16:27, Rob Verduijn wrote: >> >> >> >> 2016-12-19 16:07 GMT+01:00 Rob Verduijn <rob.verdu...@gmail.com>: >> >>> >>> >>> >>> 2016-12-19 15:52 GMT+01:00 Petr Spacek <pspa...@redhat.com>: >>> >>>> On 19.12.2016 14:07, Rob Verduijn wrote: >>>> > Hello, >>>> > >>>> > I'm running ipa on centos 7.3 with the latest patches applied. >>>> > >>>> > It seem to run fine however the ipa-dnskeysyncd keeps failing to >>>> start and >>>> > I keep seeing this message in my logs: >>>> > >>>> > ipa-dnskeysyncd[25663]: ipa : INFO LDAP bind... >>>> > python2[25663]: GSSAPI client step 1 >>>> > python2[25663]: GSSAPI client step 1 >>>> > ns-slapd[2569]: GSSAPI server step 1 >>>> > python2[25663]: GSSAPI client step 1 >>>> > ns-slapd[2569]: GSSAPI server step 2 >>>> > python2[25663]: GSSAPI client step 2 >>>> > ns-slapd[2569]: GSSAPI server step 3 >>>> > ipa-dnskeysyncd[25663]: ipa : INFO Commencing sync process >>>> > ipa-dnskeysyncd[25663]: ipa.ipapython.dnssec.keysyncer.KeySyncer: >>>> INFO >>>> > Initial LDAP dump is done, sychronizing with ODS and BIND >>>> > python2[25674]: GSSAPI client step 1 >>>> > python2[25674]: GSSAPI client step 1 >>>> > ns-slapd[2569]: GSSAPI server step 1 >>>> > python2[25674]: GSSAPI client step 1 >>>> > ns-slapd[2569]: GSSAPI server step 2 >>>> > python2[25674]: GSSAPI client step 2 >>>> > ns-slapd[2569]: GSSAPI server step 3 >>>> > ipa-dnskeysyncd[25663]: Traceback (most recent call last): >>>> > ipa-dnskeysyncd[25663]: File "/usr/libexec/ipa/ipa-dnskeysyncd", >>>> line 110, >>>> > in <module> >>>> > ipa-dnskeysyncd[25663]: while ldap_connection.syncrepl_poll(all=1, >>>> > msgid=ldap_search): >>>> > ipa-dnskeysyncd[25663]: File >>>> > "/usr/lib64/python2.7/site-packages/ldap/syncrepl.py", line 405, in >>>> > syncrepl_poll >>>> > ipa-dnskeysyncd[25663]: self.syncrepl_refreshdone() >>>> > ipa-dnskeysyncd[25663]: File >>>> > "/usr/lib/python2.7/site-packages/ipapython/dnssec/keysyncer.py", >>>> line 115, >>>> > in syncrepl_refreshdone >>>> > ipa-dnskeysyncd[25663]: self.hsm_replica_sync() >>>> > ipa-dnskeysyncd[25663]: File >>>> > "/usr/lib/python2.7/site-packages/ipapython/dnssec/keysyncer.py", >>>> line 181, >>>> > in hsm_replica_sync >>>> > ipa-dnskeysyncd[25663]: ipautil.run([paths.IPA_DNSKEYSYNCD_REPLICA]) >>>> > ipa-dnskeysyncd[25663]: File >>>> > "/usr/lib/python2.7/site-packages/ipapython/ipautil.py", line 494, >>>> in run >>>> > ipa-dnskeysyncd[25663]: raise CalledProcessError(p.returncode, >>>> arg_string, >>>> > str(output)) >>>> > ipa-dnskeysyncd[25663]: subprocess.CalledProcessError: Command >>>> > '/usr/libexec/ipa/ipa-dnskeysync-replica' returned non-zero exit >>>> status 1 >>>> > systemd[1]: ipa-dnskeysyncd.service: main process exited, code=exited, >>>> > status=1/FAILURE >>>> > systemd[1]: Unit ipa-dnskeysyncd.service entered failed state. >>>> > systemd[1]: ipa-dnskeysyncd.service failed. >>>> > >>>> > for some reason the ipa-dnskeysyncd keeops crashing. >>>> > Anybody know where to start looking for this one ? >>>> >>>> Please raise the debug level so we can see something in the logs: >>>> >>>> http://www.freeipa.org/page/Troubleshooting#ipa_command_cras >>>> hes_or_returns_no_data >>>> >>>> -- >>>> Petr^2 Spacek >>>> >>>> -- >>>> Manage your subscription for the Freeipa-users mailing list: >>>> https://www.redhat.com/mailman/listinfo/freeipa-users >>>> Go to http://freeipa.org for more info on the project >>>> >>> >>> Hello, >>> >>> The file /etc/ipa/ipa.conf or the file /etc/ipa/server.conf do not exist >>> on my system. >>> How to set debugging in this case ? >>> >>> Rob >>> >> >> I've set the debug level in /etc/ipa/default.conf >> >> now I get this output >> systemd[1]: ipa-dnskeysyncd.service: main process exited, code=exited, >> status=1/FAILURE >> systemd[1]: Unit ipa-dnskeysyncd.service entered failed state. >> systemd[1]: ipa-dnskeysyncd.service failed. >> systemd[1]: ipa-dnskeysyncd.service holdoff time over, scheduling >> restart. >> systemd[1]: Started IPA key daemon. >> systemd[1]: Starting IPA key daemon... >> ipa-dnskeysyncd[30568]: ipa : INFO LDAP bind... >> python2[30568]: GSSAPI client step 1 >> python2[30568]: GSSAPI client step 1 >> ns-slapd[26744]: GSSAPI server step 1 >> python2[30568]: GSSAPI client step 1 >> ns-slapd[26744]: GSSAPI server step 2 >> python2[30568]: GSSAPI client step 2 >> ns-slapd[26744]: GSSAPI server step 3 >> ipa-dnskeysyncd[30568]: ipa : INFO Commencing sync process >> ipa-dnskeysyncd[30568]: ipa.ipapython.dnssec.keysyncer.KeySyncer: >> INFO Initial LDAP dump is done, sychronizing with ODS and BIND >> python2[30579]: GSSAPI client step 1 >> python2[30579]: GSSAPI client step 1 >> ns-slapd[26744]: GSSAPI server step 1 >> python2[30579]: GSSAPI client step 1 >> ns-slapd[26744]: GSSAPI server step 2 >> python2[30579]: GSSAPI client step 2 >> ns-slapd[26744]: GSSAPI server step 3 >> python2[30579]: ObjectStore.cpp(59): Failed to enumerate object store in >> /var/lib/softhsm/tokens/ >> python2[30579]: SoftHSM.cpp(476): Could not load the object store >> ipa-dnskeysyncd[30568]: Traceback (most recent call last): >> ipa-dnskeysyncd[30568]: File "/usr/libexec/ipa/ipa-dnskeysyncd", line >> 110, in <module> >> ipa-dnskeysyncd[30568]: while ldap_connection.syncrepl_poll(all=1, >> msgid=ldap_search): >> ipa-dnskeysyncd[30568]: File >> "/usr/lib64/python2.7/site-packages/ldap/syncrepl.py", >> line 405, in syncrepl_poll >> ipa-dnskeysyncd[30568]: self.syncrepl_refreshdone() >> ipa-dnskeysyncd[30568]: File "/usr/lib/python2.7/site-packa >> ges/ipapython/dnssec/keysyncer.py", line 115, in syncrepl_refreshdone >> ipa-dnskeysyncd[30568]: self.hsm_replica_sync() >> ipa-dnskeysyncd[30568]: File "/usr/lib/python2.7/site-packa >> ges/ipapython/dnssec/keysyncer.py", line 181, in hsm_replica_sync >> ipa-dnskeysyncd[30568]: ipautil.run([paths.IPA_DNSKEYSYNCD_REPLICA]) >> ipa-dnskeysyncd[30568]: File >> "/usr/lib/python2.7/site-packages/ipapython/ipautil.py", >> line 494, in run >> ipa-dnskeysyncd[30568]: raise CalledProcessError(p.returncode, >> arg_string, str(output)) >> ipa-dnskeysyncd[30568]: subprocess.CalledProcessError: Command >> '/usr/libexec/ipa/ipa-dnskeysync-replica' returned non-zero exit status >> >> >> >> >> Hello, do you have selinux in enforcing mode? Any AVCs ? >> >> Martin >> > > > yes > > but ipa-dnskeysyncd still fails to start when selinux is in permissive mode > > I did : > ipactl stop > setenforce 0 > service auditd rotate > ipactl start > > and see one avc denied > type=AVC msg=audit(1482164681.053:5195): avc: denied { read } for > pid=1993 comm="ipa-dnskeysync-" name="tokens" dev="dm-7" ino=16818968 > scontext=system_u:system_r:ipa_dnskey_t:s0 > tcontext=system_u:object_r:named_cache_t:s0 > tclass=dir > > I gues that is one little bit of selinux that needs adjustment, > > however there is still no running ipa-dnskeysyncd. > > I found that this error appears before the previous one. > > ipa-dnskeysyncd[1981]: ipa: DEBUG: ipaserver.plugins.virtual is not a > valid plugin module > ipa-dnskeysyncd[1981]: ipa: DEBUG: importing plugin module > ipaserver.plugins.xmlserver > ipa-dnskeysyncd[1981]: ipa : DEBUG Kerberos principal: > ipa-dnskeysyncd/freeipa01.tjako.thuis > ipa-dnskeysyncd[1981]: ipa : DEBUG Initializing principal > ipa-dnskeysyncd/freeipa01.tjako.thuis using keytab /etc/ipa/dnssec/ipa- > dnskeysyncd.keytab > ipa-dnskeysyncd[1981]: ipa : DEBUG using ccache > /tmp/ipa-dnskeysync-replica.ccache > ipa-dnskeysyncd[1981]: ipa : DEBUG Attempt 1/5: success > ipa-dnskeysyncd[1981]: ipa : DEBUG Got TGT > ipa-dnskeysyncd[1981]: ipa : DEBUG Connecting to LDAP > ipa-dnskeysyncd[1981]: ipa : DEBUG Connected > ipa-dnskeysyncd[1981]: Traceback (most recent call last): > ipa-dnskeysyncd[1981]: File "/usr/libexec/ipa/ipa-dnskeysync-replica", > line 159, in <module> > ipa-dnskeysyncd[1981]: open(paths.DNSSEC_SOFTHSM_PIN).read()) > ipa-dnskeysyncd[1981]: File "/usr/lib/python2.7/site- > packages/ipapython/dnssec/localhsm.py", line 95, in __init__ > ipa-dnskeysyncd[1981]: self.p11 = _ipap11helper.P11_Helper(slot, pin, > library) > ipa-dnskeysyncd[1981]: File "/usr/lib/python2.7/site- > packages/ipapython/p11helper.py", line 837, in __init__ > ipa-dnskeysyncd[1981]: check_return_value(rv, "open session") > ipa-dnskeysyncd[1981]: File "/usr/lib/python2.7/site- > packages/ipapython/p11helper.py", line 576, in check_return_value > ipa-dnskeysyncd[1981]: raise Error(errmsg) > ipa-dnskeysyncd[1981]: ipapython.p11helper.Error: Error at open session: > 0xe1 > ipa-dnskeysyncd[1981]: Exception AttributeError: "'LocalHSM' object has no > attribute 'p11'" in <bound method LocalHSM.__del__ of > <ipapython.dnssec.localhsm.LocalHSM object at 0x5ec92d0>> ignored > ipa-dnskeysyncd[1981]: Traceback (most recent call last): > ipa-dnskeysyncd[1981]: File "/usr/libexec/ipa/ipa-dnskeysyncd", line 110, > in <module> > ipa-dnskeysyncd[1981]: while ldap_connection.syncrepl_poll(all=1, > msgid=ldap_search): > ipa-dnskeysyncd[1981]: File > "/usr/lib64/python2.7/site-packages/ldap/syncrepl.py", > line 405, in syncrepl_poll > ipa-dnskeysyncd[1981]: self.syncrepl_refreshdone() > ipa-dnskeysyncd[1981]: File "/usr/lib/python2.7/site- > packages/ipapython/dnssec/keysyncer.py", line 115, in syncrepl_refreshdone > ipa-dnskeysyncd[1981]: self.hsm_replica_sync() > ipa-dnskeysyncd[1981]: File "/usr/lib/python2.7/site- > packages/ipapython/dnssec/keysyncer.py", line 181, in hsm_replica_sync > ipa-dnskeysyncd[1981]: ipautil.run([paths.IPA_DNSKEYSYNCD_REPLICA]) > ipa-dnskeysyncd[1981]: File "/usr/lib/python2.7/site- > packages/ipapython/ipautil.py", line 494, in run > ipa-dnskeysyncd[1981]: raise CalledProcessError(p.returncode, arg_string, > str(output)) > ipa-dnskeysyncd[1981]: subprocess.CalledProcessError: Command > '/usr/libexec/ipa/ipa-dnskeysync-replica' returned non-zero exit status 1 > systemd[1]: ipa-dnskeysyncd.service: main process exited, code=exited, > status=1/FAILURE > systemd[1]: Unit ipa-dnskeysyncd.service entered failed state. > systemd[1]: ipa-dnskeysyncd.service failed. > > > > Selinux caused that key has not been created in HSM database, you have to > temporarily set selinux to permisive, and run ipa-dns-install again to fix > it. > > Martin >
Thanx That seemed to do the trick. Two more questions. Now I even have more AVC deny records (same kind as before) type=AVC msg=audit(1482164681.053:5195): avc: denied { read } for pid=1993 comm="ipa-dnskeysync-" name="tokens" dev="dm-7" ino=16818968 scontext=system_u:system_r:ipa_dnskey_t:s0 tcontext=system_u:object_r:named_cache_t:s0 tclass=dir How do I deal with those, I don't want to break it again by turning on enforcing mode again. Will a simple audit2allow do ? Or is there a better way ? Second question. I now have a ton off these messages in my logs: DSRetroclPlugin - delete_changerecord: could not delete change record<5 digit number> (rc: 32) What are those, is that a journal being replayed ? Cheers
-- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project