[Opendnssec-user] Error allocating ksks / zsks

[Havard Eidnes]

> a new occurrence of this problem has surfaced.
>
> Somehow my SoftHSM database had become owned by root (ouch!).  While
> that was done, a new zone was added.  Of course key allocation failed
> since the enforcer could not write to the SoftHSM database.
>
> However, the file ownership problem is now sorted, but OpenDNSSEC
> still refuses to allocate any keys:
>
> Mar  9 21:34:09 hugin ods-signerd: [parser] zone mydomainname.no added
> Mar  9 21:34:25 hugin ods-enforcerd: Zone mydomainname.no found.
> Mar  9 21:34:25 hugin ods-enforcerd: Policy for mydomainname.no set to default.
> Mar  9 21:34:25 hugin ods-enforcerd: Config will be output to /var/opendnssec/signconf/mydomainname.no.xml.
> Mar  9 21:34:25 hugin ods-enforcerd: Not enough keys to satisfy zsk policy for zone: mydomainname.no. keys_to_allocate(1) = keys_needed(1) - (keys_available(0) - keys_pending_retirement(0)) 
> Mar  9 21:34:25 hugin ods-enforcerd: Error allocating zsks to zone mydomainname.no

I've done some more code reading, and on the way found reason to
file the tangentially related

  https://issues.opendnssec.org/browse/SUPPORT-189

where any "KSM" log messages are discarded by the daemon.

However, this doesn't appear to be able to shed more light on
what the problem is.  I added some more logging in do_keygen() in
the enforcer, and got:

Mar 10 12:08:02 hugin ods-enforcerd: Connecting to Database...
Mar 10 12:08:02 hugin ods-enforcerd: Policy default found.
Mar 10 12:08:02 hugin ods-enforcerd: Key sharing is Off.
Mar 10 12:08:02 hugin ods-enforcerd: 367 zone(s) found on policy "default" 
Mar 10 12:08:02 hugin ods-enforcerd: Predict we need 367 KSKs
Mar 10 12:08:02 hugin ods-enforcerd: Have 367 KSK keys in queue
Mar 10 12:08:02 hugin ods-enforcerd: Need 0 new KSK keys
Mar 10 12:08:02 hugin ods-enforcerd: No new KSKs need to be created. 
Mar 10 12:08:02 hugin ods-enforcerd: Predict we need 367 new ZSK keys
Mar 10 12:08:02 hugin ods-enforcerd: Have 367 ZSK keys in queue
Mar 10 12:08:02 hugin ods-enforcerd: Need 0 new ZSK keys
Mar 10 12:08:02 hugin ods-enforcerd: No new ZSKs need to be created. 
Mar 10 12:08:02 hugin ods-enforcerd: Purging keys...

So this part of OpenDNSSEC seems to think it has all the keys it
needs, and that no new keys need to be generated.

However, the key allocation done by KsmKeyGetUnallocated() returns
with status=0 but keypair_id=0 as well, and allocateKeysToZone() in
the enforcer thinks this is a signal of failure:

            status = KsmKeyGetUnallocated(policy->id, policy->zsk->sm, policy->zsk->bits, policy->zsk->algorithm, zone_id, policy->keys->share_keys, &key_pair_id);
            if (status == -1 || key_pair_id == 0) {
                if (man_key_gen == 0) {
                    log_msg(NULL, LOG_WARNING, "Not enough keys to satisfy zsk policy for zone: %s. keys_to_allocate(%d) = keys_needed(%d) - (keys_available(%d) - keys_pending_retirement(%d))\n", zone_name, new_keys, keys_needed, keys_in_queue, keys_pending_retirement);
                    log_msg(NULL, LOG_WARNING, "Tried to allocate %d keys, failed on allocating key number %d", new_keys, i+1);
                    log_msg(NULL, LOG_WARNING, "Status=%d key_pair_id=%d",
                        status, key_pair_id);
                    log_msg(NULL, LOG_WARNING, "ods-enforcerd will create some more keys on its next run");
                }

(log of status code and key_pair_id added by me, and indentation
fixed to be consistent.)

So, since I'm not running with manual key generation, I'm wary of
doing "ods-ksmutil key generate", as I fear that will at best be a
temporary fix.  Besides, it appears to want a gazillion parameters
which are inconvenient at best to dig out.

If I count all the 'active' ZSKs which "ods-ksmutil key list" lists, I
come to 366, not 367.

If key_pair_id = 0 is indeed invalid, I guess the database has gotten
into a state where OpenDNSSEC refuses to mend it automatically.

Guidance sought.

Regards,

- Håvard