Unbound doesn't work, connection timed out

Please follow the below template, it will help us to help you!

If you are Experiencing issues with a Pi-hole install that has non-standard elements (e.g you are using nginx instead of lighttpd, or there is some other aspect of your install that is customised) - please use the Community Help category.

Expected Behaviour:

I install Pi-hole and then unbound. Unbound works.
Ubuntu 22.04
Raspberry Pi

Actual Behaviour:

Pi-hole works like normal, but Unbound receives the DNS Request (i checked the logs), and simply doesn't respond, like at all.

Debug Token:

https://tricorder.pi-hole.net/BEJg4q17/

Only non-standard change I made was changing verbosity to 3 to try to figure out what on earth was wrong with it. After an entire day of troubleshooting, I am at the end of my rope. HELP.

What's the output of:

dig pi-hole.net @127.0.0.1 -p 5335

Also, let's take a look at your unbound config

sudo grep -v '#\|^$' -R /etc/unbound/unbound.conf*

image
Sorry for being 20 hours late! Here you go.
Edit: Oops! Forgot this,

Your unbound configuration looks normal.

Your dig result suggest that unbound cannot be contacted.
Did you verify that unbound was active at that time, e.g.

sudo systemctl status unbound

And if you run a firewall on your RPi: even though its unlikely that your RPi 's firewall would block localhost traffic, you should check that port 5335 is not blocked.

yeah. about that. alot has happened since the last post. long story short, the entire system disintegrated and now i am trying this whole thing again with raspberry pi os. yoohoo! yay! also no i had no firewall at all. nor any issues related to it. unbound was running perfectly fine. said something aling the lines of "Unbound DNS Server started" or something and then nothing. should i open a new post or just edit this one if raspberry pi os also fails. will reply whatever cryptic error appears straight onto this post. guessing nothing will change.

welp. turns out I was wrong. everything works as intended now. for some reason ubuntu seemed to be the problem? weird. anyway, here u go.
image

it would be nice to know what happened tho. does pi-hole not supposed to work on ubuntu 22.04 or something. as far as i know it couldnt have been the installation. formatted it way too many times.
Edit: wish i got more screenshots.

Below file miss configures unbound to function as a simple regular DNS proxy/forwarder/stub resolver instead of a full blown recursive DNS resolver:

/etc/unbound/unbound.conf.d/resolvconf_resolvers.conf

Ditch that file with below:

sudo rm /etc/unbound/unbound.conf.d/resolvconf_resolvers.conf

And and make above change reboot persistent by hashing out below line (put a hash sign # in front of it):

pi@ph5b:~ $ sudo nano /etc/resolvconf.conf
[..]
#unbound_conf=/etc/unbound/unbound.conf.d/resolvconf_resolvers.conf

And run below to apply:

sudo systemctl restart unbound.service

And check status:

sudo systemctl status unbound.service

Nope, stopped working again. Same error. Tried your command, no dice though. Had to wait for exams to finish, hopefully can respond more.


image

https://tricorder.pi-hole.net/y4Pd501e/

The root problem seems to be that Unbound gives absolutely no response, despite it apparently running and being correctly assigned the port 5335, and there being no firewall.

So, this time I have a plan, I will list all the commands I did on first boot, since I will practically did nothing else except dig pi-hole.net @127.0.0.1 -p 5335 and sudo apt update, sudo apt upgrade etc.

Commands on first (and second and third) boot:

sudo apt update
sudo apt upgrade -y
sudo reboot
sudo curl -sSL https://install.pi-hole.net | bash
curl -sSL https://install.pi-hole.net | sudo PIHOLE_SKIP_OS_CHECK=true bash
sudo apt install unbound
sudo nano /etc/unbound/unbound.conf.d/pi-hole.conf
sudo service unbound restart
dig pi-hole.net @ 127.0.0.1 -p 5335
sudo pihole -a -p
sudo pihole -g
sudo systemctl is-active unbound-resolvconf.service
sudo sed -Ei 's/^unbound_conf=/#unbound_conf=/' /etc/resolvconf.conf
sudo rm /etc/unbound/unbound.conf.d/resolvconf_resolvers.conf
sudo service unbound restart
sudo reboot
sudo rm /etc/unbound/unbound.conf.d/resolvconf_resolvers.conf
sudo nano /etc/resolvconf.conf
sudo systemctl restart unbound.service
sudo systemctl status unbound.service (image above)
dig pi-hole.net @127.0.0.1 -p 5335 (image above)

all the commands i did on the first three boots, no exceptions, unbound gave absolutely no response to any queries whatsoever during the entirety of this and beyond. (why do i feel like im not being very helpful to you all)
I also promise to not format the entire drive again throughout the entirety of this thread.

Are you sure that file didnt return?

cat /etc/unbound/unbound.conf.d/resolvconf_resolvers.conf

Whats configured for local DNS?

cat /etc/resolv.conf

Check the journals for errors/warnings (might need sudo or root powers):

journalctl --full --no-pager -S today -u unbound.service

Notice I filter the journals to only show those of -S today !
Check man page for syntax eg:

pi@ph5b:~ $ man journalctl
[..]
       -S, --since=, -U, --until=
           Start showing entries on or newer than the specified date, or
           on or older than the specified date, respectively.
[..]

And please copy/paste text output to here instead of screenshots?
You can format the output here with the </> button before posting like I did above ^
Is easier to process eg copy/paste/quote, and easier to find for others with similar problems.

I am very sure that file didn't return.

cat: /etc/unbound/unbound.conf.d/resolvconf_resolvers.conf: No such file or directory

I am reduced to using cloudflare, for now

# Generated by resolvconf
nameserver 1.1.1.1
nameserver 1.0.0.1

For the journal, I managed to crash my browser instantly by copying the journal (verbosity was set to three, suprise suprise), before realizing there was a word limit

Jun 20 13:55:44 raspberrypi systemd[1]: Starting Unbound DNS server...
Jun 20 13:55:44 raspberrypi unbound[558]: [558:0] info: start of service (unbound 1.13.1).
Jun 20 13:55:44 raspberrypi systemd[1]: Started Unbound DNS server.

Is this all there is when things go south? (EDIT: with verbosity set to 3?)
If so, increase verbosity to get more details?

pi@ph5b:~ $ man unbound.conf
[..]
       verbosity: <number>
              The verbosity number, level 0 means no verbosity,  only  er‐
              rors.  Level  1 gives operational information. Level 2 gives
              detailed operational information. Level 3 gives query  level
              information,  output  per  query.   Level  4 gives algorithm
              level information.  Level 5 logs client  identification  for
              cache  misses.   Default is level 1.  The verbosity can also
              be increased from the commandline, see unbound(8).
pi@ph5b:~ $ sudo nano /etc/unbound/unbound.conf.d/pi-hole.conf
[..]
    verbosity: 0

Run below to apply:

sudo systemctl reload unbound.service

Can run below to follow the unbound journals live:

journalctl --full -f -u unbound.service

Dont forget to set back verbosity to zero when done bc this takes up disk space if run for too long!

I think I have enough disk space (for now), especially given that I had it set to verbosity 3, sometimes 5 for a month before this.

Also, Yes, this is literally all there is when things go south. It says started, earlier attempts even said that unbound got the requests, but there was no response from unbound, at all. but this time i set verbosity to 0 because of above mentioned reason. I did try to again send the journal with verbosity 3, but this happened
image
Welp, looks like i have to do with images, sorry! ...is what i would have said if i didn't run into two problems:

  1. the journal is stupidly long, couldn't even scroll to the end, --no-pager seems to keep the beginning parts out, and accessing it normally leads to an unscrollably long journal.

image

so, i am going to close my eyes and hope for the best...
and maybe also spam the last 5000 words of the journal (i don't know if this counts but i did dig google.com @127.0.0.1 -p 5335, dig www.google.com @127.0.0.1 -p 5335, dig pi-hole.net @127.0.0.1 -p 5335 right before copying this journal)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: ip4 199.7.91.13 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: ip4 192.203.230.10 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: ip4 192.5.5.241 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: ip4 192.112.36.4 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: ip4 198.97.190.53 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: ip4 192.36.148.17 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: ip4 192.58.128.30 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: ip4 193.0.14.129 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: ip4 199.7.83.42 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: ip4 202.12.27.33 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: servselect ip4 192.112.36.4 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: servselect ip4 192.5.5.241 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: servselect ip4 192.36.148.17 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: servselect ip4 202.12.27.33 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: servselect ip4 199.9.14.201 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: servselect ip4 193.0.14.129 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: rtt=3008

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: servselect ip4 199.7.83.42 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: servselect ip4 192.58.128.30 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: servselect ip4 198.41.0.4 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: servselect ip4 192.33.4.12 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: servselect ip4 192.203.230.10 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: rtt=3008

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: servselect ip4 198.97.190.53 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: rtt=3008

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: servselect ip4 199.7.91.13 port 53 (len 16)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: rtt=3008

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: selrtt 1504

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] info: sending query: . NS IN

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: sending to target: <.> 192.36.148.17#53

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: dnssec status: expected

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: EDNS lookup known=0 vs=0

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: serviced query UDP timeout=1504 msec

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: inserted new pending reply id=1d62

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: opened UDP if=0 port=33512

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: comm point start listening 12 (-1 msec)

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: mesh_run: iterator module exit state is module_wait_reply

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] info: mesh_run: end 6 recursion states (5 with reply, 0 detached), 5 waiting replies, 0 recursion replies sent, 0 replies dropped, 0 states jostled out

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] info: 0pvCD mod2 . NS IN

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] info: 1RDdc mod2 rep google.com. A IN

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] info: 2RDdc mod2 rep google.com. A IN

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] info: 3RDdc mod2 rep google.com. A IN

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] info: 4RDdc mod2 rep www.google.com. A IN

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] info: 5RDdc mod2 rep pi-hole.net. A IN

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: cache memory msg=66072 rrset=66072 infra=11669 val=66368 subnet=74504

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: svcd callbacks end

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: serviced_delete

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: close of port 18402

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: comm_point_close of 13: event_del

Jun 21 13:49:40 raspberrypi unbound[560]: [560:0] debug: close fd 13

Jun 21 13:49:42 raspberrypi unbound[560]: [560:0] debug: timeout udp

Jun 21 13:49:42 raspberrypi unbound[560]: [560:0] debug: try edns1xx0 <.> 192.36.148.17#53

Jun 21 13:49:42 raspberrypi unbound[560]: [560:0] debug: EDNS lookup known=0 vs=0

Jun 21 13:49:42 raspberrypi unbound[560]: [560:0] debug: serviced query UDP timeout=1504 msec

Jun 21 13:49:42 raspberrypi unbound[560]: [560:0] debug: inserted new pending reply id=8702

Jun 21 13:49:42 raspberrypi unbound[560]: [560:0] debug: opened UDP if=0 port=31594

Jun 21 13:49:42 raspberrypi unbound[560]: [560:0] debug: comm point start listening 13 (-1 msec)

Jun 21 13:49:42 raspberrypi unbound[560]: [560:0] debug: close of port 33512

Jun 21 13:49:42 raspberrypi unbound[560]: [560:0] debug: comm_point_close of 12: event_del

Jun 21 13:49:42 raspberrypi unbound[560]: [560:0] debug: close fd 12

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: timeout udp

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: svcd callbacks start

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: worker svcd callback for qstate 0x55876956b0

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: mesh_run: start

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: iterator operate: query . NS IN

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: process_response: new external response event

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: iter_handle processing q with state QUERY RESPONSE STATE

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: query response was timeout

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: iter_handle processing q with state QUERY TARGETS STATE

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: processQueryTargets: . NS IN

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 31

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: DelegationPoint<.>: 13 names (0 missing), 13 addrs (13 result, 0 avail) parentNS

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: A.ROOT-SERVERS.NET. * A

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: B.ROOT-SERVERS.NET. * A

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: C.ROOT-SERVERS.NET. * A

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: D.ROOT-SERVERS.NET. * A

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: E.ROOT-SERVERS.NET. * A

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: F.ROOT-SERVERS.NET. * A

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: G.ROOT-SERVERS.NET. * A

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: H.ROOT-SERVERS.NET. * A

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: I.ROOT-SERVERS.NET. * A

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: J.ROOT-SERVERS.NET. * A

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: K.ROOT-SERVERS.NET. * A

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: L.ROOT-SERVERS.NET. * A

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: M.ROOT-SERVERS.NET. * A

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: ip4 198.41.0.4 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: ip4 199.9.14.201 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: ip4 192.33.4.12 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: ip4 199.7.91.13 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: ip4 192.203.230.10 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: ip4 192.5.5.241 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: ip4 192.112.36.4 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: ip4 198.97.190.53 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: ip4 192.36.148.17 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: ip4 192.58.128.30 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: ip4 193.0.14.129 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: ip4 199.7.83.42 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: ip4 202.12.27.33 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: servselect ip4 192.33.4.12 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: servselect ip4 198.41.0.4 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: servselect ip4 192.58.128.30 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: servselect ip4 199.7.83.42 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: servselect ip4 199.9.14.201 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: servselect ip4 202.12.27.33 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: servselect ip4 192.36.148.17 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: rtt=3008

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: servselect ip4 192.5.5.241 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: servselect ip4 192.112.36.4 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: servselect ip4 193.0.14.129 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: rtt=3008

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: servselect ip4 192.203.230.10 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: rtt=3008

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: servselect ip4 198.97.190.53 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: rtt=3008

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: servselect ip4 199.7.91.13 port 53 (len 16)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: rtt=3008

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: selrtt 1504

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: sending query: . NS IN

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: sending to target: <.> 192.58.128.30#53

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: dnssec status: expected

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: EDNS lookup known=0 vs=0

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: serviced query UDP timeout=1504 msec

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: inserted new pending reply id=59e6

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: opened UDP if=0 port=35163

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: comm point start listening 12 (-1 msec)

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: mesh_run: iterator module exit state is module_wait_reply

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: mesh_run: end 6 recursion states (5 with reply, 0 detached), 5 waiting replies, 0 recursion replies sent, 0 replies dropped, 0 states jostled out

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: 0pvCD mod2 . NS IN

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: 1RDdc mod2 rep google.com. A IN

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: 2RDdc mod2 rep google.com. A IN

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: 3RDdc mod2 rep google.com. A IN

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: 4RDdc mod2 rep www.google.com. A IN

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] info: 5RDdc mod2 rep pi-hole.net. A IN

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: cache memory msg=66072 rrset=66072 infra=11669 val=66368 subnet=74504

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: svcd callbacks end

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: serviced_delete

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: close of port 31594

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: comm_point_close of 13: event_del

Jun 21 13:49:43 raspberrypi unbound[560]: [560:0] debug: close fd 13

Jun 21 13:49:45 raspberrypi unbound[560]: [560:0] debug: timeout udp

Jun 21 13:49:45 raspberrypi unbound[560]: [560:0] debug: try edns1xx0 <.> 192.58.128.30#53

Jun 21 13:49:45 raspberrypi unbound[560]: [560:0] debug: EDNS lookup known=0 vs=0

Jun 21 13:49:45 raspberrypi unbound[560]: [560:0] debug: serviced query UDP timeout=1504 msec

Jun 21 13:49:45 raspberrypi unbound[560]: [560:0] debug: inserted new pending reply id=fb63

Jun 21 13:49:45 raspberrypi unbound[560]: [560:0] debug: opened UDP if=0 port=65442

Jun 21 13:49:45 raspberrypi unbound[560]: [560:0] debug: comm point start listening 13 (-1 msec)

Jun 21 13:49:45 raspberrypi unbound[560]: [560:0] debug: close of port 35163

Jun 21 13:49:45 raspberrypi unbound[560]: [560:0] debug: comm_point_close of 12: event_del

Jun 21 13:49:45 raspberrypi unbound[560]: [560:0] debug: close fd 12

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: timeout udp

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: svcd callbacks start

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: worker svcd callback for qstate 0x55876956b0

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: mesh_run: start

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: iterator operate: query . NS IN

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: process_response: new external response event

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: iter_handle processing q with state QUERY RESPONSE STATE

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: query response was timeout

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: iter_handle processing q with state QUERY TARGETS STATE

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: processQueryTargets: . NS IN

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 32

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: DelegationPoint<.>: 13 names (0 missing), 13 addrs (13 result, 0 avail) parentNS

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: A.ROOT-SERVERS.NET. * A

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: B.ROOT-SERVERS.NET. * A

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: C.ROOT-SERVERS.NET. * A

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: D.ROOT-SERVERS.NET. * A

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: E.ROOT-SERVERS.NET. * A

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: F.ROOT-SERVERS.NET. * A

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: G.ROOT-SERVERS.NET. * A

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: H.ROOT-SERVERS.NET. * A

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: I.ROOT-SERVERS.NET. * A

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: J.ROOT-SERVERS.NET. * A

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: K.ROOT-SERVERS.NET. * A

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: L.ROOT-SERVERS.NET. * A

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: M.ROOT-SERVERS.NET. * A

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: ip4 198.41.0.4 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: ip4 199.9.14.201 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: ip4 192.33.4.12 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: ip4 199.7.91.13 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: ip4 192.203.230.10 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: ip4 192.5.5.241 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: ip4 192.112.36.4 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: ip4 198.97.190.53 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: ip4 192.36.148.17 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: ip4 192.58.128.30 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: ip4 193.0.14.129 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: ip4 199.7.83.42 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: ip4 202.12.27.33 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: servselect ip4 192.112.36.4 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: servselect ip4 192.5.5.241 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: servselect ip4 202.12.27.33 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: servselect ip4 199.9.14.201 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: servselect ip4 199.7.83.42 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: servselect ip4 192.58.128.30 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: rtt=3008

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: servselect ip4 198.41.0.4 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: servselect ip4 192.33.4.12 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: rtt=1504

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: servselect ip4 192.36.148.17 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: rtt=3008

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: servselect ip4 193.0.14.129 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: rtt=3008

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: servselect ip4 192.203.230.10 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: rtt=3008

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: servselect ip4 198.97.190.53 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: rtt=3008

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: servselect ip4 199.7.91.13 port 53 (len 16)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: rtt=3008

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: selrtt 1504

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: sending query: . NS IN

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: sending to target: <.> 202.12.27.33#53

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: dnssec status: expected

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: EDNS lookup known=0 vs=0

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: serviced query UDP timeout=1504 msec

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: inserted new pending reply id=3cc3

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: opened UDP if=0 port=7187

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: comm point start listening 12 (-1 msec)

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: mesh_run: iterator module exit state is module_wait_reply

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: mesh_run: end 6 recursion states (5 with reply, 0 detached), 5 waiting replies, 0 recursion replies sent, 0 replies dropped, 0 states jostled out

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: 0pvCD mod2 . NS IN

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: 1RDdc mod2 rep google.com. A IN

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: 2RDdc mod2 rep google.com. A IN

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: 3RDdc mod2 rep google.com. A IN

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: 4RDdc mod2 rep www.google.com. A IN

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] info: 5RDdc mod2 rep pi-hole.net. A IN

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: cache memory msg=66072 rrset=66072 infra=11669 val=66368 subnet=74504

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: svcd callbacks end

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: serviced_delete

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: close of port 65442

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: comm_point_close of 13: event_del

Jun 21 13:49:46 raspberrypi unbound[560]: [560:0] debug: close fd 13

Jun 21 13:49:48 raspberrypi unbound[560]: [560:0] debug: timeout udp

Jun 21 13:49:48 raspberrypi unbound[560]: [560:0] debug: try edns1xx0 <.> 202.12.27.33#53

Jun 21 13:49:48 raspberrypi unbound[560]: [560:0] debug: EDNS lookup known=0 vs=0

Jun 21 13:49:48 raspberrypi unbound[560]: [560:0] debug: serviced query UDP timeout=1504 msec

Jun 21 13:49:48 raspberrypi unbound[560]: [560:0] debug: inserted new pending reply id=ffeb

Jun 21 13:49:48 raspberrypi unbound[560]: [560:0] debug: opened UDP if=0 port=31006

Jun 21 13:49:48 raspberrypi unbound[560]: [560:0] debug: comm point start listening 13 (-1 msec)

Jun 21 13:49:48 raspberrypi unbound[560]: [560:0] debug: close of port 7187

Jun 21 13:49:48 raspberrypi unbound[560]: [560:0] debug: comm_point_close of 12: event_del

Jun 21 13:49:48 raspberrypi unbound[560]: [560:0] debug: close fd 12

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: timeout udp

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: svcd callbacks start

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: worker svcd callback for qstate 0x55876956b0

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: mesh_run: start

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: iterator operate: query . NS IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: process_response: new external response event

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: iter_handle processing q with state QUERY RESPONSE STATE

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: query response was timeout

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: iter_handle processing q with state QUERY TARGETS STATE

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: processQueryTargets: . NS IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 33

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: request has exceeded the maximum number of sends with 33

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: return error response SERVFAIL

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: mesh_run: iterator module exit state is module_finished

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_moddone

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: validator operate: query . NS IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: validator: nextmodule returned

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: not validating response, is valrec(validation recursion lookup)

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: mesh_run: validator module exit state is module_finished

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: subnet[module 0] operate: extstate:module_state_initial event:module_event_moddone

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: subnet operate: query . NS IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: mesh_run: subnet module exit state is module_finished

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: iterator[module 2] operate: extstate:module_wait_subquery event:module_event_pass

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: iterator operate: query google.com. A IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: iter_handle processing q with state QUERY TARGETS STATE

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: processQueryTargets: google.com. A IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: Failed to get a delegation, giving up

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: return error response SERVFAIL

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: mesh_run: iterator module exit state is module_finished

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: validator[module 1] operate: extstate:module_wait_module event:module_event_moddone

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: validator operate: query google.com. A IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: validator: nextmodule returned

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: cannot validate non-answer, rcode SERVFAIL

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: mesh_run: validator module exit state is module_finished

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: subnet[module 0] operate: extstate:module_wait_module event:module_event_moddone

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: subnet operate: query google.com. A IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: mesh_run: subnet module exit state is module_finished

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: query took 44.992892 sec

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: iterator[module 2] operate: extstate:module_wait_subquery event:module_event_pass

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: iterator operate: query google.com. A IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: iter_handle processing q with state QUERY TARGETS STATE

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: processQueryTargets: google.com. A IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: Failed to get a delegation, giving up

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: return error response SERVFAIL

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: mesh_run: iterator module exit state is module_finished

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: validator[module 1] operate: extstate:module_wait_module event:module_event_moddone

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: validator operate: query google.com. A IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: validator: nextmodule returned

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: cannot validate non-answer, rcode SERVFAIL

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: mesh_run: validator module exit state is module_finished

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: subnet[module 0] operate: extstate:module_wait_module event:module_event_moddone

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: subnet operate: query google.com. A IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: mesh_run: subnet module exit state is module_finished

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: query took 44.992892 sec

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: iterator[module 2] operate: extstate:module_wait_subquery event:module_event_pass

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: iterator operate: query www.google.com. A IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: iter_handle processing q with state QUERY TARGETS STATE

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: processQueryTargets: www.google.com. A IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: Failed to get a delegation, giving up

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: return error response SERVFAIL

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: mesh_run: iterator module exit state is module_finished

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: validator[module 1] operate: extstate:module_wait_module event:module_event_moddone

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: validator operate: query www.google.com. A IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: validator: nextmodule returned

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: cannot validate non-answer, rcode SERVFAIL

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: mesh_run: validator module exit state is module_finished

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: subnet[module 0] operate: extstate:module_wait_module event:module_event_moddone

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: subnet operate: query www.google.com. A IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: mesh_run: subnet module exit state is module_finished

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: query took 44.992892 sec

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: iterator[module 2] operate: extstate:module_wait_subquery event:module_event_pass

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: iterator operate: query pi-hole.net. A IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: iter_handle processing q with state QUERY TARGETS STATE

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: processQueryTargets: pi-hole.net. A IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: Failed to get a delegation, giving up

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: return error response SERVFAIL

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: mesh_run: iterator module exit state is module_finished

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: validator[module 1] operate: extstate:module_wait_module event:module_event_moddone

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: validator operate: query pi-hole.net. A IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: validator: nextmodule returned

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: cannot validate non-answer, rcode SERVFAIL

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: mesh_run: validator module exit state is module_finished

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: subnet[module 0] operate: extstate:module_wait_module event:module_event_moddone

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: subnet operate: query pi-hole.net. A IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: mesh_run: subnet module exit state is module_finished

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: query took 110.094140 sec

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: iterator[module 2] operate: extstate:module_wait_subquery event:module_event_pass

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: iterator operate: query google.com. A IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: iter_handle processing q with state QUERY TARGETS STATE

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: processQueryTargets: google.com. A IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: Failed to get a delegation, giving up

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: return error response SERVFAIL

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: mesh_run: iterator module exit state is module_finished

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: validator[module 1] operate: extstate:module_wait_module event:module_event_moddone

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: validator operate: query google.com. A IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: validator: nextmodule returned

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: cannot validate non-answer, rcode SERVFAIL

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: mesh_run: validator module exit state is module_finished

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: subnet[module 0] operate: extstate:module_wait_module event:module_event_moddone

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: subnet operate: query google.com. A IN

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: mesh_run: subnet module exit state is module_finished

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: query took 44.992892 sec

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: mesh_run: end 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 5 recursion replies sent, 0 replies dropped, 0 states jostled out

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: average recursion processing time 58.013141 sec

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: histogram of recursion processing times

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: [25%]=42 median[50%]=52 [75%]=62

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: lower(secs) upper(secs) recursions

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: 32.000000 64.000000 4

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] info: 64.000000 128.000000 1

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: cache memory msg=66072 rrset=66072 infra=11669 val=66368 subnet=74504

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: svcd callbacks end

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: serviced_delete

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: close of port 31006

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: comm_point_close of 13: event_del

Jun 21 13:49:49 raspberrypi unbound[560]: [560:0] debug: close fd 13

also the first 313 lines of journal





From the screenshots (the red lines) you can see unbound is having troubles communicating with below essential DNS root servers:

pi@ph5b:~ $ dig +short -x 199.9.14.201
b.root-servers.net.
pi@ph5b:~ $ dig +short -x 192.33.4.12
c.root-servers.net.
pi@ph5b:~ $ dig +short ns .
j.root-servers.net.
a.root-servers.net.
c.root-servers.net.
d.root-servers.net.
i.root-servers.net.
l.root-servers.net.
g.root-servers.net.
b.root-servers.net.
h.root-servers.net.
m.root-servers.net.
e.root-servers.net.
f.root-servers.net.
k.root-servers.net.

This could indicate that there is something going wrong on the path to those root servers (eg UDP packet size), or some DNS filtering going on upstream (maybe your ISP).
Check your router for DNS related security settings like filters or redirecting DNS!
For both above problems, you should ask your ISP for support!

When things go south, do you get below same similar reply?

pi@ph5b:~ $ dig +norecurse @199.9.14.201 ns .

; <<>> DiG 9.16.22-Raspbian <<>> +norecurse @199.9.14.201 ns .
; (1 server found)
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 27200
;; flags: qr aa; QUERY: 1, ANSWER: 13, AUTHORITY: 0, ADDITIONAL: 27

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 1232
; COOKIE: 6baf8941e3ec25050100000064936dc71d89cb79224f3b55 (good)
;; QUESTION SECTION:
;.                              IN      NS

;; ANSWER SECTION:
.                       518400  IN      NS      i.root-servers.net.
.                       518400  IN      NS      k.root-servers.net.
.                       518400  IN      NS      a.root-servers.net.
.                       518400  IN      NS      c.root-servers.net.
.                       518400  IN      NS      b.root-servers.net.
.                       518400  IN      NS      e.root-servers.net.
.                       518400  IN      NS      j.root-servers.net.
.                       518400  IN      NS      f.root-servers.net.
.                       518400  IN      NS      d.root-servers.net.
.                       518400  IN      NS      h.root-servers.net.
.                       518400  IN      NS      g.root-servers.net.
.                       518400  IN      NS      m.root-servers.net.
.                       518400  IN      NS      l.root-servers.net.

;; ADDITIONAL SECTION:
m.root-servers.net.     518400  IN      A       202.12.27.33
l.root-servers.net.     518400  IN      A       199.7.83.42
k.root-servers.net.     518400  IN      A       193.0.14.129
j.root-servers.net.     518400  IN      A       192.58.128.30
i.root-servers.net.     518400  IN      A       192.36.148.17
h.root-servers.net.     518400  IN      A       198.97.190.53
g.root-servers.net.     518400  IN      A       192.112.36.4
f.root-servers.net.     518400  IN      A       192.5.5.241
e.root-servers.net.     518400  IN      A       192.203.230.10
d.root-servers.net.     518400  IN      A       199.7.91.13
c.root-servers.net.     518400  IN      A       192.33.4.12
b.root-servers.net.     518400  IN      A       199.9.14.201
a.root-servers.net.     518400  IN      A       198.41.0.4
m.root-servers.net.     518400  IN      AAAA    2001:dc3::35
l.root-servers.net.     518400  IN      AAAA    2001:500:9f::42
k.root-servers.net.     518400  IN      AAAA    2001:7fd::1
j.root-servers.net.     518400  IN      AAAA    2001:503:c27::2:30
i.root-servers.net.     518400  IN      AAAA    2001:7fe::53
h.root-servers.net.     518400  IN      AAAA    2001:500:1::53
g.root-servers.net.     518400  IN      AAAA    2001:500:12::d0d
f.root-servers.net.     518400  IN      AAAA    2001:500:2f::f
e.root-servers.net.     518400  IN      AAAA    2001:500:a8::e
d.root-servers.net.     518400  IN      AAAA    2001:500:2d::d
c.root-servers.net.     518400  IN      AAAA    2001:500:2::c
b.root-servers.net.     518400  IN      AAAA    2001:500:200::b
a.root-servers.net.     518400  IN      AAAA    2001:503:ba3e::2:30

;; Query time: 9 msec
;; SERVER: 199.9.14.201#53(199.9.14.201)
;; WHEN: Wed Jun 21 23:38:15 CEST 2023
;; MSG SIZE  rcvd: 851

Or alternatively on a Windows/MacOS/Linux client of yours:

C:\>nslookup -type=ns . 199.9.14.201
in-addr.arpa    nameserver = c.in-addr-servers.arpa
in-addr.arpa    nameserver = a.in-addr-servers.arpa
in-addr.arpa    nameserver = b.in-addr-servers.arpa
in-addr.arpa    nameserver = f.in-addr-servers.arpa
in-addr.arpa    nameserver = e.in-addr-servers.arpa
in-addr.arpa    nameserver = d.in-addr-servers.arpa
f.in-addr-servers.arpa  internet address = 193.0.9.1
e.in-addr-servers.arpa  internet address = 203.119.86.101
d.in-addr-servers.arpa  internet address = 200.10.60.53
c.in-addr-servers.arpa  internet address = 196.216.169.10
b.in-addr-servers.arpa  internet address = 199.253.183.183
a.in-addr-servers.arpa  internet address = 199.180.182.53
f.in-addr-servers.arpa  AAAA IPv6 address = 2001:67c:e0::1
e.in-addr-servers.arpa  AAAA IPv6 address = 2001:dd8:6::101
d.in-addr-servers.arpa  AAAA IPv6 address = 2001:13c7:7010::53
c.in-addr-servers.arpa  AAAA IPv6 address = 2001:43f8:110::10
b.in-addr-servers.arpa  AAAA IPv6 address = 2001:500:87::87
a.in-addr-servers.arpa  AAAA IPv6 address = 2620:37:e000::53
Server:  UnKnown
Address:  199.9.14.201

(root)  nameserver = a.root-servers.net
(root)  nameserver = b.root-servers.net
(root)  nameserver = c.root-servers.net
(root)  nameserver = j.root-servers.net
(root)  nameserver = h.root-servers.net
(root)  nameserver = f.root-servers.net
(root)  nameserver = g.root-servers.net
(root)  nameserver = e.root-servers.net
(root)  nameserver = d.root-servers.net
(root)  nameserver = i.root-servers.net
(root)  nameserver = k.root-servers.net
(root)  nameserver = l.root-servers.net
(root)  nameserver = m.root-servers.net
m.root-servers.net      internet address = 202.12.27.33
l.root-servers.net      internet address = 199.7.83.42
k.root-servers.net      internet address = 193.0.14.129
j.root-servers.net      internet address = 192.58.128.30
i.root-servers.net      internet address = 192.36.148.17
h.root-servers.net      internet address = 198.97.190.53
g.root-servers.net      internet address = 192.112.36.4
f.root-servers.net      internet address = 192.5.5.241
e.root-servers.net      internet address = 192.203.230.10
d.root-servers.net      internet address = 199.7.91.13
c.root-servers.net      internet address = 192.33.4.12
b.root-servers.net      internet address = 199.9.14.201
a.root-servers.net      internet address = 198.41.0.4
m.root-servers.net      AAAA IPv6 address = 2001:dc3::35
l.root-servers.net      AAAA IPv6 address = 2001:500:9f::42

If not, you could include above findings when creating a support case at your ISP.

Ow what are your stats by the way?

nc localhost 4711 <<< '>stats >quit'

nc localhost 4711 <<< '>top-domains >quit'

Maybe you're getting rate limited upstream somehow.

Maybe I should have said the entire story, but when i opened this post I was way too stressed to say anything. So I am going to take a long detour (i promise to circle back) and start from the beggining:

A few days before before this debacle, everything was normal and happy (mostly) and we used all Pi-hole all the time. But then we saw something like this:

image
[copied from google cuz i didn't take screenshot]

We tried many things, but were unable to fix this issue... before Ubuntu 22.04 died (anti-climactic if you ask me). I reinstalled Ubuntu, and Good news! Pi-hole is back up and running but at the expense of Unbound not responding to anything, no errors , no answer to queries, no nothing.

I set verbosity to 3 (or 5, i forgot, but later i set it to 3). i did dig google.com @127.0.0.1 -p 5335 and checked the journal and it said somthing about query and google.com. at this point, i felt pretty sure that unbound was receiving queries and just not responding to them. and so i went searching from forum to forum for answers, reinstalled ubuntu a bunch of times, none of their solutions fixed my issue, and then...

you know what happens next. in fact, with the exception of

one single day of actually working, unbound returned to it's old ways. finally my father had enough of not being able to do anything, changed the dns, and my exams finished,

giving me a whole another chance to crack this mystery, and here we are now.

hopefully that should clear things, but i went to this whole detour to prove a point and that is that...

unbound has and had no uptime, throughout almost the entirety of this post.

i for some reason thought that you are assuming that unbound works for a few seconds after boot (i saw that in a few forum posts i think). if you were hopefully this should clear things and if not...

now that we are back from the long detour (forgive me on that one please), about this...

no. i did block those servers on my pi-hole once though, but that installation has been wiped already so that can't be it.

dig +norecurse @199.9.14.201 ns

; <<>> DiG 9.16.37-Debian <<>> +norecurse @199.9.14.201 ns
; (1 server found)
;; global options: +cmd
;; connection timed out; no servers could be reached
C:\>nslookup -type=ns . 199.9.14.201
DNS request timed out.
    timeout was 2 seconds.
Server:  UnKnown
Address:  199.9.14.201

DNS request timed out.
    timeout was 2 seconds.
*** Request to UnKnown timed-out

My router doesn't have dns related security settings like filters or redirecting dns and it's the same router and same configuration that served well with pi-hole for many years, so no issues there.

and from what i can tell, firstly no they won't help, and secondly that would actually explain a lot.

Is there any way to cirumvent isp filtering my dns, cause that would help if it were to be the case

3 subs and 59 views :frowning: ... oh wait sorry i meant

masadat@raspberrypi:~ $ nc localhost 4711 <<< '>stats >quit'
domains_being_blocked 327563
dns_queries_today 176
ads_blocked_today 0
ads_percentage_today 0.000000
unique_domains 13
queries_forwarded 155
queries_cached 21
clients_ever_seen 2
unique_clients 2
dns_queries_all_types 176
reply_UNKNOWN 34
reply_NODATA 38
reply_NXDOMAIN 0
reply_CNAME 0
reply_IP 0
reply_DOMAIN 56
reply_RRNAME 0
reply_SERVFAIL 0
reply_REFUSED 0
reply_NOTIMP 0
reply_OTHER 0
reply_DNSSEC 48
reply_NONE 0
reply_BLOB 0
dns_queries_all_replies 176
privacy_level 0
status enabled
masadat@raspberrypi:~ $ nc localhost 4711 <<< '>top-domains >quit'
0 39 1.0.0.1.in-addr.arpa
1 35 8.8.8.8.in-addr.arpa
2 25 1.in-addr.arpa
3 17 in-addr.arpa
4 17 0.1.in-addr.arpa
5 17 0.0.1.in-addr.arpa
6 12 8.in-addr.arpa
7 6 arpa
8 5 8.8.in-addr.arpa
9 3 .

There are not enough stats collected yet for proper diagnosing.
But I believe thats not relevant bc of below.

Above query is missing the dot "." at the end (the dot represents the root of DNS):

But as the nslookup command isn't able to connect either, I believe it also doesnt matter.

The way things work, remember those root.hints from the guide?

pi@ph5b:~ $ cat /usr/share/dns/root.hints
;       This file holds the information on root name servers needed to
;       initialize cache of Internet domain name servers
;       (e.g. reference this file in the "cache  .  <file>"
;       configuration file of BIND domain name servers).
[..]
B.ROOT-SERVERS.NET.      3600000      A     199.9.14.201
[..]
C.ROOT-SERVERS.NET.      3600000      A     192.33.4.12

When unbound starts, it loads all those hints in cache.
And first thing it does when receiving a query from a client is to update those root servers in cache similar like below:

pi@ph5b:~ $ dig +norecurse @199.9.14.201 ns .
[..]
;; ANSWER SECTION:
.                       518400  IN      NS      b.root-servers.net.
.                       518400  IN      NS      c.root-servers.net.
[..]
;; ADDITIONAL SECTION:
[..]
c.root-servers.net.     518400  IN      A       192.33.4.12
b.root-servers.net.     518400  IN      A       199.9.14.201
[..]

Without this connectivity, there is no way to get unbound working as a recursive DNS resolver.
unbound might have worked for you in the past, but that could have been bc of that unwanted config file:

As mentioned, this file configures unbound as a stub resolver instead of a recursive resolver and that works differently without any root.hints.
EDIT: FYI, the pihole-FTL daemon also functions as a stub resolver.

Yes if you run those DNS queries through a commercial VPN tunnel.

Ow out of curiosity, what reply do you get with below?

pi@ph5b:~ $ dig +norecurse @9.9.9.9 version.bind chaos txt
[..]
;; ANSWER SECTION:
version.bind.           0       CH      TXT     "Q9-U-7.6"

EDIT: Ow FYI:

pi@ph5b:~ $ whois 9.9.9.9
[..]
OrgName:        Quad9
[..]
Comment:        https://quad9.net/
Comment:        Global Public Recursive DNS Resolver Service

Yep, feared something like that.

But it also doesn't work if i have the file, so... what now?

oopsie

masadat@raspberrypi:~ $ dig +norecurse @9.9.9.9 version.bind chaos txt

; <<>> DiG 9.16.37-Debian <<>> +norecurse @9.9.9.9 version.bind chaos txt
; (1 server found)
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 52167
;; flags: qr ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 1232
;; QUESTION SECTION:
;version.bind.                  CH      TXT

;; ANSWER SECTION:
version.bind.           0       CH      TXT     "Q9-U-7.6"

;; Query time: 3 msec
;; SERVER: 9.9.9.9#53(9.9.9.9)
;; WHEN: Fri Jun 23 05:28:17 BST 2023
;; MSG SIZE  rcvd: 62

also i dont have whois command installed

masadat@raspberrypi:~ $ whois 9.9.9.9
-bash: whois: command not found