Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

many problems with unbound resolving dns names #1133

Open
myssv opened this issue Aug 30, 2024 · 19 comments
Open

many problems with unbound resolving dns names #1133

myssv opened this issue Aug 30, 2024 · 19 comments

Comments

@myssv
Copy link

myssv commented Aug 30, 2024 •
edited
Loading

Describe the bug
after installing unbound and connecting it with my adguard I have problems with many websites, which are not working anymore. For example support.google.com. The name is not resolved.

To reproduce
When I only habe unbound as the upstream dns server in adguard teh domain is not resolved. Adding an other DNS server to adguard everything is fine.

System:

  • Unbound version: 1.17.1
  • OS: Debiar 12
  • unbound -V output:
root@AdGuard:~# unbound -V
Version 1.17.1

Configure line: --build=x86_64-linux-gnu --prefix=/usr --includedir=${prefix}/include --mandir=${prefix}/share/man --infodir=${prefix}/share/info --sysconfdir=/etc --localstatedir=/var --disable-option-checking --disable-silent-rules --libdir=${prefix}/lib/x86_64-linux-gnu --runstatedir=/run --disable-maintainer-mode --disable-dependency-tracking --with-pythonmodule --with-pyunbound --enable-subnet --enable-dnstap --enable-systemd --with-libnghttp2 --with-chroot-dir= --with-dnstap-socket-path=/run/dnstap.sock --disable-rpath --with-pidfile=/run/unbound.pid --with-libevent --enable-tfo-client --with-rootkey-file=/usr/share/dns/root.key --enable-tfo-server
Linked libs: libevent 2.1.12-stable (it uses epoll), OpenSSL 3.0.13 30 Jan 2024
Linked modules: dns64 python subnetcache respip validator iterator
TCP Fastopen feature available

BSD licensed, see LICENSE in source package for details.
Report bugs to [email protected] or https://github.com/NLnetLabs/unbound/issues

Examples with only unbound:

PS C:\Users\Volke> ping support.google.com
Ping-Anforderung konnte Host "support.google.com" nicht finden. Überprüfen Sie den Namen, und versuchen Sie es erneut.

PS C:\Users\Volke> ping google.com

Ping wird ausgeführt für google.com [142.251.209.142] mit 32 Bytes Daten:
Antwort von 142.251.209.142: Bytes=32 Zeit=3ms TTL=118
Antwort von 142.251.209.142: Bytes=32 Zeit=3ms TTL=118
Antwort von 142.251.209.142: Bytes=32 Zeit=3ms TTL=118
Antwort von 142.251.209.142: Bytes=32 Zeit=4ms TTL=118

Ping-Statistik für 142.251.209.142:
    Pakete: Gesendet = 4, Empfangen = 4, Verloren = 0
    (0% Verlust),
Ca. Zeitangaben in Millisek.:
    Minimum = 3ms, Maximum = 4ms, Mittelwert = 3ms
@wcawijngaards
Copy link
Member

With the command 'dig' the server can be inspected to see what answers it gives. With dig '@' and the IP address and the query to look at. For unbound, the verbosity can be increased to say, level 4 or 5. This prints more details, and that may provide useful information if you look at it; in particular it prints the 'dig' like output from the upstream lookups and what it then does with that. The log-servfail: yes option is useful in that it prints single-line error messages that talk about failed lookups.

@myssv
Copy link
Author

myssv commented Aug 30, 2024 •
edited by wcawijngaards
Loading

This is what I got:

root@AdGuard:~# dig @192.168.115.210 support.google.com

; <<>> DiG 9.18.28-1~deb12u2-Debian <<>> @192.168.115.210 support.google.com
; (1 server found)
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 32446
;; flags: qr rd ra; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 1232
;; QUESTION SECTION:
;support.google.com.		IN	A

;; Query time: 47 msec
;; SERVER: 192.168.115.210#53(192.168.115.210) (UDP)
;; WHEN: Fri Aug 30 10:16:10 CEST 2024
;; MSG SIZE  rcvd: 47

@wcawijngaards
Copy link
Member

Surprising result, it prints no error, but also no data. It must have got a response somehow with zero data for this item. Is there items in the unbound configuration that deal with the name, support.google.com ? Like local-zone or forward or stub items, those would redirect the answer to a different value.

@wcawijngaards
Copy link
Member

The config items, log-local-actions: yes and log-queries: yes and log-replies: yes can be useful here. With log local actions, it is visible that a local data or local zone action is performed, and the query and reply are then logged. Also the higher verbosity is then useful, so that the unbound logs contain relevant data about the question.

@myssv
Copy link
Author

myssv commented Aug 30, 2024

I have 4 conf-files here:

adguardhome.comf

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

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

    # 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 Interftreternet 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
    module-config: "validator iterator"
    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>
    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.0.0.0/8
    private-address: 10.0.0.0/8

    # eigene Anpassungen
    qname-minimisation: yes

hyperlocal.conf

# =========================================================
# Auth Zone for the Internet root zone "."
# See RFC 8806 - Running a Root Server Local to a Resolver
# https://www.rfc-editor.org/rfc/rfc8806.html
# =========================================================
auth-zone:
    name: "."
    master: "b.root-servers.net"
    master: "c.root-servers.net"
    master: "d.root-servers.net"
    master: "f.root-servers.net"
    master: "g.root-servers.net"
    master: "k.root-servers.net"
    url: https://www.internic.net/domain/root.zone
    fallback-enabled: yes
    for-downstream: no
    for-upstream: yes
    zonefile: "/etc/unbound/root.zone"

remote-control.conf

remote-control:
  control-enable: yes
  # by default the control interface is is 127.0.0.1 and ::1 and port 8953
  # it is possible to use a unix socket too
  control-interface: /run/unbound.ctl

root-auto-trust-abchor-file.conf

server:
    # The following line will configure unbound to perform cryptographic
    # DNSSEC validation using the root trust anchor.
    auto-trust-anchor-file: "/var/lib/unbound/root.key"

@myssv
Copy link
Author

myssv commented Aug 30, 2024

With log local actions, it is visible that a local data or local zone action is performed, and the query and reply are then logged. Also the higher verbosity is then useful, so that the unbound logs contain relevant data about the question.

Sorry, but I have no idea how to do this ... I already added the options to the conf-file, but now?

@wcawijngaards
Copy link
Member

This is not the server that was queried by the dig command, that queried 192.168.115.210, but the configuration is only for 127.0.0.1 with port 5335. That is with the -p <num> port option for 'dig'.

After adding log options, enable the logfile: <name> option to log to a file perhaps, restart the server, and look in the log file, or syslog if not using a file.

@myssv
Copy link
Author

myssv commented Aug 30, 2024

Here are some more outputs:

root@AdGuard:~# ip a
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
    inet6 ::1/128 scope host noprefixroute 
       valid_lft forever preferred_lft forever
2: eth0@if121: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP group default qlen 1000
    link/ether fe:b3:dd:d4:30:c4 brd ff:ff:ff:ff:ff:ff link-netnsid 0
    inet 192.168.115.210/24 brd 192.168.115.255 scope global eth0
       valid_lft forever preferred_lft forever
    inet6 fe80::fcb3:ddff:fed4:30c4/64 scope link 
       valid_lft forever preferred_lft forever


root@AdGuard:~# dig @192.168.115.210 -p 5335 support.google.com
;; communications error to 192.168.115.210#5335: connection refused
;; communications error to 192.168.115.210#5335: connection refused
;; communications error to 192.168.115.210#5335: connection refused

; <<>> DiG 9.18.28-1~deb12u2-Debian <<>> @192.168.115.210 -p 5335 support.google.com
; (1 server found)
;; global options: +cmd
;; no servers could be reached


root@AdGuard:~# dig @127.0.0.1 -p 5335 support.google.com

; <<>> DiG 9.18.28-1~deb12u2-Debian <<>> @127.0.0.1 -p 5335 support.google.com
; (1 server found)
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 29782
;; flags: qr rd ra; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 1232
;; QUESTION SECTION:
;support.google.com.		IN	A

;; Query time: 13 msec
;; SERVER: 127.0.0.1#5335(127.0.0.1) (UDP)
;; WHEN: Fri Aug 30 10:35:45 CEST 2024
;; MSG SIZE  rcvd: 47

@wcawijngaards
Copy link
Member

So the one that is dig @127.0.0.1 -p 5335 support.google.com actually queried the unbound server. It has the same answer. I guess it means looking at the log files to see what is going on, I guess configuration in another file or the upstream gives this answer.

@myssv
Copy link
Author

myssv commented Aug 30, 2024

How to check them?

@wcawijngaards
Copy link
Member

Log files? Enable the options and look for the content of that file? With the less command, it displays the content of a file. Also for config files. There must be something because to have several files they must have been included in another one.

@myssv
Copy link
Author

myssv commented Aug 30, 2024 •
edited
Loading

I hope this helps: Ich habe um 10:58h versucht die Seite zu öffnen

2024-08-30T10:58:03.060303+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: 0RDd mod1 rep **support.google.com**. HTTPS IN
2024-08-30T10:58:03.060346+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: cache memory msg=204364 rrset=433147 infra=230634 val=99053 subnet=0
2024-08-30T10:58:03.060361+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: svcd callbacks end
2024-08-30T10:58:03.060377+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: close of port 25834
2024-08-30T10:58:03.060392+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: close fd 11
2024-08-30T10:58:03.060407+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: serviced send timer
2024-08-30T10:58:03.060421+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: EDNS lookup known=0 vs=0
2024-08-30T10:58:03.060463+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: serviced query UDP timeout=376 msec
2024-08-30T10:58:03.060480+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: inserted new pending reply id=2d61
2024-08-30T10:58:03.060495+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: opened UDP if=0 port=62035
2024-08-30T10:58:03.060511+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] error: udp connect failed: Network is unreachable for 2001:4860:4802:36::a port 53 (len 28)
2024-08-30T10:58:03.060535+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: svcd callbacks start
2024-08-30T10:58:03.060549+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: worker svcd callback for qstate 0x623a0e6b1250
2024-08-30T10:58:03.060562+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: mesh_run: start
2024-08-30T10:58:03.060575+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_noreply
2024-08-30T10:58:03.060591+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: iterator operate: query support.google.com. HTTPS IN
2024-08-30T10:58:03.060605+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: process_response: new external response event
2024-08-30T10:58:03.060618+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
2024-08-30T10:58:03.060631+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: query response was timeout
2024-08-30T10:58:03.060648+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: iter_handle processing q with state QUERY TARGETS STATE
2024-08-30T10:58:03.060661+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: processQueryTargets: support.google.com. HTTPS IN
2024-08-30T10:58:03.060675+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 2
2024-08-30T10:58:03.060689+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: DelegationPoint<google.com.>: 4 names (0 missing), 8 addrs (8 result, 0 avail) cacheNS
2024-08-30T10:58:03.060702+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info:   ns4.google.com. * A AAAA
2024-08-30T10:58:03.060732+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info:   ns3.google.com. * A AAAA
2024-08-30T10:58:03.060747+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info:   ns1.google.com. * A AAAA
2024-08-30T10:58:03.060760+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info:   ns2.google.com. * A AAAA
2024-08-30T10:58:03.060773+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    ip6 2001:4860:4802:34::a port 53 (len 28)
2024-08-30T10:58:03.060803+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    ip4 216.239.34.10 port 53 (len 16)
2024-08-30T10:58:03.060817+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    ip6 2001:4860:4802:32::a port 53 (len 28)
2024-08-30T10:58:03.060830+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    ip4 216.239.32.10 port 53 (len 16)
2024-08-30T10:58:03.060843+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    ip6 2001:4860:4802:36::a port 53 (len 28)
2024-08-30T10:58:03.060857+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    ip4 216.239.36.10 port 53 (len 16)
2024-08-30T10:58:03.060870+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    ip6 2001:4860:4802:38::a port 53 (len 28)
2024-08-30T10:58:03.060883+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    ip4 216.239.38.10 port 53 (len 16)
2024-08-30T10:58:03.060896+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: attempt to get extra 3 targets
2024-08-30T10:58:03.060909+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: rpz: iterator module callback: have_rpz=0
2024-08-30T10:58:03.060922+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: servselect ip4 216.239.38.10 port 53 (len 16)
2024-08-30T10:58:03.060935+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    rtt=156
2024-08-30T10:58:03.060948+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: servselect ip4 216.239.36.10 port 53 (len 16)
2024-08-30T10:58:03.060961+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    rtt=151
2024-08-30T10:58:03.060974+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: servselect ip6 2001:4860:4802:36::a port 53 (len 28)
2024-08-30T10:58:03.060991+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    rtt=376
2024-08-30T10:58:03.061005+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: servselect ip4 216.239.32.10 port 53 (len 16)
2024-08-30T10:58:03.061017+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    rtt=156
2024-08-30T10:58:03.061048+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: servselect ip6 2001:4860:4802:32::a port 53 (len 28)
2024-08-30T10:58:03.061063+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    rtt=376
2024-08-30T10:58:03.061076+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: servselect ip6 2001:4860:4802:34::a port 53 (len 28)
2024-08-30T10:58:03.061088+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    rtt=376
2024-08-30T10:58:03.061101+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: selrtt 151
2024-08-30T10:58:03.061114+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: sending query: support.google.com. HTTPS IN
2024-08-30T10:58:03.061127+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: sending to target: <google.com.> 216.239.34.10#53
2024-08-30T10:58:03.061144+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: dnssec status: not expected
2024-08-30T10:58:03.061158+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: mesh_run: iterator module exit state is module_wait_reply
2024-08-30T10:58:03.061172+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 1 waiting replies, 79 recursion replies sent, 0 replies drop>
2024-08-30T10:58:03.061201+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: average recursion processing time 0.125849 sec
2024-08-30T10:58:03.061222+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: histogram of recursion processing times
2024-08-30T10:58:03.061257+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: [25%]=0.02048 median[50%]=0.0596846 [75%]=0.180224
2024-08-30T10:58:03.061296+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: lower(secs) upper(secs) recursions
2024-08-30T10:58:03.061296+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: lower(secs) upper(secs) recursions
2024-08-30T10:58:03.061321+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info:    0.000000    0.000001 11
2024-08-30T10:58:03.061345+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info:    0.002048    0.004096 1
2024-08-30T10:58:03.061369+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info:    0.008192    0.016384 5
2024-08-30T10:58:03.061393+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info:    0.016384    0.032768 11
2024-08-30T10:58:03.061417+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info:    0.032768    0.065536 14
2024-08-30T10:58:03.061442+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info:    0.065536    0.131072 12
2024-08-30T10:58:03.061466+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info:    0.131072    0.262144 14
2024-08-30T10:58:03.061490+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info:    0.262144    0.524288 8
2024-08-30T10:58:03.061514+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info:    0.524288    1.000000 3
2024-08-30T10:58:03.061540+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: 0RDd mod1 rep support.google.com. HTTPS IN
2024-08-30T10:58:03.061589+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: cache memory msg=204364 rrset=433147 infra=230942 val=99053 subnet=0
2024-08-30T10:58:03.061619+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: svcd callbacks end
2024-08-30T10:58:03.061645+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: serviced send timer
2024-08-30T10:58:03.061669+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: EDNS lookup known=0 vs=0
2024-08-30T10:58:03.061693+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: serviced query UDP timeout=376 msec
2024-08-30T10:58:03.061717+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: inserted new pending reply id=6f09
2024-08-30T10:58:03.061745+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: opened UDP if=0 port=20251
2024-08-30T10:58:03.061774+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: comm point start listening 11 (-1 msec)
2024-08-30T10:58:03.061800+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: 127.0.0.1 support.google.com. A IN
2024-08-30T10:58:03.061826+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: 127.0.0.1 support.google.com. A IN NOERROR 0.000000 1 47
2024-08-30T10:58:03.061853+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: 127.0.0.1 support.google.com. A IN
2024-08-30T10:58:03.061879+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: 127.0.0.1 support.google.com. A IN NOERROR 0.000000 1 47
2024-08-30T10:58:03.061904+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: 127.0.0.1 google.com. HTTPS IN
2024-08-30T10:58:03.061932+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: mesh_run: start
2024-08-30T10:58:03.061957+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new
2024-08-30T10:58:03.061999+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: validator operate: query google.com. HTTPS IN
2024-08-30T10:58:03.062024+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: validator: pass to next module
2024-08-30T10:58:03.062049+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: mesh_run: validator module exit state is module_wait_module
2024-08-30T10:58:03.062074+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass
2024-08-30T10:58:03.062118+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: process_request: new external request event
2024-08-30T10:58:03.062143+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: iter_handle processing q with state INIT REQUEST STATE
2024-08-30T10:58:03.062168+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: resolving google.com. HTTPS IN
2024-08-30T10:58:03.062196+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: request has dependency depth of 0
2024-08-30T10:58:03.062226+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: cache delegation returns delegpt
2024-08-30T10:58:03.062250+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: DelegationPoint<google.com.>: 4 names (0 missing), 8 addrs (0 result, 8 avail) cacheNS
2024-08-30T10:58:03.062276+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info:   ns4.google.com. * A AAAA
2024-08-30T10:58:03.062301+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info:   ns3.google.com. * A AAAA
2024-08-30T10:58:03.062325+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info:   ns1.google.com. * A AAAA
2024-08-30T10:58:03.062349+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info:   ns2.google.com. * A AAAA
2024-08-30T10:58:03.062374+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    ip6 2001:4860:4802:34::a port 53 (len 28)
2024-08-30T10:58:03.062398+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    ip4 216.239.34.10 port 53 (len 16)
2024-08-30T10:58:03.062422+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    ip6 2001:4860:4802:32::a port 53 (len 28)
2024-08-30T10:58:03.062446+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    ip4 216.239.32.10 port 53 (len 16)
2024-08-30T10:58:03.062470+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    ip6 2001:4860:4802:36::a port 53 (len 28)
2024-08-30T10:58:03.062495+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    ip4 216.239.36.10 port 53 (len 16)
2024-08-30T10:58:03.062519+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    ip6 2001:4860:4802:38::a port 53 (len 28)
2024-08-30T10:58:03.062543+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    ip4 216.239.38.10 port 53 (len 16)
2024-08-30T10:58:03.062568+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: iter_handle processing q with state INIT REQUEST STATE (stage 2)
2024-08-30T10:58:03.062592+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: resolving (init part 2):  google.com. HTTPS IN
2024-08-30T10:58:03.062627+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: iter_handle processing q with state INIT REQUEST STATE (stage 3)
2024-08-30T10:58:03.062670+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: resolving (init part 3):  google.com. HTTPS IN
2024-08-30T10:58:03.062701+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: iter_handle processing q with state QUERY TARGETS STATE
2024-08-30T10:58:03.062727+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: processQueryTargets: google.com. HTTPS IN
2024-08-30T10:58:03.062775+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0
2024-08-30T10:58:03.062798+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: DelegationPoint<google.com.>: 4 names (0 missing), 8 addrs (0 result, 8 avail) cacheNS
2024-08-30T10:58:03.062824+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info:   ns4.google.com. * A AAAA
2024-08-30T10:58:03.062850+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info:   ns3.google.com. * A AAAA
2024-08-30T10:58:03.062874+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info:   ns1.google.com. * A AAAA
2024-08-30T10:58:03.062908+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info:   ns2.google.com. * A AAAA
2024-08-30T10:58:03.062942+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    ip6 2001:4860:4802:34::a port 53 (len 28)
2024-08-30T10:58:03.062968+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] debug:    ip4 216.239.34.10 port 53 (len 16)

@wcawijngaards
Copy link
Member

So it says this:

2024-08-30T10:58:03.061800+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: 127.0.0.1 support.google.com. A IN
2024-08-30T10:58:03.061826+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] info: 127.0.0.1 support.google.com. A IN NOERROR 0.000000 1 47

There was a query for support.google.com and then unbound immediately answered with the empty reply. This must have been local-zone, local-data or an rpz action of some sort that blocks access to the domain. Was 'log-local-actions' enabled? What other config is there, like the main unbound.conf file, what does that contain and include?

In addition I spot this line in the log snippet:

2024-08-30T10:58:03.060511+02:00 AdGuard unbound[122]: [1725008283] unbound[122:0] error: udp connect failed: Network is unreachable for 2001:4860:4802:36::a port 53 (len 28)

If IPv6 does not work, perhaps set do-ip6: no in config. That stops unbound from attempting on useless IPv6 upstream connections.

@myssv
Copy link
Author

myssv commented Aug 30, 2024

main unbound.conf

# Unbound configuration file for Debian.
#
# See the unbound.conf(5) man page.
#
# See /usr/share/doc/unbound/examples/unbound.conf for a commented
# reference config file.
#
# The following line includes additional configuration files from the
# /etc/unbound/unbound.conf.d directory.
include-toplevel: "/etc/unbound/unbound.conf.d/*.conf"

Yeah, ipv6 is already disabled. My fault from testing ...

log-local-actions is enabled

    # eigene Anpassungen
    qname-minimisation: yes
    log-local-actions: yes
    log-queries: yes
    log-replies: yes

@wcawijngaards
Copy link
Member

It could be an immediately reply from cache, for some reason. Could you restart the server and query again from a fresh start? Otherwise the immediate reply could be a cached response, but without the response from cache it would start recursively resolving it, with processing the query and printing the details about what happens to the log. And then it can be seen from the logs what happens when the query is resolved.

@myssv
Copy link
Author

myssv commented Aug 30, 2024

I restarted the server before the logs.

maybe it will be a good idea to install adguard and unbound on a complete new lxc. Maybe faster than searching the error?

@wcawijngaards
Copy link
Member

If you restarted the server, the logs, but earlier parts, could contain the recursive resolution of the domain support.google.com. Search for that earlier in the log file.

@myssv
Copy link
Author

myssv commented Aug 30, 2024

Sorry, I go on vacation tomorrow and just took a backup before adding unbound to the adguard.

Will go on after my holiday.

Thanks a lot for your help!!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@wcawijngaards @myssv and others