30 Bře
2017
30 Bře
'17
0:58
hey knot folks--
I'm running kresd 1.2.4. If i start it with an empty/missing cache, and
then receive a query for an A record for "www.ietf.org", there is a
substantial delay in the response.
I'm trying to debug the delay from the kresd logging output (gathered
via systemd's journald) and i don't understand what's happening.
I'm attaching the logs from the server and client. The client (kdig),
is doing three queries, waiting 10 seconds after one query completes
before sending the next query.
timestamps of both sides are in UTC.
In particular, the delay appears to be related to resolving AAAA records
for'ns1.yyz1.afilias-nst.info, but i don't know why. i do note that the
first time it shows up it's answered with "=> using root hints", but
then subsequent times don't seem to say that. I'm not sure what this
means.
Note the multiple pauses in the server timeline, as the resolver seems
to go quiet.
can anyone reproduce this result, or help me to interpret the logs?
Regards,
--dkg
0 dkg@alice:~$ date -u -Ins; dig +tls @dns.cmrg.net www.ietf.org; sleep 10; date -u -Ins;
dig +tls @dns.cmrg.net www.ietf.org; sleep 10; date -u -Ins; dig +tls @dns.cmrg.net
www.ietf.org; date -u -Ins
2017-03-29T15:29:23,075479458+00:00
;; TLS session (TLS1.2)-(ECDHE-RSA-SECP256R1)-(AES-256-GCM)
;; ->>HEADER<<- opcode: QUERY; status: SERVFAIL; id: 38148
;; Flags: qr rd ra; QUERY: 1; ANSWER: 0; AUTHORITY: 0; ADDITIONAL: 0
;; QUESTION SECTION:
;; www.ietf.org. IN A
;; Received 30 B
;; Time 2017-03-29 10:29:36 CDT
;; From 199.58.81.218@853(TCP) in 12702.6 ms
2017-03-29T15:29:46,218745354+00:00
;; TLS session (TLS1.2)-(ECDHE-RSA-SECP256R1)-(AES-256-GCM)
;; ->>HEADER<<- opcode: QUERY; status: NOERROR; id: 1748
;; Flags: qr rd ra; QUERY: 1; ANSWER: 3; AUTHORITY: 0; ADDITIONAL: 0
;; QUESTION SECTION:
;; www.ietf.org. IN A
;; ANSWER SECTION:
www.ietf.org. 1779 IN CNAME www.ietf.org.cdn.cloudflare.net.
www.ietf.org.cdn.cloudflare.net. 286 IN A 104.20.0.85
www.ietf.org.cdn.cloudflare.net. 286 IN A 104.20.1.85
;; Received 138 B
;; Time 2017-03-29 10:29:47 CDT
;; From 199.58.81.218@853(TCP) in 65.0 ms
2017-03-29T15:29:57,033222048+00:00
;; TLS session (TLS1.2)-(ECDHE-RSA-SECP256R1)-(AES-256-GCM)
;; ->>HEADER<<- opcode: QUERY; status: NOERROR; id: 40041
;; Flags: qr rd ra; QUERY: 1; ANSWER: 3; AUTHORITY: 0; ADDITIONAL: 0
;; QUESTION SECTION:
;; www.ietf.org. IN A
;; ANSWER SECTION:
www.ietf.org. 1768 IN CNAME www.ietf.org.cdn.cloudflare.net.
www.ietf.org.cdn.cloudflare.net. 275 IN A 104.20.0.85
www.ietf.org.cdn.cloudflare.net. 275 IN A 104.20.1.85
;; Received 138 B
;; Time 2017-03-29 10:29:57 CDT
;; From 199.58.81.218@853(TCP) in 66.2 ms
2017-03-29T15:29:57,356839607+00:00
0 dkg@alice:~$
Mar 29 15:29:23.073292 systemd[1]: Starting Knot DNS Resolver daemon...
Mar 29 15:29:23.138659 kresd[15749]: [tls] RFC 7858 OOB key-pin (0):
pin-sha256="3IOHSS48KOc/zlkKGtI46a9TY9PPKDVGhE3W2ZS4JZo="
Mar 29 15:29:23.139305 kresd[15749]: [tls] RFC 7858 OOB key-pin (1):
pin-sha256="YLh1dUR9y6Kja30RrAn7JKnbQG/uEtLMkBgFF2Fuihg="
Mar 29 15:29:23.140125 kresd[15749]: [ ta ] keyfile '/usr/share/dns/root.key': not
writeable, starting in unmanaged mode
Mar 29 15:29:23.141499 kresd[15749]: [ ta ] key: 19036 state: Valid
Mar 29 15:29:23.141499 kresd[15749]: [ ta ] new state of root trust anchors:
Mar 29 15:29:23.141499 kresd[15749]: . 172800 DS
19036 8 2 49AAC11D7B6F6446702E54A1607371607A1A41855200FD2CE1CDDE32F24E8FB5
Mar 29 15:29:23.142429 systemd[1]: Started Knot DNS Resolver daemon.
Mar 29 15:29:23.487464 kresd[15749]: [ 0][plan] plan 'www.ietf.org.' type
'A'
Mar 29 15:29:23.488145 kresd[15749]: [18605][iter] 'www.ietf.org.' type
'A' id was assigned, parent id 0
Mar 29 15:29:23.488442 kresd[15749]: [18605][resl] => using root hints
Mar 29 15:29:23.488672 kresd[15749]: [57308][iter] 'www.ietf.org.' type
'A' id was assigned, parent id 0
Mar 29 15:29:23.488897 kresd[15749]: [57308][plan] plan '.' type
'DNSKEY'
Mar 29 15:29:23.489121 kresd[15749]: [35296][iter] '.' type 'DNSKEY'
id was assigned, parent id 57308
Mar 29 15:29:23.489443 kresd[15749]: [35296][resl] => querying:
'2001:dc3::35' score: 10 zone cut: '.' m12n: '.' type:
'DNSKEY' proto: 'udp'
Mar 29 15:29:23.569419 kresd[15749]: [35296][iter] <= rcode: NOERROR
Mar 29 15:29:23.570171 kresd[15749]: [35296][vldr] <= parent: updating DNSKEY
Mar 29 15:29:23.570557 kresd[15749]: [35296][vldr] <= answer valid, OK
Mar 29 15:29:23.570951 kresd[15749]: [35296][resl] <= server:
'2001:dc3::35' rtt: 81 ms
Mar 29 15:29:23.571238 kresd[15749]: [38748][iter] 'www.ietf.org.' type
'A' id was assigned, parent id 0
Mar 29 15:29:23.571491 kresd[15749]: [38748][resl] => querying:
'202.12.27.33' score: 10 zone cut: '.' m12n: 'org.' type:
'NS' proto: 'udp'
Mar 29 15:29:23.656393 kresd[15749]: [38748][iter] <= using glue for
'c0.org.afilias-nst.info.': '199.19.53.1'
Mar 29 15:29:23.657407 kresd[15749]: [38748][iter] <= using glue for
'c0.org.afilias-nst.info.': '2001:500:b::1'
Mar 29 15:29:23.657407 kresd[15749]: [38748][iter] <= using glue for
'b0.org.afilias-nst.org.': '199.19.54.1'
Mar 29 15:29:23.657407 kresd[15749]: [38748][iter] <= using glue for
'b0.org.afilias-nst.org.': '2001:500:c::1'
Mar 29 15:29:23.657407 kresd[15749]: [38748][iter] <= using glue for
'a2.org.afilias-nst.info.': '199.249.112.1'
Mar 29 15:29:23.657407 kresd[15749]: [38748][iter] <= using glue for
'a2.org.afilias-nst.info.': '2001:500:40::1'
Mar 29 15:29:23.657407 kresd[15749]: [38748][iter] <= using glue for
'd0.org.afilias-nst.org.': '199.19.57.1'
Mar 29 15:29:23.657407 kresd[15749]: [38748][iter] <= using glue for
'd0.org.afilias-nst.org.': '2001:500:f::1'
Mar 29 15:29:23.657407 kresd[15749]: [38748][iter] <= using glue for
'a0.org.afilias-nst.info.': '199.19.56.1'
Mar 29 15:29:23.657407 kresd[15749]: [38748][iter] <= using glue for
'a0.org.afilias-nst.info.': '2001:500:e::1'
Mar 29 15:29:23.657407 kresd[15749]: [38748][iter] <= using glue for
'b2.org.afilias-nst.org.': '199.249.120.1'
Mar 29 15:29:23.657407 kresd[15749]: [38748][iter] <= using glue for
'b2.org.afilias-nst.org.': '2001:500:48::1'
Mar 29 15:29:23.657407 kresd[15749]: [38748][iter] <= referral response, follow
Mar 29 15:29:23.657407 kresd[15749]: [38748][vldr] <= DS: OK
Mar 29 15:29:23.657407 kresd[15749]: [38748][vldr] <= answer valid, OK
Mar 29 15:29:23.657407 kresd[15749]: [38748][resl] <= server: '202.12.27.33'
rtt: 85 ms
Mar 29 15:29:23.657407 kresd[15749]: [15657][iter] 'www.ietf.org.' type
'A' id was assigned, parent id 0
Mar 29 15:29:23.657407 kresd[15749]: [15657][plan] plan 'org.' type
'DNSKEY'
Mar 29 15:29:23.657407 kresd[15749]: [52268][iter] 'org.' type
'DNSKEY' id was assigned, parent id 15657
Mar 29 15:29:23.657407 kresd[15749]: [52268][resl] => querying:
'2001:500:f::1' score: 10 zone cut: 'org.' m12n: 'oRg.' type:
'DNSKEY' proto: 'udp'
Mar 29 15:29:23.743211 kresd[15749]: [52268][iter] <= rcode: NOERROR
Mar 29 15:29:23.743211 kresd[15749]: [52268][vldr] <= parent: updating DNSKEY
Mar 29 15:29:23.743211 kresd[15749]: [52268][vldr] <= answer valid, OK
Mar 29 15:29:23.743211 kresd[15749]: [52268][resl] <= server:
'2001:500:f::1' rtt: 82 ms
Mar 29 15:29:23.743211 kresd[15749]: [ 5685][iter] 'www.ietf.org.' type
'A' id was assigned, parent id 0
Mar 29 15:29:23.743211 kresd[15749]: [ 5685][resl] => querying: '199.19.57.1'
score: 10 zone cut: 'org.' m12n: 'ieTF.ORg.' type: 'NS' proto:
'udp'
Mar 29 15:29:23.834259 kresd[15749]: [ 5685][iter] <= referral response, follow
Mar 29 15:29:23.834259 kresd[15749]: [ 5685][vldr] <= DS: OK
Mar 29 15:29:23.834259 kresd[15749]: [ 5685][vldr] <= answer valid, OK
Mar 29 15:29:23.834259 kresd[15749]: [ 5685][resl] <= server: '199.19.57.1'
rtt: 93 ms
Mar 29 15:29:23.834259 kresd[15749]: [14306][iter] 'www.ietf.org.' type
'A' id was assigned, parent id 0
Mar 29 15:29:23.834259 kresd[15749]: [14306][plan] plan 'ietf.org.' type
'DNSKEY'
Mar 29 15:29:23.834259 kresd[15749]: [35015][iter] 'ietf.org.' type
'DNSKEY' id was assigned, parent id 14306
Mar 29 15:29:23.834259 kresd[15749]: [35015][plan] plan
'ns1.yyz1.afilias-nst.info.' type 'AAAA'
Mar 29 15:29:23.834259 kresd[15749]: [17193][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 35015
Mar 29 15:29:23.834259 kresd[15749]: [17193][resl] => using root hints
Mar 29 15:29:23.834259 kresd[15749]: [28187][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 35015
Mar 29 15:29:23.834259 kresd[15749]: [28187][plan] plan '.' type
'DNSKEY'
Mar 29 15:29:23.834259 kresd[15749]: [ 5094][iter] '.' type
'DNSKEY' id was assigned, parent id 28187
Mar 29 15:29:23.834259 kresd[15749]: [ 5094][ rc ] => satisfied from cache
Mar 29 15:29:23.834259 kresd[15749]: [ 5094][iter] <= rcode: NOERROR
Mar 29 15:29:23.834259 kresd[15749]: [ 5094][vldr] <= parent: updating DNSKEY
Mar 29 15:29:23.834259 kresd[15749]: [ 5094][vldr] <= answer valid, OK
Mar 29 15:29:23.834259 kresd[15749]: [16944][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 35015
Mar 29 15:29:23.834259 kresd[15749]: [16944][resl] => querying:
'2001:500:9f::42' score: 10 zone cut: '.' m12n: 'iNfO.' type:
'NS' proto: 'udp'
Mar 29 15:29:23.870105 kresd[15749]: [16944][iter] <= using glue for
'a0.info.afilias-nst.info.': '199.254.31.1'
Mar 29 15:29:23.870105 kresd[15749]: [16944][iter] <= using glue for
'a0.info.afilias-nst.info.': '2001:500:19::1'
Mar 29 15:29:23.870105 kresd[15749]: [16944][iter] <= using glue for
'a2.info.afilias-nst.info.': '199.249.113.1'
Mar 29 15:29:23.870105 kresd[15749]: [16944][iter] <= using glue for
'a2.info.afilias-nst.info.': '2001:500:41::1'
Mar 29 15:29:23.870105 kresd[15749]: [16944][iter] <= using glue for
'b0.info.afilias-nst.org.': '199.254.48.1'
Mar 29 15:29:23.870105 kresd[15749]: [16944][iter] <= using glue for
'b0.info.afilias-nst.org.': '2001:500:1a::1'
Mar 29 15:29:23.870105 kresd[15749]: [16944][iter] <= using glue for
'b2.info.afilias-nst.org.': '199.249.121.1'
Mar 29 15:29:23.870105 kresd[15749]: [16944][iter] <= using glue for
'b2.info.afilias-nst.org.': '2001:500:49::1'
Mar 29 15:29:23.870105 kresd[15749]: [16944][iter] <= using glue for
'c0.info.afilias-nst.info.': '199.254.49.1'
Mar 29 15:29:23.870105 kresd[15749]: [16944][iter] <= using glue for
'c0.info.afilias-nst.info.': '2001:500:1b::1'
Mar 29 15:29:23.870105 kresd[15749]: [16944][iter] <= using glue for
'd0.info.afilias-nst.org.': '199.254.50.1'
Mar 29 15:29:23.870105 kresd[15749]: [16944][iter] <= using glue for
'd0.info.afilias-nst.org.': '2001:500:1c::1'
Mar 29 15:29:23.870105 kresd[15749]: [16944][iter] <= referral response, follow
Mar 29 15:29:23.870105 kresd[15749]: [16944][vldr] <= DS: OK
Mar 29 15:29:23.870105 kresd[15749]: [16944][vldr] <= answer valid, OK
Mar 29 15:29:23.870105 kresd[15749]: [16944][resl] <= server:
'2001:500:9f::42' rtt: 35 ms
Mar 29 15:29:23.870105 kresd[15749]: [16734][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 35015
Mar 29 15:29:23.870105 kresd[15749]: [16734][plan] plan 'info.' type
'DNSKEY'
Mar 29 15:29:23.870105 kresd[15749]: [43055][iter] 'info.' type
'DNSKEY' id was assigned, parent id 16734
Mar 29 15:29:23.870105 kresd[15749]: [43055][resl] => querying:
'2001:500:1c::1' score: 10 zone cut: 'info.' m12n: 'info.' type:
'DNSKEY' proto: 'udp'
Mar 29 15:29:23.951853 kresd[15749]: [43055][iter] <= rcode: NOERROR
Mar 29 15:29:23.951853 kresd[15749]: [43055][vldr] <= parent: updating DNSKEY
Mar 29 15:29:23.951853 kresd[15749]: [43055][vldr] <= answer valid, OK
Mar 29 15:29:23.951853 kresd[15749]: [43055][resl] <= server:
'2001:500:1c::1' rtt: 81 ms
Mar 29 15:29:23.951853 kresd[15749]: [19236][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 35015
Mar 29 15:29:23.951853 kresd[15749]: [19236][resl] => querying:
'199.254.50.1' score: 10 zone cut: 'info.' m12n:
'AFIliaS-nST.INfo.' type: 'NS' proto: 'udp'
Mar 29 15:29:24.047047 kresd[15749]: [19236][iter] <= using glue for
'a0.dig.afilias-nst.info.': '65.22.6.1'
Mar 29 15:29:24.047047 kresd[15749]: [19236][iter] <= using glue for
'a0.dig.afilias-nst.info.': '2a01:8840:6::1'
Mar 29 15:29:24.047047 kresd[15749]: [19236][iter] <= using glue for
'b0.dig.afilias-nst.info.': '65.22.7.1'
Mar 29 15:29:24.047047 kresd[15749]: [19236][iter] <= using glue for
'b0.dig.afilias-nst.info.': '2a01:8840:7::1'
Mar 29 15:29:24.047047 kresd[15749]: [19236][iter] <= using glue for
'c0.dig.afilias-nst.info.': '65.22.8.1'
Mar 29 15:29:24.047047 kresd[15749]: [19236][iter] <= using glue for
'c0.dig.afilias-nst.info.': '2a01:8840:8::1'
Mar 29 15:29:24.047047 kresd[15749]: [19236][iter] <= using glue for
'd0.dig.afilias-nst.info.': '65.22.9.1'
Mar 29 15:29:24.047047 kresd[15749]: [19236][iter] <= using glue for
'd0.dig.afilias-nst.info.': '2a01:8840:9::1'
Mar 29 15:29:24.047047 kresd[15749]: [19236][iter] <= referral response, follow
Mar 29 15:29:24.047047 kresd[15749]: [19236][vldr] <= DS doesn't exist, going
insecure
Mar 29 15:29:24.047047 kresd[15749]: [19236][vldr] <= parent: updating DS
Mar 29 15:29:24.047047 kresd[15749]: [19236][vldr] <= answer valid, OK
Mar 29 15:29:24.047047 kresd[15749]: [19236][resl] <= server:
'199.254.50.1' rtt: 91 ms
Mar 29 15:29:24.047047 kresd[15749]: [52860][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 35015
Mar 29 15:29:24.047047 kresd[15749]: [52860][plan] plan 'afilias-nst.info.'
type 'DS'
Mar 29 15:29:24.047047 kresd[15749]: [ 8943][iter] 'afilias-nst.info.'
type 'DS' id was assigned, parent id 52860
Mar 29 15:29:24.047047 kresd[15749]: [56178][iter] 'afilias-nst.info.'
type 'DS' id was assigned, parent id 52860
Mar 29 15:29:24.047047 kresd[15749]: [56178][resl] => querying:
'2001:500:1b::1' score: 10 zone cut: 'info.' m12n:
'afiLIas-nst.inFO.' type: 'DS' proto: 'udp'
Mar 29 15:29:24.078527 kresd[15749]: [56178][iter] <= rcode: NOERROR
Mar 29 15:29:24.078527 kresd[15749]: [56178][ pc ] => answer cached for
TTL=900
Mar 29 15:29:24.078527 kresd[15749]: [56178][resl] <= server:
'2001:500:1b::1' rtt: 34 ms
Mar 29 15:29:24.078527 kresd[15749]: [ 5798][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 35015
Mar 29 15:29:24.078527 kresd[15749]: [ 5798][plan] plan 'afilias-nst.info.'
type 'DS'
Mar 29 15:29:24.078527 kresd[15749]: [33359][iter] 'afilias-nst.info.'
type 'DS' id was assigned, parent id 5798
Mar 29 15:29:24.078527 kresd[15749]: [33359][ pc ] => satisfied from cache
Mar 29 15:29:24.078527 kresd[15749]: [33359][iter] <= rcode: NOERROR
Mar 29 15:29:24.078527 kresd[15749]: [33359][vldr] <= cached insecure response,
going insecure
Mar 29 15:29:24.078527 kresd[15749]: [23241][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 35015
Mar 29 15:29:24.078527 kresd[15749]: [ 9532][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 35015
Mar 29 15:29:25.338465 kresd[15749]: [ 0][plan] plan 'www.ietf.org.' type
'AAAA'
Mar 29 15:29:25.339002 kresd[15749]: [30985][iter] 'www.ietf.org.' type
'AAAA' id was assigned, parent id 0
Mar 29 15:29:25.339277 kresd[15749]: [44238][iter] 'www.ietf.org.' type
'AAAA' id was assigned, parent id 0
Mar 29 15:29:25.339512 kresd[15749]: [44238][resl] => querying:
'2001:500:48::1' score: 10 zone cut: 'org.' m12n: 'IeTF.org.'
type: 'NS' proto: 'udp'
Mar 29 15:29:25.366290 kresd[15749]: [44238][iter] <= referral response, follow
Mar 29 15:29:25.366737 kresd[15749]: [44238][vldr] <= DS: OK
Mar 29 15:29:25.367264 kresd[15749]: [44238][vldr] <= answer valid, OK
Mar 29 15:29:25.367264 kresd[15749]: [44238][resl] <= server:
'2001:500:48::1' rtt: 27 ms
Mar 29 15:29:25.367264 kresd[15749]: [39313][iter] 'www.ietf.org.' type
'AAAA' id was assigned, parent id 0
Mar 29 15:29:25.367264 kresd[15749]: [39313][plan] plan 'ietf.org.' type
'DNSKEY'
Mar 29 15:29:25.367264 kresd[15749]: [35025][iter] 'ietf.org.' type
'DNSKEY' id was assigned, parent id 39313
Mar 29 15:29:25.367264 kresd[15749]: [35025][plan] plan
'ns1.yyz1.afilias-nst.info.' type 'AAAA'
Mar 29 15:29:25.367264 kresd[15749]: [13190][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 35025
Mar 29 15:29:25.367264 kresd[15749]: [11040][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 35025
Mar 29 15:29:25.367264 kresd[15749]: [11040][resl] => querying:
'2001:500:41::1' score: 10 zone cut: 'info.' m12n:
'AFIliAs-NsT.iNfO.' type: 'NS' proto: 'udp'
Mar 29 15:29:25.383557 kresd[15749]: [11040][iter] <= using glue for
'a0.dig.afilias-nst.info.': '2a01:8840:6::1'
Mar 29 15:29:25.383557 kresd[15749]: [11040][iter] <= using glue for
'a0.dig.afilias-nst.info.': '65.22.6.1'
Mar 29 15:29:25.383557 kresd[15749]: [11040][iter] <= using glue for
'b0.dig.afilias-nst.info.': '2a01:8840:7::1'
Mar 29 15:29:25.383557 kresd[15749]: [11040][iter] <= using glue for
'b0.dig.afilias-nst.info.': '65.22.7.1'
Mar 29 15:29:25.383557 kresd[15749]: [11040][iter] <= using glue for
'c0.dig.afilias-nst.info.': '2a01:8840:8::1'
Mar 29 15:29:25.383557 kresd[15749]: [11040][iter] <= using glue for
'c0.dig.afilias-nst.info.': '65.22.8.1'
Mar 29 15:29:25.383557 kresd[15749]: [11040][iter] <= using glue for
'd0.dig.afilias-nst.info.': '2a01:8840:9::1'
Mar 29 15:29:25.383557 kresd[15749]: [11040][iter] <= using glue for
'd0.dig.afilias-nst.info.': '65.22.9.1'
Mar 29 15:29:25.383557 kresd[15749]: [11040][iter] <= referral response, follow
Mar 29 15:29:25.383557 kresd[15749]: [11040][vldr] <= DS doesn't exist, going
insecure
Mar 29 15:29:25.383557 kresd[15749]: [11040][vldr] <= parent: updating DS
Mar 29 15:29:25.383557 kresd[15749]: [11040][vldr] <= answer valid, OK
Mar 29 15:29:25.383557 kresd[15749]: [11040][resl] <= server:
'2001:500:41::1' rtt: 16 ms
Mar 29 15:29:25.383557 kresd[15749]: [22805][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 35025
Mar 29 15:29:25.383557 kresd[15749]: [22805][plan] plan 'afilias-nst.info.'
type 'DS'
Mar 29 15:29:25.383557 kresd[15749]: [44795][iter] 'afilias-nst.info.'
type 'DS' id was assigned, parent id 22805
Mar 29 15:29:25.383557 kresd[15749]: [44795][ pc ] => satisfied from cache
Mar 29 15:29:25.383557 kresd[15749]: [44795][iter] <= rcode: NOERROR
Mar 29 15:29:25.383557 kresd[15749]: [44795][vldr] <= cached insecure response,
going insecure
Mar 29 15:29:25.383557 kresd[15749]: [25751][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 35025
Mar 29 15:29:25.383557 kresd[15749]: [25751][resl] => querying:
'2a01:8840:9::1' score: 10 zone cut: 'afilias-nst.info.' m12n:
'yYz1.AFilias-nst.InFO.' type: 'NS' proto: 'udp'
Mar 29 15:29:25.478535 kresd[15749]: [25751][iter] <= rcode: NOERROR
Mar 29 15:29:25.478535 kresd[15749]: [25751][iter] <= found cut, retrying with
non-minimized name
Mar 29 15:29:25.478535 kresd[15749]: [25751][resl] <= server:
'2a01:8840:9::1' rtt: 94 ms
Mar 29 15:29:25.478535 kresd[15749]: [53313][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 35025
Mar 29 15:29:25.478535 kresd[15749]: [53313][resl] => querying:
'65.22.9.1' score: 10 zone cut: 'afilias-nst.info.' m12n:
'nS1.YYZ1.AFIlIAs-NSt.INfO.' type: 'AAAA' proto: 'udp'
Mar 29 15:29:25.569438 kresd[15749]: [53313][iter] <= using glue for
'c0.dig.afilias-nst.info.': '65.22.8.1'
Mar 29 15:29:25.569438 kresd[15749]: [53313][iter] <= using glue for
'c0.dig.afilias-nst.info.': '2a01:8840:8::1'
Mar 29 15:29:25.569438 kresd[15749]: [53313][iter] <= using glue for
'b0.dig.afilias-nst.info.': '65.22.7.1'
Mar 29 15:29:25.569438 kresd[15749]: [53313][iter] <= using glue for
'b0.dig.afilias-nst.info.': '2a01:8840:7::1'
Mar 29 15:29:25.569438 kresd[15749]: [53313][iter] <= using glue for
'a0.dig.afilias-nst.info.': '65.22.6.1'
Mar 29 15:29:25.569438 kresd[15749]: [53313][iter] <= using glue for
'a0.dig.afilias-nst.info.': '2a01:8840:6::1'
Mar 29 15:29:25.569438 kresd[15749]: [53313][iter] <= using glue for
'd0.dig.afilias-nst.info.': '65.22.9.1'
Mar 29 15:29:25.569438 kresd[15749]: [53313][iter] <= using glue for
'd0.dig.afilias-nst.info.': '2a01:8840:9::1'
Mar 29 15:29:25.569438 kresd[15749]: [53313][iter] <= referral response, follow
Mar 29 15:29:25.569438 kresd[15749]: [53313][resl] <= server: '65.22.9.1'
rtt: 90 ms
Mar 29 15:29:25.569438 kresd[15749]: [61567][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 35025
Mar 29 15:29:25.569438 kresd[15749]: [61567][resl] => querying:
'2a01:8840:8::1' score: 10 zone cut: 'yyz1.afilias-nst.info.' m12n:
'Ns1.YyZ1.AFiLiAS-Nst.InFO.' type: 'AAAA' proto: 'udp'
Mar 29 15:29:25.579537 kresd[15749]: [ 0][plan] plan 'www.ietf.org.' type
'A'
Mar 29 15:29:25.579537 kresd[15749]: [45473][iter] 'www.ietf.org.' type
'A' id was assigned, parent id 0
Mar 29 15:29:25.579537 kresd[15749]: [47453][iter] 'www.ietf.org.' type
'A' id was assigned, parent id 0
Mar 29 15:29:25.579537 kresd[15749]: [47453][resl] => querying:
'2001:500:c::1' score: 10 zone cut: 'org.' m12n: 'iETf.orG.' type:
'NS' proto: 'udp'
Mar 29 15:29:25.607596 kresd[15749]: [61567][iter] <= rcode: NOERROR
Mar 29 15:29:25.607596 kresd[15749]: [61567][resl] <= server:
'2a01:8840:8::1' rtt: 34 ms
Mar 29 15:29:25.607596 kresd[15749]: [47796][iter] 'ietf.org.' type
'DNSKEY' id was assigned, parent id 39313
Mar 29 15:29:25.607596 kresd[15749]: [47796][resl] => querying:
'2a01:8840:9::1' score: 94 zone cut: 'ietf.org.' m12n: 'IETF.ORG.'
type: 'DNSKEY' proto: 'udp'
Mar 29 15:29:25.663023 kresd[15749]: [47453][iter] <= referral response, follow
Mar 29 15:29:25.663023 kresd[15749]: [47453][vldr] <= DS: OK
Mar 29 15:29:25.663023 kresd[15749]: [47453][vldr] <= answer valid, OK
Mar 29 15:29:25.663023 kresd[15749]: [47453][resl] <= server: '2001:500:c::1'
rtt: 83 ms
Mar 29 15:29:25.663023 kresd[15749]: [ 9972][iter] 'www.ietf.org.' type
'A' id was assigned, parent id 0
Mar 29 15:29:25.663023 kresd[15749]: [ 9972][plan] plan 'ietf.org.' type
'DNSKEY'
Mar 29 15:29:25.663023 kresd[15749]: [50398][iter] 'ietf.org.' type
'DNSKEY' id was assigned, parent id 9972
Mar 29 15:29:25.663023 kresd[15749]: [50398][plan] plan
'ns1.yyz1.afilias-nst.info.' type 'AAAA'
Mar 29 15:29:25.663023 kresd[15749]: [16865][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 50398
Mar 29 15:29:25.663023 kresd[15749]: [16865][ rc ] => satisfied from cache
Mar 29 15:29:25.663023 kresd[15749]: [16865][iter] <= rcode: NOERROR
Mar 29 15:29:25.663023 kresd[15749]: [16865][vldr] <= cached insecure response,
going insecure
Mar 29 15:29:25.663023 kresd[15749]: [35265][iter] 'ietf.org.' type
'DNSKEY' id was assigned, parent id 9972
Mar 29 15:29:25.700563 kresd[15749]: [47796][iter] <= rcode: NOERROR
Mar 29 15:29:25.700563 kresd[15749]: [47796][vldr] <= parent: updating DNSKEY
Mar 29 15:29:25.700563 kresd[15749]: [47796][vldr] <= answer valid, OK
Mar 29 15:29:25.700563 kresd[15749]: [47796][resl] <= server:
'2a01:8840:9::1' rtt: 37 ms
Mar 29 15:29:25.700563 kresd[15749]: [60042][iter] 'www.ietf.org.' type
'A' id was assigned, parent id 0
Mar 29 15:29:25.700563 kresd[15749]: [60042][plan] plan
'ns1.yyz1.afilias-nst.info.' type 'AAAA'
Mar 29 15:29:25.700563 kresd[15749]: [61731][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 60042
Mar 29 15:29:25.700563 kresd[15749]: [61731][ rc ] => satisfied from cache
Mar 29 15:29:25.700563 kresd[15749]: [61731][iter] <= rcode: NOERROR
Mar 29 15:29:25.700563 kresd[15749]: [61731][vldr] <= cached insecure response,
going insecure
Mar 29 15:29:25.700563 kresd[15749]: [26102][iter] 'www.ietf.org.' type
'A' id was assigned, parent id 0
Mar 29 15:29:25.700563 kresd[15749]: [26102][resl] => querying:
'2a01:8840:9::1' score: 65 zone cut: 'ietf.org.' m12n:
'Www.ieTf.ORg.' type: 'A' proto: 'udp'
Mar 29 15:29:25.700563 kresd[15749]: [47796][iter] <= rcode: NOERROR
Mar 29 15:29:25.700563 kresd[15749]: [47796][vldr] <= parent: updating DNSKEY
Mar 29 15:29:25.700563 kresd[15749]: [47796][vldr] <= answer valid, OK
Mar 29 15:29:25.700563 kresd[15749]: [47796][resl] <= server:
'2a01:8840:9::1' rtt: 96 ms
Mar 29 15:29:25.700563 kresd[15749]: [28078][iter] 'www.ietf.org.' type
'AAAA' id was assigned, parent id 0
Mar 29 15:29:25.700563 kresd[15749]: [28078][plan] plan
'ns1.yyz1.afilias-nst.info.' type 'AAAA'
Mar 29 15:29:25.700563 kresd[15749]: [14176][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 28078
Mar 29 15:29:25.700563 kresd[15749]: [14176][ rc ] => satisfied from cache
Mar 29 15:29:25.700563 kresd[15749]: [14176][iter] <= rcode: NOERROR
Mar 29 15:29:25.700563 kresd[15749]: [14176][vldr] <= cached insecure response,
going insecure
Mar 29 15:29:25.700563 kresd[15749]: [50907][iter] 'www.ietf.org.' type
'AAAA' id was assigned, parent id 0
Mar 29 15:29:25.700563 kresd[15749]: [50907][resl] => querying:
'2a01:8840:9::1' score: 80 zone cut: 'ietf.org.' m12n:
'WWw.IETF.oRG.' type: 'AAAA' proto: 'udp'
Mar 29 15:29:25.774955 kresd[15749]: [26102][resl] => querying:
'2a01:8840:9::1' score: 65 zone cut: 'ietf.org.' m12n:
'Www.ieTf.ORg.' type: 'A' proto: 'udp'
Mar 29 15:29:25.790360 kresd[15749]: [50907][resl] => querying:
'2a01:8840:9::1' score: 80 zone cut: 'ietf.org.' m12n:
'WWw.IETF.oRG.' type: 'AAAA' proto: 'udp'
Mar 29 15:29:25.795619 kresd[15749]: [26102][iter] <= rcode: NOERROR
Mar 29 15:29:25.795619 kresd[15749]: [26102][iter] <= cname chain, following
Mar 29 15:29:25.795619 kresd[15749]: [ 0][plan] plan
'www.ietf.org.cdn.cloudflare.net.' type 'A'
Mar 29 15:29:25.795619 kresd[15749]: [26102][vldr] <= answer valid, OK
Mar 29 15:29:25.795619 kresd[15749]: [26102][resl] <= server:
'2a01:8840:9::1' rtt: 95 ms
Mar 29 15:29:25.795619 kresd[15749]: [35662][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'A' id was assigned, parent id 0
Mar 29 15:29:25.795619 kresd[15749]: [35662][resl] => using root hints
Mar 29 15:29:25.795619 kresd[15749]: [24605][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'A' id was assigned, parent id 0
Mar 29 15:29:25.795619 kresd[15749]: [24605][plan] plan '.' type
'DNSKEY'
Mar 29 15:29:25.795619 kresd[15749]: [29323][iter] '.' type 'DNSKEY'
id was assigned, parent id 24605
Mar 29 15:29:25.795619 kresd[15749]: [29323][ rc ] => satisfied from cache
Mar 29 15:29:25.795619 kresd[15749]: [29323][iter] <= rcode: NOERROR
Mar 29 15:29:25.795619 kresd[15749]: [29323][vldr] <= parent: updating DNSKEY
Mar 29 15:29:25.795619 kresd[15749]: [29323][vldr] <= answer valid, OK
Mar 29 15:29:25.795619 kresd[15749]: [32007][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'A' id was assigned, parent id 0
Mar 29 15:29:25.795619 kresd[15749]: [32007][resl] => querying:
'2001:dc3::35' score: 81 zone cut: '.' m12n: 'Net.' type:
'NS' proto: 'udp'
Mar 29 15:29:25.799567 kresd[15749]: [50907][iter] <= rcode: NOERROR
Mar 29 15:29:25.799567 kresd[15749]: [50907][iter] <= cname chain, following
Mar 29 15:29:25.799567 kresd[15749]: [ 0][plan] plan
'www.ietf.org.cdn.cloudflare.net.' type 'AAAA'
Mar 29 15:29:25.799567 kresd[15749]: [50907][vldr] <= answer valid, OK
Mar 29 15:29:25.799567 kresd[15749]: [50907][resl] <= server:
'2a01:8840:9::1' rtt: 95 ms
Mar 29 15:29:25.799567 kresd[15749]: [57109][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'AAAA' id was assigned, parent id
0
Mar 29 15:29:25.799567 kresd[15749]: [57109][resl] => using root hints
Mar 29 15:29:25.799567 kresd[15749]: [ 6112][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'AAAA' id was assigned, parent id
0
Mar 29 15:29:25.799567 kresd[15749]: [ 6112][plan] plan '.' type
'DNSKEY'
Mar 29 15:29:25.799567 kresd[15749]: [36416][iter] '.' type 'DNSKEY'
id was assigned, parent id 6112
Mar 29 15:29:25.799567 kresd[15749]: [ 7384][iter] '.' type 'DNSKEY'
id was assigned, parent id 6112
Mar 29 15:29:25.878246 kresd[15749]: [32007][iter] <= using glue for
'i.gtld-servers.net.': '192.43.172.30'
Mar 29 15:29:25.878246 kresd[15749]: [32007][iter] <= using glue for
'l.gtld-servers.net.': '192.41.162.30'
Mar 29 15:29:25.878246 kresd[15749]: [32007][iter] <= using glue for
'm.gtld-servers.net.': '192.55.83.30'
Mar 29 15:29:25.878246 kresd[15749]: [32007][iter] <= using glue for
'c.gtld-servers.net.': '192.26.92.30'
Mar 29 15:29:25.878246 kresd[15749]: [32007][iter] <= using glue for
'f.gtld-servers.net.': '192.35.51.30'
Mar 29 15:29:25.878246 kresd[15749]: [32007][iter] <= using glue for
'j.gtld-servers.net.': '192.48.79.30'
Mar 29 15:29:25.878246 kresd[15749]: [32007][iter] <= using glue for
'h.gtld-servers.net.': '192.54.112.30'
Mar 29 15:29:25.878246 kresd[15749]: [32007][iter] <= using glue for
'k.gtld-servers.net.': '192.52.178.30'
Mar 29 15:29:25.878246 kresd[15749]: [32007][iter] <= using glue for
'd.gtld-servers.net.': '192.31.80.30'
Mar 29 15:29:25.878246 kresd[15749]: [32007][iter] <= using glue for
'a.gtld-servers.net.': '192.5.6.30'
Mar 29 15:29:25.878246 kresd[15749]: [32007][iter] <= using glue for
'a.gtld-servers.net.': '2001:503:a83e::2:30'
Mar 29 15:29:25.878246 kresd[15749]: [32007][iter] <= using glue for
'b.gtld-servers.net.': '192.33.14.30'
Mar 29 15:29:25.878246 kresd[15749]: [32007][iter] <= using glue for
'b.gtld-servers.net.': '2001:503:231d::2:30'
Mar 29 15:29:25.878246 kresd[15749]: [32007][iter] <= using glue for
'g.gtld-servers.net.': '192.42.93.30'
Mar 29 15:29:25.878246 kresd[15749]: [32007][iter] <= using glue for
'e.gtld-servers.net.': '192.12.94.30'
Mar 29 15:29:25.878246 kresd[15749]: [32007][iter] <= referral response, follow
Mar 29 15:29:25.878246 kresd[15749]: [32007][vldr] <= DS: OK
Mar 29 15:29:25.878246 kresd[15749]: [32007][vldr] <= answer valid, OK
Mar 29 15:29:25.878246 kresd[15749]: [32007][resl] <= server: '2001:dc3::35'
rtt: 79 ms
Mar 29 15:29:25.878246 kresd[15749]: [ 7543][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'A' id was assigned, parent id 0
Mar 29 15:29:25.878246 kresd[15749]: [ 7543][plan] plan 'net.' type
'DNSKEY'
Mar 29 15:29:25.878246 kresd[15749]: [36241][iter] 'net.' type
'DNSKEY' id was assigned, parent id 7543
Mar 29 15:29:25.878246 kresd[15749]: [36241][resl] => querying:
'192.55.83.30' score: 10 zone cut: 'net.' m12n: 'nEt.' type:
'DNSKEY' proto: 'udp'
Mar 29 15:29:25.984605 kresd[15749]: [36241][iter] <= rcode: NOERROR
Mar 29 15:29:25.984605 kresd[15749]: [36241][vldr] <= parent: updating DNSKEY
Mar 29 15:29:25.984605 kresd[15749]: [36241][vldr] <= answer valid, OK
Mar 29 15:29:25.984605 kresd[15749]: [36241][resl] <= server:
'192.55.83.30' rtt: 109 ms
Mar 29 15:29:25.984605 kresd[15749]: [21034][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'A' id was assigned, parent id 0
Mar 29 15:29:25.984605 kresd[15749]: [21034][resl] => querying:
'192.41.162.30' score: 10 zone cut: 'net.' m12n: 'CLOUdfLArE.NeT.'
type: 'NS' proto: 'udp'
Mar 29 15:29:25.994622 kresd[15749]: [21034][iter] <= using glue for
'ns1.cloudflare.net.': '173.245.59.31'
Mar 29 15:29:25.994622 kresd[15749]: [21034][iter] <= using glue for
'ns1.cloudflare.net.': '2400:cb00:2049:1::adf5:3b1f'
Mar 29 15:29:25.994622 kresd[15749]: [21034][iter] <= using glue for
'ns2.cloudflare.net.': '198.41.222.131'
Mar 29 15:29:25.994622 kresd[15749]: [21034][iter] <= using glue for
'ns2.cloudflare.net.': '2400:cb00:2049:1::c629:de83'
Mar 29 15:29:25.994622 kresd[15749]: [21034][iter] <= using glue for
'ns3.cloudflare.net.': '198.41.222.31'
Mar 29 15:29:25.994622 kresd[15749]: [21034][iter] <= using glue for
'ns3.cloudflare.net.': '2400:cb00:2049:1::c629:de1f'
Mar 29 15:29:25.994622 kresd[15749]: [21034][iter] <= using glue for
'ns4.cloudflare.net.': '198.41.223.131'
Mar 29 15:29:25.994622 kresd[15749]: [21034][iter] <= using glue for
'ns4.cloudflare.net.': '2400:cb00:2049:1::c629:df83'
Mar 29 15:29:25.994622 kresd[15749]: [21034][iter] <= using glue for
'ns5.cloudflare.net.': '198.41.223.31'
Mar 29 15:29:25.994622 kresd[15749]: [21034][iter] <= using glue for
'ns5.cloudflare.net.': '2400:cb00:2049:1::c629:df1f'
Mar 29 15:29:25.994622 kresd[15749]: [21034][iter] <= referral response, follow
Mar 29 15:29:25.994622 kresd[15749]: [21034][vldr] <= DS: OK
Mar 29 15:29:25.994622 kresd[15749]: [21034][vldr] <= answer valid, OK
Mar 29 15:29:25.994622 kresd[15749]: [21034][resl] <= server: '192.41.162.30'
rtt: 9 ms
Mar 29 15:29:25.994622 kresd[15749]: [13614][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'A' id was assigned, parent id 0
Mar 29 15:29:25.994622 kresd[15749]: [13614][plan] plan 'cloudflare.net.' type
'DNSKEY'
Mar 29 15:29:25.994622 kresd[15749]: [32290][iter] 'cloudflare.net.' type
'DNSKEY' id was assigned, parent id 13614
Mar 29 15:29:25.994622 kresd[15749]: [32290][resl] => querying:
'2400:cb00:2049:1::c629:df1f' score: 10 zone cut: 'cloudflare.net.' m12n:
'cLouDFlarE.nET.' type: 'DNSKEY' proto: 'udp'
Mar 29 15:29:26.016448 kresd[15749]: [32290][iter] <= rcode: NOERROR
Mar 29 15:29:26.016448 kresd[15749]: [32290][vldr] <= parent: updating DNSKEY
Mar 29 15:29:26.016448 kresd[15749]: [32290][vldr] <= answer valid, OK
Mar 29 15:29:26.016448 kresd[15749]: [32290][resl] <= server:
'2400:cb00:2049:1::c629:df1f' rtt: 21 ms
Mar 29 15:29:26.016448 kresd[15749]: [14537][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'A' id was assigned, parent id 0
Mar 29 15:29:26.016448 kresd[15749]: [14537][resl] => querying:
'2400:cb00:2049:1::c629:df83' score: 10 zone cut: 'cloudflare.net.' m12n:
'cdn.ClOUDFLAre.nET.' type: 'NS' proto: 'udp'
Mar 29 15:29:26.038435 kresd[15749]: [14537][iter] <= rcode: NOERROR
Mar 29 15:29:26.038435 kresd[15749]: [14537][iter] <= found cut, retrying with
non-minimized name
Mar 29 15:29:26.038435 kresd[15749]: [14537][ pc ] => answer cached for TTL=900
Mar 29 15:29:26.038435 kresd[15749]: [14537][resl] <= server:
'2400:cb00:2049:1::c629:df83' rtt: 21 ms
Mar 29 15:29:26.038435 kresd[15749]: [24680][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'A' id was assigned, parent id 0
Mar 29 15:29:26.038435 kresd[15749]: [20950][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'A' id was assigned, parent id 0
Mar 29 15:29:27.078953 kresd[15749]: [64168][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 35015
Mar 29 15:29:27.078953 kresd[15749]: [37681][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 35015
Mar 29 15:29:28.797213 kresd[15749]: [40633][iter] '.' type 'DNSKEY'
id was assigned, parent id 6112
Mar 29 15:29:28.797213 kresd[15749]: [ 6648][iter] '.' type 'DNSKEY'
id was assigned, parent id 6112
Mar 29 15:29:29.038982 kresd[15749]: [44052][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'A' id was assigned, parent id 0
Mar 29 15:29:29.038982 kresd[15749]: [ 8735][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'A' id was assigned, parent id 0
Mar 29 15:29:30.079540 kresd[15749]: [ 594][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 35015
Mar 29 15:29:30.079540 kresd[15749]: [48191][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 35015
Mar 29 15:29:31.798649 kresd[15749]: [56672][iter] '.' type 'DNSKEY'
id was assigned, parent id 6112
Mar 29 15:29:31.798649 kresd[15749]: [56672][resl] => querying:
'199.7.83.42' score: 10 zone cut: '.' m12n: '.' type:
'DNSKEY' proto: 'udp'
Mar 29 15:29:31.812915 kresd[15749]: [56672][iter] <= rcode: NOERROR
Mar 29 15:29:31.812915 kresd[15749]: [56672][vldr] <= parent: updating DNSKEY
Mar 29 15:29:31.812915 kresd[15749]: [56672][vldr] <= answer valid, OK
Mar 29 15:29:31.812915 kresd[15749]: [56672][resl] <= server: '199.7.83.42'
rtt: 14 ms
Mar 29 15:29:31.812915 kresd[15749]: [56887][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'AAAA' id was assigned, parent id
0
Mar 29 15:29:31.812915 kresd[15749]: [56887][resl] => querying: '2001:7fd::1'
score: 10 zone cut: '.' m12n: 'nEt.' type: 'NS' proto:
'udp'
Mar 29 15:29:31.873913 kresd[15749]: [56887][iter] <= using glue for
'a.gtld-servers.net.': '192.5.6.30'
Mar 29 15:29:31.873913 kresd[15749]: [56887][iter] <= using glue for
'a.gtld-servers.net.': '2001:503:a83e::2:30'
Mar 29 15:29:31.873913 kresd[15749]: [56887][iter] <= using glue for
'b.gtld-servers.net.': '192.33.14.30'
Mar 29 15:29:31.873913 kresd[15749]: [56887][iter] <= using glue for
'b.gtld-servers.net.': '2001:503:231d::2:30'
Mar 29 15:29:31.873913 kresd[15749]: [56887][iter] <= using glue for
'c.gtld-servers.net.': '192.26.92.30'
Mar 29 15:29:31.873913 kresd[15749]: [56887][iter] <= using glue for
'd.gtld-servers.net.': '192.31.80.30'
Mar 29 15:29:31.873913 kresd[15749]: [56887][iter] <= using glue for
'e.gtld-servers.net.': '192.12.94.30'
Mar 29 15:29:31.873913 kresd[15749]: [56887][iter] <= using glue for
'f.gtld-servers.net.': '192.35.51.30'
Mar 29 15:29:31.873913 kresd[15749]: [56887][iter] <= using glue for
'g.gtld-servers.net.': '192.42.93.30'
Mar 29 15:29:31.873913 kresd[15749]: [56887][iter] <= using glue for
'h.gtld-servers.net.': '192.54.112.30'
Mar 29 15:29:31.873913 kresd[15749]: [56887][iter] <= using glue for
'i.gtld-servers.net.': '192.43.172.30'
Mar 29 15:29:31.873913 kresd[15749]: [56887][iter] <= using glue for
'j.gtld-servers.net.': '192.48.79.30'
Mar 29 15:29:31.873913 kresd[15749]: [56887][iter] <= using glue for
'k.gtld-servers.net.': '192.52.178.30'
Mar 29 15:29:31.873913 kresd[15749]: [56887][iter] <= using glue for
'l.gtld-servers.net.': '192.41.162.30'
Mar 29 15:29:31.873913 kresd[15749]: [56887][iter] <= using glue for
'm.gtld-servers.net.': '192.55.83.30'
Mar 29 15:29:31.873913 kresd[15749]: [56887][iter] <= referral response, follow
Mar 29 15:29:31.873913 kresd[15749]: [56887][vldr] <= DS: OK
Mar 29 15:29:31.873913 kresd[15749]: [56887][vldr] <= answer valid, OK
Mar 29 15:29:31.873913 kresd[15749]: [56887][resl] <= server: '2001:7fd::1'
rtt: 60 ms
Mar 29 15:29:31.873913 kresd[15749]: [34711][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'AAAA' id was assigned, parent id
0
Mar 29 15:29:31.873913 kresd[15749]: [34711][plan] plan 'net.' type
'DNSKEY'
Mar 29 15:29:31.873913 kresd[15749]: [12142][iter] 'net.' type
'DNSKEY' id was assigned, parent id 34711
Mar 29 15:29:31.873913 kresd[15749]: [12142][resl] => querying:
'192.52.178.30' score: 10 zone cut: 'net.' m12n: 'neT.' type:
'DNSKEY' proto: 'udp'
Mar 29 15:29:32.039495 kresd[15749]: [47242][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'A' id was assigned, parent id 0
Mar 29 15:29:32.039495 kresd[15749]: [47242][resl] => querying:
'2400:cb00:2049:1::c629:de83' score: 10 zone cut: 'cloudflare.net.' m12n:
'wWW.iETf.ORg.Cdn.cLOuDFLARe.NEt.' type: 'A' proto: 'udp'
Mar 29 15:29:32.061000 kresd[15749]: [47242][iter] <= rcode: NOERROR
Mar 29 15:29:32.061000 kresd[15749]: [47242][vldr] <= answer valid, OK
Mar 29 15:29:32.061000 kresd[15749]: [47242][resl] <= server:
'2400:cb00:2049:1::c629:de83' rtt: 18 ms
Mar 29 15:29:32.061000 kresd[15749]: [ 0][resl] finished: 4, queries: 8, mempool:
131152 B
Mar 29 15:29:32.073521 kresd[15749]: [12142][iter] <= rcode: NOERROR
Mar 29 15:29:32.073521 kresd[15749]: [12142][vldr] <= parent: updating DNSKEY
Mar 29 15:29:32.073521 kresd[15749]: [12142][vldr] <= answer valid, OK
Mar 29 15:29:32.073521 kresd[15749]: [12142][resl] <= server:
'192.52.178.30' rtt: 199 ms
Mar 29 15:29:32.073521 kresd[15749]: [ 3229][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'AAAA' id was assigned, parent id
0
Mar 29 15:29:32.073521 kresd[15749]: [ 3229][resl] => querying:
'192.48.79.30' score: 10 zone cut: 'net.' m12n: 'clOUDFLaRE.neT.'
type: 'NS' proto: 'udp'
Mar 29 15:29:32.115931 kresd[15749]: [ 3229][iter] <= using glue for
'ns1.cloudflare.net.': '173.245.59.31'
Mar 29 15:29:32.115931 kresd[15749]: [ 3229][iter] <= using glue for
'ns1.cloudflare.net.': '2400:cb00:2049:1::adf5:3b1f'
Mar 29 15:29:32.115931 kresd[15749]: [ 3229][iter] <= using glue for
'ns2.cloudflare.net.': '198.41.222.131'
Mar 29 15:29:32.115931 kresd[15749]: [ 3229][iter] <= using glue for
'ns2.cloudflare.net.': '2400:cb00:2049:1::c629:de83'
Mar 29 15:29:32.115931 kresd[15749]: [ 3229][iter] <= using glue for
'ns3.cloudflare.net.': '198.41.222.31'
Mar 29 15:29:32.115931 kresd[15749]: [ 3229][iter] <= using glue for
'ns3.cloudflare.net.': '2400:cb00:2049:1::c629:de1f'
Mar 29 15:29:32.115931 kresd[15749]: [ 3229][iter] <= using glue for
'ns4.cloudflare.net.': '198.41.223.131'
Mar 29 15:29:32.115931 kresd[15749]: [ 3229][iter] <= using glue for
'ns4.cloudflare.net.': '2400:cb00:2049:1::c629:df83'
Mar 29 15:29:32.115931 kresd[15749]: [ 3229][iter] <= using glue for
'ns5.cloudflare.net.': '198.41.223.31'
Mar 29 15:29:32.115931 kresd[15749]: [ 3229][iter] <= using glue for
'ns5.cloudflare.net.': '2400:cb00:2049:1::c629:df1f'
Mar 29 15:29:32.115931 kresd[15749]: [ 3229][iter] <= referral response, follow
Mar 29 15:29:32.115931 kresd[15749]: [ 3229][vldr] <= DS: OK
Mar 29 15:29:32.115931 kresd[15749]: [ 3229][vldr] <= answer valid, OK
Mar 29 15:29:32.115931 kresd[15749]: [ 3229][resl] <= server: '192.48.79.30'
rtt: 42 ms
Mar 29 15:29:32.115931 kresd[15749]: [17305][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'AAAA' id was assigned, parent id
0
Mar 29 15:29:32.115931 kresd[15749]: [17305][plan] plan 'cloudflare.net.' type
'DNSKEY'
Mar 29 15:29:32.115931 kresd[15749]: [31186][iter] 'cloudflare.net.' type
'DNSKEY' id was assigned, parent id 17305
Mar 29 15:29:32.115931 kresd[15749]: [31186][ rc ] => satisfied from cache
Mar 29 15:29:32.115931 kresd[15749]: [31186][iter] <= rcode: NOERROR
Mar 29 15:29:32.115931 kresd[15749]: [31186][vldr] <= parent: updating DNSKEY
Mar 29 15:29:32.115931 kresd[15749]: [31186][vldr] <= answer valid, OK
Mar 29 15:29:32.115931 kresd[15749]: [25948][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'AAAA' id was assigned, parent id
0
Mar 29 15:29:32.115931 kresd[15749]: [25948][resl] => querying:
'2400:cb00:2049:1::c629:de1f' score: 10 zone cut: 'cloudflare.net.' m12n:
'cDN.ClOUdFlaRe.net.' type: 'NS' proto: 'udp'
Mar 29 15:29:32.137736 kresd[15749]: [25948][iter] <= rcode: NOERROR
Mar 29 15:29:32.137736 kresd[15749]: [25948][iter] <= found cut, retrying with
non-minimized name
Mar 29 15:29:32.137736 kresd[15749]: [25948][ pc ] => answer cached for TTL=900
Mar 29 15:29:32.137736 kresd[15749]: [25948][resl] <= server:
'2400:cb00:2049:1::c629:de1f' rtt: 21 ms
Mar 29 15:29:32.137736 kresd[15749]: [18856][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'AAAA' id was assigned, parent id
0
Mar 29 15:29:32.137736 kresd[15749]: [18856][resl] => querying:
'2400:cb00:2049:1::adf5:3b1f' score: 10 zone cut: 'cloudflare.net.' m12n:
'WwW.IETF.ORg.Cdn.CLOuDflARE.NET.' type: 'AAAA' proto: 'udp'
Mar 29 15:29:32.156189 kresd[15749]: [18856][iter] <= rcode: NOERROR
Mar 29 15:29:32.156189 kresd[15749]: [18856][vldr] <= answer valid, OK
Mar 29 15:29:32.156189 kresd[15749]: [18856][resl] <= server:
'2400:cb00:2049:1::adf5:3b1f' rtt: 18 ms
Mar 29 15:29:32.156189 kresd[15749]: [ 0][resl] finished: 4, queries: 9, mempool:
147552 B
Mar 29 15:29:33.079990 kresd[15749]: [31173][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 35015
Mar 29 15:29:33.079990 kresd[15749]: [12786][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 35015
Mar 29 15:29:33.103799 kresd[15749]: [ 0][plan] plan '.' type 'DNSKEY'
Mar 29 15:29:33.103799 kresd[15749]: [23021][iter] '.' type 'DNSKEY' id
was assigned, parent id 0
Mar 29 15:29:33.103799 kresd[15749]: [23021][ rc ] => satisfied from cache
Mar 29 15:29:33.103799 kresd[15749]: [23021][iter] <= rcode: NOERROR
Mar 29 15:29:33.103799 kresd[15749]: [ 0][resl] finished: 4, queries: 1, mempool:
147552 B
Mar 29 15:29:33.103799 kresd[15749]: [ ta ] key: 19036 state: Valid
Mar 29 15:29:33.103799 kresd[15749]: [ ta ] new state of root trust anchors:
Mar 29 15:29:33.103799 kresd[15749]: . 172800 DS
19036 8 2 49AAC11D7B6F6446702E54A1607371607A1A41855200FD2CE1CDDE32F24E8FB5
Mar 29 15:29:33.103799 kresd[15749]: [ ta ] next refresh in 24 hours
Mar 29 15:29:33.103799 kresd[15749]: [ 0][plan] plan '.' type 'NS'
Mar 29 15:29:33.103799 kresd[15749]: [31389][iter] '.' type 'NS' id was
assigned, parent id 0
Mar 29 15:29:33.103799 kresd[15749]: [31389][resl] => using root hints
Mar 29 15:29:33.103799 kresd[15749]: [33816][iter] '.' type 'NS' id was
assigned, parent id 0
Mar 29 15:29:33.103799 kresd[15749]: [33816][plan] plan '.' type
'DNSKEY'
Mar 29 15:29:33.103799 kresd[15749]: [21488][iter] '.' type 'DNSKEY'
id was assigned, parent id 33816
Mar 29 15:29:33.103799 kresd[15749]: [21488][ rc ] => satisfied from cache
Mar 29 15:29:33.103799 kresd[15749]: [21488][iter] <= rcode: NOERROR
Mar 29 15:29:33.103799 kresd[15749]: [21488][vldr] <= parent: updating DNSKEY
Mar 29 15:29:33.103799 kresd[15749]: [21488][vldr] <= answer valid, OK
Mar 29 15:29:33.103799 kresd[15749]: [61993][iter] '.' type 'NS' id was
assigned, parent id 0
Mar 29 15:29:33.103799 kresd[15749]: [61993][resl] => querying:
'193.0.14.129' score: 10 zone cut: '.' m12n: '.' type:
'NS' proto: 'udp'
Mar 29 15:29:33.142746 kresd[15749]: [61993][iter] <= rcode: NOERROR
Mar 29 15:29:33.142746 kresd[15749]: [61993][vldr] <= answer valid, OK
Mar 29 15:29:33.142746 kresd[15749]: [61993][resl] <= server: '193.0.14.129'
rtt: 39 ms
Mar 29 15:29:33.142746 kresd[15749]: [ 0][resl] finished: 4, queries: 2, mempool:
131152 B
Mar 29 15:29:36.081423 kresd[15749]: [16901][iter]
'ns1.yyz1.afilias-nst.info.' type 'AAAA' id was assigned, parent id 35015
Mar 29 15:29:36.081423 kresd[15749]: [ 0][resl] finished: 8, queries: 6, mempool:
147552 B
Mar 29 15:29:46.897467 kresd[15749]: [ 0][plan] plan 'www.ietf.org.' type
'A'
Mar 29 15:29:46.898006 kresd[15749]: [49098][iter] 'www.ietf.org.' type
'A' id was assigned, parent id 0
Mar 29 15:29:46.898317 kresd[15749]: [49098][ rc ] => satisfied from cache
Mar 29 15:29:46.898743 kresd[15749]: [49098][iter] <= rcode: NOERROR
Mar 29 15:29:46.898743 kresd[15749]: [49098][iter] <= cname chain, following
Mar 29 15:29:46.898743 kresd[15749]: [ 0][plan] plan
'www.ietf.org.cdn.cloudflare.net.' type 'A'
Mar 29 15:29:46.898743 kresd[15749]: [64077][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'A' id was assigned, parent id 0
Mar 29 15:29:46.898743 kresd[15749]: [64077][ rc ] => satisfied from cache
Mar 29 15:29:46.898743 kresd[15749]: [64077][iter] <= rcode: NOERROR
Mar 29 15:29:46.898743 kresd[15749]: [64077][vldr] <= answer valid, OK
Mar 29 15:29:46.898743 kresd[15749]: [ 0][resl] finished: 4, queries: 2, mempool:
147552 B
Mar 29 15:29:57.229477 kresd[15749]: [ 0][plan] plan 'www.ietf.org.' type
'A'
Mar 29 15:29:57.230003 kresd[15749]: [54278][iter] 'www.ietf.org.' type
'A' id was assigned, parent id 0
Mar 29 15:29:57.230246 kresd[15749]: [54278][ rc ] => satisfied from cache
Mar 29 15:29:57.230526 kresd[15749]: [54278][iter] <= rcode: NOERROR
Mar 29 15:29:57.230766 kresd[15749]: [54278][iter] <= cname chain, following
Mar 29 15:29:57.230980 kresd[15749]: [ 0][plan] plan
'www.ietf.org.cdn.cloudflare.net.' type 'A'
Mar 29 15:29:57.231198 kresd[15749]: [10171][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'A' id was assigned, parent id 0
Mar 29 15:29:57.231418 kresd[15749]: [10171][ rc ] => satisfied from cache
Mar 29 15:29:57.231730 kresd[15749]: [10171][iter] <= rcode: NOERROR
Mar 29 15:29:57.232079 kresd[15749]: [10171][vldr] <= answer valid, OK
Mar 29 15:29:57.232079 kresd[15749]: [ 0][resl] finished: 4, queries: 2, mempool:
147552 B
Mar 29 15:30:00.039527 kresd[15749]: [ 0][plan] plan 'www.ietf.org.' type
'AAAA'
Mar 29 15:30:00.040083 kresd[15749]: [ 3850][iter] 'www.ietf.org.' type
'AAAA' id was assigned, parent id 0
Mar 29 15:30:00.040334 kresd[15749]: [ 3850][ rc ] => satisfied from cache
Mar 29 15:30:00.040561 kresd[15749]: [ 3850][iter] <= rcode: NOERROR
Mar 29 15:30:00.040782 kresd[15749]: [ 3850][iter] <= cname chain, following
Mar 29 15:30:00.041003 kresd[15749]: [ 0][plan] plan
'www.ietf.org.cdn.cloudflare.net.' type 'AAAA'
Mar 29 15:30:00.041291 kresd[15749]: [22572][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'AAAA' id was assigned, parent id
0
Mar 29 15:30:00.041539 kresd[15749]: [22572][ rc ] => satisfied from cache
Mar 29 15:30:00.041758 kresd[15749]: [22572][iter] <= rcode: NOERROR
Mar 29 15:30:00.042114 kresd[15749]: [22572][vldr] <= answer valid, OK
Mar 29 15:30:00.042114 kresd[15749]: [ 0][resl] finished: 4, queries: 2, mempool:
147552 B
Mar 29 15:30:00.226842 kresd[15749]: [ 0][plan] plan 'www.ietf.org.' type
'A'
Mar 29 15:30:00.226842 kresd[15749]: [35156][iter] 'www.ietf.org.' type
'A' id was assigned, parent id 0
Mar 29 15:30:00.226842 kresd[15749]: [35156][ rc ] => satisfied from cache
Mar 29 15:30:00.226842 kresd[15749]: [35156][iter] <= rcode: NOERROR
Mar 29 15:30:00.226842 kresd[15749]: [35156][iter] <= cname chain, following
Mar 29 15:30:00.226842 kresd[15749]: [ 0][plan] plan
'www.ietf.org.cdn.cloudflare.net.' type 'A'
Mar 29 15:30:00.226842 kresd[15749]: [51701][iter]
'www.ietf.org.cdn.cloudflare.net.' type 'A' id was assigned, parent id 0
Mar 29 15:30:00.226842 kresd[15749]: [51701][ rc ] => satisfied from cache
Mar 29 15:30:00.226842 kresd[15749]: [51701][iter] <= rcode: NOERROR
Mar 29 15:30:00.226842 kresd[15749]: [51701][vldr] <= answer valid, OK
Mar 29 15:30:00.226842 kresd[15749]: [ 0][resl] finished: 4, queries: 2, mempool:
147552 B