[Opendnssec-user] Critical issue: CKR_OBJECT_HANDLE_INVALID after ZSK rollover

[Anne van Bemmelen]

Dear listmembers,
During a regular enforcerd wake up a new ZSK was created, according to the regular scheme.
Immediately after this wake up the critical issue 'CKR_OBJECT_HANDLE_INVALID' was logged, see below this message.
Signing the involved zone wasn't possible.
Signing of other zones was not impacted.

Workaround: restart ODS.

But this is the third time this happened, and although for a different zone in exactly the same circumstances.

The first and second time we used this configuration:

- RedHat 5

- ODS v1.3.5

- HSM Luna SA4

This third time we used the new configuration:

- Ubuntu 14.04

- ODS v1.4.7

- HSM Luna SA6

Questions:

- did anyone notice this before

- what can be the cause of this error

- what can I do to fix this

Some relevant logging:
Apr 5 20:49:11 myhost ods-enforcerd: Created key in repository ...
Apr 5 20:49:11 myhost ods-enforcerd: Created ZSK size: 1024, alg: 8 with id******** in repository: ... and database.
[...]
Apr 5 20:49:12 myhost ods-enforcerd: Sleeping for 3600 seconds.
Apr 5 20:49:12 myhost ods-signerd: [hsm] C_GetAttributeValue: CKR_OBJECT_HANDLE_INVALID
Apr 5 20:49:12 myhost ods-signerd: [hsm] unable to get key: hsm failed to create dnskey
Apr 5 20:49:12 myhost ods-signerd: [zone] unable to publish dnskeys for zone myzone: error creating dnskey
Apr 5 20:49:12 myhost ods-signerd: [tools] unable to read zone myzone: failed to publish dnskeys (General error)
Apr 5 20:49:13 myhost ods-signerd: [worker[3]] CRITICAL: failed to sign zone myzone: General error


Kind regards,
Anne (A.) van Bemmmelen

[cid:***@01D1708C.13C98000]

SIDN | Meander 501 | 6825 MD | PO Box 5022 | 6802 EA | ARNHEM | The Netherlands
T [phone] | M [phone]
***@sidn.nl<mailto:***@sidn.nl> | www.sidn.nl<http://www.sidn.nl/> | Key-ID: 0xB8A5F0B2

[Berry A.W. van Halderen]

Post by Anne van Bemmelen
Dear listmembers,
During a regular enforcerd wake up a new ZSK was created, according to the regular scheme.
Immediately after this wake up the critical issue
‘CKR_OBJECT_HANDLE_INVALID’ was logged, see below this message.
Signing the involved zone wasn’t possible.
Signing of other zones was not impacted.

We have seen this issue in 1.4 and 2.0, and are on the track of
solving this issue in those versions. I am however surprised that
this issue also occurs on your Luna HSM. The cases we have seen it
is where a key is created in the enforcer, but is not yet available
to the signer. Your conclusion might be the HSM is slow to make
it available, but I won't go this far as also the signer does not
properly handle this.

I am not too familiar with the 1.3 branch, whether this is truely
the same issue.

With kind regards,
Berry van Halderen

Post by Anne van Bemmelen
Workaround: restart ODS.
But this is the third time this happened, and although for a different
zone in exactly the same circumstances.
- RedHat 5
- ODS v1.3.5
- HSM Luna SA4
- Ubuntu 14.04
- ODS v1.4.7
- HSM Luna SA6
- did anyone notice this before
- what can be the cause of this error
- what can I do to fix this
Apr 5 20:49:11 myhost ods-enforcerd: Created key in repository …
Apr 5 20:49:11 myhost ods-enforcerd: Created ZSK size: 1024, alg: 8
with id******** in repository: … and database.
[…]
Apr 5 20:49:12 myhost ods-enforcerd: Sleeping for 3600 seconds.
CKR_OBJECT_HANDLE_INVALID
Apr 5 20:49:12 myhost ods-signerd: [hsm] unable to get key: hsm failed to create dnskey
Apr 5 20:49:12 myhost ods-signerd: [zone] unable to publish dnskeys for
zone myzone: error creating dnskey
failed to publish dnskeys (General error)
Apr 5 20:49:13 myhost ods-signerd: [worker[3]] CRITICAL: failed to sign
zone myzone: General error
Kind regards,
Anne (A.) van Bemmmelen
SIDN | Meander 501 | 6825 MD | PO Box 5022 | 6802 EA | ARNHEM | The Netherlands
T [phone] | M [phone]
<http://www.sidn.nl/>| Key-ID: 0xB8A5F0B2
_______________________________________________
Opendnssec-user mailing list
https://lists.opendnssec.org/mailman/listinfo/opendnssec-user

[Anne van Bemmelen]

Thanks Berry.
Can you tell us when the 1.4 version with the fix is likely to be released?


Kind regards,
Anne (A.) van Bemmelen


SIDN | Meander 501 | 6825 MD | PO Box 5022 | 6802 EA | ARNHEM | The Netherlands
T [phone] | M [phone]
***@sidn.nl | www.sidn.nl | Key-ID: 0xB8A5F0B2





-----Original Message-----
From: Opendnssec-user [mailto:opendnssec-user-***@lists.opendnssec.org] On Behalf Of Berry A.W. van Halderen
Sent: donderdag 7 april 2016 9:33
To: opendnssec-***@lists.opendnssec.org
Subject: Re: [Opendnssec-user] Critical issue: CKR_OBJECT_HANDLE_INVALID after ZSK rollover

Post by Anne van Bemmelen
Dear listmembers,
During a regular enforcerd wake up a new ZSK was created, according to the regular scheme.
Immediately after this wake up the critical issue
'CKR_OBJECT_HANDLE_INVALID' was logged, see below this message.
Signing the involved zone wasn't possible.
Signing of other zones was not impacted.

We have seen this issue in 1.4 and 2.0, and are on the track of
solving this issue in those versions. I am however surprised that
this issue also occurs on your Luna HSM. The cases we have seen it
is where a key is created in the enforcer, but is not yet available
to the signer. Your conclusion might be the HSM is slow to make
it available, but I won't go this far as also the signer does not
properly handle this.

I am not too familiar with the 1.3 branch, whether this is truely
the same issue.

With kind regards,
Berry van Halderen

Post by Anne van Bemmelen
Workaround: restart ODS.
But this is the third time this happened, and although for a different
zone in exactly the same circumstances.
- RedHat 5
- ODS v1.3.5
- HSM Luna SA4
- Ubuntu 14.04
- ODS v1.4.7
- HSM Luna SA6
- did anyone notice this before
- what can be the cause of this error
- what can I do to fix this
Apr 5 20:49:11 myhost ods-enforcerd: Created key in repository .
Apr 5 20:49:11 myhost ods-enforcerd: Created ZSK size: 1024, alg: 8
with id******** in repository: . and database.
[.]
Apr 5 20:49:12 myhost ods-enforcerd: Sleeping for 3600 seconds.
CKR_OBJECT_HANDLE_INVALID
Apr 5 20:49:12 myhost ods-signerd: [hsm] unable to get key: hsm failed to create dnskey
Apr 5 20:49:12 myhost ods-signerd: [zone] unable to publish dnskeys for
zone myzone: error creating dnskey
failed to publish dnskeys (General error)
Apr 5 20:49:13 myhost ods-signerd: [worker[3]] CRITICAL: failed to sign
zone myzone: General error
Kind regards,
Anne (A.) van Bemmmelen
SIDN | Meander 501 | 6825 MD | PO Box 5022 | 6802 EA | ARNHEM | The Netherlands
T [phone] | M [phone]
<http://www.sidn.nl/>| Key-ID: 0xB8A5F0B2
_______________________________________________
Opendnssec-user mailing list
https://lists.opendnssec.org/mailman/listinfo/opendnssec-user

[Berry A.W. van Halderen]

Post by Anne van Bemmelen
Thanks Berry.
Can you tell us when the 1.4 version with the fix is likely to be released?

It still needs to be back-ported, I think that will still take a few
days at least, the change is quite extensive. Before making a release
out of the change I would also like to see some testing feed-back.
There is a good option for that coming up real soon before the issue
has been back-ported.

With kind regards,
Berry van Halderen

[Juan Carlos Rodriguez]

Dear Berry,

I think we are suffering the same error at our tests using a RHEL 7, ODS
1.4.7 and a HSM Luna SA7:

Sep 6 09:16:47 dnshost ods-enforcerd: Created ZSK size: 2048, alg: 8
with id: 812c8c298040dba470085f19bf038277 in repository: ... and database.
Sep 6 09:17:04 dnshost ods-signerd: [hsm] Get attr value 2:
CKR_OBJECT_HANDLE_INVALID
Sep 6 09:17:04 dnshost ods-signerd: [hsm] unable to get key: key
812c8c298040dba470085f19bf038277 not found
Sep 6 09:17:04 dnshost ods-signerd: [zone] unable to publish dnskeys
for zone testzone: error creating dnskey
Sep 6 09:17:04 dnshost ods-signerd: [tools] unable to read zone
testzone: failed to publish dnskeys (General error)

Could you confirm us if the 1.4 version with the fix was released?

Kind regards
Juan Carlos
--
---------------------------------------------
Juan Carlos Rodríguez Merino
NOC RedIRIS
Tel: [phone] (Ext. 4345)

RedIRIS / Red.es
Edificio Bronce
Plaza de Manuel Gómez Moreno, s/n - 2ª planta
28020 Madrid
---------------------------------------------

[Berry A.W. van Halderen]

Post by Juan Carlos Rodriguez
Dear Berry,
I think we are suffering the same error at our tests using a RHEL 7, ODS
Sep 6 09:16:47 dnshost ods-enforcerd: Created ZSK size: 2048, alg: 8
with id: 812c8c298040dba470085f19bf038277 in repository: ... and database.
CKR_OBJECT_HANDLE_INVALID
Sep 6 09:17:04 dnshost ods-signerd: [hsm] unable to get key: key
812c8c298040dba470085f19bf038277 not found
Sep 6 09:17:04 dnshost ods-signerd: [zone] unable to publish dnskeys
for zone testzone: error creating dnskey
Sep 6 09:17:04 dnshost ods-signerd: [tools] unable to read zone
testzone: failed to publish dnskeys (General error)
Could you confirm us if the 1.4 version with the fix was released?

Always impossible to give a hard confirmation. But yes, the messages
you get are similar to the issues relating to the re-opening of the
HSM (issues OPENDNSSEC-{478,750,581,582},SUPPORT-88).
These issues are solved in 1.4.10 (and 2.0.1).

A quick restart will get you out of the immediate issues, as then the
keys should be found. But you should upgrade to the latest 1.4.

With kind regards,
Berry van Halderen

[Juan Carlos Rodriguez]

Thank you very much Berry, we will do as you suggest.

Kind regards
Juan Carlos

Post by Berry A.W. van Halderen

Post by Juan Carlos Rodriguez
Dear Berry,
I think we are suffering the same error at our tests using a RHEL 7, ODS
Sep 6 09:16:47 dnshost ods-enforcerd: Created ZSK size: 2048, alg: 8
with id: 812c8c298040dba470085f19bf038277 in repository: ... and database.
CKR_OBJECT_HANDLE_INVALID
Sep 6 09:17:04 dnshost ods-signerd: [hsm] unable to get key: key
812c8c298040dba470085f19bf038277 not found
Sep 6 09:17:04 dnshost ods-signerd: [zone] unable to publish dnskeys
for zone testzone: error creating dnskey
Sep 6 09:17:04 dnshost ods-signerd: [tools] unable to read zone
testzone: failed to publish dnskeys (General error)
Could you confirm us if the 1.4 version with the fix was released?

Always impossible to give a hard confirmation. But yes, the messages
you get are similar to the issues relating to the re-opening of the
HSM (issues OPENDNSSEC-{478,750,581,582},SUPPORT-88).
These issues are solved in 1.4.10 (and 2.0.1).
A quick restart will get you out of the immediate issues, as then the
keys should be found. But you should upgrade to the latest 1.4.
With kind regards,
Berry van Halderen

--
---------------------------------------------
Juan Carlos Rodríguez Merino
NOC RedIRIS
Tel: [phone] (Ext. 4345)

RedIRIS / Red.es
Edificio Bronce
Plaza de Manuel Gómez Moreno, s/n - 2ª planta
28020 Madrid
---------------------------------------------