[Opendnssec-user] [hsm] unable to get key

[Michael Grimm]

Berry van Halderen <berry at nlnetlabs.nl> wrote
> On 2021-04-15 21:29, Michael Grimm via Opendnssec-user wrote:


>> Hi,
>> I am running opendnssec 2.1.8 and softhsm2 2.6.1 in a jail on a recent
>> FreeBSD 13-STABLE system.
>> Today, out of a sudden, I am getting those errors for all of my
>> domains (e.g. example.tld):
>> Apr 15 11:10:45 <local0.notice> ods-enforcerd[52482]: [engine] running
>> as pid 52482
>> Apr 15 11:10:45 <local0.notice> ods-enforcerd[52482]: [engine] enforcer started
>> Apr 15 11:10:45 <local0.notice> ods-enforcerd[52482]: [enforcer]
>> update zone: example.tld
>> Apr 15 11:10:45 <local0.err> ods-enforcerd[52482]:
>> [hsm_key_factory_delete_key] looking for keys to purge from HSM
>> Apr 15 11:10:45 <local0.notice> ods-enforcerd[52482]: [enforcer]
>> removeDeadKeys: keys deleted from HSM: 0
>> Apr 15 11:10:45 <local0.notice> ods-enforcerd[52482]: [enforce_task]
>> No changes to signconf file required for zone example.tld
>> ...
>> Apr 15 11:10:46 <local0.err> ods-signerd[52488]: [hsm] unable to get
>> key: key c9b713853a6757d0ac806ddc6384968c not found
>> Apr 15 11:10:46 <local0.err> ods-signerd[52488]: [hsm]
>> hsm_get_dnskey(): Got NULL key
>> Apr 15 11:10:46 <local0.err> ods-signerd[52488]: [hsm] unable to get
>> key: hsm failed to create dnskey
>> Apr 15 11:10:46 <local0.err> ods-signerd[52488]: [zone] unable to
>> prepare signing keys for zone example.tld: error getting dnskey
>> Apr 15 11:10:46 <local0.crit> ods-signerd[52488]: [worker[1]]
>> CRITICAL: failed to sign zone example.tld: General error
>> Apr 15 11:10:46 <local0.notice> ods-signerd[52488]: back-off task
>> [sign] for zone example.tld with 60 seconds
>> I didn't change anything, but immediately after a restart of the jail
>> those messages started.
>> All my keys shown by 'ods-enforcer key list --verbose' can be found in
>> the SoftHSM2 database 'ods-hsmutil list', and all those keys (e.g.
>> c9b713853a6757d0ac806ddc6384968c) not. That explains the complaints
>> e.g. 'key c9b713853a6757d0ac806ddc6384968c not found'.
> 
> You mention key c9b713853a6757d0ac806ddc6384968c is:
> - not mentioned in ods-enforcer key list --verbose
> - not mentioned in ods-hsmutil list
> Corrrect?

Yes.

> Can you look in files /usr/local/var/opendnssec/signconf/*
> whether it is mentioned there, and if so, can provide a piece
> of that XML?  I suspect it is mentioned without <Publish/> mentioned
> in it's <Key> section.

MW-dns2|root> cat /usr/local/var/opendnssec/signconf/example.tld.xml
<?xml version="1.0" encoding="UTF-8"?>
<SignerConfiguration>
  <Zone name="example.tld">
    <Signatures>
      <Resign>PT2H</Resign>
      <Refresh>P3D</Refresh>
      <Validity>
        <Default>P14D</Default>
        <Denial>P14D</Denial>
      </Validity>
      <Jitter>PT12H</Jitter>
      <InceptionOffset>PT1H</InceptionOffset>
      <MaxZoneTTL>P1D</MaxZoneTTL>
    </Signatures>
    <Denial>
      <NSEC3>
        <Hash>
          <Algorithm>1</Algorithm>
          <Iterations>5</Iterations>
          <Salt>449950ba39385d3d</Salt>
        </Hash>
      </NSEC3>
    </Denial>
    <Keys>
      <TTL>PT1H</TTL>
      <Key>
        <Flags>257</Flags>
        <Algorithm>13</Algorithm>
        <Locator>96b87d64062b7520f6de0c3560d36f2a</Locator>
        <KSK/>
        <Publish/>
      </Key>
      <Key>
        <Flags>256</Flags>
        <Algorithm>13</Algorithm>
        <Locator>c9b713853a6757d0ac806ddc6384968c</Locator>

here ;-)

      </Key>
      <Key>
        <Flags>256</Flags>
        <Algorithm>13</Algorithm>
        <Locator>9eb469f412671f9a5bf03d948335c7c6</Locator>
        <ZSK/>
        <Publish/>
      </Key>
    </Keys>
    <SOA>
      <TTL>PT1H</TTL>
      <Minimum>PT1H</Minimum>
      <Serial>datecounter</Serial>
    </SOA>
  </Zone>
</SignerConfiguration>


> Did you purge old keys yourself with an ods-enforcer key purge
> command,

Yes I did, see https://lists.opendnssec.org/pipermail/opendnssec-user/2021-March/004607.html

And dammit, you warned me not to do so:
"I would however refrain from deleting the keys manually."

:-(

> or do you have a <Purge> mentioned in your /usr/local/etc/opendnsec/conf.xml
> configuration.  By change is it set to 0, or a quite low value?

No, I have not. 

But in kasp.conf (if that matters):
<Purge>P14D</Purge>
for both ZSK and KSKs

> I suspect this is an old key that was removed and with a restart there are still
> old signatures of this key around.  A ods-signer clear <zone> will repair the issue,
> but I'd like to harden the signer to not care about too agressive key purging.

I did try 'ods-signer clear <zone>' for a domain not in use but part of opendnssec2:
| Internal zone information about another-example.tld cleared

But I can still find the complained key in:
/usr/local/var/opendnssec/signconf/another-example.tld.xml:        <Locator>df0e8bd101258e85364846f5b3bfea06</Locator>


>> But why does the signer looks for keys not available in the hsm database?
> 
> Probably because there are still signatures with this key.

I have restarted that jail numerous times after my manual purge and never ran into this issue.
My ZSK rollover completed last week. Thus, that key shouldn't be in use any longer.
And, I had some signing going in the last day. I had had to update my zones due to dkim and dmarc addition.
No error messages at that time.
But anyway, how can I find out?

>> Any ideas regarding this and how to debug this issue
> 
> See above ;-)

That didn't work ;-)
Would it be an option to remove those no longare available Locator entries in /usr/local/var/opendnssec/signconf/ manually (by scripting)?

Thanks, now I do know that I should have listend last March, and regards,
Michael