[Freeipa-users] ipa-dnskeysyncd not starting
Rob Verduijn
rob.verduijn at gmail.com
Mon Dec 19 16:51:39 UTC 2016
2016-12-19 17:06 GMT+01:00 Martin Basti <mbasti at redhat.com>:
>
>
> On 19.12.2016 16:27, Rob Verduijn wrote:
>
>
>
> 2016-12-19 16:07 GMT+01:00 Rob Verduijn <rob.verduijn at gmail.com>:
>
>>
>>
>>
>> 2016-12-19 15:52 GMT+01:00 Petr Spacek <pspacek at 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-
> packages/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-
> packages/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.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://listman.redhat.com/archives/freeipa-users/attachments/20161219/4dd78f80/attachment.htm>
More information about the Freeipa-users
mailing list