[Opendnssec-user] Duplicate keys
Matthijs Mekking
matthijs at NLnetLabs.nl
Thu Oct 13 08:50:44 UTC 2011
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
Hi Casper,
The enforcer manages the keys, but the logs below only show the signer
logs. Do you have any logs on the enforcer?
Also, I would be interested in what keys are visible in the signer
configurations. Could you show me one?
Obviously from the logs, the signer cannot handle duplicate keys. I will
take a look how I can make this more robust.
Best regards,
Matthijs
On 10/12/2011 11:54 AM, Casper Gielen wrote:
> 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
>
>
>
>
>
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.11 (GNU/Linux)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/
iQEcBAEBAgAGBQJOlqZkAAoJEA8yVCPsQCW5wPMIAJLalsFGJ8s3OXgN9y/WHVIU
mOLInvz0eCg+Ax5aXZVwlcg8AwGM85tb/fgVemEce3X6hd4k3GiVQp66O8mp4f2T
kGaTl9YHDbXaSQeDMW6CjJBJLEWmEPPcTA5uHkrVIwqOgPnDI9ichy1tzpJIhi3D
uSDIyn0CMmJwlHzo0rQGNU7gUc/cKdQo5eCG5E2tRHa5y/8prAvC8i1ESyLEXRsB
xVYG5TIgKP4eCbO2WeNfDJGNkoXYNJ1eo5lV0qCSUNppoGDdBOvfH8Sw05Z/YXy1
XZcSAnEWXaHTA1Xo/j5M0YMorqE+NH0VcIco6rt5jT3AmOyxLhiF3ww39KqEiyQ=
=XWDO
-----END PGP SIGNATURE-----
More information about the Opendnssec-user
mailing list