[Opendnssec-user] signerd crash and then some

Wed Oct 19 09:46:05 UTC 2011

Hi,

running 1.3.0 right now (will update to 1.3.2 later today)

Yesterday morning was the time the enforcer choose to publish some ZSK for
some of my zones, that was a good idea at the time, and then, something
strange happened, which ended up with the signer doing a segfault.

Here are the relevant logs for one zone (well, I think I did not miss any)

Oct 18 10:09:38 ods-enforcerd: SoftHSM: C_GenerateKeyPair: Key pair
generated
Oct 18 10:09:38 ods-enforcerd: Created key in repository SoftHSM-Small
Oct 18 10:09:38 ods-enforcerd: Created ZSK size: 1024, alg: 7 with id:
dbcebb1c575665568437feac12155557 in repository: SoftHSM-Small and database.
Oct 18 10:09:39 ods-enforcerd: Zone aeroport.fr found.
Oct 18 10:09:39 ods-enforcerd: Policy for aeroport.fr set to OptOut.
Oct 18 10:09:39 ods-enforcerd: Policy OptOut found in DB.
Oct 18 10:09:39 ods-enforcerd: Config will be output to
/usr/local/var/opendnssec/signconf/aeroport.fr.xml.
Oct 18 10:09:39 ods-signerd: [signconf] zone aeroport.fr signconf:
RESIGN[PT14400S] REFRESH[PT259200S] VALIDITY[PT604800S] DENIAL[PT604800S]
JITTER[PT43200S] OFFSET[PT600S] NSEC[50] DNSKEYTTL[PT10800S]
SOATTL[PT43200S] MINIMUM[PT600S] SERIAL[counter] AUDIT[1]
Oct 18 10:09:41 ods-auditor[12480]: Auditor started
Oct 18 10:09:41 ods-auditor[12480]: Auditor starting on aeroport.fr
Oct 18 10:09:41 ods-auditor[12480]: SOA differs : from 1313509913 to
1313510085
Oct 18 10:09:41 ods-auditor[12480]: Auditing aeroport.fr zone : NSEC3 SIGNED
Oct 18 10:09:42 ods-auditor[12480]: RRSIGS should include algorithm
RSASHA1-NSEC3-SHA1 for aeroport.fr, DNSKEY, have :
Oct 18 10:09:42 ods-auditor[12480]: RRSet (aeroport.fr, DNSKEY) failed
verification : No signatures in the RRSet : aeroport.fr, DNSKEY, tag = none
Oct 18 10:09:42 ods-auditor[12480]: RRSIGS should include algorithm
RSASHA1-NSEC3-SHA1 for aeroport.fr, SOA, have :
Oct 18 10:09:42 ods-auditor[12480]: RRSet (aeroport.fr, SOA) failed
verification : No signatures in the RRSet : aeroport.fr, SOA, tag = none
Oct 18 10:09:43 ods-auditor[12480]: Finished auditing aeroport.fr zone
Oct 18 10:09:43 ods-signerd: [worker[2]] backoff task [read] for zone
aeroport.fr with 60 seconds
Oct 18 10:09:44 kernel: pid 23835 (ods-signerd), uid 0: exited on signal 11

the signer was then restarted a bit later :

Oct 18 11:08:53 ods-auditor[20068]: Auditor started
Oct 18 11:08:53 ods-auditor[20068]: Auditor starting on aeroport.fr
Oct 18 11:08:53 ods-auditor[20068]: SOA differs : from 1313509913 to
1313510085
Oct 18 11:08:53 ods-auditor[20068]: Auditing aeroport.fr zone : NSEC3 SIGNED
Oct 18 11:08:54 ods-auditor[20068]: Finished auditing aeroport.fr zone
Oct 18 11:08:54 ods-signerd: [STATS] aeroport.fr RR[count=182 time=0(sec)]
NSEC3[count=0 time=0(sec)] RRSIG[new=2 reused=19 time=0(sec)
avg=0(sig/sec)] AUDIT[time=1(sec)] TOTAL[time=1(sec)]

it all seemed good and nice as were all subsequent messages regarding it.

Then, this morning, the enforcer knew it was time to swap the two ZSK :

Oct 19 00:09:44 ods-enforcerd: Zone aeroport.fr found.
Oct 19 00:09:44 ods-enforcerd: Policy for aeroport.fr set to OptOut.
Oct 19 00:09:44 ods-enforcerd: Policy OptOut found in DB.
Oct 19 00:09:44 ods-enforcerd: Config will be output to
/usr/local/var/opendnssec/signconf/aeroport.fr.xml.
Oct 19 00:09:44 ods-enforcerd: WARNING: Making non-backed up ZSK active,
PLEASE make sure that you know the potential problems of using keys which
are not recoverable
Oct 19 00:09:45 ods-enforcerd: INFO: ZSK has been rolled for aeroport.fr 
Oct 19 00:09:45 ods-signerd: [signconf] zone aeroport.fr signconf:
RESIGN[PT14400S] REFRESH[PT259200S] VALIDITY[PT604800S] DENIAL[PT604800S]
JITTER[PT43200S] OFFSET[PT600S] NSEC[50] DNSKEYTTL[PT10800S]
SOATTL[PT43200S] MINIMUM[PT600S] SERIAL[counter] AUDIT[1]
Oct 19 00:09:46 ods-auditor[18301]: Auditor started
Oct 19 00:09:47 ods-auditor[18301]: Auditor starting on aeroport.fr
Oct 19 00:09:47 ods-auditor[18301]: SOA differs : from 1313509913 to
1313510088
Oct 19 00:09:47 ods-auditor[18301]: Auditing aeroport.fr zone : NSEC3 SIGNED
Oct 19 00:09:47 ods-auditor[18301]: RRSIGS should include algorithm
RSASHA1-NSEC3-SHA1 for aeroport.fr, DNSKEY, have :
Oct 19 00:09:47 ods-auditor[18301]: RRSet (aeroport.fr, DNSKEY) failed
verification : No signatures in the RRSet : aeroport.fr, DNSKEY, tag = none
Oct 19 00:09:47 ods-auditor[18301]: RRSIGS should include algorithm
RSASHA1-NSEC3-SHA1 for aeroport.fr, SOA, have :
Oct 19 00:09:47 ods-auditor[18301]: RRSet (aeroport.fr, SOA) failed
verification : No signatures in the RRSet : aeroport.fr, SOA, tag = none
Oct 19 00:09:48 ods-auditor[18301]: Finished auditing aeroport.fr zone
Oct 19 00:09:48 ods-signerd: [worker[1]] backoff task [read] for zone
aeroport.fr with 60 seconds

that looked bad, but I was sleeping at the time, and then :

Oct 19 00:10:48 ods-auditor[18816]: Auditor started
Oct 19 00:10:48 ods-auditor[18816]: Auditor starting on aeroport.fr
Oct 19 00:10:49 ods-auditor[18816]: SOA differs : from 1313509913 to
1313510089
Oct 19 00:10:49 ods-auditor[18816]: Auditing aeroport.fr zone : NSEC3 SIGNED
Oct 19 00:10:49 ods-auditor[18816]: Key (6870) has gone straight to active
use without a prepublished phase
Oct 19 00:10:49 ods-auditor[18816]: Finished auditing aeroport.fr zone
Oct 19 00:10:49 ods-signerd: [worker[2]] backoff task [read] for zone
aeroport.fr with 120 seconds

and since then, the backoff grew to 3600 seconds, and I can't seem to have
the zones signed again.

-- 
Mathieu Arnold