freeipa

#5334 DNSSEC key purging is not handled properly
Closed: Fixed Opened by pdf.

Closed: Fixed
Reopen Issue

This is not the first time I've had this occur, so I'm reporting it now. One of my zones has stopped signing, and so for resolvers that validate DNSSEC (eg Google's public resolvers), the zone is effectively gone from the Internet. Last time it happened I just resigned the zone and waited for the propagation delays, but given the time periods involved, and that it has happened again, I'd like to try and get it fixed - having zones missing for days on a semi-regular basis is not a tenable situation.

Below is the stack trace I get when ipa-dnskeysyncd tries to synchronize the zone:

Sep 30 20:04:19 dnsmaster.example.com ipa-dnskeysyncd[25797]: ipa.ipapython.dnssec.bindmgr.BINDMgr: INFO
Sep 30 20:04:19 dnsmaster.example.com ipa-dnskeysyncd[25797]: ipa.ipapython.dnssec.bindmgr.BINDMgr: INFO     Synchronizing zone example.com.
Sep 30 20:04:19 dnsmaster.example.com ipa-dnskeysyncd[25797]: ipa.ipapython.dnssec.bindmgr.BINDMgr: INFO     attrs: {'idnsseckeyref': ['pkcs11:object=hash1'], 'dn': 'cn=ZSK-20150531030418Z-hash1,cn=keys,idnsname=example.com.,cn=dns,dc=example,dc=com', 'cn': ['ZSK-20150531030418Z-hash1'], 'idnsseckeypublish': ['20150531030419Z'], 'objectclass': ['idnsSecKey'], 'idnssecalgorithm': ['RSASHA256'], 'idnsseckeyzone': ['TRUE'], 'idnsseckeycreated': ['20150531030418Z']}
Sep 30 20:04:19 dnsmaster.example.com python2[25797]: detected unhandled Python exception in '/usr/libexec/ipa/ipa-dnskeysyncd'
Sep 30 20:04:20 dnsmaster.example.com ipa-dnskeysyncd[25797]: Traceback (most recent call last):
Sep 30 20:04:20 dnsmaster.example.com ipa-dnskeysyncd[25797]: File "/usr/libexec/ipa/ipa-dnskeysyncd", line 112, in <module>
Sep 30 20:04:20 dnsmaster.example.com ipa-dnskeysyncd[25797]: while ldap_connection.syncrepl_poll(all=1, msgid=ldap_search):
Sep 30 20:04:20 dnsmaster.example.com ipa-dnskeysyncd[25797]: File "/usr/lib64/python2.7/site-packages/ldap/syncrepl.py", line 409, in syncrepl_poll
Sep 30 20:04:20 dnsmaster.example.com ipa-dnskeysyncd[25797]: self.syncrepl_refreshdone()       
Sep 30 20:04:20 dnsmaster.example.com ipa-dnskeysyncd[25797]: File "/usr/lib/python2.7/site-packages/ipapython/dnssec/keysyncer.py", line 115, in syncrepl_refreshdone
Sep 30 20:04:20 dnsmaster.example.com ipa-dnskeysyncd[25797]: self.bindmgr.sync()               
Sep 30 20:04:20 dnsmaster.example.com ipa-dnskeysyncd[25797]: File "/usr/lib/python2.7/site-packages/ipapython/dnssec/bindmgr.py", line 194, in sync
Sep 30 20:04:20 dnsmaster.example.com ipa-dnskeysyncd[25797]: self.sync_zone(zone)              
Sep 30 20:04:20 dnsmaster.example.com ipa-dnskeysyncd[25797]: File "/usr/lib/python2.7/site-packages/ipapython/dnssec/bindmgr.py", line 177, in sync_zone
Sep 30 20:04:20 dnsmaster.example.com ipa-dnskeysyncd[25797]: self.install_key(zone, uuid, attrs, tempdir)
Sep 30 20:04:20 dnsmaster.example.com ipa-dnskeysyncd[25797]: File "/usr/lib/python2.7/site-packages/ipapython/dnssec/bindmgr.py", line 113, in install_key
Sep 30 20:04:20 dnsmaster.example.com ipa-dnskeysyncd[25797]: basename = ipautil.run(cmd)[0].strip()
Sep 30 20:04:20 dnsmaster.example.com ipa-dnskeysyncd[25797]: File "/usr/lib/python2.7/site-packages/ipapython/ipautil.py", line 373, in run
Sep 30 20:04:20 dnsmaster.example.com ipa-dnskeysyncd[25797]: raise CalledProcessError(p.returncode, arg_string, stdout)
Sep 30 20:04:20 dnsmaster.example.com ipa-dnskeysyncd[25797]: subprocess.CalledProcessError: Command ''/usr/sbin/dnssec-keyfromlabel-pkcs11' '-K' '/var/named/dyndb-ldap/ipa/master/example.com/tmpazgVEt' '-a' 'RSASHA256' '-l' 'pkcs11:object=hash1;pin-source=/var/lib/ipa/dnssec/softhsm_pin' '-P' '20150531030419' 'example.com.'' returned non-zero exit status 1
Sep 30 20:04:20 dnsmaster.example.com systemd[1]: ipa-dnskeysyncd.service: main process exited, code=exited, status=1/FAILURE
Sep 30 20:04:20 dnsmaster.example.com systemd[1]: Unit ipa-dnskeysyncd.service entered failed state.
Sep 30 20:04:20 dnsmaster.example.com systemd[1]: ipa-dnskeysyncd.service failed.

Please let me know what additional information I can provide. This is a lesser-used domain, so I have a little leeway, but I would certainly appreciate any help that might be obtained in a timely fashion so it's not gone for too long.

Hrm, this has resolved itself somehow this time, though it was out for nearly 12 hours. I'll mark this as deferred for now, until I'm in a position to trouble-shoot again (if this is not the correct course of action, please let me know or update as you see fit).

Hmm, interesting. First of all, please add line debug=True into file /etc/ipa/default.conf and restart IPA. It will give us more details when this happens next time.

When it happens, please run following commands:

sudo -u named -s /bin/bash
source /etc/sysconfig/named
export PKCS11_PROVIDER
export SOFTHSM2_CONF
python2 /usr/lib/python2.*/site-packages/ipapython/dnssec/localhsm.py
<execute the dnssec-keyfromlabel-pkcs11 command which is failing according to the log>

Thank you!

Most probably duplicate of #5348.

@pspacek this doesn't appear to be a duplicate of #5348 since mbasti notes that restarting named-pkcs11 fixes that, however doing so has no impact on this issue. It is occurring for me now, so I have a window to troubleshoot before it either resolves itself as last time, or I have to bite the bullet and replace the keys (which I had to do the time before, and is obviously very painful due to timeouts and propagation).

I can't execute the failing command usefully because it depends on the stemp dir being created by whatever other process precedes it during normal execution.

Does the localhsm.py output include sensitive information? If so, can I send it to you off-tracker?

Debug ipa-dnskeysyncd log
ipa-dnskeysyncd.log

Replying to [comment:5 pdf]:

I can't execute the failing command usefully because it depends on the stemp dir being created by whatever other process precedes it during normal execution.

Ah, I forgot about that. Just replace the path to the directory with something existing, /tmp should be okay. The generated files do not contain any sensitive information, just timestamps and key ID.

Does the localhsm.py output include sensitive information? If so, can I send it to you off-tracker?
No, there is nothing sensitive in there, just key ID and attributes. The private key will never leave 'HSM' in an unencrypted form.

Is the error popping out on DNSSEC key master? (Running opendnssec's ods-enforcered service?) Or a replica? (Without ods-enforcered service?) Or both?

Replying to [comment:6 pspacek]:

Ah, I forgot about that. Just replace the path to the directory with something existing, /tmp should be okay. The generated files do not contain any sensitive information, just timestamps and key ID.

Executing the command simply outputs:

dnssec-keyfromlabel: fatal: failed to get key failingdomain.com/RSASHA256: not found

No, there is nothing sensitive in there, just key ID and attributes. The private key will never leave 'HSM' in an unencrypted form.

Will attach momentarily.

Is the error popping out on DNSSEC key master? (Running opendnssec's ods-enforcered service?) Or a replica? (Without ods-enforcered service?) Or both?

This is occurring on the master only.

localhsm.py output
localhsm.py.txt

Interesting ... Could you please upload output from localhsm.py (using the same commands) also from one other replica where it works?

Thank you!

Also, please provide output generated by command ods-ksmutil key list --verbose running on DNSSEC key master as described on page
http://www.freeipa.org/page/Troubleshooting#DNS_keys_are_not_generated_by_OpenDNSSEC

Thank you.

localhsm.py output from replica
localhsm.py-replica.txt

ods-ksmutil key list --verbose
ods-ksmutil.txt

Attached, thanks for taking a look.

Thank you very much. This is really really weird because the key is present on replica but not on the master, hmm. I will try to reproduce it locally. In meantime you might try to delete LDAP object cn=ZSK-20150530170525Z-ce36572b364d1ca95962273e57c28240,cn=keys,idnsname=failingdomain.com.,cn=dns,dc=example,dc=com and restart the ipa-dnskeysyncd, it might be enough to workaround it.

The affected key should not be used for signing anyway (inactivity period started at 20150920123018Z, it is apparently the old, already rotated ZSK key) so you might be lucky enough if you do not have TTLs longer than 3 days or so.

Please let me know if it helped or not.

Looks like I had one more key in the same state, having deleted them both I believe I'm in good shape - ipa-dnskeysyncd is happy and keys appear to be tracing correctly on all domains. Thanks you greatly.

Is there anything else I can do to help track down the source of this in future?

Ticket has not been triaged.

I think that we have enough information now, thank you very much for cooperation! It seems the we do not properly handle key purging in OpenDNSSEC which happens 14 days after the key is not used anymore. Considering the fact that ZSK is rotatech each 3 months, it explains why it happens so rarely. We have to fix this.

Ticket has been cloned to Bugzilla: https://bugzilla.redhat.com/show_bug.cgi?id=1296214

master:

  • 9bcb9887eab496a98a46c149c93c517c5dcb99c7 DNSSEC: Improve error reporting from ipa-ods-exporter
  • 9ff1c0ac297cba8c0d5a87f6ecfa7d41169476c0 DNSSEC: Make sure that current state in OpenDNSSEC matches key state in LDAP
  • 21e6cc6863a0bf7d832cf04dedfc3a2bdd22a78f DNSSEC: Make sure that current key state in LDAP matches key state in BIND
  • e9cdaa19924a16e811ebbdd04d5a305b0608304a DNSSEC: remove obsolete TODO note
  • 3c9c37cec1180fb6adcb8d59e367cf022d73aef1 DNSSEC: add debug mode to ldapkeydb.py
  • 6bdc18d0c538c658ae6022b127bf5776436f68e7 DNSSEC: logging improvements in ipa-ods-exporter
  • ddf7397a4beb8095a24981998461aecc0e1ec40d DNSSEC: remove keys purged by OpenDNSSEC from master HSM from LDAP
  • 43acb994f6cd78098f5dc3671c14b3ab17ca164b DNSSEC: ipa-dnskeysyncd: Skip zones with old DNSSEC metadata in LDAP
  • 9fbbe3e574c5f42e3896d9c3bee22db84d46501d DNSSEC: ipa-ods-exporter: add ldap-cleanup command
  • fe263f764b9d8eabf8ae0fa284f167fec10b4a4d DNSSEC: ipa-dnskeysyncd: call ods-signer ldap-cleanup on zone removal
  • ae2462738b47c0f00133ae377854b31ddcb912a2 DNSSEC: Log debug messages at log level DEBUG

ipa-4-3:

  • 86ee4930c1ce066d8d1448926e9202c1d08a91d5 DNSSEC: Improve error reporting from ipa-ods-exporter
  • d26c9c8682b0ae40454a720736d36989bf167e63 DNSSEC: Make sure that current state in OpenDNSSEC matches key state in LDAP
  • 84b70923591dff289fb60f483f950a9c51e4e941 DNSSEC: Make sure that current key state in LDAP matches key state in BIND
  • c6efac4657971a46465c337f21d89b532f07831c DNSSEC: remove obsolete TODO note
  • c527e8f6695ee0e4f47854339c852b644a30047e DNSSEC: add debug mode to ldapkeydb.py
  • 9b4be488a0e1bfba065b8c818d23b89c318aced9 DNSSEC: logging improvements in ipa-ods-exporter
  • 819e3d48860d95e777a1e7d33241a281900d86fb DNSSEC: remove keys purged by OpenDNSSEC from master HSM from LDAP
  • b52cb1b27201383b7c25a2f6d316abe173c6f6d9 DNSSEC: ipa-dnskeysyncd: Skip zones with old DNSSEC metadata in LDAP
  • 5070fa1a9be38b9e92c2f310a1632182144dfef3 DNSSEC: ipa-ods-exporter: add ldap-cleanup command
  • b21492f82dc8bbda63b660640a953a5ae6ffd509 DNSSEC: ipa-dnskeysyncd: call ods-signer ldap-cleanup on zone removal
  • 2e85644ab29720b07d766532d3838e08034495d8 DNSSEC: Log debug messages at log level DEBUG

ipa-4-2 needs rebase - later

ipa-4-2:

  • d2022d0b4f96e16862f2bf73e5df07e45b115636 DNSSEC: Improve error reporting from ipa-ods-exporter
  • cb8a95870137d28cc85069059c674864c9eef7f9 DNSSEC: Make sure that current state in OpenDNSSEC matches key state in LDAP
  • 52369bbf0a476de161e246f4b4207daf3d8193a2 DNSSEC: Make sure that current key state in LDAP matches key state in BIND
  • 9beb33c4f887ee2000091eb8b4d60d047e405dfa DNSSEC: remove obsolete TODO note
  • aa76c601c01f8b27015ac72ef176e59ad9fe963d DNSSEC: add debug mode to ldapkeydb.py
  • 3eaabd9268a1b7368dab476cb140b00a3978fe7a DNSSEC: logging improvements in ipa-ods-exporter
  • 66473494fcb5e273ea1305f20f0dfaf597c052e3 DNSSEC: remove keys purged by OpenDNSSEC from master HSM from LDAP
  • 2e6c3b3d31eecd76e0db93c81173790df5c7e727 DNSSEC: ipa-dnskeysyncd: Skip zones with old DNSSEC metadata in LDAP
  • dfefa6de7c1162d28864e680e5bf3dffeab07e6f DNSSEC: ipa-ods-exporter: add ldap-cleanup command
  • ab0b5e974399d9dbc66009ffa22de7f1dda26766 DNSSEC: ipa-dnskeysyncd: call ods-signer ldap-cleanup on zone removal
  • 614d9affb339020485e45b229c5431279763bfc6 DNSSEC: Log debug messages at log level DEBUG

Steps to reproduce

  1. Sign a DNS zone with DNSSEC

  2. Look at list of keys associated with the DNS zone (on DNSSEC key master):

    $ ods-ksmutil key list --verbose

  3. Compare this list with all the keys in HSM on master and all replicas:

    $ python2 /usr/lib/python2.*/site-packages/ipapython/dnssec/localhsm.py

  4. Wait for key rotation to happen (see /etc/opendnssec/kasp.xml for config)

  5. Wait for key purging interval to pass (see /etc/opendnssec/kasp.xml for config)

At this point, some of previously-used keys should be purged from HSM and LDAP. Check it the deleted keys were removed from OpenDNSSEC & HSM on all the replicas:
6. Look at list of keys associated with the DNS zone (on DNSSEC key master):

$ ods-ksmutil key list --verbose

  1. Compare this list with all the keys in HSM on master and all replicas:

    $ python2 /usr/lib/python2.*/site-packages/ipapython/dnssec/localhsm.py

Metadata Update from @pdf:
- Issue assigned to pspacek
- Issue set to the milestone: FreeIPA 4.2.4
Metadata
None
None
None
Low
defect
DNS
1
Static archive. pagure.io was sunset in 2026; this is a read-only snapshot.
Red Hat Logo

Fedora is sponsored by Red Hat. Learn more about the relationship between Red Hat and Fedora »

© Red Hat, Inc. and others.