[dns-operations] Problem with BIND 9.9.5 and automatic ZSK rollover?

[Sebastian Wiesinger]

Hello,

I use BIND 9.9.5 for automatic ZSK rollover in my zone (karotte.org).
The zone is using automatic DNSSEC maintenance and inline signing:

zone "karotte.org" {
        type master;
        file "zones/karotte.org/karotte.org";
        key-directory "zones/karotte.org";
        auto-dnssec maintain;
        inline-signing yes;
};

I tried to rollover the ZSK from keyid 38946 to keyid 50205 without
double-signing (deactivate old key and activate the new one at the
same time). The metadata for the keys is:

; This is a zone-signing key, keyid 38946, for karotte.org.
; Created: 20140519072829 (Mon May 19 09:28:29 2014)
; Publish: 20140519084611 (Mon May 19 10:46:11 2014)
; Activate: 20140526072632 (Mon May 26 09:26:32 2014)
; Inactive: 20140609140929 (Mon Jun  9 16:09:29 2014)
; Delete: 20140611140929 (Wed Jun 11 16:09:29 2014)

; This is a zone-signing key, keyid 50205, for karotte.org.
; Created: 20140526141128 (Mon May 26 16:11:28 2014)
; Publish: 20140607140929 (Sat Jun  7 16:09:29 2014)
; Activate: 20140609140929 (Mon Jun  9 16:09:29 2014)


But looking at the zone right now I see that only the SOA is signed
with the new key and all the other records are signed with the old
key.

I assumed BIND would change all the signatures at once. Or am I
getting something wrong? Also I got some strange log output when the
keys were supposed to switch:


Jun  9 16:09:29 alita named[12214]: zone karotte.org/IN (signed): reconfiguring zone keys
Jun  9 16:09:29 alita named[12214]: zone karotte.org/IN (signed): next key event: 09-Jun-2014 17:09:29.618
Jun  9 16:09:29 alita named[12214]: zone karotte.org/IN (signed): sending notifies (serial 2014051748)
Jun  9 16:09:30 alita named[12214]: client 213.95.0.65#58936 (karotte.org): transfer of 'karotte.org/IN': IXFR started
Jun  9 16:09:30 alita named[12214]: client 213.95.0.65#58936 (karotte.org): transfer of 'karotte.org/IN': IXFR ended
Jun  9 16:09:30 alita named[12214]: validating @0x7f4d6c000fc0: dlv.isc.org DNSKEY: must be secure failure,  . is under DLV (startfinddlvsep)
Jun  9 16:09:30 alita named[12214]: validating @0x7f4d70199b30: dlv.isc.org DNSKEY: must be secure failure,  . is under DLV (startfinddlvsep)
Jun  9 16:09:30 alita named[12214]: validating @0x7f4d6c000fc0: dlv.isc.org DNSKEY: must be secure failure,  . is under DLV (startfinddlvsep)
Jun  9 16:09:30 alita named[12214]: validating @0x7f4d7411c9c0: dlv.isc.org DNSKEY: must be secure failure,  . is under DLV (startfinddlvsep)
Jun  9 16:09:30 alita named[12214]: validating @0x7f4d70199b30: dlv.isc.org DNSKEY: must be secure failure,  . is under DLV (startfinddlvsep)
Jun  9 16:09:30 alita named[12214]: validating @0x7f4d86c65900: dlv.isc.org DNSKEY: must be secure failure,  . is under DLV (startfinddlvsep)
Jun  9 16:09:31 alita named[12214]: client 174.143.143.68#53154 (karotte.org): transfer of 'karotte.org/IN': IXFR started
Jun  9 16:09:31 alita named[12214]: client 174.143.143.68#53154 (karotte.org): transfer of 'karotte.org/IN': IXFR ended
Jun  9 16:09:31 alita named[12214]: validating @0x7f4d7411c9c0: dlv.isc.org DNSKEY: must be secure failure,  . is under DLV (startfinddlvsep)
Jun  9 16:09:31 alita named[12214]: validating @0x7f4d64092c80: dlv.isc.org DNSKEY: must be secure failure,  . is under DLV (startfinddlvsep)
Jun  9 16:09:31 alita named[12214]: validating @0x7f4d70199b30: dlv.isc.org DNSKEY: must be secure failure,  . is under DLV (startfinddlvsep)
Jun  9 16:09:31 alita named[12214]: validating @0x7f4d70199b30: dlv.isc.org DNSKEY: must be secure failure,  . is under DLV (startfinddlvsep)
Jun  9 16:09:31 alita named[12214]: validating @0x7f4d70199b30: dlv.isc.org DNSKEY: must be secure failure,  . is under DLV (startfinddlvsep)
Jun  9 16:09:31 alita named[12214]: validating @0x7f4d6c000fc0: dlv.isc.org DNSKEY: must be secure failure,  . is under DLV (startfinddlvsep)
Jun  9 16:09:31 alita named[12214]:   validating @0x7f4d6c000fc0: dlv.isc.org NSEC: bad cache hit (dlv.isc.org/DNSKEY)
Jun  9 16:14:22 alita named[12214]: client 194.31.2.65#42821 (karotte.org): transfer of 'karotte.org/IN': IXFR started
Jun  9 16:14:22 alita named[12214]: client 194.31.2.65#42821 (karotte.org): transfer of 'karotte.org/IN': IXFR ended

Not sure what the dlv lookup has to do with all of that but it occured
right after the zone was updated.

Input would be appreciated.

Regards
Sebastian

-- 
GPG Key: 0x93A0B9CE (F4F6 B1A3 866B 26E9 450A  9D82 58A2 D94A 93A0 B9CE)
'Are you Death?' ... IT'S THE SCYTHE, ISN'T IT? PEOPLE ALWAYS NOTICE THE SCYTHE.
            -- Terry Pratchett, The Fifth Elephant