[Unbound-users] Validation failure of DNSSEC signed domain names
Zbynek Michl
zbynek.michl at nic.cz
Fri Apr 30 09:49:26 UTC 2010
Here is another log of A www.nic.cz query. There are some blacklists which are
probably reason of the bad validation.
Also I have find out that after 900 seconds when "strange state" starts is
everything OK. Any connection with "dnssec-lameness" paragraph at
<http://www.unbound.net/documentation/requirements.html>?
Cheers,
Zbynek
--- LOG ---
[1272618346] unbound[26422:2] info: validator operate: query <www.nic.cz. A IN>
[1272618346] unbound[26422:2] debug: validator: pass to next module
[1272618346] unbound[26422:2] debug: mesh_run: validator module exit state is
module_wait_module
[1272618346] unbound[26422:2] debug: iterator[module 1] operate:
extstate:module_state_initial event:module_event_pass
[1272618346] unbound[26422:2] debug: process_request: new external request event
[1272618346] unbound[26422:2] debug: iter_handle processing q with state INIT
REQUEST STATE
[1272618346] unbound[26422:2] info: resolving <www.nic.cz. A IN>
[1272618346] unbound[26422:2] debug: request has dependency depth of 0
[1272618346] unbound[26422:2] debug: cache delegation returns delegpt
[1272618346] unbound[26422:2] info: DelegationPoint<cz.>: 5 names (0 missing),
10 addrs (0 result, 10 avail)
[1272618346] unbound[26422:2] info: f.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: d.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: c.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: b.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: a.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] debug: ip6 2001:678:f::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:10::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.13.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2a01:40:1000::2 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:1::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:628:453:420::48 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.171.255.48 port 53 (len 16)
[1272618346] unbound[26422:2] debug: iter_handle processing q with state INIT
REQUEST STATE (stage 2)
[1272618346] unbound[26422:2] info: resolving (init part 2): <www.nic.cz. A IN>
[1272618346] unbound[26422:2] debug: iter_handle processing q with state INIT
REQUEST STATE (stage 3)
[1272618346] unbound[26422:2] info: resolving (init part 3): <www.nic.cz. A IN>
[1272618346] unbound[26422:2] debug: iter_handle processing q with state QUERY
TARGETS STATE
[1272618346] unbound[26422:2] info: processQueryTargets: <www.nic.cz. A IN>
[1272618346] unbound[26422:2] debug: processQueryTargets: targetqueries 0,
currentqueries 0
[1272618346] unbound[26422:2] info: DelegationPoint<cz.>: 5 names (0 missing),
10 addrs (0 result, 10 avail)
[1272618346] unbound[26422:2] info: f.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: d.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: c.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: b.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: a.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] debug: ip6 2001:678:f::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:10::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.13.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2a01:40:1000::2 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:1::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:628:453:420::48 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.171.255.48 port 53 (len 16)
[1272618346] unbound[26422:2] debug: attempt to get extra 3 targets
[1272618346] unbound[26422:2] debug: servselect ip4 193.171.255.48 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=8898 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=722 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=1508 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 194.0.13.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=8823 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=1739 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: selrtt 120722
[1272618346] unbound[26422:2] debug: chase to dnssec lame server
[1272618346] unbound[26422:2] info: sending query: <www.nic.cz. A IN>
[1272618346] unbound[26422:2] debug: sending to target: <cz.> 193.29.206.1#53
[1272618346] unbound[26422:2] debug: serviced query UDP timeout=722 msec
[1272618346] unbound[26422:2] debug: inserted new pending reply id=3ef7
[1272618346] unbound[26422:2] debug: opened UDP if=0 port=56817
[1272618346] unbound[26422:2] debug: comm point start listening 13
[1272618346] unbound[26422:2] debug: mesh_run: iterator module exit state is
module_wait_reply
[1272618346] unbound[26422:2] info: mesh_run: end 1 recursion states (1 with
reply, 0 detached), 1 waiting replies, 6752 recursion replies sent, 0 replies
dropped, 0 states jostled out
[1272618346] unbound[26422:2] info: average recursion processing time 38.779874 sec
[1272618346] unbound[26422:2] info: histogram of recursion processing times
[1272618346] unbound[26422:2] info: [25%]=1.88123 median[50%]=6.94849 [75%]=0.732824
[1272618346] unbound[26422:2] info: lower(secs) upper(secs) recursions
[1272618346] unbound[26422:2] info: 0.000000 0.000001 159
[1272618346] unbound[26422:2] info: 0.004096 0.008192 24
[1272618346] unbound[26422:2] info: 0.008192 0.016384 4
[1272618346] unbound[26422:2] info: 0.016384 0.032768 9
[1272618346] unbound[26422:2] info: 0.032768 0.065536 11
[1272618346] unbound[26422:2] info: 0.065536 0.131072 31
[1272618346] unbound[26422:2] info: 0.131072 0.262144 8
[1272618346] unbound[26422:2] info: 0.262144 0.524288 29
[1272618346] unbound[26422:2] info: 0.524288 1.000000 48
[1272618346] unbound[26422:2] info: 1.000000 2.000000 383
[1272618346] unbound[26422:2] info: 2.000000 4.000000 1044
[1272618346] unbound[26422:2] info: 4.000000 8.000000 1137
[1272618346] unbound[26422:2] info: 8.000000 16.000000 563
[1272618346] unbound[26422:2] info: 16.000000 32.000000 721
[1272618346] unbound[26422:2] info: 32.000000 64.000000 878
[1272618346] unbound[26422:2] info: 64.000000 128.000000 1310
[1272618346] unbound[26422:2] info: 128.000000 256.000000 393
[1272618346] unbound[26422:2] info: 0RDd mod1 rep <www.nic.cz. A IN>
[1272618346] unbound[26422:2] debug: cache memory msg=3570894 rrset=4428253
infra=35743 val=4001591
[1272618346] unbound[26422:2] debug: answer cb
[1272618346] unbound[26422:2] debug: Incoming reply id = 3ef7
[1272618346] unbound[26422:2] debug: Incoming reply addr = ip4 193.29.206.1 port
53 (len 16)
[1272618346] unbound[26422:2] debug: lookup size is 1 entries
[1272618346] unbound[26422:2] debug: received udp reply.
[1272618346] unbound[26422:2] debug: udp message[227:0]
3EF78400000100010003000603777777036E696302637A0000010001C00C00010001000007080004D91FCD32C010000200010000070800070161026E73C010C010000200010000070800040162C03AC010000200010000070800040164C03AC03800010001000007080004C2000C01C038001C000100000708001020010678000F00000000000000000001C04B00010001000007080004C2000D01C04B001C000100000708001020010678001000000000000000000001C05B00010001000007080004C11DCE01C05B001C000100000708001020010678000100000000000000000001
[1272618346] unbound[26422:2] debug: outnet handle udp reply
[1272618346] unbound[26422:2] debug: measured roundtrip at 1 msec
[1272618346] unbound[26422:2] debug: svcd callbacks start
[1272618346] unbound[26422:2] debug: worker svcd callback for qstate 0x175e850
[1272618346] unbound[26422:2] debug: mesh_run: start
[1272618346] unbound[26422:2] debug: iterator[module 1] operate:
extstate:module_wait_reply event:module_event_reply
[1272618346] unbound[26422:2] info: iterator operate: query <www.nic.cz. A IN>
[1272618346] unbound[26422:2] debug: process_response: new external response event
[1272618346] unbound[26422:2] info: scrub for <cz. NS IN>
[1272618346] unbound[26422:2] info: response for <www.nic.cz. A IN>
[1272618346] unbound[26422:2] info: reply from <cz.> 193.29.206.1#53
[1272618346] unbound[26422:2] info: incoming scrubbed packet: ;; ->>HEADER<<-
opcode: QUERY, rcode: NOERROR, id: 0
;; flags: qr aa ; QUERY: 1, ANSWER: 1, AUTHORITY: 3, ADDITIONAL: 6
;; QUESTION SECTION:
;; www.nic.cz. IN A
;; ANSWER SECTION:
www.nic.cz. 1800 IN A 217.31.205.50
;; AUTHORITY SECTION:
nic.cz. 1800 IN NS a.ns.nic.cz.
nic.cz. 1800 IN NS b.ns.nic.cz.
nic.cz. 1800 IN NS d.ns.nic.cz.
;; ADDITIONAL SECTION:
a.ns.nic.cz. 1800 IN A 194.0.12.1
a.ns.nic.cz. 1800 IN AAAA 2001:678:f::1
b.ns.nic.cz. 1800 IN A 194.0.13.1
b.ns.nic.cz. 1800 IN AAAA 2001:678:10::1
d.ns.nic.cz. 1800 IN A 193.29.206.1
d.ns.nic.cz. 1800 IN AAAA 2001:678:1::1
;; Query time: 0 msec
;; WHEN: Thu Jan 1 01:00:00 1970
;; MSG SIZE rcvd: 227
[1272618346] unbound[26422:2] debug: iter_handle processing q with state QUERY
RESPONSE STATE
[1272618346] unbound[26422:2] info: query response was ANSWER
[1272618346] unbound[26422:2] debug: iter_handle processing q with state
FINISHED RESPONSE STATE
[1272618346] unbound[26422:2] info: finishing processing for <www.nic.cz. A IN>
[1272618346] unbound[26422:2] debug: mesh_run: iterator module exit state is
module_finished
[1272618346] unbound[26422:2] debug: validator[module 0] operate:
extstate:module_wait_module event:module_event_moddone
[1272618346] unbound[26422:2] info: validator operate: query <www.nic.cz. A IN>
[1272618346] unbound[26422:2] debug: validator: nextmodule returned
[1272618346] unbound[26422:2] debug: val handle processing q with state
VAL_INIT_STATE
[1272618346] unbound[26422:2] debug: validator classification positive
[1272618346] unbound[26422:2] info: no signer, using <www.nic.cz. TYPE0 CLASS0>
[1272618346] unbound[26422:2] debug: val handle processing q with state
VAL_FINDKEY_STATE
[1272618346] unbound[26422:2] info: validator: FindKey <www.nic.cz. A IN>
[1272618346] unbound[26422:2] info: current keyname <cz. DNSKEY IN>
[1272618346] unbound[26422:2] info: target keyname <www.nic.cz. DNSKEY IN>
[1272618346] unbound[26422:2] debug: striplab 1
[1272618346] unbound[26422:2] info: next keyname <nic.cz. DNSKEY IN>
[1272618346] unbound[26422:2] debug: No DS RRset
[1272618346] unbound[26422:2] info: generate request <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: mesh_run: validator module exit state is
module_wait_subquery
[1272618346] unbound[26422:2] debug: validator[module 0] operate:
extstate:module_state_initial event:module_event_pass
[1272618346] unbound[26422:2] info: validator operate: query <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: validator: pass to next module
[1272618346] unbound[26422:2] debug: mesh_run: validator module exit state is
module_wait_module
[1272618346] unbound[26422:2] debug: iterator[module 1] operate:
extstate:module_state_initial event:module_event_pass
[1272618346] unbound[26422:2] debug: process_request: new external request event
[1272618346] unbound[26422:2] debug: iter_handle processing q with state INIT
REQUEST STATE
[1272618346] unbound[26422:2] info: resolving <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: request has dependency depth of 0
[1272618346] unbound[26422:2] debug: cache delegation returns delegpt
[1272618346] unbound[26422:2] info: DelegationPoint<cz.>: 5 names (0 missing),
10 addrs (0 result, 10 avail)
[1272618346] unbound[26422:2] info: f.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: d.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: c.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: b.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: a.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] debug: ip6 2001:678:f::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:10::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.13.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2a01:40:1000::2 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:1::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:628:453:420::48 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.171.255.48 port 53 (len 16)
[1272618346] unbound[26422:2] debug: iter_handle processing q with state INIT
REQUEST STATE (stage 2)
[1272618346] unbound[26422:2] info: resolving (init part 2): <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: iter_handle processing q with state INIT
REQUEST STATE (stage 3)
[1272618346] unbound[26422:2] info: resolving (init part 3): <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: iter_handle processing q with state QUERY
TARGETS STATE
[1272618346] unbound[26422:2] info: processQueryTargets: <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: processQueryTargets: targetqueries 0,
currentqueries 0
[1272618346] unbound[26422:2] info: DelegationPoint<cz.>: 5 names (0 missing),
10 addrs (0 result, 10 avail)
[1272618346] unbound[26422:2] info: f.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: d.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: c.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: b.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: a.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] debug: ip6 2001:678:f::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:10::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.13.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2a01:40:1000::2 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:1::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:628:453:420::48 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.171.255.48 port 53 (len 16)
[1272618346] unbound[26422:2] debug: attempt to get extra 3 targets
[1272618346] unbound[26422:2] debug: servselect ip4 193.171.255.48 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=8898 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=661 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=1508 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 194.0.13.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=8823 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=1739 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: selrtt 120661
[1272618346] unbound[26422:2] debug: chase to dnssec lame server
[1272618346] unbound[26422:2] info: sending query: <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: sending to target: <cz.> 193.29.206.1#53
[1272618346] unbound[26422:2] debug: serviced query UDP timeout=661 msec
[1272618346] unbound[26422:2] debug: inserted new pending reply id=ebee
[1272618346] unbound[26422:2] debug: opened UDP if=0 port=54893
[1272618346] unbound[26422:2] debug: comm point start listening 14
[1272618346] unbound[26422:2] debug: mesh_run: iterator module exit state is
module_wait_reply
[1272618346] unbound[26422:2] info: mesh_run: end 2 recursion states (1 with
reply, 0 detached), 1 waiting replies, 6752 recursion replies sent, 0 replies
dropped, 0 states jostled out
[1272618346] unbound[26422:2] info: average recursion processing time 38.779874 sec
[1272618346] unbound[26422:2] info: histogram of recursion processing times
[1272618346] unbound[26422:2] info: [25%]=1.88123 median[50%]=6.94849 [75%]=0.732824
[1272618346] unbound[26422:2] info: lower(secs) upper(secs) recursions
[1272618346] unbound[26422:2] info: 0.000000 0.000001 159
[1272618346] unbound[26422:2] info: 0.004096 0.008192 24
[1272618346] unbound[26422:2] info: 0.008192 0.016384 4
[1272618346] unbound[26422:2] info: 0.016384 0.032768 9
[1272618346] unbound[26422:2] info: 0.032768 0.065536 11
[1272618346] unbound[26422:2] info: 0.065536 0.131072 31
[1272618346] unbound[26422:2] info: 0.131072 0.262144 8
[1272618346] unbound[26422:2] info: 0.262144 0.524288 29
[1272618346] unbound[26422:2] info: 0.524288 1.000000 48
[1272618346] unbound[26422:2] info: 1.000000 2.000000 383
[1272618346] unbound[26422:2] info: 2.000000 4.000000 1044
[1272618346] unbound[26422:2] info: 4.000000 8.000000 1137
[1272618346] unbound[26422:2] info: 8.000000 16.000000 563
[1272618346] unbound[26422:2] info: 16.000000 32.000000 721
[1272618346] unbound[26422:2] info: 32.000000 64.000000 878
[1272618346] unbound[26422:2] info: 64.000000 128.000000 1310
[1272618346] unbound[26422:2] info: 128.000000 256.000000 393
[1272618346] unbound[26422:2] info: 0RDCD mod1 <nic.cz. DS IN>
[1272618346] unbound[26422:2] info: 1RDdc mod0 rep <www.nic.cz. A IN>
[1272618346] unbound[26422:2] debug: cache memory msg=3570894 rrset=4428788
infra=35743 val=4001591
[1272618346] unbound[26422:2] debug: svcd callbacks end
[1272618346] unbound[26422:2] debug: close of port 56817
[1272618346] unbound[26422:2] debug: close fd 13
[1272618346] unbound[26422:2] debug: answer cb
[1272618346] unbound[26422:2] debug: Incoming reply id = ebee
[1272618346] unbound[26422:2] debug: Incoming reply addr = ip4 193.29.206.1 port
53 (len 16)
[1272618346] unbound[26422:2] debug: lookup size is 1 entries
[1272618346] unbound[26422:2] debug: received udp reply.
[1272618346] unbound[26422:2] debug: udp message[96:0]
EBEE84100001000200000000036E696302637A00002B0001C00C002B00010000465000186D4B0501FF11E740A0254EC63C738A47E52ABF3AD91D8C43C00C002B0001000046500018EA0C0501144130216E45C4EC2BB8595E817916E8B060D87B
[1272618346] unbound[26422:2] debug: outnet handle udp reply
[1272618346] unbound[26422:2] debug: measured roundtrip at 1 msec
[1272618346] unbound[26422:2] debug: svcd callbacks start
[1272618346] unbound[26422:2] debug: worker svcd callback for qstate 0x7f43fd12a090
[1272618346] unbound[26422:2] debug: mesh_run: start
[1272618346] unbound[26422:2] debug: iterator[module 1] operate:
extstate:module_wait_reply event:module_event_reply
[1272618346] unbound[26422:2] info: iterator operate: query <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: process_response: new external response event
[1272618346] unbound[26422:2] info: scrub for <cz. NS IN>
[1272618346] unbound[26422:2] info: response for <nic.cz. DS IN>
[1272618346] unbound[26422:2] info: reply from <cz.> 193.29.206.1#53
[1272618346] unbound[26422:2] info: incoming scrubbed packet: ;; ->>HEADER<<-
opcode: QUERY, rcode: NOERROR, id: 0
;; flags: qr aa ; QUERY: 1, ANSWER: 2, AUTHORITY: 0, ADDITIONAL: 0
;; QUESTION SECTION:
;; nic.cz. IN DS
;; ANSWER SECTION:
nic.cz. 18000 IN DS 27979 5 1 ff11e740a0254ec63c738a47e52abf3ad91d8c43 ;
xuzoc-cunug-bimud-hafus-kezal-fidig-linyd-puzef-pukoc-tefug-fuxax
nic.cz. 18000 IN DS 59916 5 1 144130216e45c4ec2bb8595e817916e8b060d87b ;
xehag-casyd-curug-hyciv-supar-mikuh-vubul-nihov-misyk-bykal-rexux
;; AUTHORITY SECTION:
;; ADDITIONAL SECTION:
;; Query time: 0 msec
;; WHEN: Thu Jan 1 01:00:00 1970
;; MSG SIZE rcvd: 96
[1272618346] unbound[26422:2] debug: iter_handle processing q with state QUERY
RESPONSE STATE
[1272618346] unbound[26422:2] info: query response was ANSWER
[1272618346] unbound[26422:2] debug: iter_handle processing q with state
FINISHED RESPONSE STATE
[1272618346] unbound[26422:2] info: finishing processing for <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: mesh_run: iterator module exit state is
module_finished
[1272618346] unbound[26422:2] debug: validator[module 0] operate:
extstate:module_wait_module event:module_event_moddone
[1272618346] unbound[26422:2] info: validator operate: query <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: validator: nextmodule returned
[1272618346] unbound[26422:2] debug: not validating response due to CD bit
[1272618346] unbound[26422:2] debug: mesh_run: validator module exit state is
module_finished
[1272618346] unbound[26422:2] info: validator: inform_super, sub is <nic.cz. DS IN>
[1272618346] unbound[26422:2] info: super is <www.nic.cz. A IN>
[1272618346] unbound[26422:2] info: verify rrset <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: rrset failed to verify due to a lack of
signatures
[1272618346] unbound[26422:2] debug: verify result: sec_status_bogus
[1272618346] unbound[26422:2] info: DS rrset in DS response did not verify
[1272618346] unbound[26422:2] debug: blacklist add ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: validator[module 0] operate:
extstate:module_wait_subquery event:module_event_pass
[1272618346] unbound[26422:2] info: validator operate: query <www.nic.cz. A IN>
[1272618346] unbound[26422:2] debug: val handle processing q with state
VAL_FINDKEY_STATE
[1272618346] unbound[26422:2] info: validator: FindKey <www.nic.cz. A IN>
[1272618346] unbound[26422:2] info: current keyname <cz. DNSKEY IN>
[1272618346] unbound[26422:2] info: target keyname <www.nic.cz. DNSKEY IN>
[1272618346] unbound[26422:2] debug: striplab 1
[1272618346] unbound[26422:2] info: next keyname <nic.cz. DNSKEY IN>
[1272618346] unbound[26422:2] debug: No DS RRset
[1272618346] unbound[26422:2] info: generate request <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: mesh_run: validator module exit state is
module_wait_subquery
[1272618346] unbound[26422:2] debug: validator[module 0] operate:
extstate:module_state_initial event:module_event_pass
[1272618346] unbound[26422:2] info: validator operate: query <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: validator: pass to next module
[1272618346] unbound[26422:2] debug: mesh_run: validator module exit state is
module_wait_module
[1272618346] unbound[26422:2] debug: iterator[module 1] operate:
extstate:module_state_initial event:module_event_pass
[1272618346] unbound[26422:2] debug: process_request: new external request event
[1272618346] unbound[26422:2] debug: iter_handle processing q with state INIT
REQUEST STATE
[1272618346] unbound[26422:2] info: resolving <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: request has dependency depth of 0
[1272618346] unbound[26422:2] debug: cache blacklisted, going to the network
[1272618346] unbound[26422:2] debug: cache delegation returns delegpt
[1272618346] unbound[26422:2] info: DelegationPoint<cz.>: 5 names (0 missing),
10 addrs (0 result, 10 avail)
[1272618346] unbound[26422:2] info: f.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: d.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: c.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: b.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: a.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] debug: ip6 2001:678:f::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:10::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.13.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2a01:40:1000::2 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:1::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:628:453:420::48 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.171.255.48 port 53 (len 16)
[1272618346] unbound[26422:2] debug: iter_handle processing q with state INIT
REQUEST STATE (stage 2)
[1272618346] unbound[26422:2] info: resolving (init part 2): <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: iter_handle processing q with state INIT
REQUEST STATE (stage 3)
[1272618346] unbound[26422:2] info: resolving (init part 3): <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: iter_handle processing q with state QUERY
TARGETS STATE
[1272618346] unbound[26422:2] info: processQueryTargets: <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: processQueryTargets: targetqueries 0,
currentqueries 0
[1272618346] unbound[26422:2] info: DelegationPoint<cz.>: 5 names (0 missing),
10 addrs (0 result, 10 avail)
[1272618346] unbound[26422:2] info: f.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: d.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: c.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: b.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: a.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] debug: ip6 2001:678:f::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:10::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.13.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2a01:40:1000::2 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:1::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:628:453:420::48 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.171.255.48 port 53 (len 16)
[1272618346] unbound[26422:2] debug: attempt to get extra 3 targets
[1272618346] unbound[26422:2] debug: servselect ip4 193.171.255.48 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=8898 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=602 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=1508 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 194.0.13.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=8823 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=1739 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: selrtt 121508
[1272618346] unbound[26422:2] debug: chase to dnssec lame server
[1272618346] unbound[26422:2] info: sending query: <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: sending to target: <cz.> 194.0.12.1#53
[1272618346] unbound[26422:2] debug: serviced query UDP timeout=1739 msec
[1272618346] unbound[26422:2] debug: inserted new pending reply id=2e2c
[1272618346] unbound[26422:2] debug: opened UDP if=0 port=36539
[1272618346] unbound[26422:2] debug: comm point start listening 13
[1272618346] unbound[26422:2] debug: mesh_run: iterator module exit state is
module_wait_reply
[1272618346] unbound[26422:2] info: mesh_run: end 2 recursion states (1 with
reply, 0 detached), 1 waiting replies, 6752 recursion replies sent, 0 replies
dropped, 0 states jostled out
[1272618346] unbound[26422:2] info: average recursion processing time 38.779874 sec
[1272618346] unbound[26422:2] info: histogram of recursion processing times
[1272618346] unbound[26422:2] info: [25%]=1.88123 median[50%]=6.94849 [75%]=0.732824
[1272618346] unbound[26422:2] info: lower(secs) upper(secs) recursions
[1272618346] unbound[26422:2] info: 0.000000 0.000001 159
[1272618346] unbound[26422:2] info: 0.004096 0.008192 24
[1272618346] unbound[26422:2] info: 0.008192 0.016384 4
[1272618346] unbound[26422:2] info: 0.016384 0.032768 9
[1272618346] unbound[26422:2] info: 0.032768 0.065536 11
[1272618346] unbound[26422:2] info: 0.065536 0.131072 31
[1272618346] unbound[26422:2] info: 0.131072 0.262144 8
[1272618346] unbound[26422:2] info: 0.262144 0.524288 29
[1272618346] unbound[26422:2] info: 0.524288 1.000000 48
[1272618346] unbound[26422:2] info: 1.000000 2.000000 383
[1272618346] unbound[26422:2] info: 2.000000 4.000000 1044
[1272618346] unbound[26422:2] info: 4.000000 8.000000 1137
[1272618346] unbound[26422:2] info: 8.000000 16.000000 563
[1272618346] unbound[26422:2] info: 16.000000 32.000000 721
[1272618346] unbound[26422:2] info: 32.000000 64.000000 878
[1272618346] unbound[26422:2] info: 64.000000 128.000000 1310
[1272618346] unbound[26422:2] info: 128.000000 256.000000 393
[1272618346] unbound[26422:2] info: 0RDCD mod1 <nic.cz. DS IN>
[1272618346] unbound[26422:2] info: 1RDdc mod0 rep <www.nic.cz. A IN>
[1272618346] unbound[26422:2] debug: cache memory msg=3570726 rrset=4429080
infra=35743 val=4001591
[1272618346] unbound[26422:2] debug: svcd callbacks end
[1272618346] unbound[26422:2] debug: close of port 54893
[1272618346] unbound[26422:2] debug: close fd 14
[1272618346] unbound[26422:2] debug: answer cb
[1272618346] unbound[26422:2] debug: Incoming reply id = 2e2c
[1272618346] unbound[26422:2] debug: Incoming reply addr = ip4 194.0.12.1 port
53 (len 16)
[1272618346] unbound[26422:2] debug: lookup size is 1 entries
[1272618346] unbound[26422:2] debug: received udp reply.
[1272618346] unbound[26422:2] debug: udp message[179:0]
2E2C84100001000200050000036E696302637A00002B0001C00C002B0001000046500018EA0C0501144130216E45C4EC2BB8595E817916E8B060D87BC00C002B00010000465000186D4B0501FF11E740A0254EC63C738A47E52ABF3AD91D8C43C010000200010000465000070164026E73C00CC010000200010000465000040162C06EC010000200010000465000040166C06EC010000200010000465000040163C06EC010000200010000465000040161C06E
[1272618346] unbound[26422:2] debug: outnet handle udp reply
[1272618346] unbound[26422:2] debug: measured roundtrip at 1 msec
[1272618346] unbound[26422:2] debug: svcd callbacks start
[1272618346] unbound[26422:2] debug: worker svcd callback for qstate 0x7f43fd12a090
[1272618346] unbound[26422:2] debug: mesh_run: start
[1272618346] unbound[26422:2] debug: iterator[module 1] operate:
extstate:module_wait_reply event:module_event_reply
[1272618346] unbound[26422:2] info: iterator operate: query <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: process_response: new external response event
[1272618346] unbound[26422:2] info: scrub for <cz. NS IN>
[1272618346] unbound[26422:2] info: response for <nic.cz. DS IN>
[1272618346] unbound[26422:2] info: reply from <cz.> 194.0.12.1#53
[1272618346] unbound[26422:2] info: incoming scrubbed packet: ;; ->>HEADER<<-
opcode: QUERY, rcode: NOERROR, id: 0
;; flags: qr aa ; QUERY: 1, ANSWER: 2, AUTHORITY: 5, ADDITIONAL: 0
;; QUESTION SECTION:
;; nic.cz. IN DS
;; ANSWER SECTION:
nic.cz. 18000 IN DS 59916 5 1 144130216e45c4ec2bb8595e817916e8b060d87b ;
xehag-casyd-curug-hyciv-supar-mikuh-vubul-nihov-misyk-bykal-rexux
nic.cz. 18000 IN DS 27979 5 1 ff11e740a0254ec63c738a47e52abf3ad91d8c43 ;
xuzoc-cunug-bimud-hafus-kezal-fidig-linyd-puzef-pukoc-tefug-fuxax
;; AUTHORITY SECTION:
cz. 18000 IN NS d.ns.nic.cz.
cz. 18000 IN NS b.ns.nic.cz.
cz. 18000 IN NS f.ns.nic.cz.
cz. 18000 IN NS c.ns.nic.cz.
cz. 18000 IN NS a.ns.nic.cz.
;; ADDITIONAL SECTION:
;; Query time: 0 msec
;; WHEN: Thu Jan 1 01:00:00 1970
;; MSG SIZE rcvd: 179
[1272618346] unbound[26422:2] debug: iter_handle processing q with state QUERY
RESPONSE STATE
[1272618346] unbound[26422:2] info: query response was ANSWER
[1272618346] unbound[26422:2] debug: iter_handle processing q with state
FINISHED RESPONSE STATE
[1272618346] unbound[26422:2] info: finishing processing for <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: mesh_run: iterator module exit state is
module_finished
[1272618346] unbound[26422:2] debug: validator[module 0] operate:
extstate:module_wait_module event:module_event_moddone
[1272618346] unbound[26422:2] info: validator operate: query <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: validator: nextmodule returned
[1272618346] unbound[26422:2] debug: not validating response due to CD bit
[1272618346] unbound[26422:2] debug: mesh_run: validator module exit state is
module_finished
[1272618346] unbound[26422:2] info: validator: inform_super, sub is <nic.cz. DS IN>
[1272618346] unbound[26422:2] info: super is <www.nic.cz. A IN>
[1272618346] unbound[26422:2] info: verify rrset <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: rrset failed to verify due to a lack of
signatures
[1272618346] unbound[26422:2] debug: verify result: sec_status_bogus
[1272618346] unbound[26422:2] info: DS rrset in DS response did not verify
[1272618346] unbound[26422:2] debug: blacklist ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: blacklist add ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: validator[module 0] operate:
extstate:module_wait_subquery event:module_event_pass
[1272618346] unbound[26422:2] info: validator operate: query <www.nic.cz. A IN>
[1272618346] unbound[26422:2] debug: val handle processing q with state
VAL_FINDKEY_STATE
[1272618346] unbound[26422:2] info: validator: FindKey <www.nic.cz. A IN>
[1272618346] unbound[26422:2] info: current keyname <cz. DNSKEY IN>
[1272618346] unbound[26422:2] info: target keyname <www.nic.cz. DNSKEY IN>
[1272618346] unbound[26422:2] debug: striplab 1
[1272618346] unbound[26422:2] info: next keyname <nic.cz. DNSKEY IN>
[1272618346] unbound[26422:2] debug: No DS RRset
[1272618346] unbound[26422:2] info: generate request <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: mesh_run: validator module exit state is
module_wait_subquery
[1272618346] unbound[26422:2] debug: validator[module 0] operate:
extstate:module_state_initial event:module_event_pass
[1272618346] unbound[26422:2] info: validator operate: query <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: validator: pass to next module
[1272618346] unbound[26422:2] debug: mesh_run: validator module exit state is
module_wait_module
[1272618346] unbound[26422:2] debug: iterator[module 1] operate:
extstate:module_state_initial event:module_event_pass
[1272618346] unbound[26422:2] debug: process_request: new external request event
[1272618346] unbound[26422:2] debug: iter_handle processing q with state INIT
REQUEST STATE
[1272618346] unbound[26422:2] info: resolving <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: request has dependency depth of 0
[1272618346] unbound[26422:2] debug: cache blacklisted, going to the network
[1272618346] unbound[26422:2] debug: cache delegation returns delegpt
[1272618346] unbound[26422:2] info: DelegationPoint<cz.>: 5 names (0 missing),
10 addrs (0 result, 10 avail)
[1272618346] unbound[26422:2] info: a.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: c.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: f.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: b.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: d.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] debug: ip6 2001:678:1::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:10::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.13.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:628:453:420::48 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.171.255.48 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2a01:40:1000::2 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:f::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: iter_handle processing q with state INIT
REQUEST STATE (stage 2)
[1272618346] unbound[26422:2] info: resolving (init part 2): <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: iter_handle processing q with state INIT
REQUEST STATE (stage 3)
[1272618346] unbound[26422:2] info: resolving (init part 3): <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: iter_handle processing q with state QUERY
TARGETS STATE
[1272618346] unbound[26422:2] info: processQueryTargets: <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: processQueryTargets: targetqueries 0,
currentqueries 0
[1272618346] unbound[26422:2] info: DelegationPoint<cz.>: 5 names (0 missing),
10 addrs (0 result, 10 avail)
[1272618346] unbound[26422:2] info: a.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: c.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: f.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: b.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: d.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] debug: ip6 2001:678:1::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:10::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.13.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:628:453:420::48 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.171.255.48 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2a01:40:1000::2 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:f::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: attempt to get extra 3 targets
[1272618346] unbound[26422:2] debug: servselect ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=1739 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=1508 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 193.171.255.48 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=8898 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 194.0.13.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=8823 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=602 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: selrtt 121508
[1272618346] unbound[26422:2] debug: chase to dnssec lame server
[1272618346] unbound[26422:2] info: sending query: <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: sending to target: <cz.> 195.66.241.202#53
[1272618346] unbound[26422:2] debug: serviced query UDP timeout=1508 msec
[1272618346] unbound[26422:2] debug: inserted new pending reply id=0a5c
[1272618346] unbound[26422:2] debug: opened UDP if=0 port=14454
[1272618346] unbound[26422:2] debug: comm point start listening 14
[1272618346] unbound[26422:2] debug: mesh_run: iterator module exit state is
module_wait_reply
[1272618346] unbound[26422:2] info: mesh_run: end 2 recursion states (1 with
reply, 0 detached), 1 waiting replies, 6752 recursion replies sent, 0 replies
dropped, 0 states jostled out
[1272618346] unbound[26422:2] info: average recursion processing time 38.779874 sec
[1272618346] unbound[26422:2] info: histogram of recursion processing times
[1272618346] unbound[26422:2] info: [25%]=1.88123 median[50%]=6.94849 [75%]=0.732824
[1272618346] unbound[26422:2] info: lower(secs) upper(secs) recursions
[1272618346] unbound[26422:2] info: 0.000000 0.000001 159
[1272618346] unbound[26422:2] info: 0.004096 0.008192 24
[1272618346] unbound[26422:2] info: 0.008192 0.016384 4
[1272618346] unbound[26422:2] info: 0.016384 0.032768 9
[1272618346] unbound[26422:2] info: 0.032768 0.065536 11
[1272618346] unbound[26422:2] info: 0.065536 0.131072 31
[1272618346] unbound[26422:2] info: 0.131072 0.262144 8
[1272618346] unbound[26422:2] info: 0.262144 0.524288 29
[1272618346] unbound[26422:2] info: 0.524288 1.000000 48
[1272618346] unbound[26422:2] info: 1.000000 2.000000 383
[1272618346] unbound[26422:2] info: 2.000000 4.000000 1044
[1272618346] unbound[26422:2] info: 4.000000 8.000000 1137
[1272618346] unbound[26422:2] info: 8.000000 16.000000 563
[1272618346] unbound[26422:2] info: 16.000000 32.000000 721
[1272618346] unbound[26422:2] info: 32.000000 64.000000 878
[1272618346] unbound[26422:2] info: 64.000000 128.000000 1310
[1272618346] unbound[26422:2] info: 128.000000 256.000000 393
[1272618346] unbound[26422:2] info: 0RDCD mod1 <nic.cz. DS IN>
[1272618346] unbound[26422:2] info: 1RDdc mod0 rep <www.nic.cz. A IN>
[1272618346] unbound[26422:2] debug: cache memory msg=3570750 rrset=4429080
infra=35743 val=4001591
[1272618346] unbound[26422:2] debug: svcd callbacks end
[1272618346] unbound[26422:2] debug: close of port 36539
[1272618346] unbound[26422:2] debug: close fd 13
[1272618346] unbound[26422:2] debug: answer cb
[1272618346] unbound[26422:2] debug: Incoming reply id = 0a5c
[1272618346] unbound[26422:2] debug: Incoming reply addr = ip4 195.66.241.202
port 53 (len 16)
[1272618346] unbound[26422:2] debug: lookup size is 1 entries
[1272618346] unbound[26422:2] debug: received udp reply.
[1272618346] unbound[26422:2] debug: udp message[179:0]
0A5C84100001000200050000036E696302637A00002B0001C00C002B00010000465000186D4B0501FF11E740A0254EC63C738A47E52ABF3AD91D8C43C00C002B0001000046500018EA0C0501144130216E45C4EC2BB8595E817916E8B060D87BC010000200010000465000070166026E73C00CC010000200010000465000040163C06EC010000200010000465000040164C06EC010000200010000465000040162C06EC010000200010000465000040161C06E
[1272618346] unbound[26422:2] debug: outnet handle udp reply
[1272618346] unbound[26422:2] debug: measured roundtrip at 24 msec
[1272618346] unbound[26422:2] debug: svcd callbacks start
[1272618346] unbound[26422:2] debug: worker svcd callback for qstate 0x7f43fd12a090
[1272618346] unbound[26422:2] debug: mesh_run: start
[1272618346] unbound[26422:2] debug: iterator[module 1] operate:
extstate:module_wait_reply event:module_event_reply
[1272618346] unbound[26422:2] info: iterator operate: query <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: process_response: new external response event
[1272618346] unbound[26422:2] info: scrub for <cz. NS IN>
[1272618346] unbound[26422:2] info: response for <nic.cz. DS IN>
[1272618346] unbound[26422:2] info: reply from <cz.> 195.66.241.202#53
[1272618346] unbound[26422:2] info: incoming scrubbed packet: ;; ->>HEADER<<-
opcode: QUERY, rcode: NOERROR, id: 0
;; flags: qr aa ; QUERY: 1, ANSWER: 2, AUTHORITY: 5, ADDITIONAL: 0
;; QUESTION SECTION:
;; nic.cz. IN DS
;; ANSWER SECTION:
nic.cz. 18000 IN DS 27979 5 1 ff11e740a0254ec63c738a47e52abf3ad91d8c43 ;
xuzoc-cunug-bimud-hafus-kezal-fidig-linyd-puzef-pukoc-tefug-fuxax
nic.cz. 18000 IN DS 59916 5 1 144130216e45c4ec2bb8595e817916e8b060d87b ;
xehag-casyd-curug-hyciv-supar-mikuh-vubul-nihov-misyk-bykal-rexux
;; AUTHORITY SECTION:
cz. 18000 IN NS f.ns.nic.cz.
cz. 18000 IN NS c.ns.nic.cz.
cz. 18000 IN NS d.ns.nic.cz.
cz. 18000 IN NS b.ns.nic.cz.
cz. 18000 IN NS a.ns.nic.cz.
;; ADDITIONAL SECTION:
;; Query time: 0 msec
;; WHEN: Thu Jan 1 01:00:00 1970
;; MSG SIZE rcvd: 179
[1272618346] unbound[26422:2] debug: iter_handle processing q with state QUERY
RESPONSE STATE
[1272618346] unbound[26422:2] info: query response was ANSWER
[1272618346] unbound[26422:2] debug: iter_handle processing q with state
FINISHED RESPONSE STATE
[1272618346] unbound[26422:2] info: finishing processing for <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: mesh_run: iterator module exit state is
module_finished
[1272618346] unbound[26422:2] debug: validator[module 0] operate:
extstate:module_wait_module event:module_event_moddone
[1272618346] unbound[26422:2] info: validator operate: query <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: validator: nextmodule returned
[1272618346] unbound[26422:2] debug: not validating response due to CD bit
[1272618346] unbound[26422:2] debug: mesh_run: validator module exit state is
module_finished
[1272618346] unbound[26422:2] info: validator: inform_super, sub is <nic.cz. DS IN>
[1272618346] unbound[26422:2] info: super is <www.nic.cz. A IN>
[1272618346] unbound[26422:2] info: verify rrset <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: rrset failed to verify due to a lack of
signatures
[1272618346] unbound[26422:2] debug: verify result: sec_status_bogus
[1272618346] unbound[26422:2] info: DS rrset in DS response did not verify
[1272618346] unbound[26422:2] debug: blacklist ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: blacklist ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: blacklist add ip4 195.66.241.202 port 53
(len 16)
[1272618346] unbound[26422:2] debug: validator[module 0] operate:
extstate:module_wait_subquery event:module_event_pass
[1272618346] unbound[26422:2] info: validator operate: query <www.nic.cz. A IN>
[1272618346] unbound[26422:2] debug: val handle processing q with state
VAL_FINDKEY_STATE
[1272618346] unbound[26422:2] info: validator: FindKey <www.nic.cz. A IN>
[1272618346] unbound[26422:2] info: current keyname <cz. DNSKEY IN>
[1272618346] unbound[26422:2] info: target keyname <www.nic.cz. DNSKEY IN>
[1272618346] unbound[26422:2] debug: striplab 1
[1272618346] unbound[26422:2] info: next keyname <nic.cz. DNSKEY IN>
[1272618346] unbound[26422:2] debug: No DS RRset
[1272618346] unbound[26422:2] info: generate request <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: mesh_run: validator module exit state is
module_wait_subquery
[1272618346] unbound[26422:2] debug: validator[module 0] operate:
extstate:module_state_initial event:module_event_pass
[1272618346] unbound[26422:2] info: validator operate: query <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: validator: pass to next module
[1272618346] unbound[26422:2] debug: mesh_run: validator module exit state is
module_wait_module
[1272618346] unbound[26422:2] debug: iterator[module 1] operate:
extstate:module_state_initial event:module_event_pass
[1272618346] unbound[26422:2] debug: process_request: new external request event
[1272618346] unbound[26422:2] debug: iter_handle processing q with state INIT
REQUEST STATE
[1272618346] unbound[26422:2] info: resolving <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: request has dependency depth of 0
[1272618346] unbound[26422:2] debug: cache blacklisted, going to the network
[1272618346] unbound[26422:2] debug: cache delegation returns delegpt
[1272618346] unbound[26422:2] info: DelegationPoint<cz.>: 5 names (0 missing),
10 addrs (0 result, 10 avail)
[1272618346] unbound[26422:2] info: a.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: b.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: d.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: c.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: f.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] debug: ip6 2001:628:453:420::48 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.171.255.48 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2a01:40:1000::2 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:1::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:10::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.13.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:f::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: iter_handle processing q with state INIT
REQUEST STATE (stage 2)
[1272618346] unbound[26422:2] info: resolving (init part 2): <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: iter_handle processing q with state INIT
REQUEST STATE (stage 3)
[1272618346] unbound[26422:2] info: resolving (init part 3): <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: iter_handle processing q with state QUERY
TARGETS STATE
[1272618346] unbound[26422:2] info: processQueryTargets: <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: processQueryTargets: targetqueries 0,
currentqueries 0
[1272618346] unbound[26422:2] info: DelegationPoint<cz.>: 5 names (0 missing),
10 addrs (0 result, 10 avail)
[1272618346] unbound[26422:2] info: a.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: b.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: d.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: c.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: f.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] debug: ip6 2001:628:453:420::48 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.171.255.48 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2a01:40:1000::2 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:1::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:10::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.13.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:f::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: attempt to get extra 3 targets
[1272618346] unbound[26422:2] debug: servselect ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=1739 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 194.0.13.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=8823 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=602 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=1482 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 193.171.255.48 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=8898 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: selrtt 128823
[1272618346] unbound[26422:2] debug: chase to dnssec lame server
[1272618346] unbound[26422:2] info: sending query: <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: sending to target: <cz.> 193.171.255.48#53
[1272618346] unbound[26422:2] debug: serviced query UDP timeout=8898 msec
[1272618346] unbound[26422:2] debug: inserted new pending reply id=cf7d
[1272618346] unbound[26422:2] debug: opened UDP if=0 port=53264
[1272618346] unbound[26422:2] debug: comm point start listening 13
[1272618346] unbound[26422:2] debug: mesh_run: iterator module exit state is
module_wait_reply
[1272618346] unbound[26422:2] info: mesh_run: end 2 recursion states (1 with
reply, 0 detached), 1 waiting replies, 6752 recursion replies sent, 0 replies
dropped, 0 states jostled out
[1272618346] unbound[26422:2] info: average recursion processing time 38.779874 sec
[1272618346] unbound[26422:2] info: histogram of recursion processing times
[1272618346] unbound[26422:2] info: [25%]=1.88123 median[50%]=6.94849 [75%]=0.732824
[1272618346] unbound[26422:2] info: lower(secs) upper(secs) recursions
[1272618346] unbound[26422:2] info: 0.000000 0.000001 159
[1272618346] unbound[26422:2] info: 0.004096 0.008192 24
[1272618346] unbound[26422:2] info: 0.008192 0.016384 4
[1272618346] unbound[26422:2] info: 0.016384 0.032768 9
[1272618346] unbound[26422:2] info: 0.032768 0.065536 11
[1272618346] unbound[26422:2] info: 0.065536 0.131072 31
[1272618346] unbound[26422:2] info: 0.131072 0.262144 8
[1272618346] unbound[26422:2] info: 0.262144 0.524288 29
[1272618346] unbound[26422:2] info: 0.524288 1.000000 48
[1272618346] unbound[26422:2] info: 1.000000 2.000000 383
[1272618346] unbound[26422:2] info: 2.000000 4.000000 1044
[1272618346] unbound[26422:2] info: 4.000000 8.000000 1137
[1272618346] unbound[26422:2] info: 8.000000 16.000000 563
[1272618346] unbound[26422:2] info: 16.000000 32.000000 721
[1272618346] unbound[26422:2] info: 32.000000 64.000000 878
[1272618346] unbound[26422:2] info: 64.000000 128.000000 1310
[1272618346] unbound[26422:2] info: 128.000000 256.000000 393
[1272618346] unbound[26422:2] info: 0RDCD mod1 <nic.cz. DS IN>
[1272618346] unbound[26422:2] info: 1RDdc mod0 rep <www.nic.cz. A IN>
[1272618346] unbound[26422:2] debug: cache memory msg=3570750 rrset=4429080
infra=35743 val=4001591
[1272618346] unbound[26422:2] debug: svcd callbacks end
[1272618346] unbound[26422:2] debug: close of port 14454
[1272618346] unbound[26422:2] debug: close fd 14
[1272618346] unbound[26422:2] debug: answer cb
[1272618346] unbound[26422:2] debug: Incoming reply id = cf7d
[1272618346] unbound[26422:2] debug: Incoming reply addr = ip4 193.171.255.48
port 53 (len 16)
[1272618346] unbound[26422:2] debug: lookup size is 1 entries
[1272618346] unbound[26422:2] debug: received udp reply.
[1272618346] unbound[26422:2] debug: udp message[317:0]
CF7D84000001000200050006036E696302637A00002B0001036E696302637A00002B00010000465000186D4B0501FF11E740A0254EC63C738A47E52ABF3AD91D8C43C018002B0001000046500018EA0C0501144130216E45C4EC2BB8595E817916E8B060D87BC01C000200010000465000070161026E73C018C01C000200010000465000040162C074C01C000200010000465000040163C074C01C000200010000465000040164C074C01C000200010000465000040166C074C07200010001000046500004C2000C01C08500010001000046500004C2000D01C0A500010001000046500004C11DCE01C072001C000100004650001020010678000F0000000000
[1272618346] unbound[26422:2] debug: udp message[317:256]
0000000001C085001C000100004650001020010678001000000000000000000001C0A5001C000100004650001020010678000100000000000000000001
[1272618346] unbound[26422:2] debug: outnet handle udp reply
[1272618346] unbound[26422:2] debug: measured roundtrip at 9 msec
[1272618346] unbound[26422:2] debug: svcd callbacks start
[1272618346] unbound[26422:2] debug: worker svcd callback for qstate 0x7f43fd12a090
[1272618346] unbound[26422:2] debug: mesh_run: start
[1272618346] unbound[26422:2] debug: iterator[module 1] operate:
extstate:module_wait_reply event:module_event_reply
[1272618346] unbound[26422:2] info: iterator operate: query <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: process_response: new external response event
[1272618346] unbound[26422:2] info: scrub for <cz. NS IN>
[1272618346] unbound[26422:2] info: response for <nic.cz. DS IN>
[1272618346] unbound[26422:2] info: reply from <cz.> 193.171.255.48#53
[1272618346] unbound[26422:2] info: incoming scrubbed packet: ;; ->>HEADER<<-
opcode: QUERY, rcode: NOERROR, id: 0
;; flags: qr aa ; QUERY: 1, ANSWER: 2, AUTHORITY: 5, ADDITIONAL: 6
;; QUESTION SECTION:
;; nic.cz. IN DS
;; ANSWER SECTION:
nic.cz. 18000 IN DS 27979 5 1 ff11e740a0254ec63c738a47e52abf3ad91d8c43 ;
xuzoc-cunug-bimud-hafus-kezal-fidig-linyd-puzef-pukoc-tefug-fuxax
nic.cz. 18000 IN DS 59916 5 1 144130216e45c4ec2bb8595e817916e8b060d87b ;
xehag-casyd-curug-hyciv-supar-mikuh-vubul-nihov-misyk-bykal-rexux
;; AUTHORITY SECTION:
cz. 18000 IN NS a.ns.nic.cz.
cz. 18000 IN NS b.ns.nic.cz.
cz. 18000 IN NS c.ns.nic.cz.
cz. 18000 IN NS d.ns.nic.cz.
cz. 18000 IN NS f.ns.nic.cz.
;; ADDITIONAL SECTION:
a.ns.nic.cz. 18000 IN A 194.0.12.1
b.ns.nic.cz. 18000 IN A 194.0.13.1
d.ns.nic.cz. 18000 IN A 193.29.206.1
a.ns.nic.cz. 18000 IN AAAA 2001:678:f::1
b.ns.nic.cz. 18000 IN AAAA 2001:678:10::1
d.ns.nic.cz. 18000 IN AAAA 2001:678:1::1
;; Query time: 0 msec
;; WHEN: Thu Jan 1 01:00:00 1970
;; MSG SIZE rcvd: 311
[1272618346] unbound[26422:2] debug: iter_handle processing q with state QUERY
RESPONSE STATE
[1272618346] unbound[26422:2] info: query response was ANSWER
[1272618346] unbound[26422:2] debug: iter_handle processing q with state
FINISHED RESPONSE STATE
[1272618346] unbound[26422:2] info: finishing processing for <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: mesh_run: iterator module exit state is
module_finished
[1272618346] unbound[26422:2] debug: validator[module 0] operate:
extstate:module_wait_module event:module_event_moddone
[1272618346] unbound[26422:2] info: validator operate: query <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: validator: nextmodule returned
[1272618346] unbound[26422:2] debug: not validating response due to CD bit
[1272618346] unbound[26422:2] debug: mesh_run: validator module exit state is
module_finished
[1272618346] unbound[26422:2] info: validator: inform_super, sub is <nic.cz. DS IN>
[1272618346] unbound[26422:2] info: super is <www.nic.cz. A IN>
[1272618346] unbound[26422:2] info: verify rrset <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: rrset failed to verify due to a lack of
signatures
[1272618346] unbound[26422:2] debug: verify result: sec_status_bogus
[1272618346] unbound[26422:2] info: DS rrset in DS response did not verify
[1272618346] unbound[26422:2] debug: blacklist ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: blacklist ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: blacklist ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: blacklist add ip4 193.171.255.48 port 53
(len 16)
[1272618346] unbound[26422:2] debug: validator[module 0] operate:
extstate:module_wait_subquery event:module_event_pass
[1272618346] unbound[26422:2] info: validator operate: query <www.nic.cz. A IN>
[1272618346] unbound[26422:2] debug: val handle processing q with state
VAL_FINDKEY_STATE
[1272618346] unbound[26422:2] info: validator: FindKey <www.nic.cz. A IN>
[1272618346] unbound[26422:2] info: current keyname <cz. DNSKEY IN>
[1272618346] unbound[26422:2] info: target keyname <www.nic.cz. DNSKEY IN>
[1272618346] unbound[26422:2] debug: striplab 1
[1272618346] unbound[26422:2] info: next keyname <nic.cz. DNSKEY IN>
[1272618346] unbound[26422:2] debug: No DS RRset
[1272618346] unbound[26422:2] info: generate request <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: mesh_run: validator module exit state is
module_wait_subquery
[1272618346] unbound[26422:2] debug: validator[module 0] operate:
extstate:module_state_initial event:module_event_pass
[1272618346] unbound[26422:2] info: validator operate: query <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: validator: pass to next module
[1272618346] unbound[26422:2] debug: mesh_run: validator module exit state is
module_wait_module
[1272618346] unbound[26422:2] debug: iterator[module 1] operate:
extstate:module_state_initial event:module_event_pass
[1272618346] unbound[26422:2] debug: process_request: new external request event
[1272618346] unbound[26422:2] debug: iter_handle processing q with state INIT
REQUEST STATE
[1272618346] unbound[26422:2] info: resolving <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: request has dependency depth of 0
[1272618346] unbound[26422:2] debug: cache blacklisted, going to the network
[1272618346] unbound[26422:2] debug: cache delegation returns delegpt
[1272618346] unbound[26422:2] info: DelegationPoint<cz.>: 5 names (0 missing),
10 addrs (0 result, 10 avail)
[1272618346] unbound[26422:2] info: f.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: d.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: c.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: b.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: a.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] debug: ip6 2001:678:f::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:10::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.13.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2a01:40:1000::2 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:1::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:628:453:420::48 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.171.255.48 port 53 (len 16)
[1272618346] unbound[26422:2] debug: iter_handle processing q with state INIT
REQUEST STATE (stage 2)
[1272618346] unbound[26422:2] info: resolving (init part 2): <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: iter_handle processing q with state INIT
REQUEST STATE (stage 3)
[1272618346] unbound[26422:2] info: resolving (init part 3): <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: iter_handle processing q with state QUERY
TARGETS STATE
[1272618346] unbound[26422:2] info: processQueryTargets: <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: processQueryTargets: targetqueries 0,
currentqueries 0
[1272618346] unbound[26422:2] info: DelegationPoint<cz.>: 5 names (0 missing),
10 addrs (0 result, 10 avail)
[1272618346] unbound[26422:2] info: f.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: d.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: c.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: b.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: a.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] debug: ip6 2001:678:f::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:10::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.13.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2a01:40:1000::2 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:1::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:628:453:420::48 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.171.255.48 port 53 (len 16)
[1272618346] unbound[26422:2] debug: attempt to get extra 3 targets
[1272618346] unbound[26422:2] debug: servselect ip4 193.171.255.48 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=8223 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=602 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=1482 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 194.0.13.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=8823 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=1739 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: selrtt 128823
[1272618346] unbound[26422:2] debug: chase to dnssec lame server
[1272618346] unbound[26422:2] info: sending query: <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: sending to target: <cz.> 194.0.13.1#53
[1272618346] unbound[26422:2] debug: serviced query UDP timeout=8823 msec
[1272618346] unbound[26422:2] debug: inserted new pending reply id=4783
[1272618346] unbound[26422:2] debug: opened UDP if=0 port=42311
[1272618346] unbound[26422:2] debug: comm point start listening 14
[1272618346] unbound[26422:2] debug: mesh_run: iterator module exit state is
module_wait_reply
[1272618346] unbound[26422:2] info: mesh_run: end 2 recursion states (1 with
reply, 0 detached), 1 waiting replies, 6752 recursion replies sent, 0 replies
dropped, 0 states jostled out
[1272618346] unbound[26422:2] info: average recursion processing time 38.779874 sec
[1272618346] unbound[26422:2] info: histogram of recursion processing times
[1272618346] unbound[26422:2] info: [25%]=1.88123 median[50%]=6.94849 [75%]=0.732824
[1272618346] unbound[26422:2] info: lower(secs) upper(secs) recursions
[1272618346] unbound[26422:2] info: 0.000000 0.000001 159
[1272618346] unbound[26422:2] info: 0.004096 0.008192 24
[1272618346] unbound[26422:2] info: 0.008192 0.016384 4
[1272618346] unbound[26422:2] info: 0.016384 0.032768 9
[1272618346] unbound[26422:2] info: 0.032768 0.065536 11
[1272618346] unbound[26422:2] info: 0.065536 0.131072 31
[1272618346] unbound[26422:2] info: 0.131072 0.262144 8
[1272618346] unbound[26422:2] info: 0.262144 0.524288 29
[1272618346] unbound[26422:2] info: 0.524288 1.000000 48
[1272618346] unbound[26422:2] info: 1.000000 2.000000 383
[1272618346] unbound[26422:2] info: 2.000000 4.000000 1044
[1272618346] unbound[26422:2] info: 4.000000 8.000000 1137
[1272618346] unbound[26422:2] info: 8.000000 16.000000 563
[1272618346] unbound[26422:2] info: 16.000000 32.000000 721
[1272618346] unbound[26422:2] info: 32.000000 64.000000 878
[1272618346] unbound[26422:2] info: 64.000000 128.000000 1310
[1272618346] unbound[26422:2] info: 128.000000 256.000000 393
[1272618346] unbound[26422:2] info: 0RDCD mod1 <nic.cz. DS IN>
[1272618346] unbound[26422:2] info: 1RDdc mod0 rep <www.nic.cz. A IN>
[1272618346] unbound[26422:2] debug: cache memory msg=3570894 rrset=4429080
infra=35743 val=4001591
[1272618346] unbound[26422:2] debug: svcd callbacks end
[1272618346] unbound[26422:2] debug: close of port 53264
[1272618346] unbound[26422:2] debug: close fd 13
[1272618346] unbound[26422:2] debug: answer cb
[1272618346] unbound[26422:2] debug: Incoming reply id = 4783
[1272618346] unbound[26422:2] debug: Incoming reply addr = ip4 194.0.13.1 port
53 (len 16)
[1272618346] unbound[26422:2] debug: lookup size is 1 entries
[1272618346] unbound[26422:2] debug: received udp reply.
[1272618346] unbound[26422:2] debug: udp message[317:0]
478384000001000200050006036E696302637A00002B0001036E696302637A00002B00010000465000186D4B0501FF11E740A0254EC63C738A47E52ABF3AD91D8C43C018002B0001000046500018EA0C0501144130216E45C4EC2BB8595E817916E8B060D87BC01C000200010000465000070161026E73C018C01C000200010000465000040162C074C01C000200010000465000040163C074C01C000200010000465000040164C074C01C000200010000465000040166C074C07200010001000046500004C2000C01C08500010001000046500004C2000D01C0A500010001000046500004C11DCE01C072001C000100004650001020010678000F0000000000
[1272618346] unbound[26422:2] debug: udp message[317:256]
0000000001C085001C000100004650001020010678001000000000000000000001C0A5001C000100004650001020010678000100000000000000000001
[1272618346] unbound[26422:2] debug: outnet handle udp reply
[1272618346] unbound[26422:2] debug: measured roundtrip at 42 msec
[1272618346] unbound[26422:2] debug: svcd callbacks start
[1272618346] unbound[26422:2] debug: worker svcd callback for qstate 0x7f43fd12a090
[1272618346] unbound[26422:2] debug: mesh_run: start
[1272618346] unbound[26422:2] debug: iterator[module 1] operate:
extstate:module_wait_reply event:module_event_reply
[1272618346] unbound[26422:2] info: iterator operate: query <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: process_response: new external response event
[1272618346] unbound[26422:2] info: scrub for <cz. NS IN>
[1272618346] unbound[26422:2] info: response for <nic.cz. DS IN>
[1272618346] unbound[26422:2] info: reply from <cz.> 194.0.13.1#53
[1272618346] unbound[26422:2] info: incoming scrubbed packet: ;; ->>HEADER<<-
opcode: QUERY, rcode: NOERROR, id: 0
;; flags: qr aa ; QUERY: 1, ANSWER: 2, AUTHORITY: 5, ADDITIONAL: 6
;; QUESTION SECTION:
;; nic.cz. IN DS
;; ANSWER SECTION:
nic.cz. 18000 IN DS 27979 5 1 ff11e740a0254ec63c738a47e52abf3ad91d8c43 ;
xuzoc-cunug-bimud-hafus-kezal-fidig-linyd-puzef-pukoc-tefug-fuxax
nic.cz. 18000 IN DS 59916 5 1 144130216e45c4ec2bb8595e817916e8b060d87b ;
xehag-casyd-curug-hyciv-supar-mikuh-vubul-nihov-misyk-bykal-rexux
;; AUTHORITY SECTION:
cz. 18000 IN NS a.ns.nic.cz.
cz. 18000 IN NS b.ns.nic.cz.
cz. 18000 IN NS c.ns.nic.cz.
cz. 18000 IN NS d.ns.nic.cz.
cz. 18000 IN NS f.ns.nic.cz.
;; ADDITIONAL SECTION:
a.ns.nic.cz. 18000 IN A 194.0.12.1
b.ns.nic.cz. 18000 IN A 194.0.13.1
d.ns.nic.cz. 18000 IN A 193.29.206.1
a.ns.nic.cz. 18000 IN AAAA 2001:678:f::1
b.ns.nic.cz. 18000 IN AAAA 2001:678:10::1
d.ns.nic.cz. 18000 IN AAAA 2001:678:1::1
;; Query time: 0 msec
;; WHEN: Thu Jan 1 01:00:00 1970
;; MSG SIZE rcvd: 311
[1272618346] unbound[26422:2] debug: iter_handle processing q with state QUERY
RESPONSE STATE
[1272618346] unbound[26422:2] info: query response was ANSWER
[1272618346] unbound[26422:2] debug: iter_handle processing q with state
FINISHED RESPONSE STATE
[1272618346] unbound[26422:2] info: finishing processing for <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: mesh_run: iterator module exit state is
module_finished
[1272618346] unbound[26422:2] debug: validator[module 0] operate:
extstate:module_wait_module event:module_event_moddone
[1272618346] unbound[26422:2] info: validator operate: query <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: validator: nextmodule returned
[1272618346] unbound[26422:2] debug: not validating response due to CD bit
[1272618346] unbound[26422:2] debug: mesh_run: validator module exit state is
module_finished
[1272618346] unbound[26422:2] info: validator: inform_super, sub is <nic.cz. DS IN>
[1272618346] unbound[26422:2] info: super is <www.nic.cz. A IN>
[1272618346] unbound[26422:2] info: verify rrset <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: rrset failed to verify due to a lack of
signatures
[1272618346] unbound[26422:2] debug: verify result: sec_status_bogus
[1272618346] unbound[26422:2] info: DS rrset in DS response did not verify
[1272618346] unbound[26422:2] debug: blacklist ip4 193.171.255.48 port 53 (len 16)
[1272618346] unbound[26422:2] debug: blacklist ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: blacklist ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: blacklist ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: blacklist add ip4 194.0.13.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: validator[module 0] operate:
extstate:module_wait_subquery event:module_event_pass
[1272618346] unbound[26422:2] info: validator operate: query <www.nic.cz. A IN>
[1272618346] unbound[26422:2] debug: val handle processing q with state
VAL_FINDKEY_STATE
[1272618346] unbound[26422:2] info: validator: FindKey <www.nic.cz. A IN>
[1272618346] unbound[26422:2] info: current keyname <cz. DNSKEY IN>
[1272618346] unbound[26422:2] info: target keyname <www.nic.cz. DNSKEY IN>
[1272618346] unbound[26422:2] debug: striplab 1
[1272618346] unbound[26422:2] info: next keyname <nic.cz. DNSKEY IN>
[1272618346] unbound[26422:2] debug: No DS RRset
[1272618346] unbound[26422:2] info: generate request <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: mesh_run: validator module exit state is
module_wait_subquery
[1272618346] unbound[26422:2] debug: validator[module 0] operate:
extstate:module_state_initial event:module_event_pass
[1272618346] unbound[26422:2] info: validator operate: query <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: validator: pass to next module
[1272618346] unbound[26422:2] debug: mesh_run: validator module exit state is
module_wait_module
[1272618346] unbound[26422:2] debug: iterator[module 1] operate:
extstate:module_state_initial event:module_event_pass
[1272618346] unbound[26422:2] debug: process_request: new external request event
[1272618346] unbound[26422:2] debug: iter_handle processing q with state INIT
REQUEST STATE
[1272618346] unbound[26422:2] info: resolving <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: request has dependency depth of 0
[1272618346] unbound[26422:2] debug: cache blacklisted, going to the network
[1272618346] unbound[26422:2] debug: cache delegation returns delegpt
[1272618346] unbound[26422:2] info: DelegationPoint<cz.>: 5 names (0 missing),
10 addrs (0 result, 10 avail)
[1272618346] unbound[26422:2] info: f.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: d.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: c.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: b.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: a.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] debug: ip6 2001:678:f::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:10::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.13.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2a01:40:1000::2 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:1::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:628:453:420::48 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.171.255.48 port 53 (len 16)
[1272618346] unbound[26422:2] debug: iter_handle processing q with state INIT
REQUEST STATE (stage 2)
[1272618346] unbound[26422:2] info: resolving (init part 2): <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: iter_handle processing q with state INIT
REQUEST STATE (stage 3)
[1272618346] unbound[26422:2] info: resolving (init part 3): <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: iter_handle processing q with state QUERY
TARGETS STATE
[1272618346] unbound[26422:2] info: processQueryTargets: <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: processQueryTargets: targetqueries 0,
currentqueries 0
[1272618346] unbound[26422:2] info: DelegationPoint<cz.>: 5 names (0 missing),
10 addrs (0 result, 10 avail)
[1272618346] unbound[26422:2] info: f.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: d.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: c.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: b.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] info: a.ns.nic.cz. * A AAAA
[1272618346] unbound[26422:2] debug: ip6 2001:678:f::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:10::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 194.0.13.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2a01:40:1000::2 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:678:1::1 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: ip6 2001:628:453:420::48 port 53 (len 28)
[1272618346] unbound[26422:2] debug: ip4 193.171.255.48 port 53 (len 16)
[1272618346] unbound[26422:2] debug: attempt to get extra 3 targets
[1272618346] unbound[26422:2] debug: servselect ip4 193.171.255.48 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=8223 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 193.29.206.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=602 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 195.66.241.202 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=1482 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 194.0.13.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=8143 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: servselect ip4 194.0.12.1 port 53 (len 16)
[1272618346] unbound[26422:2] debug: rtt=1739 lost=0 DNSSEC_LAME
[1272618346] unbound[26422:2] debug: selrtt 480602
[1272618346] unbound[26422:2] debug: chase to blacklisted dnssec lame server
[1272618346] unbound[26422:2] info: sending query: <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: sending to target: <cz.> 193.29.206.1#53
[1272618346] unbound[26422:2] debug: serviced query UDP timeout=602 msec
[1272618346] unbound[26422:2] debug: inserted new pending reply id=fd69
[1272618346] unbound[26422:2] debug: opened UDP if=0 port=55119
[1272618346] unbound[26422:2] debug: comm point start listening 13
[1272618346] unbound[26422:2] debug: mesh_run: iterator module exit state is
module_wait_reply
[1272618346] unbound[26422:2] info: mesh_run: end 2 recursion states (1 with
reply, 0 detached), 1 waiting replies, 6752 recursion replies sent, 0 replies
dropped, 0 states jostled out
[1272618346] unbound[26422:2] info: average recursion processing time 38.779874 sec
[1272618346] unbound[26422:2] info: histogram of recursion processing times
[1272618346] unbound[26422:2] info: [25%]=1.88123 median[50%]=6.94849 [75%]=0.732824
[1272618346] unbound[26422:2] info: lower(secs) upper(secs) recursions
[1272618346] unbound[26422:2] info: 0.000000 0.000001 159
[1272618346] unbound[26422:2] info: 0.004096 0.008192 24
[1272618346] unbound[26422:2] info: 0.008192 0.016384 4
[1272618346] unbound[26422:2] info: 0.016384 0.032768 9
[1272618346] unbound[26422:2] info: 0.032768 0.065536 11
[1272618346] unbound[26422:2] info: 0.065536 0.131072 31
[1272618346] unbound[26422:2] info: 0.131072 0.262144 8
[1272618346] unbound[26422:2] info: 0.262144 0.524288 29
[1272618346] unbound[26422:2] info: 0.524288 1.000000 48
[1272618346] unbound[26422:2] info: 1.000000 2.000000 383
[1272618346] unbound[26422:2] info: 2.000000 4.000000 1044
[1272618346] unbound[26422:2] info: 4.000000 8.000000 1137
[1272618346] unbound[26422:2] info: 8.000000 16.000000 563
[1272618346] unbound[26422:2] info: 16.000000 32.000000 721
[1272618346] unbound[26422:2] info: 32.000000 64.000000 878
[1272618346] unbound[26422:2] info: 64.000000 128.000000 1310
[1272618346] unbound[26422:2] info: 128.000000 256.000000 393
[1272618346] unbound[26422:2] info: 0RDCD mod1 <nic.cz. DS IN>
[1272618346] unbound[26422:2] info: 1RDdc mod0 rep <www.nic.cz. A IN>
[1272618346] unbound[26422:2] debug: cache memory msg=3570894 rrset=4429080
infra=35743 val=4001591
[1272618346] unbound[26422:2] debug: svcd callbacks end
[1272618346] unbound[26422:2] debug: close of port 42311
[1272618346] unbound[26422:2] debug: close fd 14
[1272618346] unbound[26422:2] debug: answer cb
[1272618346] unbound[26422:2] debug: Incoming reply id = fd69
[1272618346] unbound[26422:2] debug: Incoming reply addr = ip4 193.29.206.1 port
53 (len 16)
[1272618346] unbound[26422:2] debug: lookup size is 1 entries
[1272618346] unbound[26422:2] debug: received udp reply.
[1272618346] unbound[26422:2] debug: udp message[96:0]
FD6984100001000200000000036E696302637A00002B0001C00C002B0001000046500018EA0C0501144130216E45C4EC2BB8595E817916E8B060D87BC00C002B00010000465000186D4B0501FF11E740A0254EC63C738A47E52ABF3AD91D8C43
[1272618346] unbound[26422:2] debug: outnet handle udp reply
[1272618346] unbound[26422:2] debug: measured roundtrip at 1 msec
[1272618346] unbound[26422:2] debug: svcd callbacks start
[1272618346] unbound[26422:2] debug: worker svcd callback for qstate 0x7f43fd12a090
[1272618346] unbound[26422:2] debug: mesh_run: start
[1272618346] unbound[26422:2] debug: iterator[module 1] operate:
extstate:module_wait_reply event:module_event_reply
[1272618346] unbound[26422:2] info: iterator operate: query <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: process_response: new external response event
[1272618346] unbound[26422:2] info: scrub for <cz. NS IN>
[1272618346] unbound[26422:2] info: response for <nic.cz. DS IN>
[1272618346] unbound[26422:2] info: reply from <cz.> 193.29.206.1#53
[1272618346] unbound[26422:2] info: incoming scrubbed packet: ;; ->>HEADER<<-
opcode: QUERY, rcode: NOERROR, id: 0
;; flags: qr aa ; QUERY: 1, ANSWER: 2, AUTHORITY: 0, ADDITIONAL: 0
;; QUESTION SECTION:
;; nic.cz. IN DS
;; ANSWER SECTION:
nic.cz. 18000 IN DS 59916 5 1 144130216e45c4ec2bb8595e817916e8b060d87b ;
xehag-casyd-curug-hyciv-supar-mikuh-vubul-nihov-misyk-bykal-rexux
nic.cz. 18000 IN DS 27979 5 1 ff11e740a0254ec63c738a47e52abf3ad91d8c43 ;
xuzoc-cunug-bimud-hafus-kezal-fidig-linyd-puzef-pukoc-tefug-fuxax
;; AUTHORITY SECTION:
;; ADDITIONAL SECTION:
;; Query time: 0 msec
;; WHEN: Thu Jan 1 01:00:00 1970
;; MSG SIZE rcvd: 96
[1272618346] unbound[26422:2] debug: iter_handle processing q with state QUERY
RESPONSE STATE
[1272618346] unbound[26422:2] info: query response was ANSWER
[1272618346] unbound[26422:2] debug: iter_handle processing q with state
FINISHED RESPONSE STATE
[1272618346] unbound[26422:2] info: finishing processing for <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: mesh_run: iterator module exit state is
module_finished
[1272618346] unbound[26422:2] debug: validator[module 0] operate:
extstate:module_wait_module event:module_event_moddone
[1272618346] unbound[26422:2] info: validator operate: query <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: validator: nextmodule returned
[1272618346] unbound[26422:2] debug: not validating response due to CD bit
[1272618346] unbound[26422:2] debug: mesh_run: validator module exit state is
module_finished
[1272618346] unbound[26422:2] info: validator: inform_super, sub is <nic.cz. DS IN>
[1272618346] unbound[26422:2] info: super is <www.nic.cz. A IN>
[1272618346] unbound[26422:2] info: verify rrset <nic.cz. DS IN>
[1272618346] unbound[26422:2] debug: rrset failed to verify due to a lack of
signatures
[1272618346] unbound[26422:2] debug: verify result: sec_status_bogus
[1272618346] unbound[26422:2] info: DS rrset in DS response did not verify
[1272618346] unbound[26422:2] debug: validator[module 0] operate:
extstate:module_wait_subquery event:module_event_pass
[1272618346] unbound[26422:2] info: validator operate: query <www.nic.cz. A IN>
[1272618346] unbound[26422:2] debug: val handle processing q with state
VAL_VALIDATE_STATE
[1272618346] unbound[26422:2] info: Could not establish a chain of trust to keys
for <nic.cz. DNSKEY IN>
[1272618346] unbound[26422:2] debug: val handle processing q with state
VAL_FINISHED_STATE
[1272618346] unbound[26422:2] info: validation failure <www.nic.cz. A IN>: no
signatures from 193.29.206.1 for DS nic.cz. while building chain of trust
[1272618346] unbound[26422:2] debug: mesh_run: validator module exit state is
module_finished
[1272618346] unbound[26422:2] debug: query took 0.081936 sec
[1272618346] unbound[26422:2] info: mesh_run: end 0 recursion states (0 with
reply, 0 detached), 0 waiting replies, 6753 recursion replies sent, 0 replies
dropped, 0 states jostled out
[1272618346] unbound[26422:2] info: average recursion processing time 38.774144 sec
[1272618346] unbound[26422:2] info: histogram of recursion processing times
[1272618346] unbound[26422:2] info: [25%]=1.87979 median[50%]=6.94139 [75%]=0.720611
[1272618346] unbound[26422:2] info: lower(secs) upper(secs) recursions
[1272618346] unbound[26422:2] info: 0.000000 0.000001 159
[1272618346] unbound[26422:2] info: 0.004096 0.008192 24
[1272618346] unbound[26422:2] info: 0.008192 0.016384 4
[1272618346] unbound[26422:2] info: 0.016384 0.032768 9
[1272618346] unbound[26422:2] info: 0.032768 0.065536 11
[1272618346] unbound[26422:2] info: 0.065536 0.131072 32
[1272618346] unbound[26422:2] info: 0.131072 0.262144 8
[1272618346] unbound[26422:2] info: 0.262144 0.524288 29
[1272618346] unbound[26422:2] info: 0.524288 1.000000 48
[1272618346] unbound[26422:2] info: 1.000000 2.000000 383
[1272618346] unbound[26422:2] info: 2.000000 4.000000 1044
[1272618346] unbound[26422:2] info: 4.000000 8.000000 1137
[1272618346] unbound[26422:2] info: 8.000000 16.000000 563
[1272618346] unbound[26422:2] info: 16.000000 32.000000 721
[1272618346] unbound[26422:2] info: 32.000000 64.000000 878
[1272618346] unbound[26422:2] info: 64.000000 128.000000 1310
[1272618346] unbound[26422:2] info: 128.000000 256.000000 393
[1272618346] unbound[26422:2] debug: cache memory msg=3570726 rrset=4429080
infra=35743 val=4001589
[1272618346] unbound[26422:2] debug: svcd callbacks end
[1272618346] unbound[26422:2] debug: close of port 55119
[1272618346] unbound[26422:2] debug: close fd 13
[1272618346] unbound[26422:2] debug: answer from the cache failed
[1272618346] unbound[26422:2] debug: udp request from ip4 127.0.0.1 port 52101
(len 16)
[1272618346] unbound[26422:2] debug: mesh_run: start
[1272618346] unbound[26422:2] debug: validator[module 0] operate:
extstate:module_state_initial event:module_event_new
--- /LOG ---
On 29.4.2010 19:21, Zbynek Michl wrote:
> On 29.4.2010 17:56, Zbynek Michl wrote:
>>> I have just made fixes to svn trunk that may help in this case. But
>>> they may not be sufficient to help you here (its about looking in the
>>> key cache to see if nic.cz needs DNSSEC).
>>
>> Ok, thanks, I will try the latest trunk version.
>
> Hmm, r2106 experiences the same issue :(
>
> It seems that there is no exact change between correct/incorrect
> validation in the one time point. On the start there are all answers
> correct, and when I am trying more and more (different in a few cycles)
> requests, then there are more and more incorrect answers. And in some
> time point all answers are incorrect from the resolver until cache is
> flushed (probably).
>
> Regards,
> Zbynek
More information about the Unbound-users
mailing list