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