[Opendnssec-user] opendnssec2 signing error: "unable to add rr to zone: soa record has invalid owner name" ?

PGNet Dev pgnet.dev at gmail.com
Mon Dec 19 04:01:08 UTC 2016


I'm building/installing opendnssec 2 on linux/64

I've started the daemons

    systemctl restart ods-signer
    systemctl restart ods-enforcer

    ps ax | grep ods
        31030 ?        Ssl    0:00 /usr/local/opendnssec/sbin/ods-signerd
        31101 ?        Ssl    0:00 /usr/local/opendnssec/sbin/ods-enforcerd

initialized the DB

    cd /var/opendnssec
    tree
        .
        ├── [opendnssec        4096]  enforcer
        │   └── [root              51]  zones.xml
        ├── [opendnssec      364544]  kasp.db
        ├── [opendnssec        4096]  signconf
        ├── [opendnssec        4096]  signed
        ├── [opendnssec        4096]  signer
        └── [opendnssec        4096]  unsigned
            └── [root              48]  example.info.zone -> /svr/named/namedb/master/example.info.zone

        5 directories, 5 files

added a 'simple' zone

    cat /var/opendnssec/unsigned/example.info.zone
        $TTL 5
        $ORIGIN example.info.
        @    IN SOA dns.example.com. soacontact.example.com. (
                1481499040    ; Serial, Timestamp: [ 2016.12.11 15:30:40 ]
                2H            ; Refresh
                1800          ; Retry
                7D            ; Expire
                5             ; Negative Caching TTL
                )

        @   21600 IN    A        127.0.0.1
        www             A        127.0.0.1

signed the zone

    /usr/local/opendnssec/sbin/ods-enforcer --version
        opendnssec version 2.1.0-dev

which appears successful

    /usr/local/opendnssec/sbin/ods-enforcer zone add -z example.info.zone -p lab
        input is set to /var/opendnssec/unsigned/example.info.zone.
        output is set to /var/opendnssec/signed/example.info.zone.
        Zone example.info.zone added successfully

but there's NO actual output at /var/opendnssec/signed/

    ls -al /var/opendnssec/signed/
        total 8.0K
        drwxr-xr-x 2 opendnssec opendnssec 4.0K Dec 18 18:06 ./
        drwxr-xr-x 7 opendnssec opendnssec 4.0K Dec 18 19:44 ../

in syslogs

    Dec 18 19:43:58 dnssvr ods-enforcerd: [cmdhandler] accept client 9
    Dec 18 19:43:58 dnssvr ods-enforcerd: received command zone add -z example.info.zone -p lab
    Dec 18 19:43:58 dnssvr ods-enforcerd: [cmdhandler] zone add command
    Dec 18 19:43:58 dnssvr ods-enforcerd: [zone_add_cmd] zone add command
    Dec 18 19:43:58 dnssvr ods-enforcerd: SELECT zone.id, zone.rev, zone.policyId, zone.name, zone.signconfNeedsWriting, zone.signconfPath, zone.nextChange, zone.ttlEndDs, zone.ttlEndDk, zone.ttlEndRs, zone.rollKskNow, zone.rollZskNow, zone.rollCskNow, zone.inputAdapterType, zone.inputAdapterUri, zone.outputAdapterType, zone.outputAdapterUri, zone.nextKskRoll, zone.nextZskRoll, zone.nextCskRoll FROM zone WHERE zone.name = ?
    Dec 18 19:43:58 dnssvr 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.name = ?
    Dec 18 19:43:58 dnssvr ods-enforcerd: INSERT INTO zone ( policyId, name, signconfNeedsWriting, signconfPath, nextChange, ttlEndDs, ttlEndDk, ttlEndRs, rollKskNow, rollZskNow, rollCskNow, inputAdapterType, inputAdapterUri, outputAdapterType, outputAdapterUri, nextKskRoll, nextZskRoll, nextCskRoll, rev ) VALUES ( ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ? )
    Dec 18 19:43:58 dnssvr ods-enforcerd: [zone_add_cmd] zone example.info.zone added [policy: lab]
    Dec 18 19:43:58 dnssvr ods-enforcerd: INFO: The XML in /var/opendnssec/enforcer/zones.xml is valid
    Dec 18 19:43:58 dnssvr 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 = ?
    Dec 18 19:43:58 dnssvr ods-enforcerd: INFO: The XML in /var/opendnssec/enforcer/zones.xml.update is valid
    Dec 18 19:43:58 dnssvr ods-enforcerd: [zone_add_cmd] internal zonelist updated successfully
    Dec 18 19:43:58 dnssvr ods-enforcerd: [hsm_key_factory_generate_policy] policy lab
    Dec 18 19:43:58 dnssvr ods-enforcerd: SELECT policyKey.id, policyKey.rev, policyKey.policyId, policyKey.role, policyKey.algorithm, policyKey.bits, policyKey.lifetime, policyKey.repository, policyKey.standby, policyKey.manualRollover, policyKey.rfc5011, policyKey.minimize FROM policyKey WHERE policyKey.policyId = ?
    Dec 18 19:43:58 dnssvr ods-enforcerd: [hsm_key_factory_generate] repository SoftHSM role KSK
    Dec 18 19:43:58 dnssvr 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 = ?
    Dec 18 19:43:58 dnssvr ods-enforcerd: SELECT COUNT(*) FROM zone WHERE zone.policyId = ?
    Dec 18 19:43:58 dnssvr ods-enforcerd: [hsm_key_factory_generate] repository SoftHSM role ZSK
    Dec 18 19:43:58 dnssvr 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 = ?
    Dec 18 19:43:58 dnssvr ods-enforcerd: SELECT COUNT(*) FROM zone WHERE zone.policyId = ?
    Dec 18 19:43:58 dnssvr ods-enforcerd: [zone_add_cmd] Flushing enforce task
    Dec 18 19:43:58 dnssvr ods-enforcerd: [scheduler] schedule task enforce for example.info.zone
    Dec 18 19:43:58 dnssvr ods-enforcerd: [worker[1]]: report for duty
    Dec 18 19:43:58 dnssvr ods-enforcerd: [scheduler] pop task for zone example.info.zone
    Dec 18 19:43:58 dnssvr ods-enforcerd: [scheduler] unschedule task enforce for zone example.info.zone
    Dec 18 19:43:58 dnssvr ods-enforcerd: [worker[1]] start working
    Dec 18 19:43:58 dnssvr ods-enforcerd: SELECT zone.id, zone.rev, zone.policyId, zone.name, zone.signconfNeedsWriting, zone.signconfPath, zone.nextChange, zone.ttlEndDs, zone.ttlEndDk, zone.ttlEndRs, zone.rollKskNow, zone.rollZskNow, zone.rollCskNow, zone.inputAdapterType, zone.inputAdapterUri, zone.outputAdapterType, zone.outputAdapterUri, zone.nextKskRoll, zone.nextZskRoll, zone.nextCskRoll FROM zone WHERE zone.name = ?
    Dec 18 19:43:58 dnssvr 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 = ?
    Dec 18 19:43:58 dnssvr ods-enforcerd: [enforcer] update zone: example.info.zone
    Dec 18 19:43:58 dnssvr ods-enforcerd: [enforcer] updatePolicy: policyName: lab
    Dec 18 19:43:58 dnssvr ods-enforcerd: SELECT policyKey.id, policyKey.rev, policyKey.policyId, policyKey.role, policyKey.algorithm, policyKey.bits, policyKey.lifetime, policyKey.repository, policyKey.standby, policyKey.manualRollover, policyKey.rfc5011, policyKey.minimize FROM policyKey WHERE policyKey.policyId = ?
    Dec 18 19:43:58 dnssvr 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 = ?
    Dec 18 19:43:58 dnssvr ods-enforcerd: [enforcer] updatePolicy: New key needed for role KSK
    Dec 18 19:43:58 dnssvr ods-enforcerd: [hsm_key_factory_get_key] get private key
    Dec 18 19:43:58 dnssvr ods-enforcerd: SELECT hsmKey.id, hsmKey.rev, hsmKey.policyId, hsmKey.locator, hsmKey.state, hsmKey.bits, hsmKey.algorithm, hsmKey.role, hsmKey.inception, hsmKey.isRevoked, hsmKey.keyType, hsmKey.repository, hsmKey.backup 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 = ?
    Dec 18 19:43:58 dnssvr ods-enforcerd: [cmdhandler] done handling command zone add -z example.info.zone -p lab
    Dec 18 19:43:58 dnssvr ods-enforcerd: UPDATE hsmKey SET policyId = ?, locator = ?, state = ?, bits = ?, algorithm = ?, role = ?, inception = ?, isRevoked = ?, keyType = ?, repository = ?, backup = ?, rev = ? WHERE hsmKey.id = ? AND hsmKey.rev = ?
    Dec 18 19:43:58 dnssvr ods-enforcerd: [hsm_key_factory_get_key] key allocated
    Dec 18 19:43:58 dnssvr ods-enforcerd: [scheduler] schedule task hsmkeygen for hsm_key_factory_schedule_generation
    Dec 18 19:43:58 dnssvr ods-enforcerd: [enforcer] updatePolicy: got new key from HSM
    Dec 18 19:43:58 dnssvr ods-enforcerd: [worker[4]]: report for duty
    Dec 18 19:43:58 dnssvr ods-enforcerd: [scheduler] pop task for zone hsm_key_factory_schedule_generation
    Dec 18 19:43:58 dnssvr ods-enforcerd: [scheduler] unschedule task hsmkeygen for zone hsm_key_factory_schedule_generation
    Dec 18 19:43:58 dnssvr ods-enforcerd: [worker[4]] start working
    Dec 18 19:43:58 dnssvr ods-enforcerd: INSERT INTO keyData ( zoneId, hsmKeyId, algorithm, inception, role, introducing, shouldRevoke, standby, activeZsk, publish, activeKsk, dsAtParent, keytag, minimize, rev ) VALUES ( ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ? )
    Dec 18 19:43:58 dnssvr ods-enforcerd: [enforcer] updatePolicy: New key needed for role ZSK
    Dec 18 19:43:58 dnssvr ods-enforcerd: [hsm_key_factory_get_key] get private key
    Dec 18 19:43:58 dnssvr ods-enforcerd: SELECT hsmKey.id, hsmKey.rev, hsmKey.policyId, hsmKey.locator, hsmKey.state, hsmKey.bits, hsmKey.algorithm, hsmKey.role, hsmKey.inception, hsmKey.isRevoked, hsmKey.keyType, hsmKey.repository, hsmKey.backup 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 = ?
    Dec 18 19:43:58 dnssvr ods-enforcerd: UPDATE hsmKey SET policyId = ?, locator = ?, state = ?, bits = ?, algorithm = ?, role = ?, inception = ?, isRevoked = ?, keyType = ?, repository = ?, backup = ?, rev = ? WHERE hsmKey.id = ? AND hsmKey.rev = ?
    Dec 18 19:43:58 dnssvr ods-enforcerd: [hsm_key_factory_get_key] key allocated
    Dec 18 19:43:58 dnssvr ods-enforcerd: [scheduler] schedule task hsmkeygen for hsm_key_factory_schedule_generation
    Dec 18 19:43:58 dnssvr ods-enforcerd: [enforcer] updatePolicy: got new key from HSM
    Dec 18 19:43:58 dnssvr ods-enforcerd: [worker[3]]: report for duty
    Dec 18 19:43:58 dnssvr ods-enforcerd: [scheduler] pop task for zone hsm_key_factory_schedule_generation
    Dec 18 19:43:58 dnssvr ods-enforcerd: [scheduler] unschedule task hsmkeygen for zone hsm_key_factory_schedule_generation
    Dec 18 19:43:58 dnssvr ods-enforcerd: [worker[3]] start working
    Dec 18 19:43:58 dnssvr ods-enforcerd: INSERT INTO keyData ( zoneId, hsmKeyId, algorithm, inception, role, introducing, shouldRevoke, standby, activeZsk, publish, activeKsk, dsAtParent, keytag, minimize, rev ) VALUES ( ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ? )
    Dec 18 19:43:59 dnssvr ods-enforcerd: SELECT keyDependency.id, keyDependency.rev, keyDependency.zoneId, keyDependency.fromKeyDataId, keyDependency.toKeyDataId, keyDependency.type FROM keyDependency WHERE keyDependency.zoneId = ?
    Dec 18 19:43:59 dnssvr 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 = ?
    Dec 18 19:43:59 dnssvr ods-enforcerd: SELECT hsmKey.id, hsmKey.rev, hsmKey.policyId, hsmKey.locator, hsmKey.state, hsmKey.bits, hsmKey.algorithm, hsmKey.role, hsmKey.inception, hsmKey.isRevoked, hsmKey.keyType, hsmKey.repository, hsmKey.backup FROM hsmKey WHERE hsmKey.id = ?
    Dec 18 19:43:59 dnssvr ods-enforcerd: SELECT keyState.id, keyState.rev, keyState.keyDataId, keyState.type, keyState.state, keyState.lastChange, keyState.minimize, keyState.ttl FROM keyState WHERE keyState.keyDataId = ?
    Dec 18 19:43:59 dnssvr ods-enforcerd: SELECT hsmKey.id, hsmKey.rev, hsmKey.policyId, hsmKey.locator, hsmKey.state, hsmKey.bits, hsmKey.algorithm, hsmKey.role, hsmKey.inception, hsmKey.isRevoked, hsmKey.keyType, hsmKey.repository, hsmKey.backup FROM hsmKey WHERE hsmKey.id = ?
    Dec 18 19:43:59 dnssvr ods-enforcerd: SELECT keyState.id, keyState.rev, keyState.keyDataId, keyState.type, keyState.state, keyState.lastChange, keyState.minimize, keyState.ttl FROM keyState WHERE keyState.keyDataId = ?
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone: processing example.info.zone with policyName lab
    Dec 18 19:43:59 dnssvr ods-enforcerd: SELECT keyDependency.id, keyDependency.rev, keyDependency.zoneId, keyDependency.fromKeyDataId, keyDependency.toKeyDataId, keyDependency.type FROM keyDependency WHERE keyDependency.zoneId = ?
    Dec 18 19:43:59 dnssvr ods-enforcerd: INSERT INTO keyState ( keyDataId, type, state, lastChange, minimize, ttl, rev ) VALUES ( ?, ?, ?, ?, ?, ?, ? )
    Dec 18 19:43:59 dnssvr ods-enforcerd: INSERT INTO keyState ( keyDataId, type, state, lastChange, minimize, ttl, rev ) VALUES ( ?, ?, ?, ?, ?, ?, ? )
    Dec 18 19:43:59 dnssvr ods-enforcerd: INSERT INTO keyState ( keyDataId, type, state, lastChange, minimize, ttl, rev ) VALUES ( ?, ?, ?, ?, ?, ?, ? )
    Dec 18 19:43:59 dnssvr ods-enforcerd: INSERT INTO keyState ( keyDataId, type, state, lastChange, minimize, ttl, rev ) VALUES ( ?, ?, ?, ?, ?, ?, ? )
    Dec 18 19:43:59 dnssvr ods-enforcerd: SELECT keyState.id, keyState.rev, keyState.keyDataId, keyState.type, keyState.state, keyState.lastChange, keyState.minimize, keyState.ttl FROM keyState WHERE keyState.keyDataId = ?
    Dec 18 19:43:59 dnssvr ods-enforcerd: INSERT INTO keyState ( keyDataId, type, state, lastChange, minimize, ttl, rev ) VALUES ( ?, ?, ?, ?, ?, ?, ? )
    Dec 18 19:43:59 dnssvr ods-enforcerd: INSERT INTO keyState ( keyDataId, type, state, lastChange, minimize, ttl, rev ) VALUES ( ?, ?, ?, ?, ?, ?, ? )
    Dec 18 19:43:59 dnssvr ods-enforcerd: INSERT INTO keyState ( keyDataId, type, state, lastChange, minimize, ttl, rev ) VALUES ( ?, ?, ?, ?, ?, ?, ? )
    Dec 18 19:43:59 dnssvr ods-enforcerd: INSERT INTO keyState ( keyDataId, type, state, lastChange, minimize, ttl, rev ) VALUES ( ?, ?, ?, ?, ?, ?, ? )
    Dec 18 19:43:59 dnssvr ods-enforcerd: SELECT keyState.id, keyState.rev, keyState.keyDataId, keyState.type, keyState.state, keyState.lastChange, keyState.minimize, keyState.ttl FROM keyState WHERE keyState.keyDataId = ?
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone: processing key 757553f1624da814ba2876cd3737aef1 4
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone: May KSK 757553f1624da814ba2876cd3737aef1 DS in state hidden transition to rumoured?
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone: May KSK 757553f1624da814ba2876cd3737aef1 DNSKEY in state hidden transition to rumoured?
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone Policy says we can (1/3)
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone DNSSEC says we can (2/3)
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone Timing says we can (3/3) now: 1482119038 key: 1482119038
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone: Transitioning KSK 757553f1624da814ba2876cd3737aef1 DNSKEY from hidden to rumoured
    Dec 18 19:43:59 dnssvr ods-enforcerd: UPDATE keyState SET keyDataId = ?, type = ?, state = ?, lastChange = ?, minimize = ?, ttl = ?, rev = ? WHERE keyState.id = ? AND keyState.rev = ?
    Dec 18 19:43:59 dnssvr ods-enforcerd: SELECT keyDependency.id, keyDependency.rev, keyDependency.zoneId, keyDependency.fromKeyDataId, keyDependency.toKeyDataId, keyDependency.type FROM keyDependency WHERE keyDependency.zoneId = ?
    Dec 18 19:43:59 dnssvr ods-enforcerd: SELECT keyState.id, keyState.rev, keyState.keyDataId, keyState.type, keyState.state, keyState.lastChange, keyState.minimize, keyState.ttl FROM keyState WHERE keyState.keyDataId = ?
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone: May KSK 757553f1624da814ba2876cd3737aef1 RRSIGDNSKEY in state hidden transition to rumoured?
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone Policy says we can (1/3)
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone DNSSEC says we can (2/3)
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone Timing says we can (3/3) now: 1482119038 key: 1482119038
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone: Transitioning KSK 757553f1624da814ba2876cd3737aef1 RRSIGDNSKEY from hidden to rumoured
    Dec 18 19:43:59 dnssvr ods-enforcerd: UPDATE keyState SET keyDataId = ?, type = ?, state = ?, lastChange = ?, minimize = ?, ttl = ?, rev = ? WHERE keyState.id = ? AND keyState.rev = ?
    Dec 18 19:43:59 dnssvr ods-enforcerd: SELECT keyDependency.id, keyDependency.rev, keyDependency.zoneId, keyDependency.fromKeyDataId, keyDependency.toKeyDataId, keyDependency.type FROM keyDependency WHERE keyDependency.zoneId = ?
    Dec 18 19:43:59 dnssvr ods-enforcerd: SELECT keyState.id, keyState.rev, keyState.keyDataId, keyState.type, keyState.state, keyState.lastChange, keyState.minimize, keyState.ttl FROM keyState WHERE keyState.keyDataId = ?
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone: processing key 9a384acf48dd6c97898577fc6bc57c96 1
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone: May ZSK 9a384acf48dd6c97898577fc6bc57c96 DNSKEY in state hidden transition to rumoured?
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone Policy says we can (1/3)
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone DNSSEC says we can (2/3)
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone Timing says we can (3/3) now: 1482119038 key: 1482119038
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone: Transitioning ZSK 9a384acf48dd6c97898577fc6bc57c96 DNSKEY from hidden to rumoured
    Dec 18 19:43:59 dnssvr ods-enforcerd: UPDATE keyState SET keyDataId = ?, type = ?, state = ?, lastChange = ?, minimize = ?, ttl = ?, rev = ? WHERE keyState.id = ? AND keyState.rev = ?
    Dec 18 19:43:59 dnssvr ods-enforcerd: SELECT keyDependency.id, keyDependency.rev, keyDependency.zoneId, keyDependency.fromKeyDataId, keyDependency.toKeyDataId, keyDependency.type FROM keyDependency WHERE keyDependency.zoneId = ?
    Dec 18 19:43:59 dnssvr ods-enforcerd: SELECT keyState.id, keyState.rev, keyState.keyDataId, keyState.type, keyState.state, keyState.lastChange, keyState.minimize, keyState.ttl FROM keyState WHERE keyState.keyDataId = ?
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone: May ZSK 9a384acf48dd6c97898577fc6bc57c96 RRSIG in state hidden transition to rumoured?
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone Policy says we can (1/3)
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone DNSSEC says we can (2/3)
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone Timing says we can (3/3) now: 1482119038 key: 1482119038
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone: Transitioning ZSK 9a384acf48dd6c97898577fc6bc57c96 RRSIG from hidden to rumoured
    Dec 18 19:43:59 dnssvr ods-enforcerd: UPDATE keyState SET keyDataId = ?, type = ?, state = ?, lastChange = ?, minimize = ?, ttl = ?, rev = ? WHERE keyState.id = ? AND keyState.rev = ?
    Dec 18 19:43:59 dnssvr ods-enforcerd: SELECT keyDependency.id, keyDependency.rev, keyDependency.zoneId, keyDependency.fromKeyDataId, keyDependency.toKeyDataId, keyDependency.type FROM keyDependency WHERE keyDependency.zoneId = ?
    Dec 18 19:43:59 dnssvr ods-enforcerd: SELECT keyState.id, keyState.rev, keyState.keyDataId, keyState.type, keyState.state, keyState.lastChange, keyState.minimize, keyState.ttl FROM keyState WHERE keyState.keyDataId = ?
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone: processing key 757553f1624da814ba2876cd3737aef1 4
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone: May KSK 757553f1624da814ba2876cd3737aef1 DS in state hidden transition to rumoured?
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone: May KSK 757553f1624da814ba2876cd3737aef1 DNSKEY in state rumoured transition to omnipresent?
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone Policy says we can (1/3)
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone DNSSEC says we can (2/3)
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone: May KSK 757553f1624da814ba2876cd3737aef1 RRSIGDNSKEY in state rumoured transition to omnipresent?
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone Policy says we can (1/3)
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone DNSSEC says we can (2/3)
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone: processing key 9a384acf48dd6c97898577fc6bc57c96 1
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone: May ZSK 9a384acf48dd6c97898577fc6bc57c96 DNSKEY in state rumoured transition to omnipresent?
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone Policy says we can (1/3)
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone DNSSEC says we can (2/3)
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone: May ZSK 9a384acf48dd6c97898577fc6bc57c96 RRSIG in state rumoured transition to omnipresent?
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone Policy says we can (1/3)
    Dec 18 19:43:59 dnssvr ods-enforcerd: [enforcer] updateZone DNSSEC says we can (2/3)
    Dec 18 19:43:59 dnssvr 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 = ?
    Dec 18 19:44:00 dnssvr 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 = ?
    Dec 18 19:44:00 dnssvr ods-enforcerd: UPDATE zone SET policyId = ?, name = ?, signconfNeedsWriting = ?, signconfPath = ?, nextChange = ?, ttlEndDs = ?, ttlEndDk = ?, ttlEndRs = ?, rollKskNow = ?, rollZskNow = ?, rollCskNow = ?, inputAdapterType = ?, inputAdapterUri = ?, outputAdapterType = ?, outputAdapterUri = ?, nextKskRoll = ?, nextZskRoll = ?, nextCskRoll = ?, rev = ? WHERE zone.id = ? AND zone.rev = ?
    Dec 18 19:44:00 dnssvr ods-enforcerd: [scheduler] schedule task signconf for example.info.zone
    Dec 18 19:44:00 dnssvr 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 = ?
    Dec 18 19:44:00 dnssvr ods-enforcerd: [worker[2]]: report for duty
    Dec 18 19:44:00 dnssvr ods-enforcerd: [scheduler] pop task for zone example.info.zone
    Dec 18 19:44:00 dnssvr ods-enforcerd: [scheduler] unschedule task signconf for zone example.info.zone
    Dec 18 19:44:00 dnssvr ods-enforcerd: [worker[2]] start working
    Dec 18 19:44:00 dnssvr ods-enforcerd: [scheduler] schedule task enforce for example.info.zone
    Dec 18 19:44:00 dnssvr ods-enforcerd: [worker[1]] finished working
    Dec 18 19:44:00 dnssvr ods-enforcerd: [worker[1]]: report for duty
    Dec 18 19:44:00 dnssvr 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 = ?
    Dec 18 19:44:00 dnssvr ods-enforcerd: [hsm_key_factory_generate_cb] generate for policy key [duration: 0]
    Dec 18 19:44:00 dnssvr ods-enforcerd: [hsm_key_factory_generate] repository SoftHSM role KSK
    Dec 18 19:44:00 dnssvr 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 = ?
    Dec 18 19:44:00 dnssvr ods-enforcerd: SELECT COUNT(*) FROM zone WHERE zone.policyId = ?
    Dec 18 19:44:00 dnssvr ods-enforcerd: 1 zone(s) found on policy "lab"
    Dec 18 19:44:00 dnssvr ods-enforcerd: [hsm_key_factory_generate] 1 keys needed for 1 zones covering 31536000 seconds, generating 1 keys for policy lab
    Dec 18 19:44:00 dnssvr ods-enforcerd: 1 new KSK(s) (2048 bits) need to be created.
    Dec 18 19:44:00 dnssvr ods-enforcerd: INSERT INTO hsmKey ( policyId, locator, state, bits, algorithm, role, inception, isRevoked, keyType, repository, backup, rev ) VALUES ( ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ? )
    Dec 18 19:44:01 dnssvr ods-enforcerd: [hsm_key_factory_generate] generated key da2c62784af785819972e3e58aee3d40 successfully
    Dec 18 19:44:01 dnssvr ods-enforcerd: [hsm_key_factory_generate_cb] generate for policy key done
    Dec 18 19:44:01 dnssvr 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 = ?
    Dec 18 19:44:01 dnssvr ods-enforcerd: [worker[4]] finished working
    Dec 18 19:44:01 dnssvr ods-enforcerd: [worker[4]]: report for duty
    Dec 18 19:44:01 dnssvr ods-enforcerd: [hsm_key_factory_generate_cb] generate for policy key [duration: 0]
    Dec 18 19:44:01 dnssvr ods-enforcerd: [hsm_key_factory_generate] repository SoftHSM role ZSK
    Dec 18 19:44:01 dnssvr 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 = ?
    Dec 18 19:44:01 dnssvr ods-enforcerd: SELECT COUNT(*) FROM zone WHERE zone.policyId = ?
    Dec 18 19:44:01 dnssvr ods-enforcerd: 1 zone(s) found on policy "lab"
    Dec 18 19:44:01 dnssvr ods-enforcerd: [hsm_key_factory_generate] 2190 keys needed for 1 zones covering 31536000 seconds, generating 1 keys for policy lab
    Dec 18 19:44:01 dnssvr ods-enforcerd: 1 new ZSK(s) (1024 bits) need to be created.
    Dec 18 19:44:01 dnssvr ods-enforcerd: INSERT INTO hsmKey ( policyId, locator, state, bits, algorithm, role, inception, isRevoked, keyType, repository, backup, rev ) VALUES ( ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ? )
    Dec 18 19:44:01 dnssvr ods-enforcerd: [hsm_key_factory_generate] generated key 2f15ed322b100c016d093d44585a3082 successfully
    Dec 18 19:44:01 dnssvr ods-enforcerd: [hsm_key_factory_generate_cb] generate for policy key done
    Dec 18 19:44:01 dnssvr ods-enforcerd: [signconf_cmd] performing signconf for zone example.info.zone
    Dec 18 19:44:01 dnssvr ods-enforcerd: SELECT zone.id, zone.rev, zone.policyId, zone.name, zone.signconfNeedsWriting, zone.signconfPath, zone.nextChange, zone.ttlEndDs, zone.ttlEndDk, zone.ttlEndRs, zone.rollKskNow, zone.rollZskNow, zone.rollCskNow, zone.inputAdapterType, zone.inputAdapterUri, zone.outputAdapterType, zone.outputAdapterUri, zone.nextKskRoll, zone.nextZskRoll, zone.nextCskRoll FROM zone WHERE zone.name = ?
    Dec 18 19:44:01 dnssvr 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 = ?
    Dec 18 19:44:01 dnssvr ods-enforcerd: [worker[3]] finished working
    Dec 18 19:44:01 dnssvr ods-enforcerd: [worker[3]]: report for duty
    Dec 18 19:44:01 dnssvr 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 = ?
    Dec 18 19:44:01 dnssvr ods-enforcerd: SELECT hsmKey.id, hsmKey.rev, hsmKey.policyId, hsmKey.locator, hsmKey.state, hsmKey.bits, hsmKey.algorithm, hsmKey.role, hsmKey.inception, hsmKey.isRevoked, hsmKey.keyType, hsmKey.repository, hsmKey.backup FROM hsmKey WHERE hsmKey.id = ?
    Dec 18 19:44:01 dnssvr ods-enforcerd: SELECT hsmKey.id, hsmKey.rev, hsmKey.policyId, hsmKey.locator, hsmKey.state, hsmKey.bits, hsmKey.algorithm, hsmKey.role, hsmKey.inception, hsmKey.isRevoked, hsmKey.keyType, hsmKey.repository, hsmKey.backup FROM hsmKey WHERE hsmKey.id = ?
    Dec 18 19:44:01 dnssvr ods-enforcerd: UPDATE zone SET policyId = ?, name = ?, signconfNeedsWriting = ?, signconfPath = ?, nextChange = ?, ttlEndDs = ?, ttlEndDk = ?, ttlEndRs = ?, rollKskNow = ?, rollZskNow = ?, rollCskNow = ?, inputAdapterType = ?, inputAdapterUri = ?, outputAdapterType = ?, outputAdapterUri = ?, nextKskRoll = ?, nextZskRoll = ?, nextCskRoll = ?, rev = ? WHERE zone.id = ? AND zone.rev = ?
    Dec 18 19:44:01 dnssvr ods-enforcerd: [signconf_cmd] signconf done for zone example.info.zone, notifying signer
    Dec 18 19:44:01 dnssvr ods-signerd: [cmdhandler] accept client 11
    Dec 18 19:44:01 dnssvr ods-signerd: received command update example.info.zone
    Dec 18 19:44:01 dnssvr ods-signerd: [cmdhandler] update command
    Dec 18 19:44:01 dnssvr ods-signerd: [zonelist] update zone list
    Dec 18 19:44:01 dnssvr ods-signerd: [file] open file  file=/var/opendnssec/enforcer/zones.xml mode=reading
    Dec 18 19:44:01 dnssvr ods-signerd: [file] openfile /var/opendnssec/enforcer/zones.xml count 1
    Dec 18 19:44:01 dnssvr ods-signerd: [zonelist] read file /var/opendnssec/enforcer/zones.xml
    Dec 18 19:44:01 dnssvr ods-signerd: [parser] check cfgfile /var/opendnssec/enforcer/zones.xml with rngfile /usr/local/opendnssec/share/opendnssec/zonelist.rng
    Dec 18 19:44:01 dnssvr ods-signerd: [parser] zone example.info.zone added
    Dec 18 19:44:01 dnssvr ods-signerd: [parser] no more zones
    Dec 18 19:44:01 dnssvr ods-signerd: [zonelist] merge two zone lists
    Dec 18 19:44:01 dnssvr ods-signerd: [zonelist] file /var/opendnssec/enforcer/zones.xml is modified since 2016-12-18 19:43:58
    Dec 18 19:44:01 dnssvr ods-signerd: [engine] commit zone list changes
    Dec 18 19:44:01 dnssvr ods-signerd: [scheduler] schedule task [configure] for example.info.zone
    Dec 18 19:44:01 dnssvr ods-signerd: [engine] forward notify for all zones
    Dec 18 19:44:01 dnssvr ods-signerd: [worker[1]]: report for duty
    Dec 18 19:44:01 dnssvr ods-signerd: [xfrhandler] read forwarded dns packet: 6 bytes received
    Dec 18 19:44:01 dnssvr ods-signerd: [scheduler] pop task for zone example.info.zone
    Dec 18 19:44:01 dnssvr ods-signerd: [xfrhandler] netio dispatch
    Dec 18 19:44:01 dnssvr ods-signerd: [scheduler] unschedule task [configure] for zone example.info.zone
    Dec 18 19:44:01 dnssvr ods-signerd: [dnshandler] forwarded notify: 6 bytes sent
    Dec 18 19:44:01 dnssvr ods-signerd: [worker[1]] start working
    Dec 18 19:44:01 dnssvr ods-signerd: [engine] wake up workers
    Dec 18 19:44:01 dnssvr ods-signerd: [cmdhandler] done handling command update example.info.zone
    Dec 18 19:44:01 dnssvr ods-signerd: [file] open file  file=/var/opendnssec/signconf/example.info.zone.xml mode=reading
    Dec 18 19:44:01 dnssvr ods-signerd: [drudger[2]] report for duty
    Dec 18 19:44:01 dnssvr ods-signerd: [worker[2]]: report for duty
    Dec 18 19:44:01 dnssvr ods-signerd: [file] openfile /var/opendnssec/signconf/example.info.zone.xml count 1
    Dec 18 19:44:01 dnssvr ods-signerd: [signconf] read signconf file /var/opendnssec/signconf/example.info.zone.xml
    Dec 18 19:44:01 dnssvr ods-signerd: [drudger[2]] nothing to do, wait
    Dec 18 19:44:01 dnssvr ods-signerd: [drudger[4]] report for duty
    Dec 18 19:44:01 dnssvr ods-signerd: [drudger[3]] report for duty
    Dec 18 19:44:01 dnssvr ods-signerd: [drudger[1]] report for duty
    Dec 18 19:44:01 dnssvr ods-signerd: [drudger[4]] nothing to do, wait
    Dec 18 19:44:01 dnssvr ods-signerd: [worker[3]]: report for duty
    Dec 18 19:44:01 dnssvr ods-signerd: [drudger[3]] nothing to do, wait
    Dec 18 19:44:01 dnssvr ods-signerd: [worker[4]]: report for duty
    Dec 18 19:44:01 dnssvr ods-signerd: [drudger[1]] nothing to do, wait
    Dec 18 19:44:01 dnssvr ods-signerd: [parser] check cfgfile /var/opendnssec/signconf/example.info.zone.xml with rngfile /usr/local/opendnssec/share/opendnssec/signconf.rng
    Dec 18 19:44:01 dnssvr ods-enforcerd: [signconf_cmd] unable to notify signer of signconf changes for zone example.info.zone!
    Dec 18 19:44:01 dnssvr ods-enforcerd: [worker[2]] finished working
    Dec 18 19:44:01 dnssvr ods-enforcerd: [worker[2]]: report for duty
    Dec 18 19:44:01 dnssvr ods-signerd: [file] open file  file=/var/opendnssec/signconf/example.info.zone.xml mode=reading
    Dec 18 19:44:01 dnssvr ods-signerd: [file] openfile /var/opendnssec/signconf/example.info.zone.xml count 1
    Dec 18 19:44:01 dnssvr ods-signerd: [zone] zone example.info.zone signconf file /var/opendnssec/signconf/example.info.zone.xml is modified since 2016-12-18 19:44:01
    Dec 18 19:44:01 dnssvr ods-signerd: [namedb] wipe denial of existence space zone example.info.zone
    Dec 18 19:44:01 dnssvr ods-signerd: [tools] zone example.info.zone switch to new signconf
    Dec 18 19:44:01 dnssvr ods-signerd: [signconf] zone example.info.zone signconf: RESIGN[PT10M] REFRESH[PT30M] VALIDITY[PT1H] DENIAL[PT1H] KEYSET[PT0S] JITTER[PT1M] OFFSET[PT1H] NSEC[47] DNSKEYTTL[PT5M] SOATTL[PT5M] MINIMUM[PT5M] SERIAL[unixtime]
    Dec 18 19:44:01 dnssvr ods-signerd: [keys] zone example.info.zone key: LOCATOR[757553f1624da814ba2876cd3737aef1] FLAGS[257] ALGORITHM[8] KSK[1] ZSK[0] PUBLISH[1]
    Dec 18 19:44:01 dnssvr ods-signerd: [keys] zone example.info.zone key: LOCATOR[9a384acf48dd6c97898577fc6bc57c96] FLAGS[256] ALGORITHM[8] KSK[0] ZSK[1] PUBLISH[1]
    Dec 18 19:44:01 dnssvr ods-signerd: [scheduler] schedule task [read] for example.info.zone
    Dec 18 19:44:01 dnssvr ods-signerd: [worker[1]] finished working
    Dec 18 19:44:01 dnssvr ods-signerd: [worker[1]]: report for duty
    Dec 18 19:44:01 dnssvr ods-signerd: [scheduler] pop task for zone example.info.zone
    Dec 18 19:44:01 dnssvr ods-signerd: [scheduler] unschedule task [read] for zone example.info.zone
    Dec 18 19:44:01 dnssvr ods-signerd: [worker[2]]: report for duty
    Dec 18 19:44:01 dnssvr ods-signerd: [worker[1]] start working
    Dec 18 19:44:03 dnssvr ods-signerd: [zone] publish example.info.zone DNSKEY locator 757553f1624da814ba2876cd3737aef1
    Dec 18 19:44:03 dnssvr ods-signerd: [domain] +DOMAIN: example.info.zone.
    Dec 18 19:44:03 dnssvr ods-signerd: [rrset] +RRSET: <example.info.zone,DNSKEY>
    Dec 18 19:44:03 dnssvr ods-signerd: [rrset] +RR: example.info.zone. 300 IN DNSKEY 257 3 8 AwEAAbtlUloM/ZbnZz0k2GglA79iAwlWxRKkzgCmonCsUFrkCXrRQzGi+WaBvb665pfBgAQkYF9zZpU+eErit5CisAdshgNsGObRGKLtgtmaZIqFVDxuwehISfvnHVDWr1koqrRguIV3HTBtLDZNFv9Ld3M1Ux4IxkotNUJQA3K2V6GOhc+yHkNrNr7mZk2McB0+A39oNjM95FC4ctGGhYZkw+JN8y4r73O0b2BHWhSWsY6zmQ2+PYl1APwLCKRkf2ilRYfvQ0abSfeGGpAP8LBYREZ+KNxsER691kkvBIKhkI9mSNeKtmyFNPUr9NAd+LncsEJ0NA9iJzKhYWlIYjuSNYc= ;{id = 7654 (ksk), size = 2048b}
    Dec 18 19:44:04 dnssvr ods-signerd: [zone] publish example.info.zone DNSKEY locator 9a384acf48dd6c97898577fc6bc57c96
    Dec 18 19:44:04 dnssvr ods-signerd: [rrset] +RR: example.info.zone. 300 IN DNSKEY 256 3 8 AwEAAbzxcst9PnX63hPDnfsGcVDmw0UOEhsyPZkFN4Mp2kx9rArbbSNwHnnt/0J3BfQxOajvljeMGVL6bUM+5Mbalbi4F3MLKKLu7gKmmG9oLLpP0bUeEami9IIFF87R82ud4d42Bd9BCMuka3XwXbIWWwx7aSgS7vL1VMA/C1N7usEf ;{id = 9315 (zsk), size = 1024b}
    Dec 18 19:44:04 dnssvr ods-signerd: [adapter] read zone example.info.zone from file input adapter /var/opendnssec/unsigned/example.info.zone
    Dec 18 19:44:04 dnssvr ods-signerd: [file] open file  file=/var/opendnssec/unsigned/example.info.zone mode=reading
    Dec 18 19:44:04 dnssvr ods-signerd: [file] openfile /var/opendnssec/unsigned/example.info.zone count 1
    Dec 18 19:44:04 dnssvr ods-signerd: [adapter] unable to add rr to zone: soa record has invalid owner name
    Dec 18 19:44:04 dnssvr ods-signerd: [adapter] error adding RR at line 9: @    IN SOA dns.example.com. soacontact.example.com.           1481499040             2H                     1800                   7D                     5
    Dec 18 19:44:04 dnssvr ods-signerd: [tools] unable to read zone example.info.zone: adapter failed (General error)
    Dec 18 19:44:04 dnssvr ods-signerd: [rrset] -RR: example.info.zone. 300 IN DNSKEY 257 3 8 AwEAAbtlUloM/ZbnZz0k2GglA79iAwlWxRKkzgCmonCsUFrkCXrRQzGi+WaBvb665pfBgAQkYF9zZpU+eErit5CisAdshgNsGObRGKLtgtmaZIqFVDxuwehISfvnHVDWr1koqrRguIV3HTBtLDZNFv9Ld3M1Ux4IxkotNUJQA3K2V6GOhc+yHkNrNr7mZk2McB0+A39oNjM95FC4ctGGhYZkw+JN8y4r73O0b2BHWhSWsY6zmQ2+PYl1APwLCKRkf2ilRYfvQ0abSfeGGpAP8LBYREZ+KNxsER691kkvBIKhkI9mSNeKtmyFNPUr9NAd+LncsEJ0NA9iJzKhYWlIYjuSNYc= ;{id = 7654 (ksk), size = 2048b}
    Dec 18 19:44:04 dnssvr ods-signerd: [rrset] -RR: example.info.zone. 300 IN DNSKEY 256 3 8 AwEAAbzxcst9PnX63hPDnfsGcVDmw0UOEhsyPZkFN4Mp2kx9rArbbSNwHnnt/0J3BfQxOajvljeMGVL6bUM+5Mbalbi4F3MLKKLu7gKmmG9oLLpP0bUeEami9IIFF87R82ud4d42Bd9BCMuka3XwXbIWWwx7aSgS7vL1VMA/C1N7usEf ;{id = 9315 (zsk), size = 1024b}
    Dec 18 19:44:04 dnssvr ods-signerd: [rrset] -RRSET: <example.info.zone,DNSKEY>
    Dec 18 19:44:04 dnssvr ods-signerd: CRITICAL: failed to sign zone example.info.zone: General error
    Dec 18 19:44:04 dnssvr ods-signerd: back-off task [read] for zone example.info.zone with 60 seconds
    Dec 18 19:44:04 dnssvr ods-signerd: [scheduler] schedule task [read] for example.info.zone
    Dec 18 19:44:04 dnssvr ods-signerd: [task] On Sun Dec 18 19:45:04 2016 I will [read] zone example.info.zone
    Dec 18 19:44:04 dnssvr ods-signerd: [worker[1]] finished working
    Dec 18 19:44:04 dnssvr ods-signerd: [worker[3]]: report for duty
    Dec 18 19:44:04 dnssvr ods-signerd: [worker[1]]: report for duty

these are the lines that seem to identify a problem

    ...
    Dec 18 19:44:04 dnssvr ods-signerd: [adapter] unable to add rr to zone: soa record has invalid owner name
    Dec 18 19:44:04 dnssvr ods-signerd: [adapter] error adding RR at line 9: @    IN SOA dns.example.com. soacontact.example.com.           1481499040             2H                     1800                   7D                     5
    Dec 18 19:44:04 dnssvr ods-signerd: [tools] unable to read zone example.info.zone: adapter failed (General error)
    ...
    Dec 18 19:44:04 dnssvr ods-signerd: CRITICAL: failed to sign zone example.info.zone: General error
    ...

but I'm not clear what the problem actually is.

A bit of digging, and I found this old, 2014 thread

    https://lists.opendnssec.org/pipermail/opendnssec-user/2014-March/002838.html

with (then) two issues

    "Bind allows time values in SOA records like '1W' and '3H' however I'mafraid ods does not. Try: s/1W/604800/ s/3H/10800/."

and

    "found the 'problem'. Zone was example.com, zone filename was example.com.zone. I renamed zonefiles to match zone names and the issue was gone."

I've not yet found any subsequent resolution ...

Are either/both of those still a problem for opendnssec ?




More information about the Opendnssec-user mailing list