[Opendnssec-user] Stand-by key being rolled over?

[Sebastian Castro]

Hi:

After upgrading to OpenDNSSEC 1.2rc3, I saw a strange situation. For a
couple of zones, the stand-by key was "rolled over". The first evidence
was OpenDNSSEC notifying with an hour of difference about the existence
of new DS records. In my testing environment, whenever a new DS record
appears is internally included in the parent zone.

The next step is manually check if the DS record is present in the
parent (we have a script for that). If so, the key is marked as ds-seen.

To collect data, we run once per hour the command 'ods-ksmutil key list'
to keep information about the status of the keys, but the enforcer runs
each 15 minutes, missing some transitions. Also for auditing we modified
ods-ksmutil to log each call including the parameters.

For one of the zones (dns.net.nz), the key transition looks like:

                    Date     26545     19851      4768     11481
Tue Jan 11 10:13:41 2011 keypublis   publish    active     dssub
Tue Jan 11 10:20:01 2011 keypublis   publish    active     dssub
Tue Jan 11 11:20:01 2011    retire    active    retire dspublish
Tue Jan 11 12:20:01 2011    retire    active    retire dspublish
Tue Jan 11 13:20:01 2011    retire    active    retire   dsready
Tue Jan 11 14:20:02 2011    retire    active    retire   dsready
Tue Jan 11 15:20:01 2011              active             dsready
Tue Jan 11 16:20:01 2011              active             dsready
Tue Jan 11 17:20:01 2011              active             dsready

The output of ods-ksmutil (ZSK intentionally deleted) looks like:

dns.net.nz     KSK           active    2011-01-10 20:20:43
ac293d8db22c2e33cf0e35c2f5d3facc  softHSM                           4768
dns.net.nz     KSK           keypublish 2011-01-11 10:59:02
07e3dac7c7b9fffd33482eb1ef9aa3c0  softHSM                          26545
dns.net.nz     KSK           publish   2011-01-11 10:59:02
5cec637087cc0a009224e58e028f8caf  softHSM                          19851
dns.net.nz     KSK           dssub     waiting for ds-seen
b105f8229856b4fb4f536a1bbcac8812  softHSM                          11481

For this zone, the chronology goes:

9:23, new DS notification (07e3dac7c7b9fffd33482eb1ef9aa3c0,
5cec637087cc0a009224e58e028f8caf, b105f8229856b4fb4f536a1bbcac8812)
11:12, new DS notification (ac293d8db22c2e33cf0e35c2f5d3facc,
5cec637087cc0a009224e58e028f8caf, b105f8229856b4fb4f536a1bbcac8812)
11:17, ds-seen for 5cec637087cc0a009224e58e028f8caf and
b105f8229856b4fb4f536a1bbcac8812


For the other zone (pgp.net.nz) we have more complete data:

                    Date     34411     50076     47655     45061
Wed Jan 12 06:20:01 2011             dsready    active
Wed Jan 12 07:20:01 2011             dsready    active
Wed Jan 12 08:20:01 2011             dsready    active
Wed Jan 12 09:20:01 2011   publish   dsready    active
Wed Jan 12 10:20:01 2011   publish keypublis    active
Wed Jan 12 11:20:01 2011    active keypublis    retire     dssub
Wed Jan 12 12:20:01 2011    active    active    retire dspublish
Wed Jan 12 13:20:01 2011    active    active             dsready
Wed Jan 12 14:20:01 2011    active    active             dsready
Wed Jan 12 15:20:01 2011    active    active             dsready
Wed Jan 12 16:20:02 2011    active    active             dsready
Wed Jan 12 17:20:02 2011    active    active             dsready


Chronology:

09:57, enforcer complains with 'Rollover of KSK expected at 2011
-01-12 10:07:16'
10:14, enforcer complains with "WARNING: KSK rollover for zone
'pgp.net.nz' not completed as there are no keys in the 'ready' state"
10:25, new DS notification (b71c50aa3230af16325d52e4ffe18614,
2a933ecb7e4493f80e5b0c46951e9c74, c9aaebee719b5c001510c44a3781e83a)
10:44, new DS notification (b71c50aa3230af16325d52e4ffe18614,
2a933ecb7e4493f80e5b0c46951e9c74, c9aaebee719b5c001510c44a3781e83a) Yes,
no typo, the same cka_ids
11:17, keytag 34411 and 45601 are marked as ds-seen

ods-ksmutil at 11:20

pgp.net.nz     KSK           keypublish 2011-01-12 11:35:44
b71c50aa3230af16325d52e4ffe18614  softHSM                          50076
pgp.net.nz     KSK           retire    2011-01-12 12:47:31
c50704b0e4acc373130b69ca4dede316  softHSM                          47655
pgp.net.nz     KSK           active    2011-01-13 11:17:31
2a933ecb7e4493f80e5b0c46951e9c74  softHSM                          34411
pgp.net.nz     KSK           dssub     waiting for ds-seen
c9aaebee719b5c001510c44a3781e83a  softHSM                          45061


The question here is: why key 50076 moved from dsready to keypublish
without intervention? The policy uses Manual Rollovers and Manual
Generation.

During this collection I found out it's really hard to track the key
transition. Thought about some sort of transaction log over the KASP,
but it seems not straightforward. Does anyone share this perception?

Is there anything more I could do to help track this issue?


Cheers,
-- 
Sebastian Castro
DNS Specialist
.nz Registry Services (New Zealand Domain Name Registry Limited)
desk: +64 4 495 2337
mobile: +64 21 400535