freeipa

Clone
Source Code
GIT

#9216 [Tracker] Nightly failure: zone not signed
Closed: fixed 2 years ago by frenaud. Opened 2 years ago by frenaud.

Closed: fixed
Reopen Issue

The nightly tests running with the updates-testing repository detected regresssions related to DNSSEC. See for instance PR #1919 with failures in the following tests:
- test_backup_and_restore_TestBackupAndRestoreWithDNSSEC
- test_backup_and_restore_TestBackupReinstallRestoreWithDNSSEC
- test_dnssec

The tests have a similar scenario, where DNSSEC is enabled, then a zone added with dnssec and the test checks that the zone is signed after a 100-sec timeout.
The timeout expires but the zone is not signed.

Investigations for test_dnssec from this run:

The test is adding a signed zone with ipa dnszone-add dnssec.test. --skip-overlap-check --dnssec true --ttl 1 --default-ttl 1: /var/log/httpd/error_log

[Thu Aug 04 07:30:47.923537 2022] [wsgi:error] [pid 22469:tid 22983] [remote 192.168.122.54:49750] ipa: INFO: [jsonserver_session] admin@IPA.TEST: dnszone_add/1('dnssec.test.', dnsttl=1, dnsdefaultttl=1, idnssecinlinesigning=True, skip_overlap_check=True, version='2.249'): SUCCESS

Bind detects that the zone should be signed but doesn't find the key: /var/named/data/dnssec.log

04-Aug-2022 07:30:47.791 info: zone dnssec.test/IN (signed): reconfiguring zone keys
04-Aug-2022 07:30:47.791 debug 1: zone dnssec.test/IN (signed): zone_rekey:dns_dnssec_findmatchingkeys failed: not found
04-Aug-2022 07:30:47.791 info: zone dnssec.test/IN (signed): next key event: 04-Aug-2022 08:30:47.791

The journal shows a traceback when ipa-dnskeysyncd calls /usr/sbin/dnssec-keyfromlabel:
journal

Aug 04 07:30:53 master.ipa.test ipa-dnskeysyncd[22921]: Traceback (most recent call last):
Aug 04 07:30:53 master.ipa.test ns-slapd[21235]: [04/Aug/2022:07:30:53.247463774 +0000] - DEBUG - NSMMReplicationPlugin - agmt="cn=meToreplica1.ipa.test" (replica1:389): {replica 4 ldap://master.ipa.test:389} 62eb733b000100040000 62eb75ac000300040000 00000000
Aug 04 07:30:53 master.ipa.test ipa-dnskeysyncd[22921]:   File "/usr/libexec/ipa/ipa-dnskeysyncd", line 130, in <module>
Aug 04 07:30:53 master.ipa.test ipa-dnskeysyncd[22921]:     while ldap_connection.syncrepl_poll(all=1, msgid=ldap_search):
Aug 04 07:30:53 master.ipa.test ns-slapd[21235]: [04/Aug/2022:07:30:53.249375626 +0000] - DEBUG - NSMMReplicationPlugin - changelog program - _cl5PositionCursorForReplay - (agmt="cn=meToreplica1.ipa.test" (replica1:389)): Supplier RUV:
Aug 04 07:30:53 master.ipa.test ipa-dnskeysyncd[22921]:   File "/usr/lib64/python3.10/site-packages/ldap/syncrepl.py", line 435, in syncrepl_poll
Aug 04 07:30:53 master.ipa.test ipa-dnskeysyncd[22921]:     self.syncrepl_entry(dn, attrs, c.entryUUID)
Aug 04 07:30:53 master.ipa.test ipa-dnskeysyncd[22921]:   File "/usr/lib/python3.10/site-packages/ipaserver/dnssec/syncrepl.py", line 70, in syncrepl_entry
Aug 04 07:30:53 master.ipa.test ipa-dnskeysyncd[22921]:     self.application_add(uuid, dn, attributes)
Aug 04 07:30:53 master.ipa.test ipa-dnskeysyncd[22921]:   File "/usr/lib/python3.10/site-packages/ipaserver/dnssec/keysyncer.py", line 84, in application_add
Aug 04 07:30:53 master.ipa.test ns-slapd[21235]: [04/Aug/2022:07:30:53.254521462 +0000] - DEBUG - NSMMReplicationPlugin - agmt="cn=meToreplica1.ipa.test" (replica1:389): {replicageneration} 62eb733b000000040000
Aug 04 07:30:53 master.ipa.test ipa-dnskeysyncd[22921]:     self.key_meta_add(uuid, dn, attributes)
Aug 04 07:30:53 master.ipa.test ipa-dnskeysyncd[22921]:   File "/usr/lib/python3.10/site-packages/ipaserver/dnssec/keysyncer.py", line 137, in key_meta_add
Aug 04 07:30:53 master.ipa.test ipa-dnskeysyncd[22921]:     self.bindmgr_sync(self.dnssec_zones)
Aug 04 07:30:53 master.ipa.test ipa-dnskeysyncd[22921]:   File "/usr/lib/python3.10/site-packages/ipaserver/dnssec/keysyncer.py", line 150, in bindmgr_sync
Aug 04 07:30:53 master.ipa.test ipa-dnskeysyncd[22921]:     self.bindmgr.sync(dnssec_zones)
Aug 04 07:30:53 master.ipa.test ipa-dnskeysyncd[22921]:   File "/usr/lib/python3.10/site-packages/ipaserver/dnssec/bindmgr.py", line 232, in sync
Aug 04 07:30:53 master.ipa.test ipa-dnskeysyncd[22921]:     self.sync_zone(zone)
Aug 04 07:30:53 master.ipa.test ipa-dnskeysyncd[22921]:   File "/usr/lib/python3.10/site-packages/ipaserver/dnssec/bindmgr.py", line 205, in sync_zone
Aug 04 07:30:53 master.ipa.test ipa-dnskeysyncd[22921]:     self.install_key(zone, uuid, attrs, tempdir)
Aug 04 07:30:53 master.ipa.test ipa-dnskeysyncd[22921]:   File "/usr/lib/python3.10/site-packages/ipaserver/dnssec/bindmgr.py", line 146, in install_key
Aug 04 07:30:53 master.ipa.test ipa-dnskeysyncd[22921]:     result = ipautil.run(cmd, capture_output=True)
Aug 04 07:30:53 master.ipa.test ipa-dnskeysyncd[22921]:   File "/usr/lib/python3.10/site-packages/ipapython/ipautil.py", line 599, in run
Aug 04 07:30:53 master.ipa.test ipa-dnskeysyncd[22921]:     raise CalledProcessError(
Aug 04 07:30:53 master.ipa.test ipa-dnskeysyncd[22921]: ipapython.ipautil.CalledProcessError: CalledProcessError(Command ['/usr/sbin/dnssec-keyfromlabel', '-E', 'pkcs11', '-K', '/var/named/dyndb-ldap/ipa/master/dnssec.test/tmpm039l3lq', '-a', b'RSASHA256', '-l', b'pkcs11:object=3a1fca9fde28734d1f7ff7e4930fe137;pin-source=/var/lib/ipa/dnssec/softhsm_pin', '-P', b'20220804073048', '-A', 'none', '-I', 'none', '-D', 'none', '-E', 'pkcs11', 'dnssec.test.'] returned non-zero exit status 1: 'dnssec-keyfromlabel: warning: ENGINE_load_private_key failed (not found)\ndnssec-keyfromlabel: fatal: failed to get key dnssec.test/RSASHA256: not found\n')

The normal behavior is:

  • zone is created with ipa dnszone-add --dnssec true <zone>, which adds a new LDAP entry for the zone
  • ipa-dnskeysyncd detects the new zone by listening for new LDAP entries
  • ipa-dnskeysyncd daemon calls ods-ksmutil or ods-enforcer to add the zone, which results in a new zone in /var/opendnssec/enforcer/zones.xml
  • enforcerd creates the keys in the HSM and in LDAP (new entries ipk11UniqueID=...,cn=keys,cn=sec,cn=dns,dc=ipa,dc=test, cn=ZSK-...,cn=keys,idnsname=dnssec.test.,cn=dns,dc=ipa,dc=test and cn=KSK-...,cn=keys,idnsname=dnssec.test.,cn=dns,dc=ipa,dc=test visible in the audit.log)
  • ipa-dnskeysyncd detects the new entry and calls dnssec-keyfromlabel in order to create a file in /var/named/dyndb-ldap/ipa/master/<zone>/keys for the key stored in the HSM, then calls rndc sign
  • the bind daemon signs the zone, creates DNSKEY records and RRSIG records

Here, the call to dnssec-keyfromlabel is failing:

/usr/sbin/dnssec-keyfromlabel -E pkcs11 -K /var/named/dyndb-ldap/ipa/master/dnssec.test/tmpm039l3lq -a RSASHA256 -l pkcs11:object=3a1fca9fde28734d1f7ff7e4930fe137;pin-source=/var/lib/ipa/dnssec/softhsm_pin -P 20220804073048 -A none -I none -D none -E pkcs11 dnssec.test.

The issue seems related to the openssl-pkcs11 version: the test is working with openssl-pkcs11-0.4.11-8.fc36.x86_64 but failing with openssl-pkcs11-0.4.12-1.fc36.x86_64.

Opening https://bugzilla.redhat.com/show_bug.cgi?id=2115865 against openssl-pkcs11 to track the issue.

Metadata Update from @frenaud:
- Issue tagged with: tracker
2 years ago

Update:

Our azure CI is now also failing as the update of openssl-pkcs11 has reached the stable repo (https://bodhi.fedoraproject.org/updates/FEDORA-2022-99638efc30). Azure tests include test_integration/test_dnssec.py::TestInstallDNSSECFirst which is failing and needs to be disabled until https://bugzilla.redhat.com/show_bug.cgi?id=2115865 is fixed.

master:

  • 4ae9c78 azure tests: disable TestInstallDNSSECFirst

ipa-4-10:

  • eb9f606 azure tests: disable TestInstallDNSSECFirst

ipa-4-9:

  • d40fd28 azure tests: disable TestInstallDNSSECFirst

2115865 has been fixed on fedira 36 but there is another issue against rawhide/f37: 2117342

ipa-4-10:

  • a6485d6 Tests: test on f37 and f36
  • 40b9c6f ipatests: mark xfail tests using sssctl domain-status
  • 3d093c6 ipatests: mark xfail tests using dnssec

master:

  • 43fcfe4 Tests: test on f37 and f36
  • 4a4f7e7 ipatests: mark xfail tests using sssctl domain-status
  • 96cf293 ipatests: mark xfail tests using dnssec

master:

  • dface55 Spec file: bump bind version on f37+
  • d9ecb12 ipatests: re-enable dnssec tests

ipa-4-10:

  • 1dfb5d5 Spec file: bump bind version on f37+
  • 9b1af71 ipatests: re-enable dnssec tests

Metadata Update from @frenaud:
- Issue close_status updated to: fixed
- Issue status updated to: Closed (was: Open)
2 years ago

Log in to comment on this ticket.

Metadata
None

test-failure tracker

None
None
None
None
None
None
None
None
None
None
None
None
None
None
None
None
None
None
None
None
None
None
Powered by Pagure 5.14.1
Documentation • File an Issue • About • SSH Hostkey/Fingerprint
© Red Hat, Inc. and others.