I'll try explain again with some details.
First configure something else than unbound as upstream for Pi-hole (eg Google, Cloudlflare etc).
This so the logs dont get polluted with queries from your clients.
http://pi.hole/admin/settings.php?tab=dns
Stop the unbound service:
sudo service unbound stop
Start unbound manually with extra verbosity and debug logging plus output to screen:
sudo /usr/sbin/unbound -ddd -vvv -c /etc/unbound/unbound.conf
Copy/paste the output to here for inspection?
Next in another SSH session, perform below dig only ones (concurrent dig queries will be pulled from unbound cache and wont trigger querying any upstream DNS servers):
dig @localhost -p 5335 a deutsche-glasfaser.de.
Copy/paste the extra log lines generated from that one dig to here separately?
To use the scrip, first paste above last log lines resulting from the dig to a new file eg:
nano unbound.serverfail.log
And run the scrip with the log file as an argument eg:
./unbound_check.sh unbound.serverfail.log | column -t
If all goes well, it generates a list of dig commands, similar as the queries that unbound makes, that can be run manually to check results eg just copy/paste to a prompt and press enter.
You could also check with below grep on the same log file if any module_event_noreply messages are present that indicates that querying one or more of the upstream DNS servers is failing:
grep -B3 module_event_noreply unbound.serverfail.log
When finished diagnosing, you can stop unbound by pressing CTRLc
Start here up normal again via systemd:
sudo service unbound start
And configure unbound as upstream again 127.0.0.1#5335 in Pi-hole (dont forget to remove the other DNS server(s) that you selected):
http://pi.hole/admin/settings.php?tab=dns
For comparison:
pi@ph5b:~ $ sudo service unbound stop
pi@ph5b:~ $
pi@ph5b:~ $ sudo /usr/sbin/unbound -ddd -vvv -c /etc/unbound/unbound.conf
[1649154273] unbound[12778:0] notice: Start of unbound 1.13.1.
[1649154274] unbound[12778:0] debug: chdir to /etc/unbound
[1649154274] unbound[12778:0] debug: drop user privileges, run as unbound
[1649154274] unbound[12778:0] debug: switching log to stderr
[1649154274] unbound[12778:0] debug: module config: "subnetcache validator iterator"
[1649154274] unbound[12778:0] notice: init module 0: subnet
[1649154274] unbound[12778:0] debug: subnet: option registered (8)
[1649154274] unbound[12778:0] notice: init module 1: validator
[1649154274] unbound[12778:0] notice: init module 2: iterator
[1649154274] unbound[12778:0] debug: target fetch policy for level 0 is 3
[1649154274] unbound[12778:0] debug: target fetch policy for level 1 is 2
[1649154274] unbound[12778:0] debug: target fetch policy for level 2 is 1
[1649154274] unbound[12778:0] debug: target fetch policy for level 3 is 0
[1649154274] unbound[12778:0] debug: target fetch policy for level 4 is 0
[1649154274] unbound[12778:0] debug: cache memory msg=33040 rrset=33040 infra=3920 val=33196 subnet=41372
[1649154274] unbound[12778:0] info: start of service (unbound 1.13.1).
pi@ph5b:~ $ dig @localhost -p 5335 a deutsche-glasfaser.de.
; <<>> DiG 9.16.22-Raspbian <<>> @localhost -p 5335 a deutsche-glasfaser.de.
; (2 servers found)
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 45235
;; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 1
;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 1232
;; QUESTION SECTION:
;deutsche-glasfaser.de. IN A
;; ANSWER SECTION:
deutsche-glasfaser.de. 86400 IN A 185.22.44.179
;; Query time: 259 msec
;; SERVER: 127.0.0.1#5335(127.0.0.1)
;; WHEN: Tue Apr 05 12:25:58 CEST 2022
;; MSG SIZE rcvd: 66
pi@ph5b:~ $ sudo /usr/sbin/unbound -ddd -vvv -c /etc/unbound/unbound.conf
[..]
[1649154357] unbound[12818:0] debug: subnet[module 0] operate: extstate:module_state_initial event:module_event_new
[1649154357] unbound[12818:0] info: subnet operate: query deutsche-glasfaser.de. A IN
[1649154357] unbound[12818:0] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1649154357] unbound[12818:0] info: validator operate: query deutsche-glasfaser.de. A IN
[1649154357] unbound[12818:0] debug: iterator[module 2] operate: extstate:module_state_initial event:module_event_pass
[1649154357] unbound[12818:0] info: resolving deutsche-glasfaser.de. A IN
[1649154357] unbound[12818:0] info: priming . IN NS
[1649154357] unbound[12818:0] debug: iterator[module 2] operate: extstate:module_state_initial event:module_event_pass
[1649154357] unbound[12818:0] info: iterator operate: query . NS IN
[1649154357] unbound[12818:0] info: processQueryTargets: . NS IN
[1649154357] unbound[12818:0] info: sending query: . NS IN
[1649154357] unbound[12818:0] debug: sending to target: <.> 192.203.230.10#53
[1649154357] unbound[12818:0] debug: cache memory msg=33040 rrset=33040 infra=4149 val=33196 subnet=41372
[1649154357] unbound[12818:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1649154357] unbound[12818:0] info: iterator operate: query . NS IN
[1649154357] unbound[12818:0] info: response for . NS IN
[1649154357] unbound[12818:0] info: reply from <.> 192.203.230.10#53
[1649154357] unbound[12818:0] info: query response was ANSWER
[1649154357] unbound[12818:0] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_moddone
[1649154357] unbound[12818:0] info: validator operate: query . NS IN
[1649154357] unbound[12818:0] debug: subnet[module 0] operate: extstate:module_state_initial event:module_event_moddone
[1649154357] unbound[12818:0] info: subnet operate: query . NS IN
[1649154357] unbound[12818:0] info: priming successful for . NS IN
[1649154357] unbound[12818:0] debug: iterator[module 2] operate: extstate:module_wait_subquery event:module_event_pass
[1649154357] unbound[12818:0] info: iterator operate: query deutsche-glasfaser.de. A IN
[1649154357] unbound[12818:0] info: resolving (init part 2): deutsche-glasfaser.de. A IN
[1649154357] unbound[12818:0] info: resolving (init part 3): deutsche-glasfaser.de. A IN
[1649154357] unbound[12818:0] info: processQueryTargets: deutsche-glasfaser.de. A IN
[1649154357] unbound[12818:0] debug: removing 1 labels
[1649154357] unbound[12818:0] info: sending query: de. A IN
[1649154357] unbound[12818:0] debug: sending to target: <.> 192.33.4.12#53
[1649154357] unbound[12818:0] debug: cache memory msg=33701 rrset=38048 infra=4378 val=33196 subnet=41372
[1649154357] unbound[12818:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1649154357] unbound[12818:0] info: iterator operate: query deutsche-glasfaser.de. A IN
[1649154357] unbound[12818:0] info: response for deutsche-glasfaser.de. A IN
[1649154357] unbound[12818:0] info: reply from <.> 192.33.4.12#53
[1649154357] unbound[12818:0] info: query response was REFERRAL
[1649154357] unbound[12818:0] info: processQueryTargets: deutsche-glasfaser.de. A IN
[1649154357] unbound[12818:0] info: sending query: deutsche-glasfaser.de. A IN
[1649154357] unbound[12818:0] debug: sending to target: <de.> 81.91.164.5#53
[1649154357] unbound[12818:0] debug: cache memory msg=33701 rrset=40571 infra=4610 val=33196 subnet=41372
[1649154357] unbound[12818:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1649154357] unbound[12818:0] info: iterator operate: query deutsche-glasfaser.de. A IN
[1649154358] unbound[12818:0] info: response for deutsche-glasfaser.de. A IN
[1649154358] unbound[12818:0] info: reply from <de.> 81.91.164.5#53
[1649154358] unbound[12818:0] info: query response was REFERRAL
[1649154358] unbound[12818:0] info: processQueryTargets: deutsche-glasfaser.de. A IN
[1649154358] unbound[12818:0] info: sending query: deutsche-glasfaser.de. A IN
[1649154358] unbound[12818:0] debug: sending to target: <deutsche-glasfaser.de.> 185.22.44.49#53
[1649154358] unbound[12818:0] debug: cache memory msg=33701 rrset=42165 infra=4861 val=33648 subnet=41372
[1649154358] unbound[12818:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1649154358] unbound[12818:0] info: iterator operate: query deutsche-glasfaser.de. A IN
[1649154358] unbound[12818:0] info: response for deutsche-glasfaser.de. A IN
[1649154358] unbound[12818:0] info: reply from <deutsche-glasfaser.de.> 185.22.44.49#53
[1649154358] unbound[12818:0] info: query response was ANSWER
[1649154358] unbound[12818:0] info: finishing processing for deutsche-glasfaser.de. A IN
[1649154358] unbound[12818:0] debug: validator[module 1] operate: extstate:module_wait_module event:module_event_moddone
[1649154358] unbound[12818:0] info: validator operate: query deutsche-glasfaser.de. A IN
[1649154358] unbound[12818:0] info: prime trust anchor
[1649154358] unbound[12818:0] info: generate keytag query _ta-4f66. NULL IN
[1649154358] unbound[12818:0] debug: subnet[module 0] operate: extstate:module_state_initial event:module_event_pass
[1649154358] unbound[12818:0] info: subnet operate: query . DNSKEY IN
[1649154358] unbound[12818:0] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1649154358] unbound[12818:0] info: validator operate: query . DNSKEY IN
[1649154358] unbound[12818:0] debug: iterator[module 2] operate: extstate:module_state_initial event:module_event_pass
[1649154358] unbound[12818:0] info: resolving . DNSKEY IN
[1649154358] unbound[12818:0] info: resolving (init part 2): . DNSKEY IN
[1649154358] unbound[12818:0] info: resolving (init part 3): . DNSKEY IN
[1649154358] unbound[12818:0] info: processQueryTargets: . DNSKEY IN
[1649154358] unbound[12818:0] info: sending query: . DNSKEY IN
[1649154358] unbound[12818:0] debug: sending to target: <.> 192.112.36.4#53
[1649154358] unbound[12818:0] debug: subnet[module 0] operate: extstate:module_state_initial event:module_event_pass
[1649154358] unbound[12818:0] info: subnet operate: query _ta-4f66. NULL IN
[1649154358] unbound[12818:0] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1649154358] unbound[12818:0] info: validator operate: query _ta-4f66. NULL IN
[1649154358] unbound[12818:0] debug: iterator[module 2] operate: extstate:module_state_initial event:module_event_pass
[1649154358] unbound[12818:0] info: resolving _ta-4f66. NULL IN
[1649154358] unbound[12818:0] info: resolving (init part 2): _ta-4f66. NULL IN
[1649154358] unbound[12818:0] info: resolving (init part 3): _ta-4f66. NULL IN
[1649154358] unbound[12818:0] info: processQueryTargets: _ta-4f66. NULL IN
[1649154358] unbound[12818:0] info: sending query: _ta-4f66. A IN
[1649154358] unbound[12818:0] debug: sending to target: <.> 192.5.5.241#53
[1649154358] unbound[12818:0] debug: cache memory msg=33864 rrset=42322 infra=5319 val=33648 subnet=41372
[1649154358] unbound[12818:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1649154358] unbound[12818:0] info: iterator operate: query _ta-4f66. NULL IN
[1649154358] unbound[12818:0] info: response for _ta-4f66. NULL IN
[1649154358] unbound[12818:0] info: reply from <.> 192.5.5.241#53
[1649154358] unbound[12818:0] info: query response was NXDOMAIN ANSWER
[1649154358] unbound[12818:0] info: finishing processing for _ta-4f66. NULL IN
[1649154358] unbound[12818:0] debug: validator[module 1] operate: extstate:module_wait_module event:module_event_moddone
[1649154358] unbound[12818:0] info: validator operate: query _ta-4f66. NULL IN
[1649154358] unbound[12818:0] debug: subnet[module 0] operate: extstate:module_wait_module event:module_event_moddone
[1649154358] unbound[12818:0] info: subnet operate: query _ta-4f66. NULL IN
[1649154358] unbound[12818:0] debug: cache memory msg=34034 rrset=43240 infra=5319 val=33648 subnet=41372
[1649154358] unbound[12818:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1649154358] unbound[12818:0] info: iterator operate: query . DNSKEY IN
[1649154358] unbound[12818:0] info: response for . DNSKEY IN
[1649154358] unbound[12818:0] info: reply from <.> 192.112.36.4#53
[1649154358] unbound[12818:0] info: query response was ANSWER
[1649154358] unbound[12818:0] info: finishing processing for . DNSKEY IN
[1649154358] unbound[12818:0] debug: validator[module 1] operate: extstate:module_wait_module event:module_event_moddone
[1649154358] unbound[12818:0] info: validator operate: query . DNSKEY IN
[1649154358] unbound[12818:0] debug: subnet[module 0] operate: extstate:module_wait_module event:module_event_moddone
[1649154358] unbound[12818:0] info: subnet operate: query . DNSKEY IN
[1649154358] unbound[12818:0] info: validate keys with anchor(DS): sec_status_secure
[1649154358] unbound[12818:0] info: Successfully primed trust anchor . DNSKEY IN
[1649154358] unbound[12818:0] debug: validator[module 1] operate: extstate:module_wait_subquery event:module_event_pass
[1649154358] unbound[12818:0] info: validator operate: query deutsche-glasfaser.de. A IN
[1649154358] unbound[12818:0] info: validated DS de. DS IN
[1649154358] unbound[12818:0] debug: subnet[module 0] operate: extstate:module_state_initial event:module_event_pass
[1649154358] unbound[12818:0] info: subnet operate: query de. DNSKEY IN
[1649154358] unbound[12818:0] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1649154358] unbound[12818:0] info: validator operate: query de. DNSKEY IN
[1649154358] unbound[12818:0] debug: iterator[module 2] operate: extstate:module_state_initial event:module_event_pass
[1649154358] unbound[12818:0] info: resolving de. DNSKEY IN
[1649154358] unbound[12818:0] info: resolving (init part 2): de. DNSKEY IN
[1649154358] unbound[12818:0] info: resolving (init part 3): de. DNSKEY IN
[1649154358] unbound[12818:0] info: processQueryTargets: de. DNSKEY IN
[1649154358] unbound[12818:0] info: sending query: de. DNSKEY IN
[1649154358] unbound[12818:0] debug: sending to target: <de.> 194.146.107.6#53
[1649154358] unbound[12818:0] debug: cache memory msg=34175 rrset=44480 infra=5551 val=34896 subnet=41372
[1649154358] unbound[12818:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1649154358] unbound[12818:0] info: iterator operate: query de. DNSKEY IN
[1649154358] unbound[12818:0] info: response for de. DNSKEY IN
[1649154358] unbound[12818:0] info: reply from <de.> 194.146.107.6#53
[1649154358] unbound[12818:0] info: query response was ANSWER
[1649154358] unbound[12818:0] info: finishing processing for de. DNSKEY IN
[1649154358] unbound[12818:0] debug: validator[module 1] operate: extstate:module_wait_module event:module_event_moddone
[1649154358] unbound[12818:0] info: validator operate: query de. DNSKEY IN
[1649154358] unbound[12818:0] debug: subnet[module 0] operate: extstate:module_wait_module event:module_event_moddone
[1649154358] unbound[12818:0] info: subnet operate: query de. DNSKEY IN
[1649154358] unbound[12818:0] info: validated DNSKEY de. DNSKEY IN
[1649154358] unbound[12818:0] debug: validator[module 1] operate: extstate:module_wait_subquery event:module_event_pass
[1649154358] unbound[12818:0] info: validator operate: query deutsche-glasfaser.de. A IN
[1649154358] unbound[12818:0] info: NSEC3s for the referral proved no DS.
[1649154358] unbound[12818:0] info: Verified that unsigned response is INSECURE
[1649154358] unbound[12818:0] debug: subnet[module 0] operate: extstate:module_wait_module event:module_event_moddone
[1649154358] unbound[12818:0] info: subnet operate: query deutsche-glasfaser.de. A IN
[1649154358] unbound[12818:0] debug: cache memory msg=34319 rrset=45320 infra=5551 val=35855 subnet=41372
pi@ph5b:~ $ nano unbound.serverfail.log
[1649154357] unbound[12818:0] debug: subnet[module 0] operate: extstate:module_state_initial event:module_event_new
[1649154357] unbound[12818:0] info: subnet operate: query deutsche-glasfaser.de. A IN
[1649154357] unbound[12818:0] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1649154357] unbound[12818:0] info: validator operate: query deutsche-glasfaser.de. A IN
[..]
pi@ph5b:~ $ ./unbound_check.sh unbound.serverfail.log | column -t
dig +norecurse @192.203.230.10 . NS IN
dig +norecurse @192.33.4.12 de. A IN
dig +norecurse @81.91.164.5 deutsche-glasfaser.de. A IN
dig +norecurse @185.22.44.49 deutsche-glasfaser.de. A IN
dig +norecurse @192.112.36.4 . DNSKEY IN
dig +norecurse @192.5.5.241 _ta-4f66. A IN
dig +norecurse @194.146.107.6 de. DNSKEY IN
pi@ph5b:~ $ grep -B3 module_event_noreply unbound.serverfail.log
pi@ph5b:~ $