ipa-dnskeysyncd crash

[Carlos Silva]

Hi list!

I have a fully update CentOS 7 server running FreeIPA and after a
restart today (or at least it was when I noticed) ipa-dnskeysyncd is
constatly crashing. It fails with this traceback:

Jul 01 23:45:01 srv04.r3pek.org ipa-dnskeysyncd[5582]:
ipa.ipapython.dnssec.bindmgr.BINDMgr: INFO     Synchronizing zone
r3pek.org.
Jul 01 23:45:01 srv04.r3pek.org ipa-dnskeysyncd[5582]:
ipa.ipapython.dnssec.bindmgr.BINDMgr: INFO     attrs:
{'idnsseckeyref': ['pkcs11:object=xxx'], 'dn':
'cn=xxxxx,cn=keys,idnsname=r3pek.org.,cn=dns,dc=r3pek,dc=org', 'cn':
['xxxxx'], 'idnsseckeypublish': ['xxxxxx'], 'objectclass':
['idnsSecKey'], 'idnssecalgorithm': ['RSASHA256'], 'idnsseckeyzone':
['TRUE'], 'idnsseckeycreated': ['xxxxxx'], 'idnsseckeyactivate':
['xxxxxx']}
Jul 01 23:45:01 srv04.r3pek.org ipa-dnskeysyncd[5582]:
ipa.ipapython.dnssec.bindmgr.BINDMgr: INFO     attrs:
{'idnsseckeyref': ['pkcs11:object=xxxxxxxx'], 'dn':
'cn=xxxxxx,cn=keys,idnsname=r3pek.org.,cn=dns,dc=r3pek,dc=org', 'cn':
['xxxxxxxx'], 'idnsseckeypublish': ['20170108222825Z'], 'objectclass':
['idnsSecKey'], 'idnsseckeydelete': ['xxxxxx'], 'idnssecalgorithm':
['RSASHA256'], 'idnsseckeyzone': ['TRUE'], 'idnsseckeycreated':
['xxxxxxxx'], 'idnsseckeyinactive': ['xxxxxxxx'],
'idnsseckeyactivate': ['xxxxxxx']}
Jul 01 23:45:01 srv04.r3pek.org ipa-dnskeysyncd[5582]: Traceback (most
recent call last):
Jul 01 23:45:01 srv04.r3pek.org ipa-dnskeysyncd[5582]: File
"/usr/libexec/ipa/ipa-dnskeysyncd", line 110, in <module>
Jul 01 23:45:01 srv04.r3pek.org ipa-dnskeysyncd[5582]: while
ldap_connection.syncrepl_poll(all=1, msgid=ldap_search):
Jul 01 23:45:01 srv04.r3pek.org ipa-dnskeysyncd[5582]: File
"/usr/lib64/python2.7/site-packages/ldap/syncrepl.py", line 405, in
syncrepl_poll
Jul 01 23:45:01 srv04.r3pek.org ipa-dnskeysyncd[5582]:
self.syncrepl_refreshdone()
Jul 01 23:45:01 srv04.r3pek.org ipa-dnskeysyncd[5582]: File
"/usr/lib/python2.7/site-packages/ipapython/dnssec/keysyncer.py", line
117, in syncrepl_refreshdone
Jul 01 23:45:01 srv04.r3pek.org ipa-dnskeysyncd[5582]:
self.bindmgr.sync(self.dnssec_zones)
Jul 01 23:45:01 srv04.r3pek.org ipa-dnskeysyncd[5582]: File
"/usr/lib/python2.7/site-packages/ipapython/dnssec/bindmgr.py", line
206, in sync
Jul 01 23:45:01 srv04.r3pek.org ipa-dnskeysyncd[5582]: self.sync_zone(zone)
Jul 01 23:45:01 srv04.r3pek.org ipa-dnskeysyncd[5582]: File
"/usr/lib/python2.7/site-packages/ipapython/dnssec/bindmgr.py", line
179, in sync_zone
Jul 01 23:45:01 srv04.r3pek.org ipa-dnskeysyncd[5582]:
self.install_key(zone, uuid, attrs, tempdir)
Jul 01 23:45:01 srv04.r3pek.org ipa-dnskeysyncd[5582]: File
"/usr/lib/python2.7/site-packages/ipapython/dnssec/bindmgr.py", line
114, in install_key
Jul 01 23:45:01 srv04.r3pek.org ipa-dnskeysyncd[5582]: result =
ipautil.run(cmd, capture_output=True)
Jul 01 23:45:01 srv04.r3pek.org ipa-dnskeysyncd[5582]: File
"/usr/lib/python2.7/site-packages/ipapython/ipautil.py", line 494, in
run
Jul 01 23:45:01 srv04.r3pek.org ipa-dnskeysyncd[5582]: raise
CalledProcessError(p.returncode, arg_string, str(output))
Jul 01 23:45:01 srv04.r3pek.org ipa-dnskeysyncd[5582]:
subprocess.CalledProcessError: Command
'/usr/sbin/dnssec-keyfromlabel-pkcs11 -K
/var/named/dyndb-ldap/ipa/master/r3pek.org/tmpJzMW9A -a RSASHA256 -l
pkcs11:object=e60654a85b9927752d2f5f526af0317a;pin-source=/var/lib/ipa/dnssec/softhsm_pin
-I 20170408214422 -D 20170423112007 -P 20170108222825 -A
20170108222825 r3pek.org.' returned non-zero exit status 1

I run a "watch -n0.1 ls -lh
/var/named/dyndb-ldap/ipa/master/r3pek.org/" and as far as I can see,
that tmp file is never created, maybe that could be the problem?

[Carlos Silva]

OK, just a quick update.
The temp "file" is actually created and I managed to copy the
directory over to try the command myself.

It fails with "dnssec-keyfromlabel: fatal: failed to get key
r3pek.org/RSASHA256: crypto failure"

Don't know what that means :-/ (besides de obvious)

[Carlos Silva]

My bad :)

The actual error message is (after I sourced the env file myself):
dnssec-keyfromlabel: fatal: failed to get key r3pek.org/RSASHA256: not found

[Carlos Silva]

OK, for future reference if someone finds this thread on the archives.

I read this thread [1] and after debugging, I found out that I had one
extra ZSK key on the directory server (explored with 389-console).

After I deleted the key that was *not* in the output of "ods-ksmutil
key list --verbose" [2], the service started normally and didn't crash
anymore.

[1] https://pagure.io/freeipa/issue/5334
[2] http://www.freeipa.org/page/Troubleshooting#DNS_keys_are_not_generated_by_Op...