[Freeipa-users] Unable to configure DNSSEC signing

Tue May 3 13:29:08 UTC 2016

All lines from the log file with conn=152.

[03/May/2016:07:21:06 -0400] conn=152 fd=83 slot=83 connection from local to
/var/run/slapd-EXAMPLE-COM.socket
[03/May/2016:07:21:06 -0400] conn=152 op=0 BIND dn="" method=sasl version=3
mech=GSSAPI
[03/May/2016:07:21:06 -0400] conn=152 op=0 RESULT err=14 tag=97 nentries=0
etime=0, SASL bind in progress
[03/May/2016:07:21:06 -0400] conn=152 op=1 BIND dn="" method=sasl version=3
mech=GSSAPI
[03/May/2016:07:21:06 -0400] conn=152 op=1 RESULT err=14 tag=97 nentries=0
etime=0, SASL bind in progress
[03/May/2016:07:21:06 -0400] conn=152 op=2 BIND dn="" method=sasl version=3
mech=GSSAPI
[03/May/2016:07:21:06 -0400] conn=152 op=2 RESULT err=0 tag=97 nentries=0
etime=0
dn="krbprincipalname=ipa-dnskeysyncd/host.example.com at example.com,cn=service
s,cn=accounts,dc=example,dc=com"
[03/May/2016:07:21:06 -0400] conn=152 op=3 SRCH
base="cn=dns,dc=example,dc=com" scope=2
filter="(|(objectClass=idnsZone)(objectClass=idnsSecKey)(objectClass=ipk11Pu
blicKey))" attrs=ALL
[03/May/2016:07:21:06 -0400] conn=152 op=3 RESULT err=269 tag=121 nentries=0
etime=0

-----Original Message-----
From: Petr Spacek [mailto:pspacek at redhat.com] 
Sent: May-03-16 8:50 AM
To: Gary T. Giesen <ggiesen+freeipa-users at giesen.me>;
freeipa-users at redhat.com
Subject: Re: [Freeipa-users] Unable to configure DNSSEC signing

Hmm, this is really weird.

It should log message "Initial LDAP dump is done, sychronizing with ODS and
BIND" which is apparently not there. Maybe LDAP server is doing something
weird ...

Could you inspect /var/log/dirsrv/*/access_log and look for lines similar to
ones in the attached file, please?

It should start with log message like
"connection from local to /var/run/slapd-*".
This line will have identifier like "conn=84". We are looking for conn
number (e.g. "conn=84") which is related to BIND DN
"dn="krbprincipalname=ipa-dnskeysyncd/*".

If you find the right conn number, look for other lines containing the same
conn number and operation "SRCH base="cn=dns,*". This SRCH line will have
specific identifier like "conn=84 op=3".

Now you have identifier for particular operation. Look for RESULT line with
the same ID.

How does it look?

Can you copy&paste complete all lines with identifier conn=??? you found?

Thanks!
Petr^2 Spacek

On 3.5.2016 13:37, Gary T. Giesen wrote:
> See attached.
> 
> GTG
> 
> -----Original Message-----
> From: Petr Spacek [mailto:pspacek at redhat.com]
> Sent: May-03-16 7:33 AM
> To: Gary T. Giesen <ggiesen+freeipa-users at giesen.me>;
> freeipa-users at redhat.com
> Subject: Re: [Freeipa-users] Unable to configure DNSSEC signing
> 
> On 3.5.2016 13:28, Gary T. Giesen wrote:
>> 1. Confirmed, it was already set to ISMASTER=1
>>
>> 2. Logs:
>> ipa.ipapython.dnssec.keysyncer.KeySyncer: DEBUG    Current cookie is:
None
>> May 03 07:21:07 host.example.com ipa-dnskeysyncd[27240]:
>> ipa.ipapython.dnssec.keysyncer.KeySyncer: DEBUG    Detected add of
entry: 
>> May 03 07:21:07 host.example.com ipa-dnskeysyncd[27240]:
>> ipa.ipapython.dnssec.odsmgr.ODSMgr: DEBUG    LDAP zones:
{'203dbe2d-8d9c-1
>> May 03 07:21:07 host.example.com ipa-dnskeysyncd[27240]:
>> ipa.ipapython.dnssec.keysyncer.KeySyncer: DEBUG    Detected add of
entry: 
>> May 03 07:21:07 host.example.com ipa-dnskeysyncd[27240]:
>> ipa.ipapython.dnssec.keysyncer.KeySyncer: DEBUG    Detected add of
entry: 
>> May 03 07:21:07 host.example.com ipa-dnskeysyncd[27240]:
>> ipa.ipapython.dnssec.keysyncer.KeySyncer: DEBUG    Detected add of
entry: 
>> May 03 07:21:07 host.example.com ipa-dnskeysyncd[27240]:
>> ipa.ipapython.dnssec.keysyncer.KeySyncer: DEBUG    Detected add of
entry: 
>> May 03 07:21:07 host.example.com ipa-dnskeysyncd[27240]:
>> ipa.ipapython.dnssec.keysyncer.KeySyncer: DEBUG    Detected add of
entry: 
>> May 03 07:21:07 host.example.com ipa-dnskeysyncd[27240]:
>> ipa.ipapython.dnssec.keysyncer.KeySyncer: DEBUG    Detected add of
entry: 
>> May 03 07:21:07 host.example.com ipa-dnskeysyncd[27240]:
>> ipa.ipapython.dnssec.keysyncer.KeySyncer: DEBUG    New cookie is:
host.exa
> 
> The log seems to be truncated. Please attach it as a file to avoid 
> truncation and line wrapping problems.
> 
> Thanks
> Petr^2 Spacek
> 
>>
>>
>> 3. # rpm -q ipa-server
>> ipa-server-4.2.0-15.0.1.el7.centos.6.1.x86_64
>>
>> -----Original Message-----
>> From: freeipa-users-bounces at redhat.com 
>> [mailto:freeipa-users-bounces at redhat.com] On Behalf Of Petr Spacek
>> Sent: May-03-16 7:08 AM
>> To: freeipa-users at redhat.com
>> Subject: Re: [Freeipa-users] Unable to configure DNSSEC signing
>>
>> Okay, this is a problem. It should list your zone example.com because 
>> it has DNSSEC signing enabled.
>>
>> Make sure you are working on host.example.com (the host listed by the 
>> ldapsearch above).
>>
>> I would check two things:
>> 1. File /etc/sysconfig/ipa-dnskeysyncd contains line "ISMASTER=1". If 
>> it does not, re-run ipa-dns-install with --dnssec-master option to 
>> fix
> that.
>>
>> 2. Debug logs from the daemon. Please edit /etc/ipa/default.conf and 
>> make sure that it contains line "debug=True" and restart 
>> ipa-dnskeysyncd when you are done with it.
>>
>> The log should be much longer after this change.
>>
>> I hope it will help to identify the root cause.
>>
>> What IPA version do you use?
>> $ rpm -q freeipa-server
>>
>> Petr^2 Spacek
>>
>>
>>
>>> Per the instructions, I've restarted ipa-dnskeysyncd, but it has had 
>>> no effect. The only log entries I see are:
>>>
>>> # journalctl -u ipa-dnskeysyncd
>>>
>>> May 02 20:35:52 host.example.com systemd[1]: Stopping IPA key
daemon...
>>> May 02 20:35:52 host.example.com ipa-dnskeysyncd[14903]: ipa         :
>> INFO
>>> Signal 15 received: Shutting down!
>>> May 02 20:35:52 host.example.com systemd[1]: Started IPA key daemon.
>>> May 02 20:35:52 host.example.com systemd[1]: Starting IPA key
daemon...
>>> May 02 20:35:52 host.example.com ipa-dnskeysyncd[15014]: ipa: WARNING:
>>> session memcached servers not running
>>> May 02 20:35:53 host.example.com ipa-dnskeysyncd[15014]: ipa         :
>> INFO
>>> LDAP bind...
>>> May 02 20:35:53 host.example.com python2[15014]: GSSAPI client step 
>>> 1 May 02 20:35:53 host.example.com python2[15014]: GSSAPI client 
>>> step 1 May 02 20:35:54 host.example.com python2[15014]: GSSAPI 
>>> client step 1 May 02 20:35:54 host.example.com python2[15014]: GSSAPI
client step 2
>>> May 02 20:35:54 host.example.com ipa-dnskeysyncd[15014]: ipa         :
>> INFO
>>> Commencing sync process
>>>
>>>
>>>
>>> Can anyone advise on next steps? I've been banging my head against a 
>>> wall for a couple days now and would really appreciate some help.

--
Petr^2 Spacek