dnssec: ds showing hidden 3+ days after key roll

Larry Rosenman ler at lerctr.org
Thu Feb 10 14:47:47 UTC 2022 

version: bind9-devel-9.17.18.a0.2021.10.08

Debug logs from yesterday for this zone (none in todays log):
<183>1 2022-02-09T02:18:28.587884-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.587 dnssec: debug 1: keymgr: keyring: 
lerctr.org/RSASHA256/8385 (policy ler1)
<183>1 2022-02-09T02:18:28.587906-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.587 dnssec: debug 1: keymgr: keyring: 
lerctr.org/RSASHA256/34851 (policy ler1)
<183>1 2022-02-09T02:18:28.587918-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.587 dnssec: debug 1: keymgr: keyring: 
lerctr.org/RSASHA256/20014 (policy ler1)
<183>1 2022-02-09T02:18:28.587928-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.587 dnssec: debug 1: keymgr: keyring: 
lerctr.org/ECDSAP256SHA256/6539 (policy ler1)
<183>1 2022-02-09T02:18:28.587939-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.587 dnssec: debug 1: keymgr: keyring: 
lerctr.org/RSASHA256/269 (policy ler1)
<183>1 2022-02-09T02:18:28.587949-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.587 dnssec: debug 1: keymgr: dnskeys: 
lerctr.org/ECDSAP256SHA256/6539 (policy ler1)
<183>1 2022-02-09T02:18:28.587960-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.587 dnssec: debug 1: keymgr: dnskeys: 
lerctr.org/RSASHA256/269 (policy ler1)
<183>1 2022-02-09T02:18:28.588003-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.587 dnssec: debug 1: keymgr: DNSKEY 
lerctr.org/RSASHA256/20014 (KSK) matches policy ler1
<183>1 2022-02-09T02:18:28.588020-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: DNSKEY 
lerctr.org/RSASHA256/269 (KSK) matches policy ler1
<183>1 2022-02-09T02:18:28.588032-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: DNSKEY 
lerctr.org/RSASHA256/269 (KSK) is active in policy ler1
<183>1 2022-02-09T02:18:28.588045-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: new 
successor needed for DNSKEY lerctr.org/RSASHA256/269 (KSK) (policy ler1) 
in 2650572588 seconds
<183>1 2022-02-09T02:18:28.588056-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: DNSKEY 
lerctr.org/ECDSAP256SHA256/6539 (ZSK) matches policy ler1
<183>1 2022-02-09T02:18:28.588067-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: DNSKEY 
lerctr.org/ECDSAP256SHA256/6539 (ZSK) is active in policy ler1
<183>1 2022-02-09T02:18:28.588079-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: new 
successor needed for DNSKEY lerctr.org/ECDSAP256SHA256/6539 (ZSK) 
(policy ler1) in 2379102 seconds
<183>1 2022-02-09T02:18:28.588090-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: examine ZSK 
lerctr.org/RSASHA256/8385 type DNSKEY in state HIDDEN
<183>1 2022-02-09T02:18:28.588101-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: ZSK 
lerctr.org/RSASHA256/8385 type DNSKEY in stable state HIDDEN
<183>1 2022-02-09T02:18:28.588111-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: examine ZSK 
lerctr.org/RSASHA256/8385 type ZRRSIG in state UNRETENTIVE
<183>1 2022-02-09T02:18:28.588122-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: can we 
transition ZSK lerctr.org/RSASHA256/8385 type ZRRSIG state UNRETENTIVE 
to state HIDDEN?
<183>1 2022-02-09T02:18:28.588143-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: dnssec 
evaluation of ZSK lerctr.org/RSASHA256/8385 record ZRRSIG: rule1=(~false 
or false) rule2=(~true or true) rule3=(~true or true)
<183>1 2022-02-09T02:18:28.588162-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: time says no 
to ZSK lerctr.org/RSASHA256/8385 type ZRRSIG state UNRETENTIVE to state 
HIDDEN (wait 662502 seconds)
<183>1 2022-02-09T02:18:28.588174-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: examine ZSK 
lerctr.org/RSASHA256/34851 type DNSKEY in state HIDDEN
<183>1 2022-02-09T02:18:28.588184-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: ZSK 
lerctr.org/RSASHA256/34851 type DNSKEY in stable state HIDDEN
<183>1 2022-02-09T02:18:28.588194-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: examine ZSK 
lerctr.org/RSASHA256/34851 type ZRRSIG in state UNRETENTIVE
<183>1 2022-02-09T02:18:28.588205-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: can we 
transition ZSK lerctr.org/RSASHA256/34851 type ZRRSIG state UNRETENTIVE 
to state HIDDEN?
<183>1 2022-02-09T02:18:28.588225-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: dnssec 
evaluation of ZSK lerctr.org/RSASHA256/34851 record ZRRSIG: 
rule1=(~false or false) rule2=(~true or true) rule3=(~true or true)
<183>1 2022-02-09T02:18:28.588244-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: time says no 
to ZSK lerctr.org/RSASHA256/34851 type ZRRSIG state UNRETENTIVE to state 
HIDDEN (wait 592212 seconds)
<183>1 2022-02-09T02:18:28.588256-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: examine KSK 
lerctr.org/RSASHA256/20014 type DNSKEY in state HIDDEN
<183>1 2022-02-09T02:18:28.588266-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: KSK 
lerctr.org/RSASHA256/20014 type DNSKEY in stable state HIDDEN
<183>1 2022-02-09T02:18:28.588276-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: examine KSK 
lerctr.org/RSASHA256/20014 type KRRSIG in state HIDDEN
<183>1 2022-02-09T02:18:28.588286-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: KSK 
lerctr.org/RSASHA256/20014 type KRRSIG in stable state HIDDEN
<183>1 2022-02-09T02:18:28.588296-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: examine KSK 
lerctr.org/RSASHA256/20014 type DS in state HIDDEN
<183>1 2022-02-09T02:18:28.588306-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: KSK 
lerctr.org/RSASHA256/20014 type DS in stable state HIDDEN
<183>1 2022-02-09T02:18:28.588317-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: examine ZSK 
lerctr.org/ECDSAP256SHA256/6539 type DNSKEY in state OMNIPRESENT
<183>1 2022-02-09T02:18:28.588328-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: ZSK 
lerctr.org/ECDSAP256SHA256/6539 type DNSKEY in stable state OMNIPRESENT
<183>1 2022-02-09T02:18:28.588338-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: examine ZSK 
lerctr.org/ECDSAP256SHA256/6539 type ZRRSIG in state OMNIPRESENT
<183>1 2022-02-09T02:18:28.588348-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: ZSK 
lerctr.org/ECDSAP256SHA256/6539 type ZRRSIG in stable state OMNIPRESENT
<183>1 2022-02-09T02:18:28.588359-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: examine KSK 
lerctr.org/RSASHA256/269 type DNSKEY in state OMNIPRESENT
<183>1 2022-02-09T02:18:28.588369-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: KSK 
lerctr.org/RSASHA256/269 type DNSKEY in stable state OMNIPRESENT
<183>1 2022-02-09T02:18:28.588379-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: examine KSK 
lerctr.org/RSASHA256/269 type KRRSIG in state OMNIPRESENT
<183>1 2022-02-09T02:18:28.588389-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: KSK 
lerctr.org/RSASHA256/269 type KRRSIG in stable state OMNIPRESENT
<183>1 2022-02-09T02:18:28.588399-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: examine KSK 
lerctr.org/RSASHA256/269 type DS in state HIDDEN
<183>1 2022-02-09T02:18:28.588410-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: can we 
transition KSK lerctr.org/RSASHA256/269 type DS state HIDDEN to state 
RUMOURED?
<183>1 2022-02-09T02:18:28.588432-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: dnssec 
evaluation of KSK lerctr.org/RSASHA256/269 record DS: rule1=(~false or 
true) rule2=(~true or true) rule3=(~true or false)
<183>1 2022-02-09T02:18:28.588453-06:00 thebighonker.lerctr.org named 
44101 - - 09-Feb-2022 02:18:28.588 dnssec: debug 1: keymgr: dnssec says 
no to KSK lerctr.org/RSASHA256/269 type DS state HIDDEN to state 
RUMOURED

ler in thebighonker in ~ via ☕ v1.8.0 via 🐪 v5.32.1 via 💎 v2.7.5 as 🧙
❯

On 02/10/2022 6:20 am, Matthijs Mekking wrote:
> Hi Larry,
> 
> There has been several bug fixes for dnssec-policy since its
> introduction. What version of 9.17 are you running?
> 
> I can't tell what causes the ds to stay in the hidden state. The
> timings in the state file should allow it to move to the next state.
> 
> If you were able to turn on logging, on each run the keymgr will tell
> you the reason why it cannot move the DS to the next state. Such logs
> happen on DEBUG(1) level.
> 
> Best regards,
> 
> Matthijs
> 
> 
> 
> On 09-02-2022 17:35, Larry Rosenman wrote:
>> On 02/09/2022 9:52 am, Matthijs Mekking wrote:
>>> Hi Larry,
>>> 
>>> Without more information it is hard to tell what is going on.
>>> 
>>> Can you share your dnssec-policy and the contents of the key state
>>> file? And if you have useful logs (grep for keymgr) that would be
>>> handy too to see what is going on.
>>> 
>>> If you prefer to share them off list, you can mail them me directly.
>>> 
>>> Best regards,
>>> 
>>> Matthijs
>>> 
>>> On 08-02-2022 18:00, Larry Rosenman wrote:
>>>> Greetings,
>>>>      new poster.  I just converted over to DNSSEC-policy,  and 
>>>> rolled my KSK.  I see:
>>>> key: 269 (RSASHA256), KSK
>>>>    published:      yes - since Sun Feb  6 14:31:32 2022
>>>>    key signing:    yes - since Sun Feb  6 14:31:32 2022
>>>> 
>>>>    No rollover scheduled
>>>>    - goal:           omnipresent
>>>>    - dnskey:         omnipresent
>>>>    - ds:             hidden
>>>>    - key rrsig:      omnipresent
>>>> 
>>>> 
>>>> ler in thebighonker in namedb🔒 on  master [!] as 🧙
>>>> ❯
>>>> 
>>>> Is it normal to see the ds as hidden?  It IS published, and I told 
>>>> rndc that.
>>>> 
>>>> Any insight appreciated.
>>>> 
>> 
>> thebighonker# cat Klerctr.org.+008+00269.state
>> ; This is the state of key 269, for lerctr.org.
>> Algorithm: 8
>> Length: 2048
>> Lifetime: 0
>> Predecessor: 20014
>> KSK: yes
>> ZSK: no
>> Generated: 20220206203132 (Sun Feb  6 14:31:32 2022)
>> Published: 20220206203132 (Sun Feb  6 14:31:32 2022)
>> Active: 20220206213632 (Sun Feb  6 15:36:32 2022)
>> DSPublish: 20220207015646 (Sun Feb  6 19:56:46 2022)
>> PublishCDS: 20220206223632 (Sun Feb  6 16:36:32 2022)
>> DNSKEYChange: 20220206223632 (Sun Feb  6 16:36:32 2022)
>> KRRSIGChange: 20220206223632 (Sun Feb  6 16:36:32 2022)
>> DSChange: 20220206203132 (Sun Feb  6 14:31:32 2022)
>> DNSKEYState: omnipresent
>> KRRSIGState: omnipresent
>> DSState: hidden
>> GoalState: omnipresent
>> thebighonker#
>> 
>> dnssec-policy "ler1" {
>>         keys {
>>                 ksk lifetime unlimited algorithm 8 2048 ;
>>                 zsk lifetime 30d algorithm 13;
>>         };
>>         // Key timings
>>         dnskey-ttl 3600;
>>         publish-safety 1h;
>>         retire-safety 1h;
>>         purge-keys P90D;
>>         // Signature timings
>>         signatures-refresh 5d;
>>         signatures-validity 14d;
>>         signatures-validity-dnskey 14d;
>>         // Zone parameters
>>         max-zone-ttl 86400;
>>         zone-propagation-delay 300;
>>         // Parent parameters
>>         parent-ds-ttl 86400;
>>         parent-propagation-delay 1h;
>>         nsec3param iterations 0 salt-length 0;
>> };
>> 
>> Unfortunately my 9.17(alpha) named got into a signing loop, so I don't 
>> want to look through that logging.
>> 
>> I know -- I need to update to 9.18, but am waiting on the FreeBSD port 
>> maintainer to add 9.18 to the ports tree

-- 
Larry Rosenman                     http://www.lerctr.org/~ler
Phone: +1 214-642-9640                 E-Mail: ler at lerctr.org
US Mail: 5708 Sabbia Dr, Round Rock, TX 78665-2106

More information about the bind-users mailing list