Unbound times out

Hey,

i followed the official documentation for unbound as an recursive resolver and I want to use it.
Currently my pihole uses stubby for DoT.
The first tests on console says there is an "communication error" on unbound. This error doesn't happen always but often.
I'm using Raspian as OS.

pi@pihole:dig pi-hole.net @127.0.0.1 -p 51234 
;; communications error to 127.0.0.1#51234: timed out
;; communications error to 127.0.0.1#51234: timed out
;; communications error to 127.0.0.1#51234: timed out

; <<>> DiG 9.18.28-1~deb12u2-Debian <<>> pi-hole.net @127.0.0.1 -p 51234
;; global options: +cmd
;; no servers could be reached

Sometimes it works

pi@pihole:~ $ dig pi-hole.net @127.0.0.1 -p 51234 

; <<>> DiG 9.18.28-1~deb12u2-Debian <<>> pi-hole.net @127.0.0.1 -p 51234
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 2958
;; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 1232
;; QUESTION SECTION:
;pi-hole.net.			IN	A

;; ANSWER SECTION:
pi-hole.net.		262	IN	A	3.18.136.52

;; Query time: 0 msec
;; SERVER: 127.0.0.1#51234(127.0.0.1) (UDP)
;; WHEN: Fri Jan 10 14:43:29 CET 2025
;; MSG SIZE  rcvd: 56

Config Check gives no errors

pi@pihole:~ $ unbound-checkconf 
unbound-checkconf: no errors in /etc/unbound/unbound.conf

I don't know, but the problem probably lies within "ports already in use". But I can't imagine what causes it, because I tried now many different high ports and the error always appears:

pi@pihole:~ $ unbound -v
[1736517641] unbound[7413:0] notice: Start of unbound 1.17.1.
[1736517641] unbound[7413:0] debug: increased limit(open files) from 1024 to 4140
[1736517641] unbound[7413:0] debug: creating udp4 socket 127.0.0.1 51234
[1736517641] unbound[7413:0] warning: so-rcvbuf 1048576 was not granted. Got 425984. To fix: start with root permissions(linux) or sysctl bigger net.core.rmem_max(linux) or kern.ipc.maxsockbuf(bsd) values.
[1736517641] unbound[7413:0] debug: creating tcp4 socket 127.0.0.1 51234
[1736517641] unbound[7413:0] error: can't bind socket: Address already in use for 127.0.0.1 port 51234 (len 16)
[1736517641] unbound[7413:0] fatal error: could not open ports

Output of opened ports

pi@pihole:~ $ sudo netstat -tulpn | sort -t: -k2 -n
Active Internet connections (only servers)
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name    
tcp6       0      0 ::1:4711                :::*                    LISTEN      773/pihole-FTL      
tcp6       0      0 :::22                   :::*                    LISTEN      696/sshd: /usr/sbin 
tcp6       0      0 :::53                   :::*                    LISTEN      773/pihole-FTL      
tcp6       0      0 :::80                   :::*                    LISTEN      777/lighttpd        
udp6       0      0 :::33348                :::*                                545/avahi-daemon: r 
udp6       0      0 :::5353                 :::*                                545/avahi-daemon: r 
udp6       0      0 :::53                   :::*                                773/pihole-FTL      
tcp        0      0 0.0.0.0:22              0.0.0.0:*               LISTEN      696/sshd: /usr/sbin 
tcp        0      0 0.0.0.0:53              0.0.0.0:*               LISTEN      773/pihole-FTL      
udp        0      0 0.0.0.0:53              0.0.0.0:*                           773/pihole-FTL      
tcp        0      0 0.0.0.0:80              0.0.0.0:*               LISTEN      777/lighttpd        
tcp        0      0 127.0.0.1:4711          0.0.0.0:*               LISTEN      773/pihole-FTL      
udp        0      0 0.0.0.0:5353            0.0.0.0:*                           545/avahi-daemon: r 
udp        0      0 0.0.0.0:41866           0.0.0.0:*                           545/avahi-daemon: r 
tcp        0      0 127.0.0.1:50535         0.0.0.0:*               LISTEN      756/stubby          
udp        0      0 127.0.0.1:50535         0.0.0.0:*                           756/stubby          
tcp        0      0 127.0.0.1:51234         0.0.0.0:*               LISTEN      7409/unbound        
udp        0      0 127.0.0.1:51234         0.0.0.0:*                           7409/unbound

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). 
; 
;       This file is made available by InterNIC 
;       under anonymous FTP as
;           file                /domain/named.cache 
;           on server           FTP.INTERNIC.NET
;       -OR-                    RS.INTERNIC.NET
;
;       last update:     December 18, 2024
;       related version of root zone:     2024121801
; 
; FORMERLY NS.INTERNIC.NET 
;
.                        3600000      NS    A.ROOT-SERVERS.NET.
A.ROOT-SERVERS.NET.      3600000      A     198.41.0.4
A.ROOT-SERVERS.NET.      3600000      AAAA  2001:503:ba3e::2:30
; 
; FORMERLY NS1.ISI.EDU 
;
.                        3600000      NS    B.ROOT-SERVERS.NET.
B.ROOT-SERVERS.NET.      3600000      A     170.247.170.2
B.ROOT-SERVERS.NET.      3600000      AAAA  2801:1b8:10::b
; 
; FORMERLY C.PSI.NET 
;
.                        3600000      NS    C.ROOT-SERVERS.NET.
C.ROOT-SERVERS.NET.      3600000      A     192.33.4.12
C.ROOT-SERVERS.NET.      3600000      AAAA  2001:500:2::c
; 
; FORMERLY TERP.UMD.EDU 
;
.                        3600000      NS    D.ROOT-SERVERS.NET.
D.ROOT-SERVERS.NET.      3600000      A     199.7.91.13
D.ROOT-SERVERS.NET.      3600000      AAAA  2001:500:2d::d
; 
; FORMERLY NS.NASA.GOV
;
.                        3600000      NS    E.ROOT-SERVERS.NET.
E.ROOT-SERVERS.NET.      3600000      A     192.203.230.10
E.ROOT-SERVERS.NET.      3600000      AAAA  2001:500:a8::e
; 
; FORMERLY NS.ISC.ORG
;
.                        3600000      NS    F.ROOT-SERVERS.NET.
F.ROOT-SERVERS.NET.      3600000      A     192.5.5.241
F.ROOT-SERVERS.NET.      3600000      AAAA  2001:500:2f::f
; 
; FORMERLY NS.NIC.DDN.MIL
;
.                        3600000      NS    G.ROOT-SERVERS.NET.
G.ROOT-SERVERS.NET.      3600000      A     192.112.36.4
G.ROOT-SERVERS.NET.      3600000      AAAA  2001:500:12::d0d
; 
; FORMERLY AOS.ARL.ARMY.MIL
;
.                        3600000      NS    H.ROOT-SERVERS.NET.
H.ROOT-SERVERS.NET.      3600000      A     198.97.190.53
H.ROOT-SERVERS.NET.      3600000      AAAA  2001:500:1::53
; 
; FORMERLY NIC.NORDU.NET
;
.                        3600000      NS    I.ROOT-SERVERS.NET.
I.ROOT-SERVERS.NET.      3600000      A     192.36.148.17
I.ROOT-SERVERS.NET.      3600000      AAAA  2001:7fe::53
; 
; OPERATED BY VERISIGN, INC.
;
.                        3600000      NS    J.ROOT-SERVERS.NET.
J.ROOT-SERVERS.NET.      3600000      A     192.58.128.30
J.ROOT-SERVERS.NET.      3600000      AAAA  2001:503:c27::2:30
; 
; OPERATED BY RIPE NCC
;
.                        3600000      NS    K.ROOT-SERVERS.NET.
K.ROOT-SERVERS.NET.      3600000      A     193.0.14.129
K.ROOT-SERVERS.NET.      3600000      AAAA  2001:7fd::1
; 
; OPERATED BY ICANN
;
.                        3600000      NS    L.ROOT-SERVERS.NET.
L.ROOT-SERVERS.NET.      3600000      A     199.7.83.42
L.ROOT-SERVERS.NET.      3600000      AAAA  2001:500:9f::42
; 
; OPERATED BY WIDE
;
.                        3600000      NS    M.ROOT-SERVERS.NET.
M.ROOT-SERVERS.NET.      3600000      A     202.12.27.33
M.ROOT-SERVERS.NET.      3600000      AAAA  2001:dc3::35
; End of file

Unbound Conf:

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

    interface: 127.0.0.1
    port: 51234
    do-ip4: yes
    do-udp: yes
    do-tcp: yes

    # May be set to yes if you have IPv6 connectivity
    do-ip6: yes

    # You want to leave this to no unless you have *native* IPv6. With 6to4 and
    # Terredo tunnels your web browser should favor IPv4 for the same reasons
    prefer-ip6: yes

    # Use this only when you downloaded the list of primary root servers!
    # If you use the default dns-root-data package, unbound will find it automatically
    root-hints: "/var/lib/unbound/root.hints"

    # Trust glue only if it is within the server's authority
    harden-glue: yes

    # Require DNSSEC data for trust-anchored zones, if such data is absent, the zone becomes BOGUS
    harden-dnssec-stripped: yes

    # Don't use Capitalization randomization as it known to cause DNSSEC issues sometimes
    # see https://discourse.pi-hole.net/t/unbound-stubby-or-dnscrypt-proxy/9378 for further details
    use-caps-for-id: no

    # Reduce EDNS reassembly buffer size.
    # IP fragmentation is unreliable on the Internet today, and can cause
    # transmission failures when large DNS messages are sent via UDP. Even
    # when fragmentation does work, it may not be secure; it is theoretically
    # possible to spoof parts of a fragmented DNS message, without easy
    # detection at the receiving end. Recently, there was an excellent study
    # >>> Defragmenting DNS - Determining the optimal maximum UDP response size for DNS <<<
    # by Axel Koolhaas, and Tjeerd Slokker (https://indico.dns-oarc.net/event/36/contributions/776/)
    # in collaboration with NLnet Labs explored DNS using real world data from the
    # the RIPE Atlas probes and the researchers suggested different values for
    # IPv4 and IPv6 and in different scenarios. They advise that servers should
    # be configured to limit DNS messages sent over UDP to a size that will not
    # trigger fragmentation on typical network links. DNS servers can switch
    # from UDP to TCP when a DNS response is too big to fit in this limited
    # buffer size. This value has also been suggested in DNS Flag Day 2020.
    edns-buffer-size: 1232

    # Perform prefetching of close to expired message cache entries
    # This only applies to domains that have been frequently queried
    prefetch: yes

    # One thread should be sufficient, can be increased on beefy machines. In reality for most users running on small networks or on a single machine, it should be unnecessary to seek performance enhancement by increasing num-threads above 1.
    num-threads: 1

    # Ensure kernel buffer is large enough to not lose messages in traffic spikes
    so-rcvbuf: 1m

    # Ensure privacy of local IP ranges
    private-address: 192.168.0.0/16
    private-address: 169.254.0.0/16
    private-address: 172.16.0.0/12
    private-address: 10.0.0.0/8
    private-address: fd00::/8
    private-address: fe80::/10

Debug Token:

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

Some tips would be nice, thanks

Is there a reason for not using port 5335 as detailed in the guide?

First I used the port. I switched it multiple times during debug and trying, also because I got this everytime:

[1736517641] unbound[7413:0] error: can't bind socket: Address already in use for 127.0.0.1 port 51234 (len 16)

Complete unbound config:

pi@pihole:~ $ 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: 4
/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: yes
/etc/unbound/unbound.conf.d/pi-hole.conf:    prefer-ip6: yes
/etc/unbound/unbound.conf.d/pi-hole.conf:    root-hints: "/var/lib/unbound/root.hints"
/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/remote-control.conf:remote-control:
/etc/unbound/unbound.conf.d/remote-control.conf:  control-enable: yes
/etc/unbound/unbound.conf.d/remote-control.conf:  control-interface: /run/unbound.ctl
/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"

I have found a thread with a similiar problem: Unbound times out with: "communications error to 127.0.0.1#5335: timed out"
But it doesn't seem that this got fixed by the guys

From the netstat output, it seems port 5335 (from the official guide) is free to use.
Configure that port from the guide instead of 51234 pls?

Could you post output for below one?

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

You already have Unbound configured to log to a file.
But lower verbosity to three instead of four at first bc it can be very talkative and cryptic?
After you've lowered verbosity and changed the port to 5335, run below one to apply:

sudo systemctl restart unbound.service

I dont know if you can reproduce the time-outs but if you can get it to fail, tail/follow the logs live with below:

sudo tail -F /var/log/unbound/unbound.log

Run below query in another session (if thats the domain failing):

dig pi-hole.net @127.0.0.1 -p 5335

And post the resulting log lines here pls?

Ps. you dont have to configure that root-hints: directive!
When you've installed Unbound with apt, the root hints are already installed as a dependency:

$ apt depends unbound
unbound
[..]
  Depends: dns-root-data
$ dpkg -L dns-root-data
[..]
/usr/share/dns/root.hints
/usr/share/dns/root.hints.sig
/usr/share/dns/root.key

And Unbound knows where to find it without that root-hints: directive.

Another remark, dont forget to lower verbosity to zero and hash out/comment that logfile: directive when finished diagnosing!
See below two postings of mine:

1 Like

I have already switched back, that was just for testing.

pi@pihole:~ $ sudo rgrep -v '^ *#\|^ *$' /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: 3
/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: yes
/etc/unbound/unbound.conf.d/pi-hole.conf:    prefer-ip6: yes
/etc/unbound/unbound.conf.d/pi-hole.conf:    root-hints: "/var/lib/unbound/root.hints"
/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/remote-control.conf:remote-control:
/etc/unbound/unbound.conf.d/remote-control.conf:  control-enable: yes
/etc/unbound/unbound.conf.d/remote-control.conf:  control-interface: /run/unbound.ctl
/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"

Log with the communication error. A bit shortened, was to long for forum post.

pi@pihole:~ $ sudo tail -F /var/log/unbound/unbound.log
[1736925616] unbound[16364:0] notice: init module 2: iterator
[1736925616] unbound[16364:0] debug: target fetch policy for level 0 is 3
[1736925616] unbound[16364:0] debug: target fetch policy for level 1 is 2
[1736925616] unbound[16364:0] debug: target fetch policy for level 2 is 1
[1736925616] unbound[16364:0] debug: target fetch policy for level 3 is 0
[1736925616] unbound[16364:0] debug: target fetch policy for level 4 is 0
[1736925616] unbound[16364:0] debug: Reading root hints from /var/lib/unbound/root.hints
[1736925616] unbound[16364:0] info: DelegationPoint<.>: 13 names (0 missing), 26 addrs (0 result, 26 avail) parentNS
[1736925616] unbound[16364:0] debug: cache memory msg=66072 rrset=66072 infra=7808 val=66368 subnet=74504
[1736925616] unbound[16364:0] info: start of service (unbound 1.17.1).
[1736925790] unbound[16364:0] debug: subnetcache[module 0] operate: extstate:module_state_initial event:module_event_new
[1736925790] unbound[16364:0] info: subnetcache operate: query pi-hole.net. A IN
[1736925790] unbound[16364:0] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1736925790] unbound[16364:0] info: validator operate: query pi-hole.net. A IN
[1736925790] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_state_initial event:module_event_pass
[1736925790] unbound[16364:0] info: resolving pi-hole.net. A IN
[1736925790] unbound[16364:0] info: priming . IN NS
[1736925790] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_state_initial event:module_event_pass
[1736925790] unbound[16364:0] info: iterator operate: query . NS IN
[1736925790] unbound[16364:0] info: processQueryTargets: . NS IN
[1736925790] unbound[16364:0] info: sending query: . NS IN
[1736925790] unbound[16364:0] debug: sending to target: <.> 2001:500:2f::f#53
[1736925790] unbound[16364:0] debug: cache memory msg=66072 rrset=66072 infra=7808 val=66368 subnet=74504
[1736925791] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925791] unbound[16364:0] info: iterator operate: query . NS IN
[1736925791] unbound[16364:0] info: processQueryTargets: . NS IN
[1736925791] unbound[16364:0] info: sending query: . NS IN
[1736925791] unbound[16364:0] debug: sending to target: <.> 2001:500:2d::d#53
[1736925791] unbound[16364:0] debug: cache memory msg=66072 rrset=66072 infra=8105 val=66368 subnet=74504
[1736925792] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925792] unbound[16364:0] info: iterator operate: query . NS IN
[1736925792] unbound[16364:0] info: processQueryTargets: . NS IN
[1736925792] unbound[16364:0] info: sending query: . NS IN
[1736925792] unbound[16364:0] debug: sending to target: <.> 2001:dc3::35#53
[1736925792] unbound[16364:0] debug: cache memory msg=66072 rrset=66072 infra=8402 val=66368 subnet=74504
[1736925793] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925793] unbound[16364:0] info: iterator operate: query . NS IN
[1736925793] unbound[16364:0] info: processQueryTargets: . NS IN
[1736925793] unbound[16364:0] info: sending query: . NS IN
[1736925793] unbound[16364:0] debug: sending to target: <.> 2001:500:a8::e#53
[1736925793] unbound[16364:0] debug: cache memory msg=66072 rrset=66072 infra=8699 val=66368 subnet=74504
[1736925793] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925793] unbound[16364:0] info: iterator operate: query . NS IN
[1736925793] unbound[16364:0] info: processQueryTargets: . NS IN
[1736925793] unbound[16364:0] info: sending query: . NS IN
[1736925793] unbound[16364:0] debug: sending to target: <.> 2001:7fd::1#53
[1736925793] unbound[16364:0] debug: cache memory msg=66072 rrset=66072 infra=8996 val=66368 subnet=74504
[1736925794] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925794] unbound[16364:0] info: iterator operate: query . NS IN
[1736925794] unbound[16364:0] info: processQueryTargets: . NS IN
[1736925794] unbound[16364:0] info: sending query: . NS IN
[1736925794] unbound[16364:0] debug: sending to target: <.> 2001:500:12::d0d#53
[1736925794] unbound[16364:0] debug: cache memory msg=66072 rrset=66072 infra=9293 val=66368 subnet=74504
[1736925795] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925795] unbound[16364:0] info: iterator operate: query . NS IN
[1736925795] unbound[16364:0] info: processQueryTargets: . NS IN
[1736925795] unbound[16364:0] info: sending query: . NS IN
[1736925795] unbound[16364:0] debug: sending to target: <.> 202.12.27.33#53
[1736925795] unbound[16364:0] debug: cache memory msg=66072 rrset=66072 infra=9590 val=66368 subnet=74504
[1736925795] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1736925795] unbound[16364:0] info: iterator operate: query . NS IN
[1736925795] unbound[16364:0] info: response for . NS IN
[1736925795] unbound[16364:0] info: reply from <.> 202.12.27.33#53
[1736925795] unbound[16364:0] info: query response was ANSWER
[1736925795] unbound[16364:0] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_moddone
[1736925795] unbound[16364:0] info: validator operate: query . NS IN
[1736925795] unbound[16364:0] debug: subnetcache[module 0] operate: extstate:module_state_initial event:module_event_moddone
[1736925795] unbound[16364:0] info: subnetcache operate: query . NS IN
[1736925795] unbound[16364:0] info: priming successful for . NS IN
[1736925795] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_subquery event:module_event_pass
[1736925795] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925795] unbound[16364:0] info: resolving (init part 2):  pi-hole.net. A IN
[1736925795] unbound[16364:0] info: resolving (init part 3):  pi-hole.net. A IN
[1736925795] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925795] unbound[16364:0] debug: removing 1 labels
[1736925795] unbound[16364:0] info: sending query: net. A IN
[1736925795] unbound[16364:0] debug: sending to target: <.> 2001:503:ba3e::2:30#53
[1736925795] unbound[16364:0] debug: cache memory msg=66937 rrset=73828 infra=9887 val=66368 subnet=74504
[1736925795] unbound[16364:0] debug: subnetcache[module 0] operate: extstate:module_state_initial event:module_event_new
[1736925795] unbound[16364:0] info: subnetcache operate: query pi-hole.net. A IN
[1736925795] unbound[16364:0] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1736925795] unbound[16364:0] info: validator operate: query pi-hole.net. A IN
[1736925795] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_state_initial event:module_event_pass
[1736925795] unbound[16364:0] info: resolving pi-hole.net. A IN
[1736925795] unbound[16364:0] info: resolving (init part 2):  pi-hole.net. A IN
[1736925795] unbound[16364:0] info: resolving (init part 3):  pi-hole.net. A IN
[1736925795] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925795] unbound[16364:0] debug: removing 1 labels
[1736925795] unbound[16364:0] info: sending query: net. A IN
[1736925795] unbound[16364:0] debug: sending to target: <.> 2001:503:ba3e::2:30#53
[1736925795] unbound[16364:0] debug: cache memory msg=66937 rrset=73828 infra=10184 val=66368 subnet=74504
[1736925796] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925796] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925796] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925796] unbound[16364:0] info: sending query: net. A IN
[1736925796] unbound[16364:0] debug: sending to target: <.> 2001:503:c27::2:30#53
[1736925796] unbound[16364:0] debug: cache memory msg=66937 rrset=73828 infra=10184 val=66368 subnet=74504
[1736925796] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925796] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925796] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925796] unbound[16364:0] info: sending query: net. A IN
[1736925796] unbound[16364:0] debug: sending to target: <.> 2001:500:9f::42#53
[1736925796] unbound[16364:0] debug: cache memory msg=66937 rrset=73828 infra=10184 val=66368 subnet=74504
[1736925796] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925796] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925796] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925796] unbound[16364:0] info: sending query: net. A IN
[1736925796] unbound[16364:0] debug: sending to target: <.> 2001:500:1::53#53
[1736925796] unbound[16364:0] debug: cache memory msg=66937 rrset=73828 infra=10778 val=66368 subnet=74504
[1736925796] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925796] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925796] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925796] unbound[16364:0] info: sending query: net. A IN
[1736925796] unbound[16364:0] debug: sending to target: <.> 2001:7fe::53#53
[1736925796] unbound[16364:0] debug: cache memory msg=66937 rrset=73828 infra=10778 val=66368 subnet=74504
[1736925797] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925797] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925797] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925797] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925797] unbound[16364:0] debug: sending to target: <.> 2801:1b8:10::b#53
[1736925797] unbound[16364:0] debug: cache memory msg=66937 rrset=73828 infra=11372 val=66368 subnet=74504
[1736925797] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925797] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925797] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925797] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925797] unbound[16364:0] debug: sending to target: <.> 2801:1b8:10::b#53
[1736925797] unbound[16364:0] debug: cache memory msg=66937 rrset=73828 infra=11372 val=66368 subnet=74504
[1736925798] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925798] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925798] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925798] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925798] unbound[16364:0] debug: sending to target: <.> 2001:500:2::c#53
[1736925798] unbound[16364:0] debug: cache memory msg=66937 rrset=73828 infra=11669 val=66368 subnet=74504
[1736925798] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925798] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925798] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925798] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925798] unbound[16364:0] debug: sending to target: <.> 2001:500:2::c#53
[1736925798] unbound[16364:0] debug: cache memory msg=66937 rrset=73828 infra=11669 val=66368 subnet=74504
[1736925799] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925799] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925799] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925799] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925799] unbound[16364:0] debug: sending to target: <.> 170.247.170.2#53
[1736925799] unbound[16364:0] debug: cache memory msg=66937 rrset=73828 infra=11966 val=66368 subnet=74504
[1736925799] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925799] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925799] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925799] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925799] unbound[16364:0] debug: sending to target: <.> 192.58.128.30#53
[1736925799] unbound[16364:0] debug: cache memory msg=66937 rrset=73828 infra=11966 val=66368 subnet=74504
[1736925799] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1736925799] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925799] unbound[16364:0] info: response for pi-hole.net. A IN
[1736925799] unbound[16364:0] info: reply from <.> 192.58.128.30#53
[1736925799] unbound[16364:0] info: query response was REFERRAL
[1736925799] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925799] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925799] unbound[16364:0] debug: sending to target: <net.> 2001:503:d414::30#53
[1736925799] unbound[16364:0] debug: cache memory msg=66937 rrset=81855 infra=12560 val=66368 subnet=74504
[1736925799] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1736925799] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925799] unbound[16364:0] info: response for pi-hole.net. A IN
[1736925799] unbound[16364:0] info: reply from <.> 170.247.170.2#53
[1736925799] unbound[16364:0] info: query response was REFERRAL
[1736925799] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925799] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925799] unbound[16364:0] debug: sending to target: <net.> 2001:503:eea3::30#53
[1736925799] unbound[16364:0] debug: cache memory msg=66937 rrset=81855 infra=12861 val=66368 subnet=74504
[1736925800] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925800] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925800] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925800] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925800] unbound[16364:0] debug: sending to target: <net.> 2001:502:7094::30#53
[1736925800] unbound[16364:0] debug: cache memory msg=66937 rrset=81855 infra=13162 val=66368 subnet=74504
[1736925800] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925800] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925800] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925800] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925800] unbound[16364:0] debug: sending to target: <net.> 2001:500:d937::30#53
[1736925800] unbound[16364:0] debug: cache memory msg=66937 rrset=81855 infra=13162 val=66368 subnet=74504
[1736925800] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925800] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925800] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925800] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925800] unbound[16364:0] debug: sending to target: <net.> 2001:502:1ca1::30#53
[1736925800] unbound[16364:0] debug: cache memory msg=66937 rrset=81855 infra=13764 val=66368 subnet=74504
[1736925800] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925800] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925800] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925800] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925800] unbound[16364:0] debug: sending to target: <net.> 2001:503:a83e::2:30#53
[1736925800] unbound[16364:0] debug: cache memory msg=66937 rrset=81855 infra=13764 val=66368 subnet=74504
[1736925800] unbound[16364:0] debug: subnetcache[module 0] operate: extstate:module_state_initial event:module_event_new
[1736925800] unbound[16364:0] info: subnetcache operate: query pi-hole.net. A IN
[1736925800] unbound[16364:0] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1736925800] unbound[16364:0] info: validator operate: query pi-hole.net. A IN
[1736925800] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_state_initial event:module_event_pass
[1736925800] unbound[16364:0] info: resolving pi-hole.net. A IN
[1736925800] unbound[16364:0] info: resolving (init part 2):  pi-hole.net. A IN
[1736925800] unbound[16364:0] info: resolving (init part 3):  pi-hole.net. A IN
[1736925800] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925800] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925800] unbound[16364:0] debug: sending to target: <net.> 2001:502:8cc::30#53
[1736925800] unbound[16364:0] debug: cache memory msg=66937 rrset=81855 infra=14366 val=66368 subnet=74504
[1736925801] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925801] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925801] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925801] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925801] unbound[16364:0] debug: sending to target: <net.> 2001:502:7094::30#53
[1736925801] unbound[16364:0] debug: cache memory msg=66937 rrset=81855 infra=14667 val=66368 subnet=74504
[1736925801] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925801] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925801] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925801] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925801] unbound[16364:0] debug: sending to target: <net.> 2001:503:39c1::30#53
[1736925801] unbound[16364:0] debug: cache memory msg=66937 rrset=81855 infra=14667 val=66368 subnet=74504
[1736925801] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925801] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925801] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925801] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925801] unbound[16364:0] debug: sending to target: <net.> 2001:500:856e::30#53
[1736925801] unbound[16364:0] debug: cache memory msg=66937 rrset=81855 infra=14968 val=66368 subnet=74504
[1736925802] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925802] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925802] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925802] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925802] unbound[16364:0] debug: sending to target: <net.> 2001:503:231d::2:30#53
[1736925802] unbound[16364:0] debug: cache memory msg=66937 rrset=81855 infra=15269 val=66368 subnet=74504
[1736925802] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925802] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925802] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925802] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925802] unbound[16364:0] debug: sending to target: <net.> 2001:503:d2d::30#53
[1736925802] unbound[16364:0] debug: cache memory msg=66937 rrset=81855 infra=15570 val=66368 subnet=74504
[1736925803] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925803] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925803] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925803] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925803] unbound[16364:0] debug: sending to target: <net.> 2001:503:231d::2:30#53
[1736925803] unbound[16364:0] debug: cache memory msg=66937 rrset=81855 infra=15871 val=66368 subnet=74504
[1736925803] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925803] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925803] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925803] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925803] unbound[16364:0] debug: sending to target: <net.> 2001:502:8cc::30#53
[1736925803] unbound[16364:0] debug: cache memory msg=66937 rrset=81855 infra=15871 val=66368 subnet=74504
[1736925803] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925803] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925803] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925803] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925803] unbound[16364:0] debug: sending to target: <net.> 192.52.178.30#53
[1736925803] unbound[16364:0] debug: cache memory msg=66937 rrset=81855 infra=15871 val=66368 subnet=74504
[1736925803] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1736925803] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925803] unbound[16364:0] info: response for pi-hole.net. A IN
[1736925803] unbound[16364:0] info: reply from <net.> 192.52.178.30#53
[1736925803] unbound[16364:0] info: query response was REFERRAL
[1736925803] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925803] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925803] unbound[16364:0] debug: sending to target: <pi-hole.net.> 2600:9000:5303:f100::1#53
[1736925803] unbound[16364:0] debug: cache memory msg=66937 rrset=85087 infra=16172 val=67176 subnet=74504
[1736925803] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925803] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925803] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925803] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925803] unbound[16364:0] debug: sending to target: <net.> 2001:503:83eb::30#53
[1736925803] unbound[16364:0] debug: cache memory msg=66937 rrset=85087 infra=16481 val=67176 subnet=74504
[1736925803] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925803] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925803] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925803] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925803] unbound[16364:0] debug: sending to target: <pi-hole.net.> 2600:9000:5304:7d00::1#53
[1736925803] unbound[16364:0] debug: cache memory msg=66937 rrset=85087 infra=16782 val=67176 subnet=74504
[1736925803] unbound[16364:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply
[1736925803] unbound[16364:0] info: iterator operate: query pi-hole.net. A IN
[1736925803] unbound[16364:0] info: processQueryTargets: pi-hole.net. A IN
[1736925803] unbound[16364:0] info: sending query: pi-hole.net. A IN
[1736925803] unbound[16364:0] debug: sending to target: <net.> 2001:501:b1f9::30#53

It seems to me I have a problem with ipv6. I can't ping6 the Ipv6 addresses.
I have disabled the options do-ip6 and prefer-ip6 for now and can't reproduce it anymore. I have full IPv6 on my network. Could it be that I only configured an ULA address asnd no GUA address for the pi? I can't think why that schouldn't work, maybe I lack some networking knowledge for IPv6.

I know, but I wanted to manage and update the file myself, since I don't know how often/fast the package is updated for Raspian/Debian if the file got changed. That directive should not be a problem.

If I test a dnssec fail from the docs, I still get a communication error:

pi@pihole:~ $ dig fail01.dnssec.works @127.0.0.1 -p 5335
;; communications error to 127.0.0.1#5335: timed out
;; communications error to 127.0.0.1#5335: timed out
;; communications error to 127.0.0.1#5335: timed out

; <<>> DiG 9.18.28-1~deb12u2-Debian <<>> fail01.dnssec.works @127.0.0.1 -p 5335
;; global options: +cmd
;; no servers could be reached
pi@pihole:~ $ cat /var/log/unbound/unbound.log 
[1736927146] unbound[16736:0] debug: module config: "subnetcache validator iterator"
[1736927146] unbound[16736:0] notice: init module 0: subnetcache
[1736927146] unbound[16736:0] warning: subnetcache: prefetch is set but not working for data originating from the subnet module cache.
[1736927146] unbound[16736:0] debug: subnetcache: option registered (8)
[1736927146] unbound[16736:0] notice: init module 1: validator
[1736927146] unbound[16736:0] notice: init module 2: iterator
[1736927146] unbound[16736:0] debug: target fetch policy for level 0 is 3
[1736927146] unbound[16736:0] debug: target fetch policy for level 1 is 2
[1736927146] unbound[16736:0] debug: target fetch policy for level 2 is 1
[1736927146] unbound[16736:0] debug: target fetch policy for level 3 is 0
[1736927146] unbound[16736:0] debug: target fetch policy for level 4 is 0
[1736927146] unbound[16736:0] debug: Reading root hints from /var/lib/unbound/root.hints
[1736927146] unbound[16736:0] info: DelegationPoint<.>: 13 names (0 missing), 26 addrs (0 result, 26 avail) parentNS
[1736927146] unbound[16736:0] debug: cache memory msg=66072 rrset=66072 infra=7808 val=66368 subnet=74504
[1736927146] unbound[16736:0] info: start of service (unbound 1.17.1).
[1736927150] unbound[16736:0] debug: subnetcache[module 0] operate: extstate:module_state_initial event:module_event_new
[1736927150] unbound[16736:0] info: subnetcache operate: query fail01.dnssec.works. A IN
[1736927150] unbound[16736:0] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1736927150] unbound[16736:0] info: validator operate: query fail01.dnssec.works. A IN
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_state_initial event:module_event_pass
[1736927150] unbound[16736:0] info: resolving fail01.dnssec.works. A IN
[1736927150] unbound[16736:0] info: priming . IN NS
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_state_initial event:module_event_pass
[1736927150] unbound[16736:0] info: iterator operate: query . NS IN
[1736927150] unbound[16736:0] info: processQueryTargets: . NS IN
[1736927150] unbound[16736:0] info: sending query: . NS IN
[1736927150] unbound[16736:0] debug: sending to target: <.> 192.203.230.10#53
[1736927150] unbound[16736:0] debug: cache memory msg=66072 rrset=66072 infra=7808 val=66368 subnet=74504
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1736927150] unbound[16736:0] info: iterator operate: query . NS IN
[1736927150] unbound[16736:0] info: response for . NS IN
[1736927150] unbound[16736:0] info: reply from <.> 192.203.230.10#53
[1736927150] unbound[16736:0] info: query response was ANSWER
[1736927150] unbound[16736:0] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_moddone
[1736927150] unbound[16736:0] info: validator operate: query . NS IN
[1736927150] unbound[16736:0] debug: subnetcache[module 0] operate: extstate:module_state_initial event:module_event_moddone
[1736927150] unbound[16736:0] info: subnetcache operate: query . NS IN
[1736927150] unbound[16736:0] info: priming successful for . NS IN
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_wait_subquery event:module_event_pass
[1736927150] unbound[16736:0] info: iterator operate: query fail01.dnssec.works. A IN
[1736927150] unbound[16736:0] info: resolving (init part 2):  fail01.dnssec.works. A IN
[1736927150] unbound[16736:0] info: resolving (init part 3):  fail01.dnssec.works. A IN
[1736927150] unbound[16736:0] info: processQueryTargets: fail01.dnssec.works. A IN
[1736927150] unbound[16736:0] debug: removing 2 labels
[1736927150] unbound[16736:0] info: sending query: works. A IN
[1736927150] unbound[16736:0] debug: sending to target: <.> 202.12.27.33#53
[1736927150] unbound[16736:0] debug: cache memory msg=66937 rrset=73828 infra=8105 val=66368 subnet=74504
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1736927150] unbound[16736:0] info: iterator operate: query fail01.dnssec.works. A IN
[1736927150] unbound[16736:0] info: response for fail01.dnssec.works. A IN
[1736927150] unbound[16736:0] info: reply from <.> 202.12.27.33#53
[1736927150] unbound[16736:0] info: query response was REFERRAL
[1736927150] unbound[16736:0] info: processQueryTargets: fail01.dnssec.works. A IN
[1736927150] unbound[16736:0] debug: removing 1 labels
[1736927150] unbound[16736:0] info: sending query: dnssec.works. A IN
[1736927150] unbound[16736:0] debug: sending to target: <works.> 161.232.12.6#53
[1736927150] unbound[16736:0] debug: cache memory msg=66937 rrset=77881 infra=8402 val=66368 subnet=74504
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1736927150] unbound[16736:0] info: iterator operate: query fail01.dnssec.works. A IN
[1736927150] unbound[16736:0] info: response for fail01.dnssec.works. A IN
[1736927150] unbound[16736:0] info: reply from <works.> 161.232.12.6#53
[1736927150] unbound[16736:0] info: query response was REFERRAL
[1736927150] unbound[16736:0] info: processQueryTargets: fail01.dnssec.works. A IN
[1736927150] unbound[16736:0] info: new target ns5.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] info: new target ns3.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_state_initial event:module_event_pass
[1736927150] unbound[16736:0] info: iterator operate: query ns5.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] info: resolving ns5.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] info: resolving (init part 2):  ns5.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] info: resolving (init part 3):  ns5.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] info: processQueryTargets: ns5.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] debug: removing 2 labels
[1736927150] unbound[16736:0] info: sending query: org. A IN
[1736927150] unbound[16736:0] debug: sending to target: <.> 192.112.36.4#53
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_state_initial event:module_event_pass
[1736927150] unbound[16736:0] info: iterator operate: query ns3.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] info: resolving ns3.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] info: resolving (init part 2):  ns3.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] info: resolving (init part 3):  ns3.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] info: processQueryTargets: ns3.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] debug: removing 2 labels
[1736927150] unbound[16736:0] info: sending query: org. A IN
[1736927150] unbound[16736:0] debug: sending to target: <.> 198.41.0.4#53
[1736927150] unbound[16736:0] debug: cache memory msg=66937 rrset=78654 infra=8705 val=66368 subnet=74504
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1736927150] unbound[16736:0] info: iterator operate: query ns3.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] info: response for ns3.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] info: reply from <.> 198.41.0.4#53
[1736927150] unbound[16736:0] info: query response was REFERRAL
[1736927150] unbound[16736:0] info: processQueryTargets: ns3.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] debug: removing 1 labels
[1736927150] unbound[16736:0] info: sending query: myinfrastructure.org. A IN
[1736927150] unbound[16736:0] debug: sending to target: <org.> 199.19.53.1#53
[1736927150] unbound[16736:0] debug: cache memory msg=66937 rrset=82856 infra=9299 val=66368 subnet=74504
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1736927150] unbound[16736:0] info: iterator operate: query ns5.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] info: response for ns5.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] info: reply from <.> 192.112.36.4#53
[1736927150] unbound[16736:0] info: query response was REFERRAL
[1736927150] unbound[16736:0] info: processQueryTargets: ns5.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] debug: removing 1 labels
[1736927150] unbound[16736:0] info: sending query: myinfrastructure.org. A IN
[1736927150] unbound[16736:0] debug: sending to target: <org.> 199.19.54.1#53
[1736927150] unbound[16736:0] debug: cache memory msg=66937 rrset=82856 infra=9600 val=66368 subnet=74504
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1736927150] unbound[16736:0] info: iterator operate: query ns5.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] info: response for ns5.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] info: reply from <org.> 199.19.54.1#53
[1736927150] unbound[16736:0] info: query response was REFERRAL
[1736927150] unbound[16736:0] info: processQueryTargets: ns5.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] info: new target ns.udag.de. A IN
[1736927150] unbound[16736:0] info: new target ns.udag.net. A IN
[1736927150] unbound[16736:0] info: sending query: ns5.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] debug: sending to target: <myinfrastructure.org.> 176.97.158.91#53
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_state_initial event:module_event_pass
[1736927150] unbound[16736:0] info: iterator operate: query ns.udag.de. A IN
[1736927150] unbound[16736:0] info: resolving ns.udag.de. A IN
[1736927150] unbound[16736:0] info: resolving (init part 2):  ns.udag.de. A IN
[1736927150] unbound[16736:0] info: resolving (init part 3):  ns.udag.de. A IN
[1736927150] unbound[16736:0] info: processQueryTargets: ns.udag.de. A IN
[1736927150] unbound[16736:0] debug: removing 2 labels
[1736927150] unbound[16736:0] info: sending query: de. A IN
[1736927150] unbound[16736:0] debug: sending to target: <.> 202.12.27.33#53
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_state_initial event:module_event_pass
[1736927150] unbound[16736:0] info: iterator operate: query ns.udag.net. A IN
[1736927150] unbound[16736:0] info: resolving ns.udag.net. A IN
[1736927150] unbound[16736:0] info: resolving (init part 2):  ns.udag.net. A IN
[1736927150] unbound[16736:0] info: resolving (init part 3):  ns.udag.net. A IN
[1736927150] unbound[16736:0] info: processQueryTargets: ns.udag.net. A IN
[1736927150] unbound[16736:0] debug: removing 2 labels
[1736927150] unbound[16736:0] info: sending query: net. A IN
[1736927150] unbound[16736:0] debug: sending to target: <.> 192.5.5.241#53
[1736927150] unbound[16736:0] debug: cache memory msg=66937 rrset=84659 infra=9901 val=67176 subnet=74504
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1736927150] unbound[16736:0] info: iterator operate: query ns.udag.net. A IN
[1736927150] unbound[16736:0] info: response for ns.udag.net. A IN
[1736927150] unbound[16736:0] info: reply from <.> 192.5.5.241#53
[1736927150] unbound[16736:0] info: query response was REFERRAL
[1736927150] unbound[16736:0] info: processQueryTargets: ns.udag.net. A IN
[1736927150] unbound[16736:0] debug: removing 1 labels
[1736927150] unbound[16736:0] info: sending query: udag.net. A IN
[1736927150] unbound[16736:0] debug: sending to target: <net.> 192.35.51.30#53
[1736927150] unbound[16736:0] debug: cache memory msg=66937 rrset=92686 infra=10516 val=67176 subnet=74504
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1736927150] unbound[16736:0] info: iterator operate: query ns5.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] info: response for ns5.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] info: reply from <myinfrastructure.org.> 176.97.158.91#53
[1736927150] unbound[16736:0] info: query response was ANSWER
[1736927150] unbound[16736:0] info: finishing processing for ns5.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_moddone
[1736927150] unbound[16736:0] info: validator operate: query ns5.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] debug: subnetcache[module 0] operate: extstate:module_state_initial event:module_event_moddone
[1736927150] unbound[16736:0] info: subnetcache operate: query ns5.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_wait_subquery event:module_event_pass
[1736927150] unbound[16736:0] info: iterator operate: query fail01.dnssec.works. A IN
[1736927150] unbound[16736:0] info: processQueryTargets: fail01.dnssec.works. A IN
[1736927150] unbound[16736:0] info: sending query: fail01.dnssec.works. A IN
[1736927150] unbound[16736:0] debug: sending to target: <dnssec.works.> 185.92.221.212#53
[1736927150] unbound[16736:0] debug: cache memory msg=67203 rrset=92942 infra=10817 val=67176 subnet=74504
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1736927150] unbound[16736:0] info: iterator operate: query ns.udag.de. A IN
[1736927150] unbound[16736:0] info: response for ns.udag.de. A IN
[1736927150] unbound[16736:0] info: reply from <.> 202.12.27.33#53
[1736927150] unbound[16736:0] info: query response was REFERRAL
[1736927150] unbound[16736:0] info: processQueryTargets: ns.udag.de. A IN
[1736927150] unbound[16736:0] debug: removing 1 labels
[1736927150] unbound[16736:0] info: sending query: udag.de. A IN
[1736927150] unbound[16736:0] debug: sending to target: <de.> 194.146.107.6#53
[1736927150] unbound[16736:0] debug: cache memory msg=67203 rrset=96881 infra=11127 val=67176 subnet=74504
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1736927150] unbound[16736:0] info: iterator operate: query ns.udag.net. A IN
[1736927150] unbound[16736:0] info: response for ns.udag.net. A IN
[1736927150] unbound[16736:0] info: reply from <net.> 192.35.51.30#53
[1736927150] unbound[16736:0] info: query response was REFERRAL
[1736927150] unbound[16736:0] info: processQueryTargets: ns.udag.net. A IN
[1736927150] unbound[16736:0] info: new target ns.udag.de. A IN
[1736927150] unbound[16736:0] info: sending query: ns.udag.net. A IN
[1736927150] unbound[16736:0] debug: sending to target: <udag.net.> 176.97.158.91#53
[1736927150] unbound[16736:0] debug: cache memory msg=67203 rrset=98528 infra=11427 val=67847 subnet=74504
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1736927150] unbound[16736:0] info: iterator operate: query fail01.dnssec.works. A IN
[1736927150] unbound[16736:0] info: response for fail01.dnssec.works. A IN
[1736927150] unbound[16736:0] info: reply from <dnssec.works.> 185.92.221.212#53
[1736927150] unbound[16736:0] info: query response was ANSWER
[1736927150] unbound[16736:0] info: finishing processing for fail01.dnssec.works. A IN
[1736927150] unbound[16736:0] debug: validator[module 1] operate: extstate:module_wait_module event:module_event_moddone
[1736927150] unbound[16736:0] info: validator operate: query fail01.dnssec.works. A IN
[1736927150] unbound[16736:0] info: prime trust anchor
[1736927150] unbound[16736:0] info: generate keytag query _ta-4f66. NULL IN
[1736927150] unbound[16736:0] debug: subnetcache[module 0] operate: extstate:module_state_initial event:module_event_pass
[1736927150] unbound[16736:0] info: subnetcache operate: query . DNSKEY IN
[1736927150] unbound[16736:0] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1736927150] unbound[16736:0] info: validator operate: query . DNSKEY IN
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_state_initial event:module_event_pass
[1736927150] unbound[16736:0] info: resolving . DNSKEY IN
[1736927150] unbound[16736:0] info: resolving (init part 2):  . DNSKEY IN
[1736927150] unbound[16736:0] info: resolving (init part 3):  . DNSKEY IN
[1736927150] unbound[16736:0] info: processQueryTargets: . DNSKEY IN
[1736927150] unbound[16736:0] info: sending query: . DNSKEY IN
[1736927150] unbound[16736:0] debug: sending to target: <.> 192.58.128.30#53
[1736927150] unbound[16736:0] debug: subnetcache[module 0] operate: extstate:module_state_initial event:module_event_pass
[1736927150] unbound[16736:0] info: subnetcache operate: query _ta-4f66. NULL IN
[1736927150] unbound[16736:0] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1736927150] unbound[16736:0] info: validator operate: query _ta-4f66. NULL IN
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_state_initial event:module_event_pass
[1736927150] unbound[16736:0] info: resolving _ta-4f66. NULL IN
[1736927150] unbound[16736:0] info: resolving (init part 2):  _ta-4f66. NULL IN
[1736927150] unbound[16736:0] info: resolving (init part 3):  _ta-4f66. NULL IN
[1736927150] unbound[16736:0] info: processQueryTargets: _ta-4f66. NULL IN
[1736927150] unbound[16736:0] info: sending query: _ta-4f66. A IN
[1736927150] unbound[16736:0] debug: sending to target: <.> 193.0.14.129#53
[1736927150] unbound[16736:0] debug: cache memory msg=67488 rrset=99361 infra=11733 val=67847 subnet=74504
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1736927150] unbound[16736:0] info: iterator operate: query ns.udag.de. A IN
[1736927150] unbound[16736:0] info: response for ns.udag.de. A IN
[1736927150] unbound[16736:0] info: reply from <de.> 194.146.107.6#53
[1736927150] unbound[16736:0] info: query response was REFERRAL
[1736927150] unbound[16736:0] info: processQueryTargets: ns.udag.de. A IN
[1736927150] unbound[16736:0] info: sending query: ns.udag.de. A IN
[1736927150] unbound[16736:0] debug: sending to target: <udag.de.> 176.97.158.8#53
[1736927150] unbound[16736:0] debug: cache memory msg=67488 rrset=101145 infra=12327 val=68514 subnet=74504
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1736927150] unbound[16736:0] info: iterator operate: query _ta-4f66. NULL IN
[1736927150] unbound[16736:0] info: response for _ta-4f66. NULL IN
[1736927150] unbound[16736:0] info: reply from <.> 193.0.14.129#53
[1736927150] unbound[16736:0] info: query response was NXDOMAIN ANSWER
[1736927150] unbound[16736:0] info: finishing processing for _ta-4f66. NULL IN
[1736927150] unbound[16736:0] debug: validator[module 1] operate: extstate:module_wait_module event:module_event_moddone
[1736927150] unbound[16736:0] info: validator operate: query _ta-4f66. NULL IN
[1736927150] unbound[16736:0] debug: subnetcache[module 0] operate: extstate:module_wait_module event:module_event_moddone
[1736927150] unbound[16736:0] info: subnetcache operate: query _ta-4f66. NULL IN
[1736927150] unbound[16736:0] debug: cache memory msg=67488 rrset=102280 infra=12632 val=68514 subnet=74504
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1736927150] unbound[16736:0] info: iterator operate: query . DNSKEY IN
[1736927150] unbound[16736:0] info: response for . DNSKEY IN
[1736927150] unbound[16736:0] info: reply from <.> 192.58.128.30#53
[1736927150] unbound[16736:0] info: query response was ANSWER
[1736927150] unbound[16736:0] info: finishing processing for . DNSKEY IN
[1736927150] unbound[16736:0] debug: validator[module 1] operate: extstate:module_wait_module event:module_event_moddone
[1736927150] unbound[16736:0] info: validator operate: query . DNSKEY IN
[1736927150] unbound[16736:0] debug: subnetcache[module 0] operate: extstate:module_wait_module event:module_event_moddone
[1736927150] unbound[16736:0] info: subnetcache operate: query . DNSKEY IN
[1736927150] unbound[16736:0] info: validate keys with anchor(DS): sec_status_secure
[1736927150] unbound[16736:0] info: Successfully primed trust anchor . DNSKEY IN
[1736927150] unbound[16736:0] debug: validator[module 1] operate: extstate:module_wait_subquery event:module_event_pass
[1736927150] unbound[16736:0] info: validator operate: query fail01.dnssec.works. A IN
[1736927150] unbound[16736:0] info: validated DS works. DS IN
[1736927150] unbound[16736:0] debug: subnetcache[module 0] operate: extstate:module_state_initial event:module_event_pass
[1736927150] unbound[16736:0] info: subnetcache operate: query works. DNSKEY IN
[1736927150] unbound[16736:0] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1736927150] unbound[16736:0] info: validator operate: query works. DNSKEY IN
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_state_initial event:module_event_pass
[1736927150] unbound[16736:0] info: resolving works. DNSKEY IN
[1736927150] unbound[16736:0] info: resolving (init part 2):  works. DNSKEY IN
[1736927150] unbound[16736:0] info: resolving (init part 3):  works. DNSKEY IN
[1736927150] unbound[16736:0] info: processQueryTargets: works. DNSKEY IN
[1736927150] unbound[16736:0] info: sending query: works. DNSKEY IN
[1736927150] unbound[16736:0] debug: sending to target: <works.> 65.22.26.6#53
[1736927150] unbound[16736:0] debug: cache memory msg=67729 rrset=103652 infra=12632 val=69926 subnet=74504
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1736927150] unbound[16736:0] info: iterator operate: query ns.udag.net. A IN
[1736927150] unbound[16736:0] info: response for ns.udag.net. A IN
[1736927150] unbound[16736:0] info: reply from <udag.net.> 176.97.158.91#53
[1736927150] unbound[16736:0] info: query response was ANSWER
[1736927150] unbound[16736:0] info: finishing processing for ns.udag.net. A IN
[1736927150] unbound[16736:0] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_moddone
[1736927150] unbound[16736:0] info: validator operate: query ns.udag.net. A IN
[1736927150] unbound[16736:0] debug: subnetcache[module 0] operate: extstate:module_state_initial event:module_event_moddone
[1736927150] unbound[16736:0] info: subnetcache operate: query ns.udag.net. A IN
[1736927150] unbound[16736:0] debug: cache memory msg=67982 rrset=103652 infra=12632 val=69926 subnet=74504
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1736927150] unbound[16736:0] info: iterator operate: query ns3.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] info: response for ns3.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] info: reply from <org.> 199.19.53.1#53
[1736927150] unbound[16736:0] info: query response was REFERRAL
[1736927150] unbound[16736:0] info: processQueryTargets: ns3.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] info: sending query: ns3.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] debug: sending to target: <myinfrastructure.org.> 176.97.158.91#53
[1736927150] unbound[16736:0] debug: cache memory msg=67982 rrset=103652 infra=12632 val=69926 subnet=74504
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1736927150] unbound[16736:0] info: iterator operate: query ns.udag.de. A IN
[1736927150] unbound[16736:0] info: response for ns.udag.de. A IN
[1736927150] unbound[16736:0] info: reply from <udag.de.> 176.97.158.8#53
[1736927150] unbound[16736:0] info: query response was ANSWER
[1736927150] unbound[16736:0] info: finishing processing for ns.udag.de. A IN
[1736927150] unbound[16736:0] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_moddone
[1736927150] unbound[16736:0] info: validator operate: query ns.udag.de. A IN
[1736927150] unbound[16736:0] debug: subnetcache[module 0] operate: extstate:module_state_initial event:module_event_moddone
[1736927150] unbound[16736:0] info: subnetcache operate: query ns.udag.de. A IN
[1736927150] unbound[16736:0] debug: cache memory msg=68234 rrset=103652 infra=12632 val=69926 subnet=74504
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1736927150] unbound[16736:0] info: iterator operate: query works. DNSKEY IN
[1736927150] unbound[16736:0] info: response for works. DNSKEY IN
[1736927150] unbound[16736:0] info: reply from <works.> 65.22.26.6#53
[1736927150] unbound[16736:0] info: query response was ANSWER
[1736927150] unbound[16736:0] info: finishing processing for works. DNSKEY IN
[1736927150] unbound[16736:0] debug: validator[module 1] operate: extstate:module_wait_module event:module_event_moddone
[1736927150] unbound[16736:0] info: validator operate: query works. DNSKEY IN
[1736927150] unbound[16736:0] debug: subnetcache[module 0] operate: extstate:module_wait_module event:module_event_moddone
[1736927150] unbound[16736:0] info: subnetcache operate: query works. DNSKEY IN
[1736927150] unbound[16736:0] info: validated DNSKEY works. DNSKEY IN
[1736927150] unbound[16736:0] debug: validator[module 1] operate: extstate:module_wait_subquery event:module_event_pass
[1736927150] unbound[16736:0] info: validator operate: query fail01.dnssec.works. A IN
[1736927150] unbound[16736:0] info: validated DS dnssec.works. DS IN
[1736927150] unbound[16736:0] debug: subnetcache[module 0] operate: extstate:module_state_initial event:module_event_pass
[1736927150] unbound[16736:0] info: subnetcache operate: query dnssec.works. DNSKEY IN
[1736927150] unbound[16736:0] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1736927150] unbound[16736:0] info: validator operate: query dnssec.works. DNSKEY IN
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_state_initial event:module_event_pass
[1736927150] unbound[16736:0] info: resolving dnssec.works. DNSKEY IN
[1736927150] unbound[16736:0] info: resolving (init part 2):  dnssec.works. DNSKEY IN
[1736927150] unbound[16736:0] info: resolving (init part 3):  dnssec.works. DNSKEY IN
[1736927150] unbound[16736:0] info: processQueryTargets: dnssec.works. DNSKEY IN
[1736927150] unbound[16736:0] info: new target ns3.myinfrastructure.org. A IN
[1736927150] unbound[16736:0] info: sending query: dnssec.works. DNSKEY IN
[1736927150] unbound[16736:0] debug: sending to target: <dnssec.works.> 185.92.221.212#53
[1736927150] unbound[16736:0] debug: cache memory msg=68481 rrset=104780 infra=12935 val=71094 subnet=74504
[1736927150] unbound[16736:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply

Complete Log: pi@pihole:~ $ cat /var/log/unbound/unbound.log [1736927146] unbound[16736:0] d - Pastebin.com

From above, you seem to have connectivity problems connecting to the IPv6 root name server addresses:

module_event_noreply ---> no reply, timeout or other error

$ dig +short -x 2001:500:2f::f
f.root-servers.net.
$ dig +short ns .
h.root-servers.net.
j.root-servers.net.
f.root-servers.net.
d.root-servers.net.
a.root-servers.net.
c.root-servers.net.
l.root-servers.net.
g.root-servers.net.
e.root-servers.net.
i.root-servers.net.
m.root-servers.net.
b.root-servers.net.
k.root-servers.net.

Can check with below one:

dig @2001:500:2f::f ns .

When browsing to below site, does it show IPv6 connectivity is being supported upstream by your ISP?

If not, I would suggest to flip below one to default "no" from the guide:

Can run below one to apply:

sudo systemctl restart unbound.service

1 Like

Oops, I missed above bit somehow!

Yes the Pi-hole host needs a Global Unicast Address to communicate with anything on the Internet.
But you cant I dont recommend to manually set that IP!
That GUA IP needs to be automatically constructed from the prefix thats delegated from the ISP via the router plus SLAAC.

Below one helps me out to distinct between GUA, ULA and LLA:

1 Like

When via IPv6 works, there are 26 redundant root server IP's available to query:

$ awk '/ ...A / {print $4}' /usr/share/dns/root.hints
198.41.0.4
2001:503:ba3e::2:30
199.9.14.201
2001:500:200::b
192.33.4.12
2001:500:2::c
199.7.91.13
2001:500:2d::d
192.203.230.10
2001:500:a8::e
192.5.5.241
2001:500:2f::f
192.112.36.4
2001:500:12::d0d
198.97.190.53
2001:500:1::53
192.36.148.17
2001:7fe::53
192.58.128.30
2001:503:c27::2:30
193.0.14.129
2001:7fd::1
199.7.83.42
2001:500:9f::42
202.12.27.33
2001:dc3::35

Which currently runs on 1921 instances via an anycast backbone:

Those root server addresses have not changed and most likely wont change for a long time.
If one is changed, you still have the other 25 until the root.hints file is updated in APT.

I dont see any profit from maintaining that file yourself.
Only more work and things to go wrong if have it automated via Cron.

EDIT: Totally forgot the changelog:

apt changelog dns-root-data

1 Like

I guess that missing a GUA address was my problem here.
I let that adress be pulled via dhcp and have my ULA still set manual.
I think that shouldn't be a problem with IPv6.
grafik

Seems to be working now:

i have also turned on do-ip6 and prefer-ip6 and it still works like a charm.
The only thing I can't resolve is the sigfail test, but I don't think it matters since it shouldn't resolve correct in any way with dnssec.

pi@pihole:~ $ dig fail01.dnssec.works @127.0.0.1 -p 5335
;; communications error to 127.0.0.1#5335: timed out
[1737011071] unbound[1138:0] info: processQueryTargets: fail01.dnssec.works. A IN
[1737011071] unbound[1138:0] info: sending query: fail01.dnssec.works. A IN
[1737011071] unbound[1138:0] debug: sending to target: <fail01.dnssec.works.> 37.153.96.134#53
[1737011071] unbound[1138:0] debug: cache memory msg=71092 rrset=109286 infra=15415 val=73789 subnet=74504
[1737011071] unbound[1138:0] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_noreply

I thought that should still resolve without any dns response (no IP returned) regarding the docs unbound - Pi-hole documentation

I believe most of us experience the same.
Just keep hitting it a couple of times until you get the SERVFAIL status returned.

1 Like

Yes, it works after a few times.

All of my questions are now answered, thanks for the help.

1 Like

Marked your reply as a "solution" if you dont mind?

Thats totally fine :slightly_smiling_face:

1 Like

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