I removed root hints as you said. And, I did add remote control config and then did command below
sudo unbound-control lookup .
The following name servers are used for lookup of .
;rrset 44236 13 1 11 5
. 44236 IN NS g.root-servers.net.
. 44236 IN NS j.root-servers.net.
. 44236 IN NS e.root-servers.net.
. 44236 IN NS l.root-servers.net.
. 44236 IN NS d.root-servers.net.
. 44236 IN NS a.root-servers.net.
. 44236 IN NS b.root-servers.net.
. 44236 IN NS i.root-servers.net.
. 44236 IN NS m.root-servers.net.
. 44236 IN NS h.root-servers.net.
. 44236 IN NS c.root-servers.net.
. 44236 IN NS k.root-servers.net.
. 44236 IN NS f.root-servers.net.
. 44236 IN RRSIG NS 8 0 518400 20230309170000 20230224160000 951 . EGckAF/tzzcND0InCUcV3gVnaSSvOnptCgFfRJG4drpfVr/sRLs7WYrxJvlLxzKoXbakcRas7l40RmEivL2L6ZQbEPcKppdY79pdNoqSLPtgFuKL7qo+EgLLIJ72htgF9YKYAU41MJZsUfDXmp9dkMVC2NkY7x15lUq4WQTMvWSOR9Wz6GITrPXJQma6SsRqU00YV4upkZBb8+9palGZqIePBltHeKfGjCmQJ/2kRHxojO3HT5QMExSuNva2JFNXuyYFniAB8fpfM59Kp0688ItwS7FibcaG73BtDAg1fQGYTsMcIpAoJBJcnP+eSFp5EuKlL/yZQZK0N8+OK4OIaw== ;{id = 951}
;rrset 44236 1 0 3 0
f.root-servers.net. 44236 IN A 192.5.5.241
;rrset 44236 1 0 3 0
f.root-servers.net. 44236 IN AAAA 2001:500:2f::f
;rrset 44236 1 0 3 0
k.root-servers.net. 44236 IN A 193.0.14.129
;rrset 44236 1 0 3 0
k.root-servers.net. 44236 IN AAAA 2001:7fd::1
;rrset 44236 1 0 3 0
c.root-servers.net. 44236 IN A 192.33.4.12
;rrset 44236 1 0 3 0
c.root-servers.net. 44236 IN AAAA 2001:500:2::c
;rrset 44236 1 0 3 0
h.root-servers.net. 44236 IN A 198.97.190.53
;rrset 44236 1 0 3 0
h.root-servers.net. 44236 IN AAAA 2001:500:1::53
;rrset 44236 1 0 3 0
m.root-servers.net. 44236 IN A 202.12.27.33
;rrset 44236 1 0 3 0
m.root-servers.net. 44236 IN AAAA 2001:dc3::35
;rrset 44236 1 0 3 0
i.root-servers.net. 44236 IN A 192.36.148.17
;rrset 44236 1 0 3 0
i.root-servers.net. 44236 IN AAAA 2001:7fe::53
;rrset 44236 1 0 3 0
b.root-servers.net. 44236 IN A 199.9.14.201
;rrset 44236 1 0 3 0
b.root-servers.net. 44236 IN AAAA 2001:500:200::b
;rrset 44236 1 0 3 0
a.root-servers.net. 44236 IN A 198.41.0.4
;rrset 44236 1 0 3 0
a.root-servers.net. 44236 IN AAAA 2001:503:ba3e::2:30
;rrset 44236 1 0 3 0
d.root-servers.net. 44236 IN A 199.7.91.13
;rrset 44236 1 0 3 0
d.root-servers.net. 44236 IN AAAA 2001:500:2d::d
;rrset 44236 1 0 3 0
l.root-servers.net. 44236 IN A 199.7.83.42
;rrset 44236 1 0 3 0
l.root-servers.net. 44236 IN AAAA 2001:500:9f::42
;rrset 44236 1 0 3 0
e.root-servers.net. 44236 IN A 192.203.230.10
;rrset 44236 1 0 3 0
e.root-servers.net. 44236 IN AAAA 2001:500:a8::e
;rrset 44236 1 0 3 0
j.root-servers.net. 44236 IN A 192.58.128.30
;rrset 44236 1 0 3 0
j.root-servers.net. 44236 IN AAAA 2001:503:c27::2:30
;rrset 44236 1 0 3 0
g.root-servers.net. 44236 IN A 192.112.36.4
;rrset 44236 1 0 3 0
g.root-servers.net. 44236 IN AAAA 2001:500:12::d0d
Delegation with 13 names, of which 0 can be examined to query further addresses.
It provides 26 IP addresses.
2001:500:12::d0d not in infra cache.
192.112.36.4 NoAuthButRecursive rto 148 msec, ttl 724, ping 16 var 33 rtt 148, tA 0, tAAAA 0, tother 2, EDNS 0 probed.
2001:503:c27::2:30 not in infra cache.
192.58.128.30 NoAuthButRecursive rto 504 msec, ttl 727, ping 4 var 62 rtt 252, tA 0, tAAAA 0, tother 1, EDNS 0 probed.
2001:500:a8::e not in infra cache.
192.203.230.10 NoAuthButRecursive rto 196 msec, ttl 722, ping 16 var 45 rtt 196, tA 0, tAAAA 0, tother 1, EDNS 0 probed.
2001:500:9f::42 not in infra cache.
199.7.83.42 NoAuthButRecursive rto 137 msec, ttl 723, ping 5 var 33 rtt 137, tA 0, tAAAA 0, tother 2, EDNS 0 probed.
2001:500:2d::d not in infra cache.
199.7.91.13 NoAuthButRecursive rto 594 msec, ttl 726, ping 1 var 74 rtt 297, tA 0, tAAAA 0, tother 1, EDNS 0 probed.
2001:503:ba3e::2:30 not in infra cache.
198.41.0.4 NoAuthButRecursive rto 136 msec, ttl 722, ping 0 var 34 rtt 136, tA 0, tAAAA 0, tother 0, EDNS 0 probed.
2001:500:200::b not in infra cache.
199.9.14.201 NoAuthButRecursive rto 274 msec, ttl 726, ping 1 var 34 rtt 137, tA 0, tAAAA 0, tother 1, EDNS 0 probed.
2001:7fe::53 not in infra cache.
192.36.148.17 NoAuthButRecursive rto 181 msec, ttl 726, ping 17 var 41 rtt 181, tA 0, tAAAA 0, tother 2, EDNS 0 probed.
2001:dc3::35 not in infra cache.
202.12.27.33 NoAuthButRecursive rto 145 msec, ttl 728, ping 17 var 32 rtt 145, tA 0, tAAAA 0, tother 1, EDNS 0 probed.
2001:500:1::53 not in infra cache.
198.97.190.53 NoAuthButRecursive rto 636 msec, ttl 722, ping 11 var 37 rtt 159, tA 0, tAAAA 0, tother 3, EDNS 0 probed.
2001:500:2::c not in infra cache.
192.33.4.12 NoAuthButRecursive rto 968 msec, ttl 722, ping 76 var 223 rtt 968, tA 0, tAAAA 0, tother 0, EDNS 0 probed.
2001:7fd::1 not in infra cache.
193.0.14.129 NoAuthButRecursive rto 121 msec, ttl 725, ping 13 var 27 rtt 121, tA 0, tAAAA 0, tother 1, EDNS 0 probed.
2001:500:2f::f not in infra cache.
192.5.5.241 NoAuthButRecursive rto 151 msec, ttl 724, ping 3 var 37 rtt 151, tA 0, tAAAA 0, tother 0, EDNS 0 probed.
However, sometimes lookup for . returns nothing. I didn't figure out why.
sudo unbound-control lookup .
The following name servers are used for lookup of .
no delegation from cache; goes to configured roots
and still looking up domains don't work (or sometimes returns wrong IP)
dig +noall @127.0.0.1 -p 5335 google.com
;; connection timed out; no servers could be reached
dig @127.0.0.1 -p 5335 google.com
; <<>> DiG 9.11.5-P4-5.1+deb10u8-Raspbian <<>> @127.0.0.1 -p 5335 google.com
; (1 server found)
;; global options: +cmd
;; connection timed out; no servers could be reached
and this is my verbos log
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] info: validator operate: query google.com. A IN
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] debug: validator: nextmodule returned
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] debug: val handle processing q with state VAL_INIT_STATE
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] debug: validator classification positive
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] info: no signer, using google.com. TYPE0 CLASS0
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] debug: val handle processing q with state VAL_FINDKEY_STATE
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] info: validator: FindKey google.com. A IN
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] info: current keyname com. DNSKEY IN
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] info: target keyname google.com. DNSKEY IN
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] debug: striplab 0
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] info: next keyname google.com. DNSKEY IN
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] debug: No DS RRset
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] info: generate request google.com. DS IN
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] debug: mesh_run: validator module exit state is module_wait_subquery
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] debug: subnet[module 0] operate: extstate:module_state_initial event:module_event_pass
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] info: subnet operate: query google.com. DS IN
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] debug: subnet: pass to next module
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] debug: mesh_run: subnet module exit state is module_wait_module
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_pass
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] info: validator operate: query google.com. DS IN
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] debug: validator: pass to next module
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] debug: mesh_run: validator module exit state is module_wait_module
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] debug: iterator[module 2] operate: extstate:module_state_initial event:module_event_pass
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] debug: process_request: new external request event
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] debug: iter_handle processing q with state INIT REQUEST STATE
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] info: resolving google.com. DS IN
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] debug: request has dependency depth of 0
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] info: msg from cache lookup ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0
;; flags: qr ra ; QUERY: 1, ANSWER: 0, AUTHORITY: 6, ADDITIONAL: 0
;; QUESTION SECTION:
google.com. IN DS
;; ANSWER SECTION:
;; AUTHORITY SECTION:
CK0POJMG874LJREF7EFN8430QVIT8BSM.com. 20857 IN NSEC3 1 1 0 - ck0q2d6ni4i7eqh8na30ns61o48ul8g5 NS SOA RRSIG DNSKEY NSEC3PARAM ;{flags: optout}
CK0POJMG874LJREF7EFN8430QVIT8BSM.com. 20857 IN RRSIG NSEC3 8 2 86400 20230303052249 20230224041249 36739 com. rXXhjgHhBHyFnZNsXtNvn2jSCLCInjirm5afZvn+wcu2dIQ/wGP9TAbtZXDgA78A21Bgbtfm04wVemAUSg3dOBWZaPGJqftBUffy9mr8eSFeOfe4cx35PzknJp6BVqUwYGQtogdUu9A7iFldK6AJhFWpeIL194qhtJY6kQMdHRmL3S8kgI5KbxzpzB90bWpetBPxs493GpP/R4pBvH2nsA== ;{id = 36739}
com. 3548 IN SOA a.gtld-servers.net. nstld.verisign-grs.com. 1677306908 1800 900 604800 86400
com. 20857 IN RRSIG SOA 8 1 900 20230304063508 20230225052508 36739 com. tlRS6ij1Co1cm98lbP7Vu5FrQyE10lbTwo6y2lTBM71DAbraUx+hK7zdR9YC5PzedqKXbkVdZA0UJHVjCH1M3NGahSVuCKHyipM05/5MwjGfNxOqQ6P87DmaIkC0pt8TgWBQue9+gRk6iiFuraKnPUj79mTTet6u+u+QsZOOvCNbjV5W0tXX6CWdXQrt3UFonNLmbSJaC4cIP5Rez0K5Eg== ;{id = 36739}
S84BKCIBC38P58340AKVNFN5KR9O59QC.com. 20857 IN NSEC3 1 1 0 - s84buo64gqcvn69rjfuo6lvc7fslunj5 NS DS RRSIG ;{flags: optout}
S84BKCIBC38P58340AKVNFN5KR9O59QC.com. 20857 IN RRSIG NSEC3 8 2 86400 20230304060135 20230225045135 36739 com. cXaYy0la+1W3vD6vMRJqyuTMycvYhTRWUBA2ytY9LPwTzcN6wP1WUp9D9ZtFK5A4aTavzz28nFy53WLCDsWYWr3ogIb5M0BGjZqFZ3oHIwmqgRwhgG+8P/etYTW1TTfDQQXo0mGGc50D1GLzhTMiBnKJsTir3xLcbq8Mx1y0Cp/DlRQkV+RC4o8USaWA4E3Ib0gbG36KMa2DBIYswFgpxA== ;{id = 36739}
;; ADDITIONAL SECTION:
;; MSG SIZE rcvd: 845
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] debug: msg ttl is 3548, prefetch ttl 3188
Feb 25 07:04:38 raspberrypi unbound[9636]: [9636:0] debug: returning answer from cache.
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: iter_handle processing q with state FINISHED RESPONSE STATE
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: finishing processing for google.com. DS IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: mesh_run: iterator module exit state is module_finished
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: validator[module 1] operate: extstate:module_wait_module event:module_event_moddone
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: validator operate: query google.com. DS IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: validator: nextmodule returned
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: not validating response, is valrec(validation recursion lookup)
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: mesh_run: validator module exit state is module_finished
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: subnet[module 0] operate: extstate:module_wait_module event:module_event_moddone
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: subnet operate: query google.com. DS IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: mesh_run: subnet module exit state is module_finished
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: validator: inform_super, sub is google.com. DS IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: super is google.com. A IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: nsec3: keysize 1280 bits, max iterations 500
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: ce candidate com. TYPE0 CLASS0
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: NSEC3s for the referral proved no DS.
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: validator[module 1] operate: extstate:module_wait_subquery event:module_event_pass
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: validator operate: query google.com. A IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: val handle processing q with state VAL_VALIDATE_STATE
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: Verified that unsigned response is INSECURE
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: val handle processing q with state VAL_FINISHED_STATE
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: mesh_run: validator module exit state is module_finished
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: subnet[module 0] operate: extstate:module_wait_module event:module_event_moddone
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: subnet operate: query google.com. A IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: mesh_run: subnet module exit state is module_finished
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: query took 22.472322 sec
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 1 waiting replies, 7 recursion replies sent, 0 replies dropped, 0 states jostled out
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: average recursion processing time 18.317582 sec
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: histogram of recursion processing times
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: [25%]=7 median[50%]=20.8 [75%]=26.4
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: lower(secs) upper(secs) recursions
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: 2.000000 4.000000 1
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: 4.000000 8.000000 1
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: 16.000000 32.000000 5
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: 0RDd mod2 rep google.com. A IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: cache memory msg=37167 rrset=41815 infra=16157 val=36012 subnet=41372
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: svcd callbacks end
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: close of port 53976
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: close fd 12
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: answer cb
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: Incoming reply id = a983
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: Incoming reply addr = ip4 198.18.1.138 port 53 (len 16)
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: lookup size is 1 entries
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: received udp reply.
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: udp message[55:0] A9838490000100010000000106676F6F676C6503636F6D0000010001C00C00010001000000010004C612001000002904D0000000010000
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: outnet handle udp reply
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: measured roundtrip at 2012 msec
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: svcd callbacks start
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: worker svcd callback for qstate 0x1732ec8
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: mesh_run: start
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: iterator operate: query google.com. A IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: process_response: new external response event
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: scrub for com. NS IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: response for google.com. A IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: reply from <com.> 198.18.1.138#53
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: incoming scrubbed packet: ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0
;; flags: qr aa ra ; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0
;; QUESTION SECTION:
google.com. IN A
;; ANSWER SECTION:
google.com. 1 IN A 198.18.0.16
;; AUTHORITY SECTION:
;; ADDITIONAL SECTION:
;; MSG SIZE rcvd: 44
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: query response was DNSSEC LAME
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: iter_handle processing q with state QUERY TARGETS STATE
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: processQueryTargets: google.com. A IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 3
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: DelegationPoint<com.>: 13 names (7 missing), 6 addrs (4 result, 2 avail) cacheNS
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: j.gtld-servers.net. * A
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: h.gtld-servers.net. * A
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: e.gtld-servers.net. * A
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: f.gtld-servers.net. * A
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: d.gtld-servers.net.
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: i.gtld-servers.net.
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: m.gtld-servers.net. * A
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: a.gtld-servers.net.
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: b.gtld-servers.net.
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: l.gtld-servers.net.
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: g.gtld-servers.net.
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: k.gtld-servers.net. * A
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: c.gtld-servers.net.
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: ip4 198.18.1.135 port 53 (len 16)
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: ip4 198.18.1.146 port 53 (len 16)
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: ip4 198.18.1.147 port 53 (len 16)
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: ip4 198.18.1.134 port 53 (len 16)
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: ip4 198.18.1.138 port 53 (len 16)
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: ip4 198.18.1.143 port 53 (len 16)
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: servselect ip4 198.18.1.146 port 53 (len 16)
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: rtt=3497
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: servselect ip4 198.18.1.135 port 53 (len 16)
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: rtt=11836
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: servselect ip4 198.18.1.138 port 53 (len 16)
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: rtt=5554
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: servselect ip4 198.18.1.147 port 53 (len 16)
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: rtt=5797
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: servselect ip4 198.18.1.134 port 53 (len 16)
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: rtt=7822
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: servselect ip4 198.18.1.143 port 53 (len 16)
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: rtt=7436
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: selrtt 3497
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: sending query: google.com. A IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: sending to target: <com.> 198.18.1.146#53
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: dnssec status: expected
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: EDNS lookup known=1 vs=0
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: serviced query UDP timeout=3497 msec
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: inserted new pending reply id=c7ef
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: opened UDP if=0 port=31056
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: comm point start listening 12
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: mesh_run: iterator module exit state is module_wait_reply
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 1 waiting replies, 7 recursion replies sent, 0 replies dropped, 0 states jostled out
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: average recursion processing time 18.317582 sec
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: histogram of recursion processing times
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: [25%]=7 median[50%]=20.8 [75%]=26.4
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: lower(secs) upper(secs) recursions
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: 2.000000 4.000000 1
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: 4.000000 8.000000 1
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: 16.000000 32.000000 5
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: 0RDd mod2 rep google.com. A IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: cache memory msg=37167 rrset=41815 infra=16157 val=36012 subnet=41372
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: svcd callbacks end
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: close of port 30113
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: close fd 13
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: answer cb
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: Incoming reply id = c7ef
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: Incoming reply addr = ip4 198.18.1.146 port 53 (len 16)
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: lookup size is 1 entries
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: received udp reply.
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: udp message[55:0] C7EF8490000100010000000106676F6F676C6503636F6D0000010001C00C00010001000000010004C612001000002904D0000000010000
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: outnet handle udp reply
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: measured roundtrip at 36 msec
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: svcd callbacks start
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: worker svcd callback for qstate 0x1732ec8
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: mesh_run: start
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: iterator operate: query google.com. A IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: process_response: new external response event
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: scrub for com. NS IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: response for google.com. A IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: reply from <com.> 198.18.1.146#53
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: incoming scrubbed packet: ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0
;; flags: qr aa ra ; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0
;; QUESTION SECTION:
google.com. IN A
;; ANSWER SECTION:
google.com. 1 IN A 198.18.0.16
;; AUTHORITY SECTION:
;; ADDITIONAL SECTION:
;; MSG SIZE rcvd: 44
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: query response was ANSWER
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: iter_handle processing q with state FINISHED RESPONSE STATE
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: finishing processing for google.com. A IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: mesh_run: iterator module exit state is module_finished
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: validator[module 1] operate: extstate:module_wait_module event:module_event_moddone
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: validator operate: query google.com. A IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: validator: nextmodule returned
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: val handle processing q with state VAL_INIT_STATE
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: validator classification positive
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: no signer, using google.com. TYPE0 CLASS0
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: val handle processing q with state VAL_FINDKEY_STATE
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: validator: FindKey google.com. A IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: current keyname com. DNSKEY IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: target keyname google.com. DNSKEY IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: striplab 0
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: next keyname google.com. DNSKEY IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: No DS RRset
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: generate request google.com. DS IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: mesh_run: validator module exit state is module_wait_subquery
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: subnet[module 0] operate: extstate:module_state_initial event:module_event_pass
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: subnet operate: query google.com. DS IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: subnet: pass to next module
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: mesh_run: subnet module exit state is module_wait_module
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_pass
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: validator operate: query google.com. DS IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: validator: pass to next module
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: mesh_run: validator module exit state is module_wait_module
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: iterator[module 2] operate: extstate:module_state_initial event:module_event_pass
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: process_request: new external request event
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: iter_handle processing q with state INIT REQUEST STATE
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: resolving google.com. DS IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: request has dependency depth of 0
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: msg from cache lookup ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0
;; flags: qr ra ; QUERY: 1, ANSWER: 0, AUTHORITY: 6, ADDITIONAL: 0
;; QUESTION SECTION:
google.com. IN DS
;; ANSWER SECTION:
;; AUTHORITY SECTION:
CK0POJMG874LJREF7EFN8430QVIT8BSM.com. 20856 IN NSEC3 1 1 0 - ck0q2d6ni4i7eqh8na30ns61o48ul8g5 NS SOA RRSIG DNSKEY NSEC3PARAM ;{flags: optout}
CK0POJMG874LJREF7EFN8430QVIT8BSM.com. 20856 IN RRSIG NSEC3 8 2 86400 20230303052249 20230224041249 36739 com. rXXhjgHhBHyFnZNsXtNvn2jSCLCInjirm5afZvn+wcu2dIQ/wGP9TAbtZXDgA78A21Bgbtfm04wVemAUSg3dOBWZaPGJqftBUffy9mr8eSFeOfe4cx35PzknJp6BVqUwYGQtogdUu9A7iFldK6AJhFWpeIL194qhtJY6kQMdHRmL3S8kgI5KbxzpzB90bWpetBPxs493GpP/R4pBvH2nsA== ;{id = 36739}
com. 3547 IN SOA a.gtld-servers.net. nstld.verisign-grs.com. 1677306908 1800 900 604800 86400
com. 20856 IN RRSIG SOA 8 1 900 20230304063508 20230225052508 36739 com. tlRS6ij1Co1cm98lbP7Vu5FrQyE10lbTwo6y2lTBM71DAbraUx+hK7zdR9YC5PzedqKXbkVdZA0UJHVjCH1M3NGahSVuCKHyipM05/5MwjGfNxOqQ6P87DmaIkC0pt8TgWBQue9+gRk6iiFuraKnPUj79mTTet6u+u+QsZOOvCNbjV5W0tXX6CWdXQrt3UFonNLmbSJaC4cIP5Rez0K5Eg== ;{id = 36739}
S84BKCIBC38P58340AKVNFN5KR9O59QC.com. 20856 IN NSEC3 1 1 0 - s84buo64gqcvn69rjfuo6lvc7fslunj5 NS DS RRSIG ;{flags: optout}
S84BKCIBC38P58340AKVNFN5KR9O59QC.com. 20856 IN RRSIG NSEC3 8 2 86400 20230304060135 20230225045135 36739 com. cXaYy0la+1W3vD6vMRJqyuTMycvYhTRWUBA2ytY9LPwTzcN6wP1WUp9D9ZtFK5A4aTavzz28nFy53WLCDsWYWr3ogIb5M0BGjZqFZ3oHIwmqgRwhgG+8P/etYTW1TTfDQQXo0mGGc50D1GLzhTMiBnKJsTir3xLcbq8Mx1y0Cp/DlRQkV+RC4o8USaWA4E3Ib0gbG36KMa2DBIYswFgpxA== ;{id = 36739}
;; ADDITIONAL SECTION:
;; MSG SIZE rcvd: 845
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: msg ttl is 3547, prefetch ttl 3187
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: returning answer from cache.
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: iter_handle processing q with state FINISHED RESPONSE STATE
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: finishing processing for google.com. DS IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: mesh_run: iterator module exit state is module_finished
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: validator[module 1] operate: extstate:module_wait_module event:module_event_moddone
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: validator operate: query google.com. DS IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: validator: nextmodule returned
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: not validating response, is valrec(validation recursion lookup)
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: mesh_run: validator module exit state is module_finished
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: subnet[module 0] operate: extstate:module_wait_module event:module_event_moddone
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: subnet operate: query google.com. DS IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: mesh_run: subnet module exit state is module_finished
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: validator: inform_super, sub is google.com. DS IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: super is google.com. A IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: nsec3: keysize 1280 bits, max iterations 500
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: ce candidate com. TYPE0 CLASS0
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: NSEC3s for the referral proved no DS.
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: validator[module 1] operate: extstate:module_wait_subquery event:module_event_pass
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: validator operate: query google.com. A IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: val handle processing q with state VAL_VALIDATE_STATE
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: Verified that unsigned response is INSECURE
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: val handle processing q with state VAL_FINISHED_STATE
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: mesh_run: validator module exit state is module_finished
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: subnet[module 0] operate: extstate:module_wait_module event:module_event_moddone
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: subnet operate: query google.com. A IN
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: mesh_run: subnet module exit state is module_finished
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] debug: query took 20.385447 sec
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: mesh_run: end 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 8 recursion replies sent, 0 replies dropped, 0 states jostled out
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: average recursion processing time 18.576065 sec
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: histogram of recursion processing times
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: [25%]=8 median[50%]=21.3333 [75%]=26.6667
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: lower(secs) upper(secs) recursions
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: 2.000000 4.000000 1
Feb 25 07:04:39 raspberrypi unbound[9636]: [9636:0] info: 4.000000 8.000000 1
Feb 25 07:04:40 raspberrypi unbound[9636]: [9636:0] info: 16.000000 32.000000 6
Feb 25 07:04:40 raspberrypi unbound[9636]: [9636:0] debug: cache memory msg=37167 rrset=41815 infra=16157 val=36012 subnet=41372
Feb 25 07:04:40 raspberrypi unbound[9636]: [9636:0] debug: svcd callbacks end
Feb 25 07:04:40 raspberrypi unbound[9636]: [9636:0] debug: close of port 31056
Feb 25 07:04:40 raspberrypi unbound[9636]: [9636:0] debug: close fd 12