On 06/25/2018 03:05 PM, Casper Gielen wrote:
> Op 25-06-18 om 11:49 schreef Casper Gielen:
>>
>> I've verified that everything under /var/lib/opendnssec is readable and
>> writable by the opendnssec user. The configuration, under
>> /etc/opendnssec, is readable but not writable.
> 
> Minutes after I wrote this a colleague added a new zone (ucgv.nl) that 
> immediately ran into trouble. 
> Unfortunately I do not have complete logging, this is what I do have:

This could be much unrelated from the earlier issue.

Are you using SoftHSM as HSM?  If so, which version?
There is a known, resolved issue with certain versions.

\Berry


>  Jun 25 11:15:49 ramachandra ods-enforcerd: [zonelist_import] zone ucgv.nl 
> created
>  ...
>  Jun 25 11:16:02 ramachandra ods-enforcerd: [enforcer] update zone: ucgv.nl
>  Jun 25 11:16:02 ramachandra ods-enforcerd: 199 zone(s) found on policy "sidn"
>  Jun 25 11:16:02 ramachandra ods-enforcerd: [hsm_key_factory_generate] 1 keys 
> needed for 199 zones covering 31536000 seconds, generating 1 keys for policy 
> sidn
>  Jun 25 11:16:02 ramachandra ods-enforcerd: 1 new KSK(s) (2048 bits) need to 
> be created.
>  Jun 25 11:16:02 ramachandra ods-enforcerd: 199 zone(s) found on policy "sidn"
>  Jun 25 11:16:02 ramachandra ods-enforcerd: [hsm_key_factory_generate] 13 
> keys needed for 199 zones covering 31536000 seconds, generating 1 keys for 
> policy sidn
>  Jun 25 11:16:02 ramachandra ods-enforcerd: 1 new ZSK(s) (1024 bits) need to 
> be created.
>  Jun 25 11:16:02 ramachandra ods-enforcerd: [signconf_cmd] performing 
> signconf for all zones
>  Jun 25 11:16:02 ramachandra ods-enforcerd: [signconf_cmd] signconf done, 
> notifying signer
>  ...
>  Jun 25 11:30:17 ramachandra ods-signerd: [hsm] unable to get key: key 
> a1d5274f2e3c73eb73ec99c16e781d0d not found
>  Jun 25 11:30:17 ramachandra ods-signerd: [hsm] hsm_get_dnskey(): Got NULL key
>  Jun 25 11:30:17 ramachandra ods-signerd: [hsm] unable to get key: hsm failed 
> to create dnskey
>  Jun 25 11:30:17 ramachandra ods-signerd: [zone] unable to prepare signing 
> keys for zone ucgv.nl: error getting dnskey
>  Jun 25 11:30:17 ramachandra ods-signerd: [worker[1]] CRITICAL: failed to 
> sign zone ucgv.nl: General error
> 
> root@ramachandra:~# ods-enforcer key list --zone ucgv.nl -v
> Keys:
> Zone:                           Keytype: State:    Date of next transition: 
> Size: Algorithm: CKA_ID:                          Repository: KeyTag:
> ucgv.nl                         ZSK      publish   2018-06-26 11:16:27      
> 1024  8          991337c6e4aba10487ef75d8ca990668 LocalHSM    24390
> 
> root@ramachandra:~# ods-enforcer key list --zone ucgv.nl -d
> Keys:
> Zone:                           Key role:     DS:          DNSKEY:      
> RRSIGDNSKEY: RRSIG:       Pub: Act: Id:
> ucgv.nl                         ZSK           NA           hidden       NA    
>        rumoured     0    1    991337c6e4aba10487ef75d8ca990668
> 
> The log shows he followed our usual procedure to the tee.
> I immediatly repeated his steps, except for a different domain name, but was 
> unable to reproduce te problem.
> The difference might be that I worked with a frehsly restarted ods-enforcer, 
> while it had been running for three days straight when my colleague added the 
> zone.
> 
> 
> 
> Jun 25 13:40:08 ramachandra ods-enforcerd: [zonelist_import] zone 
> ucgvtest2.nl created
> Jun 25 13:40:16 ramachandra ods-enforcerd: [enforcer] update zone: 
> ucgvtest2.nl
> Jun 25 13:40:16 ramachandra ods-enforcerd: [hsm_key_factory_get_key] key 
> allocated
> Jun 25 13:40:16 ramachandra ods-enforcerd: [scheduler] schedule task 
> [hsmkeygen] for policy_key
> Jun 25 13:40:16 ramachandra ods-enforcerd: [scheduler] signal now
> Jun 25 13:40:16 ramachandra ods-enforcerd: [enforcer] updatePolicy: got new 
> key from HSM
> Jun 25 13:40:16 ramachandra ods-enforcerd: [worker[4]]: report for duty
> Jun 25 13:40:16 ramachandra ods-enforcerd: [scheduler] SIGALRM set
> Jun 25 13:40:16 ramachandra ods-enforcerd: [worker[4]] start working
> Jun 25 13:40:16 ramachandra ods-enforcerd: [worker[4]]: perform task 
> [hsmkeygen] for policy_key
> Jun 25 13:40:16 ramachandra ods-enforcerd: SELECT policy.id, policy.rev, 
> policy.name, policy.description, policy.signaturesResign, 
> policy.signaturesRefresh, policy.signaturesJitter, 
> policy.signaturesInceptionOffset, policy.signaturesValidityDefault, 
> policy.signaturesValidityDenial, policy.signaturesValidityKeyset, 
> policy.signaturesMaxZoneTtl, policy.denialType, policy.denialOptout, 
> policy.denialTtl, policy.denialResalt, policy.denialAlgorithm, 
> policy.denialIterations, policy.denialSaltLength, policy.denialSalt, 
> policy.denialSaltLastChange, policy.keysTtl, policy.keysRetireSafety, 
> policy.keysPublishSafety, policy.keysShared, policy.keysPurgeAfter, 
> policy.zonePropagationDelay, policy.zoneSoaTtl, policy.zoneSoaMinimum, 
> policy.zoneSoaSerial, policy.parentRegistrationDelay, 
> policy.parentPropagationDelay, policy.parentDsTtl, policy.parentSoaTtl, 
> policy.parentSoaMinimum, policy.passthrough FROM policy WHERE policy.id = ?
> Jun 25 13:40:16 ramachandra ods-enforcerd: [hsm_key_factory_generate_task] 
> generate for policy key [duration: 0]
> Jun 25 13:40:16 ramachandra ods-enforcerd: [hsm_key_factory_generate] 
> repository LocalHSM role KSK
> Jun 25 13:40:16 ramachandra ods-enforcerd: SELECT COUNT(*) FROM hsmKey WHERE 
> hsmKey.policyId = ? AND hsmKey.state = ? AND hsmKey.bits = ? AND 
> hsmKey.algorithm = ? AND hsmKey.role = ? AND hsmKey.isRevoked = ? AND 
> hsmKey.keyType = ? AND hsmKey.repository = ?
> Jun 25 13:40:16 ramachandra ods-enforcerd: SELECT COUNT(*) FROM zone WHERE 
> zone.policyId = ?
> Jun 25 13:40:16 ramachandra ods-enforcerd: 200 zone(s) found on policy "sidn"
> Jun 25 13:40:16 ramachandra ods-enforcerd: [hsm_key_factory_generate] 1 keys 
> needed for 200 zones covering 31536000 seconds, generating 1 keys for policy 
> sidn
> Jun 25 13:40:16 ramachandra ods-enforcerd: 1 new KSK(s) (2048 bits) need to 
> be created.
> Jun 25 13:40:16 ramachandra ods-enforcerd: [hsm_key_factory_generate] 
> generated key 5ddcfb83faa841d034ee262586391216 successfully
> Jun 25 13:40:16 ramachandra ods-enforcerd: [hsm_key_factory_generate_task] 
> generate for policy key done
> 
> Jun 25 13:40:16 ramachandra ods-enforcerd: 200 zone(s) found on policy "sidn"
> Jun 25 13:40:16 ramachandra ods-enforcerd: [hsm_key_factory_generate] 13 keys 
> needed for 200 zones covering 31536000 seconds, generating 1 keys for policy 
> sidn
> Jun 25 13:40:16 ramachandra ods-enforcerd: 1 new ZSK(s) (1024 bits) need to 
> be created.
> Jun 25 13:40:17 ramachandra ods-enforcerd: [hsm_key_factory_generate] 
> generated key e484bf43583403c1a1658c2c7e30d47b successfully
> Jun 25 13:40:17 ramachandra ods-enforcerd: [hsm_key_factory_generate_task] 
> generate for policy key done
> Jun 25 13:40:17 ramachandra ods-enforcerd: [worker[2]] finished working
> Jun 25 13:40:17 ramachandra ods-enforcerd: [worker[2]]: report for duty
> 
> 
> Jun 25 13:40:17 ramachandra ods-enforcerd: SELECT keyDependency.id, 
> keyDependency.rev, keyDependency.zoneId, keyDependency.fromKeyDataId, 
> keyDependency.toKeyDataId, keyDependency.type FROM keyDependency WHERE 
> keyDependency.zoneId = ?
> Jun 25 13:40:17 ramachandra ods-enforcerd: SELECT keyState.id, keyState.rev, 
> keyState.keyDataId, keyState.type, keyState.state, keyState.lastChange, 
> keyState.minimize, keyState.ttl FROM keyState WHERE keyState.keyDataId = ?
> Jun 25 13:40:17 ramachandra ods-enforcerd: [enforcer] updateZone: processing 
> key 0c9c2506e33fe702c96f989bf78ab66f 4
> Jun 25 13:40:17 ramachandra ods-enforcerd: [enforcer] updateZone: May KSK 
> 0c9c2506e33fe702c96f989bf78ab66f DS in state hidden transition to rumoured?
> Jun 25 13:40:17 ramachandra ods-enforcerd: [enforcer] updateZone: May KSK 
> 0c9c2506e33fe702c96f989bf78ab66f DNSKEY in state hidden transition to 
> rumoured?
> Jun 25 13:40:17 ramachandra ods-enforcerd: [enforcer] updateZone Policy says 
> we can (1/3)
> Jun 25 13:40:17 ramachandra ods-enforcerd: [enforcer] updateZone: May KSK 
> 0c9c2506e33fe702c96f989bf78ab66f RRSIGDNSKEY in state hidden transition to 
> rumoured?
> Jun 25 13:40:17 ramachandra ods-enforcerd: [enforcer] updateZone: processing 
> key 68e476a72a0ab6e296dc309334276588 1
> Jun 25 13:40:17 ramachandra ods-enforcerd: [enforcer] updateZone: May ZSK 
> 68e476a72a0ab6e296dc309334276588 DNSKEY in state hidden transition to 
> rumoured?
> Jun 25 13:40:17 ramachandra ods-enforcerd: [enforcer] updateZone Policy says 
> we can (1/3)
> Jun 25 13:40:17 ramachandra ods-enforcerd: [enforcer] updateZone: May ZSK 
> 68e476a72a0ab6e296dc309334276588 RRSIG in state rumoured transition to 
> omnipresent?
> Jun 25 13:40:17 ramachandra ods-enforcerd: [enforcer] updateZone Policy says 
> we can (1/3)
> Jun 25 13:40:17 ramachandra ods-enforcerd: [enforcer] updateZone DNSSEC says 
> we can (2/3)
> Jun 25 13:40:17 ramachandra ods-enforcerd: UPDATE keyData SET zoneId = ?, 
> hsmKeyId = ?, algorithm = ?, inception = ?, role = ?, introducing = ?, 
> shouldRevoke = ?, standby = ?, activeZsk = ?, publish = ?, activeKsk = ?, 
> dsAtParent = ?, keytag = ?, minimize = ?, rev = ? WHERE keyData.id = ? AND 
> keyData.rev = ?
> Jun 25 13:40:17 ramachandra ods-enforcerd: UPDATE keyData SET zoneId = ?, 
> hsmKeyId = ?, algorithm = ?, inception = ?, role = ?, introducing = ?, 
> shouldRevoke = ?, standby = ?, activeZsk = ?, publish = ?, activeKsk = ?, 
> dsAtParent = ?, keytag = ?, minimize = ?, rev = ? WHERE keyData.id = ? AND 
> keyData.rev = ?
> Jun 25 13:40:17 ramachandra ods-enforcerd: SELECT keyData.id, keyData.rev, 
> keyData.zoneId, keyData.hsmKeyId, keyData.algorithm, keyData.inception, 
> keyData.role, keyData.introducing, keyData.shouldRevoke, keyData.standby, 
> keyData.activeZsk, keyData.publish, keyData.activeKsk, keyData.dsAtParent, 
> keyData.keytag, keyData.minimize FROM keyData WHERE keyData.zoneId = ?
> Jun 25 13:40:17 ramachandra ods-enforcerd: Next update for zone ucgvtest2.nl 
> scheduled at Tue Jun 26 13:40:40 2018
> 
> root@ramachandra:~# ods-enforcer key list --zone ucgvtest2.nl -v
> Keys:
> Zone:                           Keytype: State:    Date of next transition: 
> Size: Algorithm: CKA_ID:                          Repository: KeyTag:
> ucgvtest2.nl                    ZSK      publish   2018-06-26 13:40:40      
> 1024  8          68e476a72a0ab6e296dc309334276588 LocalHSM    14190
> key list completed in 0 seconds.
> root@ramachandra:~# ods-enforcer key list --zone ucgvtest2.nl -d
> Keys:
> Zone:                           Key role:     DS:          DNSKEY:      
> RRSIGDNSKEY: RRSIG:       Pub: Act: Id:
> ucgvtest2.nl                    ZSK           NA           hidden       NA    
>        rumoured     0    1    68e476a72a0ab6e296dc309334276588
> 
> Now I'm a bit miffed by these zones with a ZSK but without a KSK.
> 
> My original problem, the zone wiskundeoptiu.nl, remains, but the situation 
> has been slightly improved
> because some of the signatures have been replaced by signatures with the 
> current ZSK.
> 
> I'm considering wether or not to edit the database directly to get the zone 
> back in a workable condition by removing the problematic keys.
> First I'm going to delete the zone ucgv.nl, which is not yet in use, and redo 
> it in the hope that it magically works out this time.
> 

_______________________________________________
Opendnssec-user mailing list
[email protected]
https://lists.opendnssec.org/mailman/listinfo/opendnssec-user

Reply via email to