ADH unable to use TLS upstream server

[diasdmhub]

While testing an ADH instance in a docker container, I can't use TLS upstream domains.
When I try to use a TLS server, ADH fails to test the upstream DNS or respond to any client request.

Test upstream DNS Servers

tls://94.140.14.140
tls://dns.adguard-dns.com

Using default bootstrap DNS servers:

9.9.9.10
149.112.112.10
2620:fe::10
2620:fe::fe:10

When I test the DNS server, ADH displays the following error.

Server "tls://94.140.14.140": could not be used, please check that you've written it correctly

When I try an HTTPS server, the connection is successful (https://94.140.14.140/dns-query).

Specified DNS servers are working correctly

From the container shell, Netstat shows that the DNS port is open.

# netstat -ltunp
Active Internet connections (only servers)
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
tcp        0      0 :::53                   :::*                    LISTEN      1/AdGuardHome
tcp        0      0 :::3000                 :::*                    LISTEN      1/AdGuardHome
udp        0      0 :::53                   :::*                                1/AdGuardHome

What bugs me more is that I have two other setups with ADH and TLS servers and the tests are all successful.

So, I'm lost. Why is it that only TLS is not working in a docker instance?

[diasdmhub]

BTW, I'm using the latest ADH version available from Docker Hub, v0.107.45.

I've enabled AdGuard log verbosity and it shows connection refused message for every TLS server I test:

2024/03/08 17:36:49.922844 1#1 [info] AdGuard Home, version v0.107.45
2024/03/08 17:36:49.922967 1#1 [debug] current working directory is /opt/adguardhome/work
2024/03/08 17:36:49.923014 1#1 [debug] reading config file: /opt/adguardhome/conf/AdGuardHome.yaml
2024/03/08 17:36:49.923394 1#1 [debug] got schema version 28
2024/03/08 17:36:49.923698 1#1 [info] tls: using default ciphers
2024/03/08 17:36:49.923730 1#1 [debug] hosts container: starting
2024/03/08 17:36:49.923739 1#1 [debug] hosts container: refreshing
2024/03/08 17:36:49.923775 1#1 [debug] hosts container: sending upd
2024/03/08 17:36:49.924272 1#1 [debug] filtering: initialized 112 services
2024/03/08 17:36:49.924305 1#1 [info] safesearch default: disabled
2024/03/08 17:36:49.924329 1#1 [debug] dhcpd: warning: creating dhcpv4 srv: dhcpv4: invalid IP is not an IPv4 address
2024/03/08 17:36:49.924475 1#14 [debug] clients: removed 0 client aliases
2024/03/08 17:36:49.924504 1#14 [debug] clients: adding client info fe00:: -> "etc/hosts" "ip6-localnet" [1]
2024/03/08 17:36:49.924514 1#14 [debug] clients: adding client info ff00:: -> "etc/hosts" "ip6-mcastprefix" [2]
2024/03/08 17:36:49.924522 1#14 [debug] clients: adding client info ff02::1 -> "etc/hosts" "ip6-allnodes" [3]
2024/03/08 17:36:49.924529 1#14 [debug] clients: adding client info ff02::2 -> "etc/hosts" "ip6-allrouters" [4]
2024/03/08 17:36:49.924537 1#14 [debug] clients: adding client info 172.17.0.2 -> "etc/hosts" "fe832d23986f" [5]
2024/03/08 17:36:49.924544 1#14 [debug] clients: adding client info 127.0.0.1 -> "etc/hosts" "localhost" [6]
2024/03/08 17:36:49.924551 1#14 [debug] clients: adding client info ::1 -> "etc/hosts" "localhost" [7]
2024/03/08 17:36:49.924557 1#14 [debug] clients: added 7 client aliases from system hosts file
2024/03/08 17:36:49.924582 1#1 [debug] writing config file "/opt/adguardhome/conf/AdGuardHome.yaml"
2024/03/08 17:36:49.950813 1#1 [info] Initializing auth module: /opt/adguardhome/work/data/sessions.db
2024/03/08 17:36:49.950876 1#1 [debug] auth: loaded 1 sessions from DB (removed 0 expired)
2024/03/08 17:36:49.950889 1#1 [info] auth: initialized.  users:1  sessions:1
2024/03/08 17:36:49.950904 1#1 [info] AdGuard Home updates are disabled
2024/03/08 17:36:49.950916 1#1 [info] web: initializing
2024/03/08 17:36:49.950948 1#1 [debug] stats: opening database
2024/03/08 17:36:49.950989 1#1 [debug] stats: database opened
2024/03/08 17:36:49.951010 1#1 [debug] stats: deleting old units until id 474952
2024/03/08 17:36:49.951034 1#1 [debug] github.com/AdguardTeam/AdGuardHome/internal/stats.loadUnitFromDB(): Loading unit 474977
2024/03/08 17:36:49.951107 1#1 [debug] stats: initialized
2024/03/08 17:36:49.951140 1#1 [debug] filtering: loading filter 1 from "/opt/adguardhome/work/data/filters/1.txt"
2024/03/08 17:36:49.951161 1#1 [debug] filtering: file "/opt/adguardhome/work/data/filters/1.txt", id 1, length 1251412
2024/03/08 17:36:49.954754 1#1 [debug] github.com/AdguardTeam/AdGuardHome/internal/stats.loadUnitFromDB(): Loading unit 474974
2024/03/08 17:36:49.954791 1#1 [debug] github.com/AdguardTeam/AdGuardHome/internal/stats.loadUnitFromDB(): Loading unit 474975
2024/03/08 17:36:49.954818 1#1 [debug] github.com/AdguardTeam/AdGuardHome/internal/stats.loadUnitFromDB(): Loading unit 474976
2024/03/08 17:36:49.954870 1#1 [debug] dnsproxy: upstream at index 0: tls://94.140.14.140:853
2024/03/08 17:36:49.954889 1#1 [info] dnsproxy: cache: enabled, size 4096 b
2024/03/08 17:36:49.954899 1#1 [info] dnsproxy: max goroutines is set to 300
2024/03/08 17:36:49.955009 1#1 [debug] dnsforward: filtering out addresses [127.0.0.1 172.17.0.2] on ports map[53:{}]
2024/03/08 17:36:49.955022 1#1 [debug] dnsforward: upstreams to resolve ptr for local addresses: [192.168.7.1:53]
2024/03/08 17:36:49.955036 1#1 [debug] dnsproxy: upstream at index 0: 192.168.7.1:53
2024/03/08 17:36:49.955046 1#1 [info] dnsproxy: cache: disabled
2024/03/08 17:36:49.955095 1#1 [debug] web: applying new tls configuration
2024/03/08 17:36:49.955106 1#1 [info] AdGuard Home is available at the following addresses:
2024/03/08 17:36:49.955171 1#21 [info] clients: processing addresses
2024/03/08 17:36:49.955172 1#1 [info] go to http://127.0.0.1:80
2024/03/08 17:36:49.955205 1#1 [info] go to http://172.17.0.2:80
2024/03/08 17:36:50.034002 1#22 [debug] filtering: initialized filtering engine
2024/03/08 17:36:50.034040 1#22 [info] dnsproxy: starting dns proxy server
2024/03/08 17:36:50.034059 1#22 [info] Ratelimit is enabled and set to 20 rps, IPv4 subnet mask len 24, IPv6 subnet mask len 56
2024/03/08 17:36:50.034068 1#22 [info] The server is configured to refuse ANY requests
2024/03/08 17:36:50.034077 1#22 [info] dnsproxy: cache: enabled, size 4194304 b
2024/03/08 17:36:50.034086 1#22 [info] dnsproxy: max goroutines is set to 300
2024/03/08 17:36:50.034101 1#22 [info] dnsproxy: creating udp server socket 0.0.0.0:53
2024/03/08 17:36:50.034159 1#22 [info] dnsproxy: listening to udp://[::]:53
2024/03/08 17:36:50.034172 1#22 [info] dnsproxy: creating tcp server socket 0.0.0.0:53
2024/03/08 17:36:50.034174 1#33 [debug] refreshing arp container: the update is empty
2024/03/08 17:36:50.034197 1#22 [info] dnsproxy: listening to tcp://[::]:53
2024/03/08 17:36:50.034218 1#34 [info] dnsproxy: entering udp listener loop on [::]:53
2024/03/08 17:36:50.034249 1#38 [debug] querylog: no log to rotate
2024/03/08 17:36:50.034256 1#38 [debug] querylog: rotated successfully
2024/03/08 17:36:50.034270 1#35 [info] dnsproxy: entering tcp listener loop on [::]:53
2024/03/08 17:36:55.034443 1#36 [debug] filtering: starting updating
2024/03/08 17:36:55.034473 1#36 [debug] filtering: finished updating, 0 updated
2024/03/08 17:36:59.074037 1#40 [debug] started POST 192.168.7.5 /control/login
2024/03/08 17:36:59.120289 1#40 [debug] auth: created session 0000: expire=1712511419
2024/03/08 17:36:59.120319 1#40 [info] auth: user "USER" successfully logged in from ip 192.168.7.3
2024/03/08 17:36:59.120355 1#40 [debug] finished POST 192.168.7.5 /control/login in 46.341185ms
2024/03/08 17:36:59.366627 1#25 [debug] started GET 192.168.7.5 /control/status
2024/03/08 17:36:59.366858 1#25 [debug] finished GET 192.168.7.5 /control/status in 249.746µs
2024/03/08 17:36:59.386460 1#25 [debug] started GET 192.168.7.5 /control/access/list
2024/03/08 17:36:59.386527 1#25 [debug] finished GET 192.168.7.5 /control/access/list in 86.826µs
2024/03/08 17:36:59.386622 1#40 [debug] started GET 192.168.7.5 /control/stats
2024/03/08 17:36:59.386689 1#40 [debug] github.com/AdguardTeam/AdGuardHome/internal/stats.loadUnitFromDB(): Loading unit 474974
2024/03/08 17:36:59.386762 1#40 [debug] github.com/AdguardTeam/AdGuardHome/internal/stats.loadUnitFromDB(): Loading unit 474975
2024/03/08 17:36:59.386802 1#40 [debug] github.com/AdguardTeam/AdGuardHome/internal/stats.loadUnitFromDB(): Loading unit 474976
2024/03/08 17:36:59.386844 1#40 [debug] stats: prepared data in 194.1µs
2024/03/08 17:36:59.386923 1#40 [debug] finished GET 192.168.7.5 /control/stats in 311.935µs
2024/03/08 17:36:59.388975 1#25 [debug] started GET 192.168.7.5 /control/stats/config
2024/03/08 17:36:59.389020 1#25 [debug] finished GET 192.168.7.5 /control/stats/config in 49.695µs
2024/03/08 17:36:59.391838 1#25 [debug] started GET 192.168.7.5 /control/tls/status
2024/03/08 17:36:59.391930 1#25 [debug] finished GET 192.168.7.5 /control/tls/status in 95.452µs
2024/03/08 17:36:59.392635 1#25 [debug] started GET 192.168.7.5 /control/profile
2024/03/08 17:36:59.392674 1#25 [debug] finished GET 192.168.7.5 /control/profile in 43.282µs
2024/03/08 17:36:59.397334 1#25 [debug] started GET 192.168.7.5 /control/clients/find?
2024/03/08 17:36:59.397437 1#25 [debug] finished GET 192.168.7.5 /control/clients/find? in 107.686µs
2024/03/08 17:37:01.604138 1#40 [debug] started GET 192.168.7.5 /control/dns_info
2024/03/08 17:37:01.604138 1#25 [debug] started GET 192.168.7.5 /control/access/list
2024/03/08 17:37:01.604275 1#25 [debug] finished GET 192.168.7.5 /control/access/list in 161.989µs
2024/03/08 17:37:01.604308 1#40 [debug] dnsforward: filtering out addresses [127.0.0.1 172.17.0.2] on ports map[53:{}]
2024/03/08 17:37:01.604426 1#40 [debug] finished GET 192.168.7.5 /control/dns_info in 311.635µs
2024/03/08 17:37:08.121800 1#25 [debug] started POST 192.168.7.5 /control/test_upstream_dns
2024/03/08 17:37:08.121924 1#53 [debug] bootstrap: dialing 94.140.14.140:853 (1/1)
2024/03/08 17:37:08.122751 1#53 [debug] bootstrap: connection to 94.140.14.140:853 failed in 801.248µs: dial tcp 94.140.14.140:853: connect: connection refused
2024/03/08 17:37:08.122813 1#25 [debug] finished POST 192.168.7.5 /control/test_upstream_dns in 1.030425ms
2024/03/08 17:37:13.416395 1#25 [debug] started GET 192.168.7.5 /control/logout
2024/03/08 17:37:13.437703 1#25 [debug] auth: removed session from DB
2024/03/08 17:37:13.437736 1#25 [debug] finished GET 192.168.7.5 /control/logout in 21.362515ms

It seems like the problem is with ADH itself.
Why is it refusing the connection?

This problem seems very similar to #4655, but mine is version 107 and the test fails immediately.

[diasdmhub]

Upon closer inspection, I traced the packets back to my main firewall IPTables.
There was a chain blocking any packet on port 853 that was not destined for the main DNS host, which is also an ADH instance.
After changing the rule, the upstream TLS servers are reachable again.