Maintained by: NLnet Labs

[Unbound-users] Problem with SHA256 DS as trust anchors ?

Ralf Weber
Tue Feb 17 16:52:25 CET 2009


Moin!

RIPE recently published all there trust anchors as zone file format as  
DS records with SHA256 as digest algorithm. Now I seem to have  
problems when I use this file with unbound 1.2.1 as trust-anchor-file.  
Some keys seem to work, some not. One that does not work is:
	ripe.net. DS 7543 5 2  
A281F1D5BB5DE2FA435D77C0989321D757EA0FACED1CC7643D1ED6E64A4D3999
now when I generate an SHA1 DS record out of the key it does work  
perfectly.
	ripe.net. DS 7543 5 1 5f4134815032c5b39b02b9d248bbf49de44e1297
Here's the verbosity 3 output of a failed lookup to www.ripe.net using  
the first DS as trust anchor:

[1234885698] unbound[51557:0] debug: validator[module 0] operate:  
extstate:module_state_initial event:module_event_new
[1234885698] unbound[51557:0] info: validator operate: query <www.ripe.net 
. A IN>
[1234885698] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_state_initial event:module_event_pass
[1234885698] unbound[51557:0] info: resolving <www.ripe.net. A IN>
[1234885698] unbound[51557:0] info: priming . IN NS
[1234885698] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_state_initial event:module_event_pass
[1234885698] unbound[51557:0] info: iterator operate: query <. NS IN>
[1234885698] unbound[51557:0] info: processQueryTargets: <. NS IN>
[1234885698] unbound[51557:0] info: sending query: <. NS IN>
[1234885698] unbound[51557:0] debug: sending to target: <.>  
192.228.79.201#53
[1234885698] unbound[51557:0] debug: cache memory msg=197040  
rrset=197040 infra=55504 val=205432
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_reply
[1234885699] unbound[51557:0] info: iterator operate: query <. NS IN>
[1234885699] unbound[51557:0] info: response for <. NS IN>
[1234885699] unbound[51557:0] info: reply from <.> 192.228.79.201#53
[1234885699] unbound[51557:0] info: query response was ANSWER
[1234885699] unbound[51557:0] debug: validator[module 0] operate:  
extstate:module_state_initial event:module_event_moddone
[1234885699] unbound[51557:0] info: validator operate: query <. NS IN>
[1234885699] unbound[51557:0] info: priming successful for <. NS IN>
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_subquery event:module_event_pass
[1234885699] unbound[51557:0] info: iterator operate: query <www.ripe.net 
. A IN>
[1234885699] unbound[51557:0] info: resolving (init part 2):  <www.ripe.net 
. A IN>
[1234885699] unbound[51557:0] info: resolving (init part 3):  <www.ripe.net 
. A IN>
[1234885699] unbound[51557:0] info: processQueryTargets:  
<www.ripe.net. A IN>
[1234885699] unbound[51557:0] info: sending query: <www.ripe.net. A IN>
[1234885699] unbound[51557:0] debug: sending to target: <.>  
192.33.4.12#53
[1234885699] unbound[51557:0] debug: cache memory msg=197573  
rrset=202695 infra=55504 val=205432
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_reply
[1234885699] unbound[51557:0] info: iterator operate: query <www.ripe.net 
. A IN>
[1234885699] unbound[51557:0] info: response for <www.ripe.net. A IN>
[1234885699] unbound[51557:0] info: reply from <.> 192.33.4.12#53
[1234885699] unbound[51557:0] info: query response was REFERRAL
[1234885699] unbound[51557:0] info: processQueryTargets:  
<www.ripe.net. A IN>
[1234885699] unbound[51557:0] info: sending query: <www.ripe.net. A IN>
[1234885699] unbound[51557:0] debug: sending to target: <net.>  
192.5.6.30#53
[1234885699] unbound[51557:0] debug: cache memory msg=197573  
rrset=207064 infra=55504 val=205432
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_reply
[1234885699] unbound[51557:0] info: iterator operate: query <www.ripe.net 
. A IN>
[1234885699] unbound[51557:0] info: response for <www.ripe.net. A IN>
[1234885699] unbound[51557:0] info: reply from <net.> 192.5.6.30#53
[1234885699] unbound[51557:0] info: query response was REFERRAL
[1234885699] unbound[51557:0] info: processQueryTargets:  
<www.ripe.net. A IN>
[1234885699] unbound[51557:0] info: new target <sunic.sunet.se. A IN>
[1234885699] unbound[51557:0] info: new target <ns3.nic.fr. A IN>
[1234885699] unbound[51557:0] info: new target <ns-ext.isc.org. A IN>
[1234885699] unbound[51557:0] info: sending query: <www.ripe.net. A IN>
[1234885699] unbound[51557:0] debug: sending to target: <ripe.net.>  
193.0.0.195#53
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_state_initial event:module_event_pass
[1234885699] unbound[51557:0] info: iterator operate: query  
<sunic.sunet.se. A IN>
[1234885699] unbound[51557:0] info: resolving <sunic.sunet.se. A IN>
[1234885699] unbound[51557:0] info: resolving (init part 2):   
<sunic.sunet.se. A IN>
[1234885699] unbound[51557:0] info: resolving (init part 3):   
<sunic.sunet.se. A IN>
[1234885699] unbound[51557:0] info: processQueryTargets:  
<sunic.sunet.se. A IN>
[1234885699] unbound[51557:0] info: sending query: <sunic.sunet.se. A  
IN>
[1234885699] unbound[51557:0] debug: sending to target: <.>  
128.8.10.90#53
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_state_initial event:module_event_pass
[1234885699] unbound[51557:0] info: iterator operate: query <ns- 
ext.isc.org. A IN>
[1234885699] unbound[51557:0] info: resolving <ns-ext.isc.org. A IN>
[1234885699] unbound[51557:0] info: resolving (init part 2):  <ns- 
ext.isc.org. A IN>
[1234885699] unbound[51557:0] info: resolving (init part 3):  <ns- 
ext.isc.org. A IN>
[1234885699] unbound[51557:0] info: processQueryTargets: <ns- 
ext.isc.org. A IN>
[1234885699] unbound[51557:0] info: sending query: <ns-ext.isc.org. A  
IN>
[1234885699] unbound[51557:0] debug: sending to target: <.>  
192.228.79.201#53
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_state_initial event:module_event_pass
[1234885699] unbound[51557:0] info: iterator operate: query  
<ns3.nic.fr. A IN>
[1234885699] unbound[51557:0] info: resolving <ns3.nic.fr. A IN>
[1234885699] unbound[51557:0] info: resolving (init part 2):   
<ns3.nic.fr. A IN>
[1234885699] unbound[51557:0] info: resolving (init part 3):   
<ns3.nic.fr. A IN>
[1234885699] unbound[51557:0] info: processQueryTargets: <ns3.nic.fr.  
A IN>
[1234885699] unbound[51557:0] info: sending query: <ns3.nic.fr. A IN>
[1234885699] unbound[51557:0] debug: sending to target: <.>  
192.203.230.10#53
[1234885699] unbound[51557:0] debug: cache memory msg=197573  
rrset=207897 infra=55504 val=205432
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_reply
[1234885699] unbound[51557:0] info: iterator operate: query <www.ripe.net 
. A IN>
[1234885699] unbound[51557:0] info: sanitize: removing extraneous  
answer RRset: <aquila-www.ripe.net. A IN>
[1234885699] unbound[51557:0] info: response for <www.ripe.net. A IN>
[1234885699] unbound[51557:0] info: reply from <ripe.net.>  
193.0.0.195#53
[1234885699] unbound[51557:0] info: query response was CNAME
[1234885699] unbound[51557:0] info: resolving <www.ripe.net. A IN>
[1234885699] unbound[51557:0] info: resolving (init part 2):  <www.ripe.net 
. A IN>
[1234885699] unbound[51557:0] info: resolving (init part 3):  <www.ripe.net 
. A IN>
[1234885699] unbound[51557:0] info: processQueryTargets:  
<www.ripe.net. A IN>
[1234885699] unbound[51557:0] info: new target <ns-ext.isc.org. A IN>
[1234885699] unbound[51557:0] info: new target <sunic.sunet.se. A IN>
[1234885699] unbound[51557:0] info: new target <ns3.nic.fr. A IN>
[1234885699] unbound[51557:0] info: sending query: <aquila- 
www.ripe.net. A IN>
[1234885699] unbound[51557:0] debug: sending to target: <ripe.net.>  
193.0.0.195#53
[1234885699] unbound[51557:0] debug: cache memory msg=197573  
rrset=208922 infra=55504 val=205432
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_reply
[1234885699] unbound[51557:0] info: iterator operate: query <www.ripe.net 
. A IN>
[1234885699] unbound[51557:0] info: iterator operate: chased to  
<aquila-www.ripe.net. A IN>
[1234885699] unbound[51557:0] info: response for <www.ripe.net. A IN>
[1234885699] unbound[51557:0] info: reply from <ripe.net.>  
193.0.0.195#53
[1234885699] unbound[51557:0] info: query response was ANSWER
[1234885699] unbound[51557:0] info: finishing processing for <www.ripe.net 
. A IN>
[1234885699] unbound[51557:0] debug: validator[module 0] operate:  
extstate:module_wait_module event:module_event_moddone
[1234885699] unbound[51557:0] info: validator operate: query <www.ripe.net 
. A IN>
[1234885699] unbound[51557:0] info: prime trust anchor
[1234885699] unbound[51557:0] debug: validator[module 0] operate:  
extstate:module_state_initial event:module_event_pass
[1234885699] unbound[51557:0] info: validator operate: query  
<ripe.net. DNSKEY IN>
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_state_initial event:module_event_pass
[1234885699] unbound[51557:0] info: resolving <ripe.net. DNSKEY IN>
[1234885699] unbound[51557:0] info: resolving (init part 2):   
<ripe.net. DNSKEY IN>
[1234885699] unbound[51557:0] info: resolving (init part 3):   
<ripe.net. DNSKEY IN>
[1234885699] unbound[51557:0] info: processQueryTargets: <ripe.net.  
DNSKEY IN>
[1234885699] unbound[51557:0] info: new target <ns-ext.isc.org. A IN>
[1234885699] unbound[51557:0] info: new target <sunic.sunet.se. A IN>
[1234885699] unbound[51557:0] info: new target <ns3.nic.fr. A IN>
[1234885699] unbound[51557:0] info: sending query: <ripe.net. DNSKEY IN>
[1234885699] unbound[51557:0] debug: sending to target: <ripe.net.>  
193.0.0.195#53
[1234885699] unbound[51557:0] debug: cache memory msg=198144  
rrset=209361 infra=55504 val=205432
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_reply
[1234885699] unbound[51557:0] info: iterator operate: query <ns- 
ext.isc.org. A IN>
[1234885699] unbound[51557:0] info: response for <ns-ext.isc.org. A IN>
[1234885699] unbound[51557:0] info: reply from <.> 192.228.79.201#53
[1234885699] unbound[51557:0] info: query response was REFERRAL
[1234885699] unbound[51557:0] info: processQueryTargets: <ns- 
ext.isc.org. A IN>
[1234885699] unbound[51557:0] info: sending query: <ns-ext.isc.org. A  
IN>
[1234885699] unbound[51557:0] debug: sending to target: <org.>  
199.249.120.1#53
[1234885699] unbound[51557:0] debug: cache memory msg=198144  
rrset=212883 infra=55504 val=205432
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_reply
[1234885699] unbound[51557:0] info: iterator operate: query  
<ns3.nic.fr. A IN>
[1234885699] unbound[51557:0] info: response for <ns3.nic.fr. A IN>
[1234885699] unbound[51557:0] info: reply from <.> 192.203.230.10#53
[1234885699] unbound[51557:0] info: query response was REFERRAL
[1234885699] unbound[51557:0] info: processQueryTargets: <ns3.nic.fr.  
A IN>
[1234885699] unbound[51557:0] info: sending query: <ns3.nic.fr. A IN>
[1234885699] unbound[51557:0] debug: sending to target: <fr.>  
204.152.184.85#53
[1234885699] unbound[51557:0] debug: cache memory msg=198144  
rrset=215963 infra=55504 val=205432
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_reply
[1234885699] unbound[51557:0] info: iterator operate: query  
<sunic.sunet.se. A IN>
[1234885699] unbound[51557:0] info: response for <sunic.sunet.se. A IN>
[1234885699] unbound[51557:0] info: reply from <.> 128.8.10.90#53
[1234885699] unbound[51557:0] info: query response was REFERRAL
[1234885699] unbound[51557:0] info: processQueryTargets:  
<sunic.sunet.se. A IN>
[1234885699] unbound[51557:0] info: sending query: <sunic.sunet.se. A  
IN>
[1234885699] unbound[51557:0] debug: sending to target: <se.>  
199.7.49.30#53
[1234885699] unbound[51557:0] debug: cache memory msg=198144  
rrset=219496 infra=55816 val=205432
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_reply
[1234885699] unbound[51557:0] info: iterator operate: query  
<sunic.sunet.se. A IN>
[1234885699] unbound[51557:0] info: response for <sunic.sunet.se. A IN>
[1234885699] unbound[51557:0] info: reply from <se.> 199.7.49.30#53
[1234885699] unbound[51557:0] info: query response was REFERRAL
[1234885699] unbound[51557:0] info: processQueryTargets:  
<sunic.sunet.se. A IN>
[1234885699] unbound[51557:0] info: new target <server.nordu.net. A IN>
[1234885699] unbound[51557:0] info: sending query: <sunic.sunet.se. A  
IN>
[1234885699] unbound[51557:0] debug: sending to target: <sunet.se.>  
130.237.72.250#53
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_state_initial event:module_event_pass
[1234885699] unbound[51557:0] info: iterator operate: query  
<server.nordu.net. A IN>
[1234885699] unbound[51557:0] info: resolving <server.nordu.net. A IN>
[1234885699] unbound[51557:0] info: resolving (init part 2):   
<server.nordu.net. A IN>
[1234885699] unbound[51557:0] info: resolving (init part 3):   
<server.nordu.net. A IN>
[1234885699] unbound[51557:0] info: processQueryTargets:  
<server.nordu.net. A IN>
[1234885699] unbound[51557:0] info: sending query: <server.nordu.net.  
A IN>
[1234885699] unbound[51557:0] debug: sending to target: <net.>  
192.33.14.30#53
[1234885699] unbound[51557:0] debug: cache memory msg=198144  
rrset=221474 infra=55816 val=205764
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_reply
[1234885699] unbound[51557:0] info: iterator operate: query  
<server.nordu.net. A IN>
[1234885699] unbound[51557:0] info: response for <server.nordu.net. A  
IN>
[1234885699] unbound[51557:0] info: reply from <net.> 192.33.14.30#53
[1234885699] unbound[51557:0] info: query response was REFERRAL
[1234885699] unbound[51557:0] info: processQueryTargets:  
<server.nordu.net. A IN>
[1234885699] unbound[51557:0] info: skipping target due to dependency  
cycle (harden-glue: no may fix some of the cycles) <server.nordu.net.  
A IN>
[1234885699] unbound[51557:0] info: new target <nn.uninett.no. A IN>
[1234885699] unbound[51557:0] info: sending query: <server.nordu.net.  
A IN>
[1234885699] unbound[51557:0] debug: sending to target: <nordu.net.>  
193.10.252.19#53
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_state_initial event:module_event_pass
[1234885699] unbound[51557:0] info: iterator operate: query  
<nn.uninett.no. A IN>
[1234885699] unbound[51557:0] info: resolving <nn.uninett.no. A IN>
[1234885699] unbound[51557:0] info: resolving (init part 2):   
<nn.uninett.no. A IN>
[1234885699] unbound[51557:0] info: resolving (init part 3):   
<nn.uninett.no. A IN>
[1234885699] unbound[51557:0] info: processQueryTargets:  
<nn.uninett.no. A IN>
[1234885699] unbound[51557:0] info: sending query: <nn.uninett.no. A IN>
[1234885699] unbound[51557:0] debug: sending to target: <.>  
192.36.148.17#53
[1234885699] unbound[51557:0] debug: cache memory msg=198144  
rrset=222318 infra=55816 val=205764
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_reply
[1234885699] unbound[51557:0] info: iterator operate: query  
<sunic.sunet.se. A IN>
[1234885699] unbound[51557:0] info: sanitize: removing potential  
poison RRset: <b.ns.kth.se. A IN>
[1234885699] unbound[51557:0] info: response for <sunic.sunet.se. A IN>
[1234885699] unbound[51557:0] info: reply from <sunet.se.>  
130.237.72.250#53
[1234885699] unbound[51557:0] info: query response was ANSWER
[1234885699] unbound[51557:0] info: finishing processing for  
<sunic.sunet.se. A IN>
[1234885699] unbound[51557:0] debug: validator[module 0] operate:  
extstate:module_state_initial event:module_event_moddone
[1234885699] unbound[51557:0] info: validator operate: query  
<sunic.sunet.se. A IN>
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_pass
[1234885699] unbound[51557:0] info: iterator operate: query <ripe.net.  
DNSKEY IN>
[1234885699] unbound[51557:0] info: processQueryTargets: <ripe.net.  
DNSKEY IN>
[1234885699] unbound[51557:0] debug: cache memory msg=198436  
rrset=222318 infra=55816 val=205764
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_reply
[1234885699] unbound[51557:0] info: iterator operate: query  
<ns3.nic.fr. A IN>
[1234885699] unbound[51557:0] info: sanitize: removing potential  
poison RRset: <ns-sec.ripe.net. A IN>
[1234885699] unbound[51557:0] info: sanitize: removing potential  
poison RRset: <ns-sec.ripe.net. AAAA IN>
[1234885699] unbound[51557:0] info: response for <ns3.nic.fr. A IN>
[1234885699] unbound[51557:0] info: reply from <fr.> 204.152.184.85#53
[1234885699] unbound[51557:0] info: query response was REFERRAL
[1234885699] unbound[51557:0] info: processQueryTargets: <ns3.nic.fr.  
A IN>
[1234885699] unbound[51557:0] info: sending query: <ns3.nic.fr. A IN>
[1234885699] unbound[51557:0] debug: sending to target: <nic.fr.>  
192.134.0.49#53
[1234885699] unbound[51557:0] debug: cache memory msg=198436  
rrset=224185 infra=55816 val=205764
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_noreply
[1234885699] unbound[51557:0] info: iterator operate: query <ripe.net.  
DNSKEY IN>
[1234885699] unbound[51557:0] info: processQueryTargets: <ripe.net.  
DNSKEY IN>
[1234885699] unbound[51557:0] info: sending query: <ripe.net. DNSKEY IN>
[1234885699] unbound[51557:0] debug: sending to target: <ripe.net.>  
192.36.125.2#53
[1234885699] unbound[51557:0] debug: cache memory msg=198436  
rrset=224185 infra=55816 val=205764
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_reply
[1234885699] unbound[51557:0] info: iterator operate: query  
<nn.uninett.no. A IN>
[1234885699] unbound[51557:0] info: response for <nn.uninett.no. A IN>
[1234885699] unbound[51557:0] info: reply from <.> 192.36.148.17#53
[1234885699] unbound[51557:0] info: query response was REFERRAL
[1234885699] unbound[51557:0] info: processQueryTargets:  
<nn.uninett.no. A IN>
[1234885699] unbound[51557:0] info: sending query: <nn.uninett.no. A IN>
[1234885699] unbound[51557:0] debug: sending to target: <no.>  
198.133.199.104#53
[1234885699] unbound[51557:0] debug: cache memory msg=198436  
rrset=225975 infra=56128 val=205764
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_reply
[1234885699] unbound[51557:0] info: iterator operate: query  
<server.nordu.net. A IN>
[1234885699] unbound[51557:0] info: sanitize: removing potential  
poison RRset: <sunic.sunet.se. A IN>
[1234885699] unbound[51557:0] info: sanitize: removing potential  
poison RRset: <sunic.sunet.se. AAAA IN>
[1234885699] unbound[51557:0] info: sanitize: removing potential  
poison RRset: <nn.uninett.no. A IN>
[1234885699] unbound[51557:0] info: response for <server.nordu.net. A  
IN>
[1234885699] unbound[51557:0] info: reply from <nordu.net.>  
193.10.252.19#53
[1234885699] unbound[51557:0] info: query response was ANSWER
[1234885699] unbound[51557:0] info: finishing processing for  
<server.nordu.net. A IN>
[1234885699] unbound[51557:0] debug: validator[module 0] operate:  
extstate:module_state_initial event:module_event_moddone
[1234885699] unbound[51557:0] info: validator operate: query  
<server.nordu.net. A IN>
[1234885699] unbound[51557:0] debug: cache memory msg=198698  
rrset=225975 infra=56128 val=205764
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_reply
[1234885699] unbound[51557:0] info: iterator operate: query  
<ns3.nic.fr. A IN>
[1234885699] unbound[51557:0] info: sanitize: removing potential  
poison RRset: <ns1.oleane.net. A IN>
[1234885699] unbound[51557:0] info: sanitize: removing potential  
poison RRset: <ns-sec.ripe.net. A IN>
[1234885699] unbound[51557:0] info: sanitize: removing potential  
poison RRset: <ns-sec.ripe.net. AAAA IN>
[1234885699] unbound[51557:0] info: response for <ns3.nic.fr. A IN>
[1234885699] unbound[51557:0] info: reply from <nic.fr.> 192.134.0.49#53
[1234885699] unbound[51557:0] info: query response was ANSWER
[1234885699] unbound[51557:0] info: finishing processing for  
<ns3.nic.fr. A IN>
[1234885699] unbound[51557:0] debug: validator[module 0] operate:  
extstate:module_state_initial event:module_event_moddone
[1234885699] unbound[51557:0] info: validator operate: query  
<ns3.nic.fr. A IN>
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_pass
[1234885699] unbound[51557:0] info: iterator operate: query <ripe.net.  
DNSKEY IN>
[1234885699] unbound[51557:0] info: processQueryTargets: <ripe.net.  
DNSKEY IN>
[1234885699] unbound[51557:0] debug: cache memory msg=199018  
rrset=226225 infra=56128 val=205764
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_reply
[1234885699] unbound[51557:0] info: iterator operate: query <ns- 
ext.isc.org. A IN>
[1234885699] unbound[51557:0] info: response for <ns-ext.isc.org. A IN>
[1234885699] unbound[51557:0] info: reply from <org.> 199.249.120.1#53
[1234885699] unbound[51557:0] info: query response was REFERRAL
[1234885699] unbound[51557:0] info: processQueryTargets: <ns- 
ext.isc.org. A IN>
[1234885699] unbound[51557:0] info: sending query: <ns-ext.isc.org. A  
IN>
[1234885699] unbound[51557:0] debug: sending to target: <isc.org.>  
199.6.0.30#53
[1234885699] unbound[51557:0] debug: cache memory msg=199018  
rrset=227566 infra=56440 val=205764
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_reply
[1234885699] unbound[51557:0] info: iterator operate: query <ripe.net.  
DNSKEY IN>
[1234885699] unbound[51557:0] info: sanitize: removing potential  
poison RRset: <ns3.nic.fr. A IN>
[1234885699] unbound[51557:0] info: sanitize: removing potential  
poison RRset: <ns3.nic.fr. AAAA IN>
[1234885699] unbound[51557:0] info: sanitize: removing potential  
poison RRset: <sunic.sunet.se. A IN>
[1234885699] unbound[51557:0] info: sanitize: removing potential  
poison RRset: <sunic.sunet.se. AAAA IN>
[1234885699] unbound[51557:0] info: sanitize: removing potential  
poison RRset: <ns-ext.isc.org. A IN>
[1234885699] unbound[51557:0] info: sanitize: removing potential  
poison RRset: <ns-ext.isc.org. AAAA IN>
[1234885699] unbound[51557:0] info: response for <ripe.net. DNSKEY IN>
[1234885699] unbound[51557:0] info: reply from <ripe.net.>  
192.36.125.2#53
[1234885699] unbound[51557:0] info: query response was ANSWER
[1234885699] unbound[51557:0] info: finishing processing for  
<ripe.net. DNSKEY IN>
[1234885699] unbound[51557:0] debug: validator[module 0] operate:  
extstate:module_wait_module event:module_event_moddone
[1234885699] unbound[51557:0] info: validator operate: query  
<ripe.net. DNSKEY IN>
[1234885699] unbound[51557:0] info: validate keys with anchor(DS):  
sec_status_bogus
[1234885699] unbound[51557:0] info: failed to prime trust anchor --  
could not fetch secure DNSKEY rrset <ripe.net. DNSKEY IN>
[1234885699] unbound[51557:0] debug: validator[module 0] operate:  
extstate:module_wait_subquery event:module_event_pass
[1234885699] unbound[51557:0] info: validator operate: query <www.ripe.net 
. A IN>
[1234885699] unbound[51557:0] info: Could not establish a chain of  
trust to keys for <ripe.net. DNSKEY IN>
[1234885699] unbound[51557:0] debug: cache memory msg=199288  
rrset=228896 infra=56440 val=205950
[1234885699] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_reply
[1234885699] unbound[51557:0] info: iterator operate: query  
<nn.uninett.no. A IN>
[1234885699] unbound[51557:0] info: response for <nn.uninett.no. A IN>
[1234885699] unbound[51557:0] info: reply from <no.> 198.133.199.104#53
[1234885699] unbound[51557:0] info: query response was REFERRAL
[1234885699] unbound[51557:0] info: processQueryTargets:  
<nn.uninett.no. A IN>
[1234885699] unbound[51557:0] info: sending query: <nn.uninett.no. A IN>
[1234885699] unbound[51557:0] debug: sending to target: <uninett.no.>  
158.38.0.181#53
[1234885699] unbound[51557:0] debug: cache memory msg=199288  
rrset=230218 infra=56440 val=205950
[1234885700] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_reply
[1234885700] unbound[51557:0] info: iterator operate: query  
<nn.uninett.no. A IN>
[1234885700] unbound[51557:0] info: sanitize: removing potential  
poison RRset: <nac.no. A IN>
[1234885700] unbound[51557:0] info: sanitize: removing potential  
poison RRset: <server.nordu.net. A IN>
[1234885700] unbound[51557:0] info: response for <nn.uninett.no. A IN>
[1234885700] unbound[51557:0] info: reply from <uninett.no.>  
158.38.0.181#53
[1234885700] unbound[51557:0] info: query response was ANSWER
[1234885700] unbound[51557:0] info: finishing processing for  
<nn.uninett.no. A IN>
[1234885700] unbound[51557:0] debug: validator[module 0] operate:  
extstate:module_state_initial event:module_event_moddone
[1234885700] unbound[51557:0] info: validator operate: query  
<nn.uninett.no. A IN>
[1234885700] unbound[51557:0] debug: cache memory msg=199563  
rrset=230473 infra=56440 val=205950
[1234885700] unbound[51557:0] debug: iterator[module 1] operate:  
extstate:module_wait_reply event:module_event_reply
[1234885700] unbound[51557:0] info: iterator operate: query <ns- 
ext.isc.org. A IN>
[1234885700] unbound[51557:0] info: response for <ns-ext.isc.org. A IN>
[1234885700] unbound[51557:0] info: reply from <isc.org.> 199.6.0.30#53
[1234885700] unbound[51557:0] info: query response was ANSWER
[1234885700] unbound[51557:0] info: finishing processing for <ns- 
ext.isc.org. A IN>
[1234885700] unbound[51557:0] debug: validator[module 0] operate:  
extstate:module_state_initial event:module_event_moddone
[1234885700] unbound[51557:0] info: validator operate: query <ns- 
ext.isc.org. A IN>
[1234885700] unbound[51557:0] debug: cache memory msg=199871  
rrset=231988 infra=56440 val=205950

I'm not sure if the error is in unbound or the DS record, so please  
have a look.

TIA and so long
-Ralf
---
Ralf Weber
e: unbound at fl1ger.de