PiHole and Unbound won't resolve certain sites

Expected Behaviour:

The site https://nextcloudpi.com/ should resolve and show the page.

OS = W10
Browser = Firefox

Actual Behaviour:

When navigating to the site I get "Hmm. We’re having trouble finding that site.".

Query Log shows SERVFAIL when navigating to the site.

Using Mobile Data fixes the issue, so I would assume its something to do with my PiHole and Unbound setup.

Debug Token:

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

From the Pi terminal, what are the outputs of the following commands:

nslookup nextcloudpi.com 127.0.0.1

nslookup nextcloudpi.com 1.0.0.1

sudo grep nextcloud /var/log/pihole/pihole.log | tail -n15

Server: 127.0.0.1
Address: 127.0.0.1#53

Non-authoritative answer:
nextcloudpi.com canonical name = nextcloud.github.io.
Name: nextcloud.github.io
Address: 185.199.109.153
Name: nextcloud.github.io
Address: 185.199.108.153
Name: nextcloud.github.io
Address: 185.199.111.153
Name: nextcloud.github.io
Address: 185.199.110.153
Name: nextcloud.github.io
Address: 2606:50c0:8002::153
Name: nextcloud.github.io
Address: 2606:50c0:8001::153
Name: nextcloud.github.io
Address: 2606:50c0:8003::153
Name: nextcloud.github.io
Address: 2606:50c0:8000::153

Server: 1.0.0.1
Address: 1.0.0.1#53

Non-authoritative answer:
nextcloudpi.com canonical name = nextcloud.github.io.
Name: nextcloud.github.io
Address: 185.199.111.153
Name: nextcloud.github.io
Address: 185.199.108.153
Name: nextcloud.github.io
Address: 185.199.110.153
Name: nextcloud.github.io
Address: 185.199.109.153
Name: nextcloud.github.io
Address: 2606:50c0:8001::153
Name: nextcloud.github.io
Address: 2606:50c0:8002::153
Name: nextcloud.github.io
Address: 2606:50c0:8000::153
Name: nextcloud.github.io
Address: 2606:50c0:8003::153

Sep 30 22:05:53 dnsmasq[13773]: query[A] nextcloudpi.com from 127.0.0.1
Sep 30 22:05:53 dnsmasq[13773]: forwarded nextcloudpi.com to 127.0.0.1#5335
Sep 30 22:05:53 dnsmasq[13773]: reply nextcloudpi.com is
Sep 30 22:05:53 dnsmasq[13773]: reply nextcloud.github.io is 185.199.109.153
Sep 30 22:05:53 dnsmasq[13773]: reply nextcloud.github.io is 185.199.108.153
Sep 30 22:05:53 dnsmasq[13773]: reply nextcloud.github.io is 185.199.111.153
Sep 30 22:05:53 dnsmasq[13773]: reply nextcloud.github.io is 185.199.110.153
Sep 30 22:05:53 dnsmasq[13773]: query[AAAA] nextcloud.github.io from 127.0.0.1
Sep 30 22:05:53 dnsmasq[13773]: forwarded nextcloud.github.io to 127.0.0.1#5335
Sep 30 22:05:53 dnsmasq[13773]: reply nextcloud.github.io is 2606:50c0:8002::153
Sep 30 22:05:53 dnsmasq[13773]: reply nextcloud.github.io is 2606:50c0:8001::153
Sep 30 22:05:53 dnsmasq[13773]: reply nextcloud.github.io is 2606:50c0:8003::153
Sep 30 22:05:53 dnsmasq[13773]: reply nextcloud.github.io is 2606:50c0:8000::153

After trying to browse to that site:

sudo grep -i SERVFAIL -B10 /var/log/pihole/pihole.log | tail -20

???

Oct 2 17:04:42 dnsmasq[13773]: reply error is SERVFAIL

Oct 2 17:08:09 dnsmasq[13773]: reply piholediscourse.b-cdn.net is 143.244.38.137
Oct 2 17:08:09 dnsmasq[13773]: query[A] piholediscourse.b-cdn.net from 192.168.0.227
Oct 2 17:08:09 dnsmasq[13773]: cached piholediscourse.b-cdn.net is 143.244.38.137
Oct 2 17:08:12 dnsmasq[13773]: query[A] safebrowsing.googleapis.com from 192.168.0.227
Oct 2 17:08:12 dnsmasq[13773]: forwarded safebrowsing.googleapis.com to 127.0.0.1#5335
Oct 2 17:08:12 dnsmasq[13773]: reply safebrowsing.googleapis.com is 142.250.200.42
Oct 2 17:08:19 dnsmasq[13773]: query[A] nextcloudpi.com from 192.168.0.227
Oct 2 17:08:19 dnsmasq[13773]: forwarded nextcloudpi.com to 127.0.0.1#5335
Oct 2 17:08:19 dnsmasq[13773]: query[A] nextcloudpi.com from 192.168.0.227
Oct 2 17:08:19 dnsmasq[13773]: forwarded nextcloudpi.com to 127.0.0.1#5335
Oct 2 17:08:19 dnsmasq[13773]: reply error is SERVFAIL
Oct 2 17:08:19 dnsmasq[13773]: query[A] www.nextcloudpi.com from 192.168.0.227
Oct 2 17:08:19 dnsmasq[13773]: forwarded www.nextcloudpi.com to 127.0.0.1#5335
Oct 2 17:08:19 dnsmasq[13773]: query[A] www.nextcloudpi.com from 192.168.0.227
Oct 2 17:08:19 dnsmasq[13773]: forwarded www.nextcloudpi.com to 127.0.0.1#5335
Oct 2 17:08:20 dnsmasq[13773]: query[A] www.nextcloudpi.com from 192.168.0.227
Oct 2 17:08:20 dnsmasq[13773]: forwarded www.nextcloudpi.com to 127.0.0.1#5335
Oct 2 17:08:21 dnsmasq[13773]: reply error is SERVFAIL

That SERVFAIL message is coming from Unbound.
If its easy to reproduce, you could try run Unbound manually with extra debug logging to see what is logged when encountering that SERVFAIL message:

> `journalctl --full --no-pager -u unbound`

-- Journal begins at Tue 2022-09-06 22:48:47 BST, ends at Tue 2022-10-04 17:04:57 BST. --
Sep 25 16:38:47 raspberrypi systemd[1]: Starting Unbound DNS server...
Sep 25 16:38:47 raspberrypi package-helper[11950]: /var/lib/unbound/root.key does not exist, copying from /usr/share/dns/root.key
Sep 25 16:38:47 raspberrypi unbound[11954]: [1664120327] unbound[11954:0] error: can't bind socket: Address already in use for ::1 port 53
Sep 25 16:38:47 raspberrypi unbound[11954]: [1664120327] unbound[11954:0] fatal error: could not open ports
Sep 25 16:38:47 raspberrypi systemd[1]: unbound.service: Main process exited, code=exited, status=1/FAILURE
Sep 25 16:38:47 raspberrypi systemd[1]: unbound.service: Failed with result 'exit-code'.
Sep 25 16:38:47 raspberrypi systemd[1]: Failed to start Unbound DNS server.
Sep 25 16:38:47 raspberrypi systemd[1]: unbound.service: Scheduled restart job, restart counter is at 1.
Sep 25 16:38:48 raspberrypi systemd[1]: Stopped Unbound DNS server.
Sep 25 16:38:48 raspberrypi systemd[1]: Starting Unbound DNS server...
Sep 25 16:38:48 raspberrypi unbound[12102]: [1664120328] unbound[12102:0] error: can't bind socket: Address already in use for ::1 port 53
Sep 25 16:38:48 raspberrypi unbound[12102]: [1664120328] unbound[12102:0] fatal error: could not open ports
Sep 25 16:38:48 raspberrypi systemd[1]: unbound.service: Main process exited, code=exited, status=1/FAILURE
Sep 25 16:38:48 raspberrypi systemd[1]: unbound.service: Failed with result 'exit-code'.
Sep 25 16:38:48 raspberrypi systemd[1]: Failed to start Unbound DNS server.
Sep 25 16:38:48 raspberrypi systemd[1]: unbound.service: Scheduled restart job, restart counter is at 2.
Sep 25 16:38:48 raspberrypi systemd[1]: Stopped Unbound DNS server.
Sep 25 16:38:48 raspberrypi systemd[1]: Starting Unbound DNS server...
Sep 25 16:38:48 raspberrypi unbound[12247]: [1664120328] unbound[12247:0] error: can't bind socket: Address already in use for ::1 port 53
Sep 25 16:38:48 raspberrypi unbound[12247]: [1664120328] unbound[12247:0] fatal error: could not open ports
Sep 25 16:38:48 raspberrypi systemd[1]: unbound.service: Main process exited, code=exited, status=1/FAILURE
Sep 25 16:38:48 raspberrypi systemd[1]: unbound.service: Failed with result 'exit-code'.
Sep 25 16:38:48 raspberrypi systemd[1]: Failed to start Unbound DNS server.
Sep 25 16:38:48 raspberrypi systemd[1]: unbound.service: Scheduled restart job, restart counter is at 3.
Sep 25 16:38:48 raspberrypi systemd[1]: Stopped Unbound DNS server.
Sep 25 16:38:48 raspberrypi systemd[1]: Starting Unbound DNS server...
Sep 25 16:38:48 raspberrypi unbound[12372]: [1664120328] unbound[12372:0] error: can't bind socket: Address already in use for ::1 port 53
Sep 25 16:38:48 raspberrypi unbound[12372]: [1664120328] unbound[12372:0] fatal error: could not open ports
Sep 25 16:38:48 raspberrypi systemd[1]: unbound.service: Main process exited, code=exited, status=1/FAILURE
Sep 25 16:38:48 raspberrypi systemd[1]: unbound.service: Failed with result 'exit-code'.
Sep 25 16:38:48 raspberrypi systemd[1]: Failed to start Unbound DNS server.
Sep 25 16:38:48 raspberrypi systemd[1]: unbound.service: Scheduled restart job, restart counter is at 4.
Sep 25 16:38:49 raspberrypi systemd[1]: Stopped Unbound DNS server.
Sep 25 16:38:49 raspberrypi systemd[1]: Starting Unbound DNS server...
Sep 25 16:38:49 raspberrypi unbound[12493]: [1664120329] unbound[12493:0] error: can't bind socket: Address already in use for ::1 port 53
Sep 25 16:38:49 raspberrypi unbound[12493]: [1664120329] unbound[12493:0] fatal error: could not open ports
Sep 25 16:38:49 raspberrypi systemd[1]: unbound.service: Main process exited, code=exited, status=1/FAILURE
Sep 25 16:38:49 raspberrypi systemd[1]: unbound.service: Failed with result 'exit-code'.
Sep 25 16:38:49 raspberrypi systemd[1]: Failed to start Unbound DNS server.
Sep 25 16:38:49 raspberrypi systemd[1]: unbound.service: Scheduled restart job, restart counter is at 5.
Sep 25 16:38:49 raspberrypi systemd[1]: Stopped Unbound DNS server.
Sep 25 16:38:49 raspberrypi systemd[1]: Starting Unbound DNS server...
Sep 25 16:38:49 raspberrypi unbound[12613]: [1664120329] unbound[12613:0] error: can't bind socket: Address already in use for ::1 port 53
Sep 25 16:38:49 raspberrypi unbound[12613]: [1664120329] unbound[12613:0] fatal error: could not open ports
Sep 25 16:38:49 raspberrypi systemd[1]: unbound.service: Main process exited, code=exited, status=1/FAILURE
Sep 25 16:38:49 raspberrypi systemd[1]: unbound.service: Failed with result 'exit-code'.
Sep 25 16:38:49 raspberrypi systemd[1]: Failed to start Unbound DNS server.
Sep 25 16:38:49 raspberrypi systemd[1]: unbound.service: Scheduled restart job, restart counter is at 6.
Sep 25 16:38:49 raspberrypi systemd[1]: Stopped Unbound DNS server.
Sep 25 16:38:49 raspberrypi systemd[1]: unbound.service: Start request repeated too quickly.
Sep 25 16:38:49 raspberrypi systemd[1]: unbound.service: Failed with result 'exit-code'.
Sep 25 16:38:49 raspberrypi systemd[1]: Failed to start Unbound DNS server.
Sep 25 16:53:13 raspberrypi systemd[1]: Starting Unbound DNS server...
Sep 25 16:53:13 raspberrypi unbound[12919]: [12919:0] info: start of service (unbound 1.13.1).
Sep 25 16:53:13 raspberrypi systemd[1]: Started Unbound DNS server.
Sep 25 17:15:35 raspberrypi unbound[12919]: [12919:0] info: service stopped (unbound 1.13.1).
Sep 25 17:15:35 raspberrypi systemd[1]: Stopping Unbound DNS server...
Sep 25 17:15:35 raspberrypi systemd[1]: unbound.service: Succeeded.
Sep 25 17:15:35 raspberrypi systemd[1]: Stopped Unbound DNS server.
Sep 25 17:15:35 raspberrypi systemd[1]: Starting Unbound DNS server...
Sep 25 17:15:35 raspberrypi systemd[1]: Started Unbound DNS server.
> `unbound-checkconf`

unbound-checkconf: no errors in /etc/unbound/unbound.conf

sudo /usr/sbin/unbound -ddd -vvv -c /etc/unbound/unbound.conf

Do you know of any way to save the debugging logs to a file? I have tried saving using >, but that has not worked.

I have got the output for another command that @jfb recommended on the thread you posted.

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

/etc/unbound/unbound.conf:include-toplevel: "/etc/unbound/unbound.conf.d/*.conf"
/etc/unbound/unbound.conf.d/pi-hole.conf:server:
/etc/unbound/unbound.conf.d/pi-hole.conf:	logfile: "/var/log/unbound/unbound.log"
/etc/unbound/unbound.conf.d/pi-hole.conf:	verbosity: 2
/etc/unbound/unbound.conf.d/pi-hole.conf:	interface: 127.0.0.1
/etc/unbound/unbound.conf.d/pi-hole.conf:	port: 5335
/etc/unbound/unbound.conf.d/pi-hole.conf:	do-ip4: yes
/etc/unbound/unbound.conf.d/pi-hole.conf:	do-udp: yes
/etc/unbound/unbound.conf.d/pi-hole.conf:	do-tcp: yes
/etc/unbound/unbound.conf.d/pi-hole.conf:	do-ip6: no
/etc/unbound/unbound.conf.d/pi-hole.conf:	prefer-ip6: no
/etc/unbound/unbound.conf.d/pi-hole.conf:	harden-glue: yes
/etc/unbound/unbound.conf.d/pi-hole.conf:	harden-dnssec-stripped: yes
/etc/unbound/unbound.conf.d/pi-hole.conf:	use-caps-for-id: no
/etc/unbound/unbound.conf.d/pi-hole.conf:	edns-buffer-size: 1232
/etc/unbound/unbound.conf.d/pi-hole.conf:	prefetch: yes
/etc/unbound/unbound.conf.d/pi-hole.conf:	num-threads: 1
/etc/unbound/unbound.conf.d/pi-hole.conf:	so-rcvbuf: 1m
/etc/unbound/unbound.conf.d/pi-hole.conf:	private-address: 192.168.0.0/16
/etc/unbound/unbound.conf.d/pi-hole.conf:	private-address: 169.254.0.0/16
/etc/unbound/unbound.conf.d/pi-hole.conf:	private-address: 172.16.0.0/12
/etc/unbound/unbound.conf.d/pi-hole.conf:	private-address: 10.0.0.0/8
/etc/unbound/unbound.conf.d/pi-hole.conf:	private-address: fd00::/8
/etc/unbound/unbound.conf.d/pi-hole.conf:	private-address: fe80::/10
/etc/unbound/unbound.conf.d/resolvconf_resolvers.conf:forward-zone:
/etc/unbound/unbound.conf.d/resolvconf_resolvers.conf:	name: "."
/etc/unbound/unbound.conf.d/resolvconf_resolvers.conf:	forward-addr: 192.168.0.1
/etc/unbound/unbound.conf.d/root-auto-trust-anchor-file.conf:server:
/etc/unbound/unbound.conf.d/root-auto-trust-anchor-file.conf:    auto-trust-anchor-file: "/var/lib/unbound/root.key"

Above three directives are messing up your setup forwarding everything to your router @192.168.0.1 instead of recursive lookups as is intended.
Try below:

You can un-hash/comment below logfile line and up verbosity:

pi@ph5b:~ $ head /etc/unbound/unbound.conf.d/pi-hole.conf
server:
#    edns-buffer-size: 1500
#edns-buffer-size: 1500

    # If no logfile is specified, syslog is used
    # logfile: "/var/log/unbound/unbound.log"
    verbosity: 0

    interface: 127.0.0.1
    port: 5335
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).

Restart to apply:

sudo service unbound restart

A warning though, use this only to diagnose issues and dont leave it running for too long with upped verbosity.
This log file is not log rotated like the Pi-hole ones and many other log files are ... I believe.
So your disk could run full with logs.

EDIT:

pi@ph5b:~ $ ls -1 /etc/logrotate.d/
alternatives
apt
btmp
dpkg
lighttpd
monit
rsyslog
wtmp
pi@ph5b:~ $ cat /etc/pihole/logrotate
/var/log/pihole/pihole.log {
        su root root
        daily
        copytruncate
        rotate 5
        compress
        delaycompress
        notifempty
        nomail
}

/var/log/pihole/FTL.log {
        su root root
        weekly
        copytruncate
        rotate 3
        compress
        delaycompress
        notifempty
        nomail
}
1 Like

As well as the steps you’ve linked, should I remove those three lines?

  1. Edit file /etc/resolvconf.conf and comment out the last line which should then read:

#unbound_conf=/etc/unbound/unbound.conf.d/resolvconf_resolvers.conf

  1. Delete the unwanted unbound configuration file:

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

  1. Restart unbound:

sudo service unbound restart

2 Likes

If you look closely, this should have been sorted already when followed the steps:

1 Like

My mistake, I had not read the thread yet, but it has worked! Thanks @jfb and @deHakkelaar https://nextcloudpi.com/ now loads.

Just out of curiosity, did I miss a crucial step in the unbound setup docs that caused the line to not be commented out.

No. This is an oddity of Bullseye OS.

1 Like

Worth adding a section to the docs about this?

It's on my to-do list.

1 Like

This topic was automatically closed 21 days after the last reply. New replies are no longer allowed.