[Opendnssec-user] Duplicate keys
Casper Gielen
C.Gielen at uvt.nl
Wed Oct 12 09:54:12 UTC 2011
Hello,
one of my OpenDNS-servers shows duplicate keys for a number of recently added zones.
Some show a few duplicates, some show many. I've included the output of ods-ksmutil below.
Older zones seem to be free of the problem including those that have recently been changed.
I'm running OpenDNSSEC 1.3.2 on Debian. The cause might be that at one time I started
OpenDNS before the HSM was available.
The server is operated in tandem with another server. All interaction with OpenDNS is done
through scripts so both servers should receive the same commands*. The other server does
not show any duplicate keys. That server is still using 1.2.1 .
ny ideas about what is going wrong?
Any suggestions for fixing this?
I am about to add a number of new domains which makes this a good time for debugging.
Any hints about where to point my attention?
root at metagross:~# ods-ksmutil key list --zone example.nl -v
MySQL database host set to: localhost
MySQL database port set to: 3306
MySQL database schema set to: opendnssec
MySQL database user set to: opendnssec
MySQL database password set
Keys:
Zone: Keytype: State: Date of next transition: CKA_ID: Repository: Keytag:
example.nl ZSK active 2011-11-04 14:11:24 b17e71ad4ed9d0567da0a39c33fe5430 LocalHSM 62370
example.nl ZSK active 2011-11-04 14:11:24 b17e71ad4ed9d0567da0a39c33fe5430 LocalHSM 62370
example.nl ZSK ready next rollover bc84bb3a6364cb46527d80144ab00574 LocalHSM 57616
example.nl ZSK ready next rollover bc84bb3a6364cb46527d80144ab00574 LocalHSM 57616
example.nl ZSK ready next rollover 2dee14ce5efa28ff2305f05d8f552e0f LocalHSM 1675
example.nl ZSK ready next rollover 2dee14ce5efa28ff2305f05d8f552e0f LocalHSM 1675
example.nl KSK dsready When required 3010833a37e9783a1bed3f71ecd28b43 LocalHSM 22865
example.nl KSK dsready When required 5310b51bab48aa088694990a8c7ba8fa LocalHSM 21080
example.nl KSK dsready When required 5310b51bab48aa088694990a8c7ba8fa LocalHSM 21080
example.nl KSK active 2012-10-11 09:52:24 8b56d5e67aa844ca0a1629226a12313e LocalHSM 12866
Below is a full log of the signer attempting to sign the zone above (verbosity 6).
Oct 12 09:58:24 metagross ods-signerd: [cmdhandler] accept client 33
Oct 12 09:58:24 metagross ods-signerd: [cmdhandler] 1 clients in progress...
Oct 12 09:58:24 metagross ods-signerd: [cmdhandler] received command sign example.nl[24]
Oct 12 09:58:24 metagross ods-signerd: [cmdhandler] sign zone command
Oct 12 09:58:24 metagross ods-signerd: [scheduler] unschedule task [read] for zone example.nl
Oct 12 09:58:24 metagross ods-signerd: [cmdhandler] reschedule task for zone example.nl
Oct 12 09:58:24 metagross ods-signerd: [scheduler] schedule task [read] for zone example.nl
Oct 12 09:58:24 metagross ods-signerd: [cmdhandler] zone example.nl scheduled for immediate re-sign
Oct 12 09:58:24 metagross ods-signerd: [engine] wake up workers
Oct 12 09:58:24 metagross ods-signerd: [worker[2]] wake up
Oct 12 09:58:24 metagross ods-signerd: [worker[2]] report for duty
Oct 12 09:58:24 metagross ods-signerd: [scheduler] pop task for zone example.nl
Oct 12 09:58:24 metagross ods-signerd: [scheduler] unschedule task [read] for zone example.nl
Oct 12 09:58:24 metagross ods-signerd: [worker[2]] start working on zone example.nl
Oct 12 09:58:24 metagross ods-signerd: [worker[2]] perform task [read] for zone example.nl at 1318406304
Oct 12 09:58:24 metagross ods-signerd: [worker[2]] read zone example.nl
Oct 12 09:58:24 metagross ods-signerd: [adapter] read zone example.nl from file input adapter /var/lib/opendnssec/unsigned/example.nl
Oct 12 09:58:24 metagross ods-signerd: [file] open file file=/var/lib/opendnssec/unsigned/example.nl mode=reading
Oct 12 09:58:24 metagross ods-signerd: [zone] zone example.nl set SOA TTL to 3600
Oct 12 09:58:24 metagross ods-signerd: [zone] zone example.nl set SOA MINIMUM to 3600
Oct 12 09:58:24 metagross ods-signerd: [worker[3]] wake up
Oct 12 09:58:24 metagross ods-signerd: [worker[3]] report for duty
Oct 12 09:58:24 metagross ods-signerd: [worker[3]] nothing to do
Oct 12 09:58:24 metagross ods-signerd: [worker[4]] wake up
Oct 12 09:58:24 metagross ods-signerd: [cmdhandler] done handling command sign example.nl[24]
Oct 12 09:58:24 metagross ods-signerd: [worker[4]] report for duty
Oct 12 09:58:24 metagross ods-signerd: [worker[4]] nothing to do
Oct 12 09:58:24 metagross ods-signerd: [tools] commit updates for zone example.nl
Oct 12 09:58:24 metagross ods-signerd: -RR example.nl. 3600 IN SOA ns1.uvt.nl. hostmaster.uvt.nl. 2011101200 28800 14400 604800 3600
Oct 12 09:58:24 metagross ods-signerd: +RR example.nl. 3600 IN SOA ns1.uvt.nl. hostmaster.uvt.nl. 2011100500 28800 14400 604800 3600
Oct 12 09:58:24 metagross ods-signerd: [worker[2]] nsecify zone example.nl
Oct 12 09:58:24 metagross ods-signerd: [worker[2]] sign zone example.nl
Oct 12 09:58:24 metagross ods-signerd: [data] update serial: in=2011100500 internal=0 out=0 now=1318406304
Oct 12 09:58:24 metagross ods-signerd: [data] update serial: 2011100500 + 700 = 2011101200
Oct 12 09:58:24 metagross ods-signerd: [fifo] threshold 1 reached, notify drudgers
Oct 12 09:58:24 metagross ods-signerd: [worker[2]] wait until drudgers are finished signing zone example.nl, 8 signatures queued
Oct 12 09:58:24 metagross ods-signerd: [drudger[3]] report for duty
Oct 12 09:58:24 metagross ods-signerd: [fifo] popped item, count=7
Oct 12 09:58:24 metagross ods-signerd: [rrset] signature set has no RRSIG record: drop signatures for RRset[2]
Oct 12 09:58:24 metagross ods-signerd: [rrset] signature validity 606646 in range [565200 - 651600]
Oct 12 09:58:24 metagross ods-signerd: [rrset] skipping key 8b56d5e67aa844ca0a1629226a12313e for signing RRset[2]: no active ZSK
Oct 12 09:58:24 metagross ods-signerd: [rrset] signing RRset[2] with key b17e71ad4ed9d0567da0a39c33fe5430
Oct 12 09:58:24 metagross ods-signerd: [drudger[6]] report for duty
Oct 12 09:58:24 metagross ods-signerd: [fifo] popped item, count=6
Oct 12 09:58:24 metagross ods-signerd: [rrset] drop signatures for RRset[6]
Oct 12 09:58:24 metagross ods-signerd: [rrset] signature validity 645906 in range [565200 - 651600]
Oct 12 09:58:24 metagross ods-signerd: [rrset] skipping key 8b56d5e67aa844ca0a1629226a12313e for signing RRset[6]: no active ZSK
Oct 12 09:58:24 metagross ods-signerd: [rrset] signing RRset[6] with key b17e71ad4ed9d0567da0a39c33fe5430
Oct 12 09:58:24 metagross ods-signerd: [hsm] sign RRset[6] with key b17e71ad4ed9d0567da0a39c33fe5430 tag 62370
Oct 12 09:58:24 metagross ods-signerd: [drudger[5]] report for duty
Oct 12 09:58:24 metagross ods-signerd: [fifo] popped item, count=5
Oct 12 09:58:24 metagross ods-signerd: [rrset] signature set has no RRSIG record: drop signatures for RRset[16]
Oct 12 09:58:24 metagross ods-signerd: [rrset] signature validity 602145 in range [565200 - 651600]
Oct 12 09:58:24 metagross ods-signerd: [rrset] skipping key 8b56d5e67aa844ca0a1629226a12313e for signing RRset[16]: no active ZSK
Oct 12 09:58:24 metagross ods-signerd: [drudger[4]] report for duty
Oct 12 09:58:24 metagross ods-signerd: [rrset] signing RRset[16] with key b17e71ad4ed9d0567da0a39c33fe5430
Oct 12 09:58:24 metagross ods-signerd: [fifo] popped item, count=4
Oct 12 09:58:24 metagross ods-signerd: [hsm] sign RRset[16] with key b17e71ad4ed9d0567da0a39c33fe5430 tag 62370
Oct 12 09:58:24 metagross ods-signerd: [rrset] recycle signature for RRset[48] (refresh=1318665504, signtime=1318406304, inception=1318268221, expiration=1318841423)
Oct 12 09:58:24 metagross ods-signerd: [drudger[7]] report for duty
Oct 12 09:58:24 metagross ods-signerd: [rrset] signature validity 576520 in range [565200 - 651600]
Oct 12 09:58:24 metagross ods-signerd: skipping key 8b56d5e67aa844ca0a1629226a12313e for signing: RRset[8] already has signature with same algorithm
Oct 12 09:58:24 metagross ods-signerd: [rrset] skipping key b17e71ad4ed9d0567da0a39c33fe5430 for signing RRset[48]: no active KSK
Oct 12 09:58:24 metagross ods-signerd: [rrset] skipping key b17e71ad4ed9d0567da0a39c33fe5430 for signing RRset[48]: no active KSK
Oct 12 09:58:24 metagross ods-signerd: [drudger[1]] report for duty
Oct 12 09:58:24 metagross ods-signerd: [drudger[8]] report for duty
Oct 12 09:58:24 metagross ods-signerd: [rrset] new signature created for RRset[6]
Oct 12 09:58:24 metagross ods-signerd: [rrset] skipping key bc84bb3a6364cb46527d80144ab00574 for signing RRset[48]: no active KSK
Oct 12 09:58:24 metagross ods-signerd: [drudger[2]] report for duty
Oct 12 09:58:24 metagross ods-signerd: [cmdhandler] 1 clients in progress...
Oct 12 09:58:24 metagross ods-signerd: [cmdhandler] accept client 33
Oct 12 09:58:24 metagross ods-signerd: [rrset] skipping key bc84bb3a6364cb46527d80144ab00574 for signing RRset[48]: no active KSK
Oct 12 09:58:24 metagross ods-signerd: [rrset] signing RRset[6] with key b17e71ad4ed9d0567da0a39c33fe5430
Oct 12 09:58:24 metagross ods-signerd: [hsm] sign RRset[6] with key b17e71ad4ed9d0567da0a39c33fe5430 tag 62370
Oct 12 09:58:24 metagross ods-signerd: [rrset] new signature created for RRset[16]
Oct 12 09:58:24 metagross ods-signerd: [rrset] signing RRset[16] with key b17e71ad4ed9d0567da0a39c33fe5430
Oct 12 09:58:24 metagross ods-signerd: [rrset] new signature created for RRset[6]
Oct 12 09:58:24 metagross ods-signerd: [hsm] sign RRset[16] with key b17e71ad4ed9d0567da0a39c33fe5430 tag 62370
Oct 12 09:58:24 metagross ods-signerd: [rrsig] adding duplicate RRSIG?
Oct 12 09:58:24 metagross ods-signerd: [rrset] unable to sign RRset[6]: error adding RRSIG
Oct 12 09:58:24 metagross ods-signerd: +RRSIG example.nl. 3600 IN RRSIG SOA 8 2 3600 20111019182330 20111012065824 62370 example.nl. rl57VKC253WfJ/V5LWUK/T3bS0+4KDIMp+5eLBqSK/X7daoYm8MeCjlYgjJYx6ovG+sK3RTgHRGn9XVhnUH9j3tbROLR7fpbz7EVf3i55r4X9GeUtuojgSdMw0X+1DR5IpvrXO4POYABb07IgD9KbAFDbZEkocT96BS30W3sOec= ;{id = 62370}
Oct 12 09:58:24 metagross ods-signerd: [drudger[6]] report for duty
Oct 12 09:58:24 metagross ods-signerd: [fifo] popped item, count=3
Oct 12 09:58:24 metagross ods-signerd: [hsm] sign RRset[2] with key b17e71ad4ed9d0567da0a39c33fe5430 tag 62370
Oct 12 09:58:24 metagross ods-signerd: [rrset] signature set has no RRSIG record: drop signatures for RRset[51]
Oct 12 09:58:24 metagross ods-signerd: [rrset] signature validity 648782 in range [565200 - 651600]
Oct 12 09:58:24 metagross ods-signerd: [rrset] skipping key 8b56d5e67aa844ca0a1629226a12313e for signing RRset[51]: no active ZSK
Oct 12 09:58:24 metagross ods-signerd: [rrset] signing RRset[51] with key b17e71ad4ed9d0567da0a39c33fe5430
Oct 12 09:58:24 metagross ods-signerd: [hsm] sign RRset[51] with key b17e71ad4ed9d0567da0a39c33fe5430 tag 62370
Oct 12 09:58:24 metagross ods-signerd: [cmdhandler] received command verbosity 2[11]
Oct 12 09:58:24 metagross ods-signerd: [fifo] popped item, count=2
Oct 12 09:58:24 metagross ods-signerd: [fifo] popped item, count=1
Oct 12 09:58:24 metagross ods-signerd: [rrset] signature set has no RRSIG record: drop signatures for RRset[1]
Oct 12 09:58:24 metagross ods-signerd: [rrset] signature validity 608366 in range [565200 - 651600]
Oct 12 09:58:24 metagross ods-signerd: [rrset] skipping key 8b56d5e67aa844ca0a1629226a12313e for signing RRset[1]: no active ZSK
Oct 12 09:58:24 metagross ods-signerd: [rrset] signing RRset[1] with key b17e71ad4ed9d0567da0a39c33fe5430
Oct 12 09:58:24 metagross ods-signerd: [hsm] sign RRset[1] with key b17e71ad4ed9d0567da0a39c33fe5430 tag 62370
Oct 12 09:58:24 metagross ods-signerd: [fifo] popped item, count=0
Oct 12 09:58:24 metagross ods-signerd: [rrset] signature set has no RRSIG record: drop signatures for RRset[50]
Oct 12 09:58:24 metagross ods-signerd: [rrset] signature validity 596111 in range [565200 - 651600]
Oct 12 09:58:24 metagross ods-signerd: [rrset] skipping key 8b56d5e67aa844ca0a1629226a12313e for signing RRset[50]: no active ZSK
Oct 12 09:58:24 metagross ods-signerd: [rrset] signing RRset[50] with key b17e71ad4ed9d0567da0a39c33fe5430
Oct 12 09:58:24 metagross ods-signerd: [hsm] sign RRset[50] with key b17e71ad4ed9d0567da0a39c33fe5430 tag 62370
Oct 12 09:58:24 metagross ods-signerd: [drudger[6]] nothing to do
Oct 12 09:58:24 metagross ods-signerd: [cmdhandler] verbosity command
Oct 12 09:58:24 metagross ods-signerd: [rrset] signature set has no RRSIG record: drop signatures for RRset[50]
Oct 12 09:58:24 metagross ods-signerd: [rrset] signature validity 599406 in range [565200 - 651600]
Oct 12 09:58:24 metagross ods-signerd: [rrset] skipping key 8b56d5e67aa844ca0a1629226a12313e for signing RRset[50]: no active ZSK
Oct 12 09:58:24 metagross ods-signerd: [rrset] signing RRset[50] with key b17e71ad4ed9d0567da0a39c33fe5430
Oct 12 09:58:24 metagross ods-signerd: [hsm] sign RRset[50] with key b17e71ad4ed9d0567da0a39c33fe5430 tag 62370
Oct 12 09:58:24 metagross ods-signerd: [rrset] skipping key 2dee14ce5efa28ff2305f05d8f552e0f for signing RRset[48]: no active KSK
Oct 12 09:58:24 metagross ods-signerd: [rrset] skipping key 2dee14ce5efa28ff2305f05d8f552e0f for signing RRset[48]: no active KSK
Oct 12 09:58:24 metagross ods-signerd: [log] switching log to syslog verbosity 2 (log level 4)
Oct 12 09:58:24 metagross ods-signerd: [drudger[4]] report for duty
Oct 12 09:58:24 metagross ods-signerd: [rrsig] adding duplicate RRSIG?
Oct 12 09:58:24 metagross ods-signerd: [rrset] unable to sign RRset[1]: error adding RRSIG
Oct 12 09:58:24 metagross ods-signerd: +RRSIG www.example.nl. 3600 IN RRSIG A 8 3 3600 20111019075750 20111012065824 62370 example.nl. IS4lZgSibyT21Qwh6Wtv/ImEIZp+jX6JtmhHXOjVGQMxnlGzHoB16oMog39ssyEgzqXT1hlaxydvK/ZZPblwQL+/0QkEbUlSKXw8zTenEi2Jm5Cqzzl0I78AyfYz8xIkowhNCWd6N+zhPDSgg0khcsyhBUoYzWNKnYjjflQkMZY= ;{id = 62370}
Oct 12 09:58:24 metagross ods-signerd: [rrsig] adding duplicate RRSIG?
Oct 12 09:58:24 metagross ods-signerd: [rrset] unable to sign RRset[50]: error adding RRSIG
Oct 12 09:58:24 metagross ods-signerd: +RRSIG 2gm7c2d5s26femt655rt526usj2ppvuq.example.nl. 3600 IN RRSIG NSEC3 8 3 3600 20111019043335 20111012065824 62370 example.nl. sx6p1qT4dSrD06RxbPmvPiphCpfS8yF/W4keqZ3p0apFms7yQxhGxBIG4J/bgkbX4ezTYRAXJSlXaBwYedvO5s3f03aMB5ICxUiT+mb6tu45bJfhSdJLlUGvIRHJ/BBY32Uqe7G1XIafEaN9e2bZfKwCLuPYnezJScUkVotsFzo= ;{id = 62370}
Oct 12 09:58:24 metagross ods-signerd: [rrsig] adding duplicate RRSIG?
Oct 12 09:58:24 metagross ods-signerd: [rrset] unable to sign RRset[50]: error adding RRSIG
Oct 12 09:58:24 metagross ods-signerd: +RRSIG qea9nrfccopecso0sugaeo72i448251v.example.nl. 3600 IN RRSIG NSEC3 8 3 3600 20111019052830 20111012065824 62370 example.nl. RgNpchbpX9PsoT+PZ+osyRXDuBUQ+6bcp4Y/0JUBN/VSCiBTwTpJLNWd1sJC2oFRs8wcj8ze2N99+J9PVceU5XlZKWrsvtA33qS0FoNwer920fMTvgbG1NzRaIOjhfIiWdta3m7KMOhSvvqvZUx/tFyzVQ7qQpdA9W2Cv5nT0sA= ;{id = 62370}
Oct 12 09:58:24 metagross ods-signerd: [rrsig] adding duplicate RRSIG?
Oct 12 09:58:24 metagross ods-signerd: [rrset] unable to sign RRset[2]: error adding RRSIG
Oct 12 09:58:24 metagross ods-signerd: +RRSIG example.nl. 86400 IN RRSIG NS 8 2 86400 20111019072910 20111012065824 62370 example.nl. ObrOhwmkmkdwW1phaKoLdEO51cazAlqRfd8nOsk8IyfXXV1Qt3A1xoLx6EHrf9G2/K9QSk/zUuMQm5H6/tIRXEa350DM0AgBQFfSCDi60cMzPyIN8gOdDzFX86FofGLut4mPYy+Gc/ihf+vdfr+7Gzlxl/9QRc7zbnuEGflV8RI= ;{id = 62370}
Oct 12 09:58:24 metagross ods-signerd: [rrsig] adding duplicate RRSIG?
Oct 12 09:58:24 metagross ods-signerd: [rrset] unable to sign RRset[16]: error adding RRSIG
Oct 12 09:58:24 metagross ods-signerd: +RRSIG example.nl. 86400 IN RRSIG TXT 8 2 86400 20111019061409 20111012065824 62370 example.nl. b9le9nDZ7WpwjBGLuzswtI19SUNQZ6It1pwo95GRHoicdDX7eeJLPS4WDdHZf6TxTCIFvEbHXmVLWtWTdWGlub6uNlsgjHnF4hVMy2eCSrBJ+2oaFomUD0F5ruAxekpHkkwQBy7ig4j70BsTeY3YEBZ+n8njX/zQYzWLohbKgtk= ;{id = 62370}
Oct 12 09:58:24 metagross ods-signerd: [rrsig] adding duplicate RRSIG?
Oct 12 09:58:24 metagross ods-signerd: [rrset] unable to sign RRset[51]: error adding RRSIG
Oct 12 09:58:24 metagross ods-signerd: +RRSIG example.nl. 3600 IN RRSIG NSEC3PARAM 8 2 3600 20111019191126 20111012065824 62370 example.nl. cI1Wdbr5uDSDAlzPLouoEBtFAc0qjEMdYe8Xo073MRme5jSVxXN/LrI95+VfFEIoC5xS0XVSBP95XAkH7Dy8SdIaXFckwX9ygAE1PWpa78cU53rYiynAtVOQNWi3sAhwATYM0GNNMJB+ScQqtKqWptq1UYLXmKJ+LUcEcAQsKYw= ;{id = 62370}
Oct 12 09:58:24 metagross ods-signerd: [worker[2]] sign zone example.nl failed: 7 of 8 signatures failed
--
Casper Gielen <cgielen at uvt.nl> | LIS UNIX
PGP fingerprint = 16BD 2C9F 8156 C242 F981 63B8 2214 083C F80E 4AF7
Universiteit van Tilburg | Postbus 90153, 5000 LE
Warandelaan 2 | Telefoon 013 466 4100 | G 236 | http://www.uvt.nl
More information about the Opendnssec-user
mailing list