[Opendnssec-develop] Unexpected behavior

Mon Dec 28 14:59:08 UTC 2009

Hello,

While trying to sign a zone with softHSM, I am getting note's and errors
which belong to the hardware HSM. Even though the hardware HSM isn't
being used at all.

These are the repositories (conf.xml):

        <RepositoryList>

                <Repository name="softHSM">

                        <Module>/usr/local/lib/libsofthsm.so</Module>

                        <TokenLabel>test</TokenLabel>

                        <PIN>1111</PIN>

                </Repository>

                <Repository name="luna1">

                        <Module>/usr/lib/libCryptoki2_64.so</Module>

                        <TokenLabel>signer1-ksk</TokenLabel>

                        <PIN>PR46-dH7b-9TSX-9pTX</PIN>

                        <Capacity>1000</Capacity>

                        <RequireBackup/>

                </Repository>

        </RepositoryList>

Part of the Policy which I attached to the zone I am signing (kasp.xml):

                        <KSK>

                                <Algorithm length="2048">7</Algorithm>

                                <Lifetime>PT5H</Lifetime>

                                <Repository>softHSM</Repository>

                                <Standby>1</Standby>

                                <!-- <ManualRollover/> -->

                        </KSK>

                        <ZSK>

                                <Algorithm length="1024">7</Algorithm>

                                <Lifetime>PT2H</Lifetime>

                                <Repository>softHSM</Repository>

                                <Standby>1</Standby>

                        </ZSK>

It looks like ODS is trying to use softHSM as repository since he is
creating new keys in softHSM, but the ERROR, NOTE messages are referring
to the luna1 (Error creating key in repository luna1) which isn't being
used at all.

I only have 1 zone in the zonelist and updated the KASP before starting
the deamons. Also, I have signed nl before with the default policy and
it was no problem. Now that I removed nl from the zonelist, it seems ODS
tries to create 1000 KSK's for no obvious reason.

Also the logging tells me (15:06:01 NOTE: keys generated in repository
SoftHSM..) to backup the keys, but SoftHSM hasn't got <RequireBackup/>
added.

Dec 28 15:05:59 signer2 ods-signerd: Error updating zone configuration
for: rick.nl

Dec 28 15:05:59 signer2 ods-signerd: [Errno 2] No such file or
directory: u'/var/opendnssec/signconf/rick.nl.xml'

Dec 28 15:05:59 signer2 ods-signerd: opening socket:
/var/run/opendnssec/engine.sock

Dec 28 15:05:59 signer2 ods-signerd: Engine running

Dec 28 15:05:59 signer2 ods-enforcerd: opendnssec-enforcer starting...

Dec 28 15:05:59 signer2 ods-enforcerd: opendnssec-enforcer Parent
exiting...

Dec 28 15:05:59 signer2 ods-enforcerd: opendnssec-enforcer forked OK...

Dec 28 15:05:59 signer2 ods-enforcerd: opendnssec-enforcer started
(version 1.0.0rc2), pid 1394

Dec 28 15:05:59 signer2 ods-enforcerd: SSL cipher list set to AES256-SHA

Dec 28 15:05:59 signer2 ods-enforcerd: HSM opened successfully.

Dec 28 15:05:59 signer2 ods-enforcerd: Reading config
"/etc/opendnssec/conf.xml"

Dec 28 15:05:59 signer2 ods-enforcerd: Reading config schema
"/usr/local/share/opendnssec/conf.rng"

Dec 28 15:05:59 signer2 ods-enforcerd: Communication Interval: 3600

Dec 28 15:05:59 signer2 ods-enforcerd: SQLite database set to:
/var/opendnssec/kasp.db

Dec 28 15:05:59 signer2 ods-enforcerd: Log User set to: local0

Dec 28 15:05:59 signer2 ods-enforcerd: Switched log facility to: local0

Dec 28 15:05:59 signer2 ods-enforcerd: Connecting to Database...

Dec 28 15:05:59 signer2 ods-enforcerd: Policy default found.

Dec 28 15:05:59 signer2 ods-enforcerd: Key sharing is Off.

Dec 28 15:05:59 signer2 ods-enforcerd: NOTE: keys generated in
repository luna1 will not become active until they have been backed up

Dec 28 15:05:59 signer2 ods-enforcerd: Policy SCKR_S1T1 found.

Dec 28 15:05:59 signer2 ods-enforcerd: Key sharing is On

Dec 28 15:06:00 signer2 ods-enforcerd: SoftHSM: C_GenerateKeyPair: Key
pair generated

Dec 28 15:06:00 signer2 ods-enforcerd: Created KSK size: 2048, alg: 7
with id: d4b41a1c08cd125868d071d41f7eb11a in repository: softHSM and
database.

Dec 28 15:06:01 signer2 ods-enforcerd: SoftHSM: C_GenerateKeyPair: Key
pair generated

Dec 28 15:06:01 signer2 ods-enforcerd: Created KSK size: 2048, alg: 7
with id: 80c10f316ea259642f7714aceeece25a in repository: softHSM and
database.

Dec 28 15:06:01 signer2 ods-enforcerd: SoftHSM: C_GenerateKeyPair: Key
pair generated

Dec 28 15:06:01 signer2 ods-enforcerd: Created ZSK size: 1024, alg: 7
with id: 578b649144cc6dbd59c1a2d73477e7a7 in repository: softHSM and
database.

Dec 28 15:06:01 signer2 ods-enforcerd: SoftHSM: C_GenerateKeyPair: Key
pair generated

Dec 28 15:06:01 signer2 ods-enforcerd: Created ZSK size: 1024, alg: 7
with id: 7b831287fe74cc5d12277873fca0fa93 in repository: softHSM and
database.

Dec 28 15:06:01 signer2 ods-enforcerd: NOTE: keys generated in
repository softHSM will not become active until they have been backed up

Dec 28 15:06:01 signer2 ods-enforcerd: zonelist filename set to
/etc/opendnssec/zonelist.xml.

Dec 28 15:06:01 signer2 ods-enforcerd: Zone rick.nl found.

Dec 28 15:06:01 signer2 ods-enforcerd: Policy for rick.nl set to
SCKR_S1T1.

Dec 28 15:06:01 signer2 ods-enforcerd: Config will be output to
/var/opendnssec/signconf/rick.nl.xml.

Dec 28 15:06:01 signer2 ods-enforcerd: INFO: Promoting KSK from publish
to active as this is the first pass for the zone

Dec 28 15:06:01 signer2 ods-enforcerd: ERROR: Trying to make non-backed
up KSK active when RequireBackup flag is set

Dec 28 15:06:01 signer2 ods-enforcerd: KsmRequestKeys returned: 65562

Dec 28 15:06:01 signer2 ods-enforcerd: Signconf not written for rick.nl

Dec 28 15:06:01 signer2 ods-enforcerd: Disconnecting from Database...

Dec 28 15:06:01 signer2 ods-enforcerd: Sleeping for 3600 seconds.

Dec 28 15:37:18 signer2 ods-enforcerd: Reading config
"/etc/opendnssec/conf.xml"

Dec 28 15:37:18 signer2 ods-enforcerd: Reading config schema
"/usr/local/share/opendnssec/conf.rng"

Dec 28 15:37:18 signer2 ods-enforcerd: Communication Interval: 3600

Dec 28 15:37:18 signer2 ods-enforcerd: SQLite database set to:
/var/opendnssec/kasp.db

Dec 28 15:37:18 signer2 ods-enforcerd: Log User set to: local0

Dec 28 15:37:18 signer2 ods-enforcerd: Switched log facility to: local0

Dec 28 15:37:18 signer2 ods-enforcerd: Connecting to Database...

Dec 28 15:37:18 signer2 ods-enforcerd: Policy default found.

Dec 28 15:37:18 signer2 ods-enforcerd: Key sharing is Off.

Dec 28 15:37:18 signer2 ods-enforcerd: Repository luna1 is nearly full,
will create 1000 KSKs for policy default (reduced from -2)

Dec 28 15:37:18 signer2 ods-enforcerd: Error creating key in repository
luna1

Dec 28 15:37:18 signer2 ods-enforcerd: Find objects init:
CKR_DEVICE_ERROR

Dec 28 15:37:27 signer2 ods-enforcerd: Reading config
"/etc/opendnssec/conf.xml"

Dec 28 15:37:27 signer2 ods-enforcerd: Reading config schema
"/usr/local/share/opendnssec/conf.rng"

Dec 28 15:37:27 signer2 ods-enforcerd: Communication Interval: 3600

Dec 28 15:37:27 signer2 ods-enforcerd: SQLite database set to:
/var/opendnssec/kasp.db

Dec 28 15:37:27 signer2 ods-enforcerd: Log User set to: local0

Dec 28 15:37:27 signer2 ods-enforcerd: Switched log facility to: local0

Dec 28 15:37:27 signer2 ods-enforcerd: Connecting to Database...

Dec 28 15:37:27 signer2 ods-enforcerd: Policy default found.

Dec 28 15:37:27 signer2 ods-enforcerd: Key sharing is Off.

Dec 28 15:37:27 signer2 ods-enforcerd: Repository luna1 is nearly full,
will create 1000 KSKs for policy default (reduced from -2)

Dec 28 15:37:27 signer2 ods-enforcerd: Error creating key in repository
luna1

Dec 28 15:37:27 signer2 ods-enforcerd: Find objects init:
CKR_DEVICE_ERROR

Can anyone (if there is even anyone not having holiday) enlighten me?

Cheers,

Rick

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opendnssec.org/pipermail/opendnssec-develop/attachments/20091228/a68aec5b/attachment.htm>