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

conditional_upstream timeouts #1403

Open
bcookatpcsd opened this issue Mar 15, 2024 · 7 comments
Open

conditional_upstream timeouts #1403

bcookatpcsd opened this issue Mar 15, 2024 · 7 comments
Labels
👋 help wanted Extra attention is needed

Comments

@bcookatpcsd
Copy link

docker image.. seem to be the same with the :latest tag as well..

[2024-03-15 07:56:17]  INFO _/  Version: v0.23-58-gca74978  Build time: 20240314-090153     _/

[2024-03-15 07:56:17]  INFO server: -> conditional_upstream:
[2024-03-15 07:56:17]  INFO server:      88.168.192.in-addr.arpa = [tcp+udp:192.168.88.1]
[2024-03-15 07:56:17]  INFO server:      mktk88.home = [tcp+udp:192.168.88.1]
[2024-03-15 07:56:17]  INFO server: -> special_use_domains:

I get tons of these:

[2024-03-15 07:59:31] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:41734->192.168.88.1:53: i/o timeout
[2024-03-15 07:59:31] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:39235->192.168.88.1:53: i/o timeout
[2024-03-15 07:59:32] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:48845->192.168.88.1:53: i/o timeout
[2024-03-15 07:59:33] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:34105->192.168.88.1:53: i/o timeout
[2024-03-15 07:59:34] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:52122->192.168.88.1:53: i/o timeout
[2024-03-15 07:59:39] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:35708->192.168.88.1:53: i/o timeout
[2024-03-15 07:59:41] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:39174->192.168.88.1:53: i/o timeout
[2024-03-15 07:59:43] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:55545->192.168.88.1:53: i/o timeout
[2024-03-15 07:59:49] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:58024->192.168.88.1:53: i/o timeout
[2024-03-15 07:59:51] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:53574->192.168.88.1:53: i/o timeout

Restarting without conditional_upstream

[2024-03-15 08:02:12]  INFO _/  Version: v0.23-58-gca74978  Build time: 20240314-090153     _/

/var/log/blocky/2024-03-15_ALL.log:2024-03-15 08:02:14  192.168.88.1    192.168.88.1    0       Special-Use Domain Name 135.88.168.192.in-addr.arpa.            NXDOMAIN        SPECIAL PTR     blocky-docker
/var/log/blocky/2024-03-15_ALL.log:2024-03-15 08:02:14  192.168.88.1    192.168.88.1    0       Special-Use Domain Name lb._dns-sd._udp.0.88.168.192.in-addr.arpa.              NXDOMAIN        SPECIAL PTR     blocky-docker
/var/log/blocky/2024-03-15_ALL.log:2024-03-15 08:02:14  192.168.88.1    192.168.88.1    0       Special-Use Domain Name db._dns-sd._udp.0.88.168.192.in-addr.arpa.              NXDOMAIN        SPECIAL PTR     blocky-docker
/var/log/blocky/2024-03-15_ALL.log:2024-03-15 08:02:14  192.168.88.1    192.168.88.1    0       Special-Use Domain Name b._dns-sd._udp.0.88.168.192.in-addr.arpa.               NXDOMAIN        SPECIAL PTR     blocky-docker
/var/log/blocky/2024-03-15_ALL.log:2024-03-15 08:03:18  192.168.88.127  192.168.88.127  0       Special-Use Domain Name wpad.mktk88.home.               NXDOMAIN        SPECIAL A       blocky-docker
/var/log/blocky/2024-03-15_ALL.log:2024-03-15 08:04:15  172.19.0.1      172.19.0.1      0       Special-Use Domain Name instance-data.ec2.internal.             NXDOMAIN        SPECIAL A       blocky-docker
/var/log/blocky/2024-03-15_ALL.log:2024-03-15 08:04:15  172.19.0.1      172.19.0.1      0       Special-Use Domain Name metadata.google.internal.               NXDOMAIN        SPECIAL A       blocky-docker

88.1 is serving functional dns (afaict)

 drill -x 192.168.88.254 @192.168.88.1
;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 19077
;; flags: qr rd ra ; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 1
;; QUESTION SECTION:
;; 254.88.168.192.in-addr.arpa. IN      PTR

;; ANSWER SECTION:
254.88.168.192.in-addr.arpa.    86400   IN      PTR     alpine.mktk88.home.

;; AUTHORITY SECTION:

;; ADDITIONAL SECTION:
alpine.mktk88.home.     86400   IN      A       192.168.88.254

;; Query time: 0 msec
;; SERVER: 192.168.88.1
;; WHEN: Fri Mar 15 08:10:47 2024
;; MSG SIZE  rcvd: 93

config.yml:

 cat config.yml | egrep -v \#
bootstrapDns:
  - upstream: https://dns.nextdns.io/dns-query
    ips:
    - 45.90.28.0
    - 45.90.30.0


upstreams:
  strategy: parallel_best
  groups:
    default:
      - tcp-tls:blocky-alpine-dot-xxxyyyzzz.dns.nextdns.io:853
      - https://dns.nextdns.io/xxxyyyzzz/blocky-alpine-doh


ports:
  dns: 0.0.0.0:53
  http: 0.0.0.0:4000

prometheus:
  enable: yes
  path: /metrics

filtering:
  queryTypes:
    - AAAA
    - ANY

connectIPVersion: v4

caching:
  minTime: 10m
  maxTime: 60m
  maxItemsCount: 10240
  prefetching: true

ede:
  enable: true

queryLog:
  type: csv
  target: /var/log/blocky

fqdnOnly:
  enable: true

specialUseDomains:
  rfc6762-appendixG: true

blocking:
  blockType: zeroIP
  blockTTL: 5m
  loading:
    strategy: fast
    refreshPeriod: 12h
    downloads:
      timeout: 30s
  blackLists:
    ads:
      - https://cdn.jsdelivr.net/gh/hagezi/dns-blocklists@main/wildcard/multi.txt
  clientGroupsBlock:
    default:
      - ads

customDNS:
  customTTL: 300s
  filterUnmappedTypes: true
  mapping:
    pool.ntp.org: 192.168.88.254
    time.google.com: 192.168.88.254

fwiw, it is a mikrotik router with its own dns server.. 7.14 of the OS.. I do not know how it reacts to tcp queries (drill -t responds as it should on cmd line..)

I am not sure if I am doing something incorrect in my configuration..

I tried to manually define things to rule out default settings and such..

  #conditional:
  #  fallbackUpstream: true
  #  mapping:
  #    88.168.192.in-addr.arpa: 192.168.88.1
  #    mktk88.home: 192.168.88.1

This is my commented out conditional section..

(as always)

Thank you in advance.
@ThinkChaos ThinkChaos changed the title incompatiable together? conditional_upstream and special_use_domains? conditional_upstream timeouts Mar 15, 2024
@ThinkChaos
Copy link
Collaborator

Hi,

The special use domains resolver is after the conditional one in the resolver chain, so requests handled by the conditional one never reach the SUDN resolver.
The behavior you saw when disabling the conditional resolver is expected: reverse lookups for private IPs and requests to .home and .internal TLDs (amongst others) are prevented from reaching upstream resolvers by default.

I think you're just getting real time outs. You can try increasing the upstream timeout, and maybe doing manual tests from where blocky runs when you see timeouts in the logs.

@bcookatpcsd
Copy link
Author

added the timeouts to the upstream.. don't see a timeouts for conditional.. (changed from default 2s to 10s)


[2024-03-15 10:31:02]  INFO list_cache: import succeeded count=134173 source=https://cdn.jsdelivr.net/gh/hagezi/dns-blocklists@main/wildcard/multi.txt
[2024-03-15 10:31:02]  INFO list_cache: group import finished group=ads total_count=134173
[2024-03-15 10:31:06]  WARN upstream: initial resolver test failed error=can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:38504->192.168.88.1:53: i/o timeout upstream=tcp+udp:192.168.88.1
[2024-03-15 10:31:10]  WARN upstream: initial resolver test failed error=can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): upstream server failed upstream=tcp+udp:192.168.88.1
[2024-03-15 10:31:10]  INFO server: current configuration:

still see these:

[2024-03-15 10:32:09] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:48157->192.168.88.1:53: i/o timeout
[2024-03-15 10:32:09] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:40367->192.168.88.1:53: i/o timeout
[2024-03-15 10:32:09] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:45901->192.168.88.1:53: i/o timeout
[2024-03-15 10:32:09] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:45565->192.168.88.1:53: i/o timeout
[2024-03-15 10:32:09] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:54424->192.168.88.1:53: i/o timeout
[2024-03-15 10:32:09] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:43527->192.168.88.1:53: i/o timeout
[2024-03-15 10:32:09] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:34338->192.168.88.1:53: i/o timeout
[2024-03-15 10:32:09] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:36905->192.168.88.1:53: i/o timeout
[2024-03-15 10:32:10] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:42360->192.168.88.1:53: i/o timeout
[2024-03-15 10:32:10] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:46464->192.168.88.1:53: i/o timeout
[2024-03-15 10:32:10] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:35852->192.168.88.1:53: i/o timeout
[2024-03-15 10:32:10] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:60194->192.168.88.1:53: i/o timeout
[2024-03-15 10:32:10] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:58150->192.168.88.1:53: i/o timeout
[2024-03-15 10:32:10] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:56309->192.168.88.1:53: i/o timeout
[2024-03-15 10:32:10] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 172.19.0.2:47506->192.168.88.1:53: i/o timeout

again with conditional enabled I no longer see speical use entries..

/var/log/blocky/2024-03-15_ALL.log:2024-03-15 10:30:37  192.168.88.158  192.168.88.158  0       Special-Use Domain Name _aaplcache1._tcp.mktk88.home.           NXDOMAIN        SPECIAL TXT     blocky-docker
/var/log/blocky/2024-03-15_ALL.log:2024-03-15 10:30:37  192.168.88.158  192.168.88.158  0       Special-Use Domain Name _aaplcache3._tcp.mktk88.home.           NXDOMAIN        SPECIAL TXT     blocky-docker
``

10:31 restart.. 10.30 was the last special use in the logs.. 

172.19.0/24 is the local docker bridge..

@ThinkChaos
Copy link
Collaborator

Yes the upstreams: timeouts apply to all DNS requests made to other servers (bootstrap, conditional, etc.).

Is it all requests that timeout?
Did you try a manual request from where blocky runs? If in a jail/container/whatever, inside that?
If you can't reproduce from the exact same environment then the next test is capturing packets and to see what's actually going on.

again with conditional enabled I no longer see speical use entries..

Yeah that's for the same reason: the conditional resolver handles the request, so the SUDN one never sees it.
The SUDN resolver is really just a last barrier to leaking your private requests.

@kwitsch
Copy link
Collaborator

kwitsch commented Mar 15, 2024

172.19.0.2:48157->192.168.88.1:53: i/o timeout

Seems like your container can't reach the outbound network.
There could be multiple reasons for that depending on your host configuration, container start, firewall configurations,...

In such a case I would start with explicitly creating a new docker network and using it as default for the blocky container.
If this also fails try adding an interactive container and start debugging the connection from inside the network.

@bcookatpcsd
Copy link
Author

172.19.0.2:48157->192.168.88.1:53: i/o timeout

Seems like your container can't reach the outbound network. There could be multiple reasons for that depending on your host configuration, container start, firewall configurations,...

In such a case I would start with explicitly creating a new docker network and using it as default for the blocky container. If this also fails try adding an interactive container and start debugging the connection from inside the network.

172.19.0.2 was blocky

now blocky is network host mode..

with no conditional statement, those errors never showed in the logs..

(let me try and say this another way.. )

[I] root@gk41 /e/s/compose (master)# grep Special /var/log/blocky/2024-03-17_ALL.log | egrep -v 'arpa|home'
2024-03-17 00:05:59     172.19.0.1      172.19.0.1      0       Special-Use Domain Name instance-data.ec2.internal.             NXDOMAIN        SPECIAL A       blocky-docker
2024-03-17 00:05:59     172.19.0.1      172.19.0.1      0       Special-Use Domain Name metadata.google.internal.               NXDOMAIN        SPECIAL A       blocky-docker
2024-03-17 01:06:49     172.19.0.1      172.19.0.1      0       Special-Use Domain Name instance-data.ec2.internal.             NXDOMAIN        SPECIAL A       blocky-docker
2024-03-17 01:06:49     172.19.0.1      172.19.0.1      0       Special-Use Domain Name metadata.google.internal.               NXDOMAIN        SPECIAL A       blocky-docker
2024-03-17 02:05:14     172.19.0.1      172.19.0.1      0       Special-Use Domain Name instance-data.ec2.internal.             NXDOMAIN        SPECIAL A       blocky-docker
2024-03-17 02:05:14     172.19.0.1      172.19.0.1      0       Special-Use Domain Name metadata.google.internal.               NXDOMAIN        SPECIAL A       blocky-docker
2024-03-17 03:03:48     172.19.0.1      172.19.0.1      0       Special-Use Domain Name instance-data.ec2.internal.             NXDOMAIN        SPECIAL A       blocky-docker
2024-03-17 03:03:48     172.19.0.1      172.19.0.1      0       Special-Use Domain Name metadata.google.internal.               NXDOMAIN        SPECIAL A       blocky-docker
2024-03-17 04:03:40     172.19.0.1      172.19.0.1      0       Special-Use Domain Name instance-data.ec2.internal.             NXDOMAIN        SPECIAL A       blocky-docker
2024-03-17 04:03:40     172.19.0.1      172.19.0.1      0       Special-Use Domain Name metadata.google.internal.               NXDOMAIN        SPECIAL A       blocky-docker
2024-03-17 05:04:04     172.19.0.1      172.19.0.1      0       Special-Use Domain Name instance-data.ec2.internal.             NXDOMAIN        SPECIAL A       blocky-docker
2024-03-17 05:04:04     172.19.0.1      172.19.0.1      0       Special-Use Domain Name metadata.google.internal.               NXDOMAIN        SPECIAL A       blocky-docker
2024-03-17 06:06:01     172.19.0.1      172.19.0.1      0       Special-Use Domain Name instance-data.ec2.internal.             NXDOMAIN        SPECIAL A       blocky-docker
2024-03-17 06:06:01     172.19.0.1      172.19.0.1      0       Special-Use Domain Name metadata.google.internal.               NXDOMAIN        SPECIAL A       blocky-docker
2024-03-17 07:03:08     172.19.0.1      172.19.0.1      0       Special-Use Domain Name instance-data.ec2.internal.             NXDOMAIN        SPECIAL A       blocky-docker
2024-03-17 07:03:08     172.19.0.1      172.19.0.1      0       Special-Use Domain Name metadata.google.internal.               NXDOMAIN        SPECIAL A       blocky-docker
2024-03-17 08:05:44     172.19.0.1      172.19.0.1      0       Special-Use Domain Name instance-data.ec2.internal.             NXDOMAIN        SPECIAL A       blocky-docker
2024-03-17 08:05:44     172.19.0.1      172.19.0.1      0       Special-Use Domain Name metadata.google.internal.               NXDOMAIN        SPECIAL A       blocky-docker
2024-03-17 09:06:29     172.19.0.1      172.19.0.1      0       Special-Use Domain Name instance-data.ec2.internal.             NXDOMAIN        SPECIAL A       blocky-docker
2024-03-17 09:06:29     172.19.0.1      172.19.0.1      0       Special-Use Domain Name metadata.google.internal.               NXDOMAIN        SPECIAL A       blocky-docker
2024-03-17 10:03:57     172.19.0.1      172.19.0.1      0       Special-Use Domain Name instance-data.ec2.internal.             NXDOMAIN        SPECIAL A       blocky-docker
2024-03-17 10:03:57     172.19.0.1      172.19.0.1      0       Special-Use Domain Name metadata.google.internal.               NXDOMAIN        SPECIAL A       blocky-docker

The above stops showing when I enable this is in blocky..

conditional:
  fallbackUpstream: true
  mapping:
    88.168.192.in-addr.arpa: 192.168.88.1
    mktk88.home: 192.168.88.1

(conditional enabled and restart)

[2024-03-17 10:48:39]  INFO Terminating...
[2024-03-17 10:48:39]  INFO server: Stopping server
[2024-03-17 10:48:40]  INFO _/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/
[2024-03-17 10:48:40]  INFO _/                                                              _/
[2024-03-17 10:48:40]  INFO _/                                                              _/
[2024-03-17 10:48:40]  INFO _/       _/        _/                      _/                   _/
[2024-03-17 10:48:40]  INFO _/      _/_/_/    _/    _/_/      _/_/_/  _/  _/    _/    _/    _/
[2024-03-17 10:48:40]  INFO _/     _/    _/  _/  _/    _/  _/        _/_/      _/    _/     _/
[2024-03-17 10:48:40]  INFO _/    _/    _/  _/  _/    _/  _/        _/  _/    _/    _/      _/
[2024-03-17 10:48:40]  INFO _/   _/_/_/    _/    _/_/      _/_/_/  _/    _/    _/_/_/       _/
[2024-03-17 10:48:40]  INFO _/                                                    _/        _/
[2024-03-17 10:48:40]  INFO _/                                               _/_/           _/
[2024-03-17 10:48:40]  INFO _/                                                              _/
[2024-03-17 10:48:40]  INFO _/                                                              _/
[2024-03-17 10:48:40]  INFO _/  Version: v0.23-58-gca74978  Build time: 20240314-090153     _/
[2024-03-17 10:48:40]  INFO _/                                                              _/
[2024-03-17 10:48:40]  INFO _/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/
[2024-03-17 10:48:42]  INFO list_cache: import succeeded count=134158 source=https://cdn.jsdelivr.net/gh/hagezi/dns-blocklists@main/wildcard/multi.txt
[2024-03-17 10:48:42]  INFO list_cache: group import finished group=ads total_count=134158
[2024-03-17 10:48:46]  WARN upstream: initial resolver test failed error=can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 192.168.88.254:14417->192.168.88.1:53: i/o timeout upstream=tcp+udp:192.168.88.1
[2024-03-17 10:48:50]  WARN upstream: initial resolver test failed error=can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): upstream server failed upstream=tcp+udp:192.168.88.1
[2024-03-17 10:48:50]  INFO server: current configuration:
[2024-03-17 10:48:50]  INFO server: -> filtering:
[2024-03-17 10:48:50]  INFO server:      query types:
[2024-03-17 10:48:50]  INFO server:        - AAAA
[2024-03-17 10:48:50]  INFO server:        - ANY
[2024-03-17 10:48:50]  INFO server: -> fqdn_only:
[2024-03-17 10:48:50]  INFO server:      enabled
[2024-03-17 10:48:50]  INFO server: -> extended_error_code:
[2024-03-17 10:48:50]  INFO server:      enabled
[2024-03-17 10:48:50]  INFO server: -> query_logging:
[2024-03-17 10:48:50]  INFO server:      type: csv
[2024-03-17 10:48:50]  INFO server:      target: /var/log/blocky
[2024-03-17 10:48:50]  INFO server:      logRetentionDays: 0
[2024-03-17 10:48:50]  INFO server:      flushInterval: 30 seconds
[2024-03-17 10:48:50]  INFO server:      fields: [clientIP clientName responseReason responseAnswer question duration]
[2024-03-17 10:48:50]  INFO server: -> metrics:
[2024-03-17 10:48:50]  INFO server:      url path: /metrics
[2024-03-17 10:48:50]  INFO server: -> custom_dns:
[2024-03-17 10:48:50]  INFO server:      mapping:
[2024-03-17 10:48:50]  INFO server:        pool.ntp.org = [     300     CLASS0  None    192.168.88.254]
[2024-03-17 10:48:50]  INFO server:        time.google.com = [  300     CLASS0  None    192.168.88.254]
[2024-03-17 10:48:50]  INFO server: -> blocking:
[2024-03-17 10:48:50]  INFO server:      clientGroupsBlock:
[2024-03-17 10:48:50]  INFO server:        default = [ads]
[2024-03-17 10:48:50]  INFO server:      blockType = zeroIP
[2024-03-17 10:48:50]  INFO server:      blockTTL = 5 minutes
[2024-03-17 10:48:50]  INFO server:      loading:
[2024-03-17 10:48:50]  INFO server:        concurrency = 4
[2024-03-17 10:48:50]  INFO server:        refresh = every 12 hours
[2024-03-17 10:48:50]  INFO server:        downloads:
[2024-03-17 10:48:50]  INFO server:          timeout = 30 seconds
[2024-03-17 10:48:50]  INFO server:          attempts = 3
[2024-03-17 10:48:50]  INFO server:      blacklist:
[2024-03-17 10:48:50]  INFO server:        ads:
[2024-03-17 10:48:50]  INFO server:           - https://cdn.jsdelivr.net/gh/hagezi/dns-blocklists@main/wildcard/multi.txt
[2024-03-17 10:48:50]  INFO server:      whitelist:
[2024-03-17 10:48:50]  INFO server:      blacklist cache entries:
[2024-03-17 10:48:50]  INFO server:        ads: 134158 entries
[2024-03-17 10:48:50]  INFO server:        TOTAL: 134158 entries
[2024-03-17 10:48:50]  INFO server:      whitelist cache entries:
[2024-03-17 10:48:50]  INFO server:        TOTAL: 0 entries
[2024-03-17 10:48:50]  INFO server: -> caching:
[2024-03-17 10:48:50]  INFO server:      minTime = 10 minutes
[2024-03-17 10:48:50]  INFO server:      maxTime = 1 hour
[2024-03-17 10:48:50]  INFO server:      cacheTimeNegative = 30 minutes
[2024-03-17 10:48:50]  INFO server:      prefetching:
[2024-03-17 10:48:50]  INFO server:        expires   = 2 hours
[2024-03-17 10:48:50]  INFO server:        threshold = 5
[2024-03-17 10:48:50]  INFO server:        maxItems  = 0
[2024-03-17 10:48:50]  INFO server:      cache entries = 0
[2024-03-17 10:48:50]  INFO server: -> conditional_upstream:
[2024-03-17 10:48:50]  INFO server:      88.168.192.in-addr.arpa = [tcp+udp:192.168.88.1]
[2024-03-17 10:48:50]  INFO server:      mktk88.home = [tcp+udp:192.168.88.1]
[2024-03-17 10:48:50]  INFO server: -> special_use_domains:
[2024-03-17 10:48:50]  INFO server: -> parallel_best:
[2024-03-17 10:48:50]  INFO server:      group: default
[2024-03-17 10:48:50]  INFO server:      upstreams:
[2024-03-17 10:48:50]  INFO server:        - tcp-tls:blocky-alpine-dot-xyz123.dns.nextdns.io
[2024-03-17 10:48:50]  INFO server:        - https://dns.nextdns.io/xyz123/blocky-alpine-doh
[2024-03-17 10:48:50]  INFO server: listeners:
[2024-03-17 10:48:50]  INFO server:   DNS   = [0.0.0.0:53]
[2024-03-17 10:48:50]  INFO server:   TLS   = []
[2024-03-17 10:48:50]  INFO server:   HTTP  = [0.0.0.0:4000]
[2024-03-17 10:48:50]  INFO server:   HTTPS = []
[2024-03-17 10:48:50]  INFO server: runtime information:
[2024-03-17 10:48:50]  INFO server:   numCPU =       4
[2024-03-17 10:48:50]  INFO server:   numGoroutine = 18
[2024-03-17 10:48:50]  INFO server:   memory:
[2024-03-17 10:48:50]  INFO server:     heap =             16 MB
[2024-03-17 10:48:50]  INFO server:     sys =              62 MB
[2024-03-17 10:48:50]  INFO server:     numGC =           191
[2024-03-17 10:48:50]  INFO server: Starting server
[2024-03-17 10:48:50]  INFO server: http server is up and running on addr/port 0.0.0.0:4000
[2024-03-17 10:48:50]  INFO server: TCP server is up and running on address 0.0.0.0:53
[2024-03-17 10:48:50]  INFO server: UDP server is up and running on address 0.0.0.0:53

(conditional disabled and restart)

[2024-03-17 10:50:38]  INFO Terminating...
[2024-03-17 10:50:38]  INFO server: Stopping server
[2024-03-17 10:50:38]  INFO _/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/
[2024-03-17 10:50:38]  INFO _/                                                              _/
[2024-03-17 10:50:38]  INFO _/                                                              _/
[2024-03-17 10:50:38]  INFO _/       _/        _/                      _/                   _/
[2024-03-17 10:50:38]  INFO _/      _/_/_/    _/    _/_/      _/_/_/  _/  _/    _/    _/    _/
[2024-03-17 10:50:38]  INFO _/     _/    _/  _/  _/    _/  _/        _/_/      _/    _/     _/
[2024-03-17 10:50:38]  INFO _/    _/    _/  _/  _/    _/  _/        _/  _/    _/    _/      _/
[2024-03-17 10:50:38]  INFO _/   _/_/_/    _/    _/_/      _/_/_/  _/    _/    _/_/_/       _/
[2024-03-17 10:50:38]  INFO _/                                                    _/        _/
[2024-03-17 10:50:38]  INFO _/                                               _/_/           _/
[2024-03-17 10:50:38]  INFO _/                                                              _/
[2024-03-17 10:50:38]  INFO _/                                                              _/
[2024-03-17 10:50:38]  INFO _/  Version: v0.23-58-gca74978  Build time: 20240314-090153     _/
[2024-03-17 10:50:38]  INFO _/                                                              _/
[2024-03-17 10:50:38]  INFO _/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/
[2024-03-17 10:50:38]  INFO server: current configuration:
[2024-03-17 10:50:38]  INFO server: -> filtering:
[2024-03-17 10:50:38]  INFO server:      query types:
[2024-03-17 10:50:38]  INFO server:        - AAAA
[2024-03-17 10:50:38]  INFO server:        - ANY
[2024-03-17 10:50:38]  INFO server: -> fqdn_only:
[2024-03-17 10:50:38]  INFO server:      enabled
[2024-03-17 10:50:38]  INFO server: -> extended_error_code:
[2024-03-17 10:50:38]  INFO server:      enabled
[2024-03-17 10:50:38]  INFO server: -> query_logging:
[2024-03-17 10:50:38]  INFO server:      type: csv
[2024-03-17 10:50:38]  INFO server:      target: /var/log/blocky
[2024-03-17 10:50:38]  INFO server:      logRetentionDays: 0
[2024-03-17 10:50:38]  INFO server:      flushInterval: 30 seconds
[2024-03-17 10:50:38]  INFO server:      fields: [clientIP clientName responseReason responseAnswer question duration]
[2024-03-17 10:50:38]  INFO server: -> metrics:
[2024-03-17 10:50:38]  INFO server:      url path: /metrics
[2024-03-17 10:50:38]  INFO server: -> custom_dns:
[2024-03-17 10:50:38]  INFO server:      mapping:
[2024-03-17 10:50:38]  INFO server:        time.google.com = [  300     CLASS0  None    192.168.88.254]
[2024-03-17 10:50:38]  INFO server:        pool.ntp.org = [     300     CLASS0  None    192.168.88.254]
[2024-03-17 10:50:38]  INFO server: -> blocking:
[2024-03-17 10:50:38]  INFO server:      clientGroupsBlock:
[2024-03-17 10:50:38]  INFO server:        default = [ads]
[2024-03-17 10:50:38]  INFO server:      blockType = zeroIP
[2024-03-17 10:50:38]  INFO server:      blockTTL = 5 minutes
[2024-03-17 10:50:38]  INFO server:      loading:
[2024-03-17 10:50:38]  INFO server:        concurrency = 4
[2024-03-17 10:50:38]  INFO server:        refresh = every 12 hours
[2024-03-17 10:50:38]  INFO server:        downloads:
[2024-03-17 10:50:38]  INFO server:          timeout = 30 seconds
[2024-03-17 10:50:38]  INFO server:          attempts = 3
[2024-03-17 10:50:38]  INFO server:      blacklist:
[2024-03-17 10:50:38]  INFO server:        ads:
[2024-03-17 10:50:38]  INFO server:           - https://cdn.jsdelivr.net/gh/hagezi/dns-blocklists@main/wildcard/multi.txt
[2024-03-17 10:50:38]  INFO server:      whitelist:
[2024-03-17 10:50:38]  INFO server:      blacklist cache entries:
[2024-03-17 10:50:38]  INFO server:        ads: 0 entries
[2024-03-17 10:50:38]  INFO server:        TOTAL: 0 entries
[2024-03-17 10:50:38]  INFO server:      whitelist cache entries:
[2024-03-17 10:50:38]  INFO server:        TOTAL: 0 entries
[2024-03-17 10:50:38]  INFO server: -> caching:
[2024-03-17 10:50:38]  INFO server:      minTime = 10 minutes
[2024-03-17 10:50:38]  INFO server:      maxTime = 1 hour
[2024-03-17 10:50:38]  INFO server:      cacheTimeNegative = 30 minutes
[2024-03-17 10:50:38]  INFO server:      prefetching:
[2024-03-17 10:50:38]  INFO server:        expires   = 2 hours
[2024-03-17 10:50:38]  INFO server:        threshold = 5
[2024-03-17 10:50:38]  INFO server:        maxItems  = 0
[2024-03-17 10:50:38]  INFO server:      cache entries = 0
[2024-03-17 10:50:38]  INFO server: -> special_use_domains:
[2024-03-17 10:50:38]  INFO server: -> parallel_best:
[2024-03-17 10:50:38]  INFO server:      group: default
[2024-03-17 10:50:38]  INFO server:      upstreams:
[2024-03-17 10:50:38]  INFO server:        - tcp-tls:blocky-alpine-dot-xyz123.dns.nextdns.io
[2024-03-17 10:50:38]  INFO server:        - https://dns.nextdns.io/xyz123/blocky-alpine-doh
[2024-03-17 10:50:38]  INFO server: listeners:
[2024-03-17 10:50:38]  INFO server:   DNS   = [0.0.0.0:53]
[2024-03-17 10:50:38]  INFO server:   TLS   = []
[2024-03-17 10:50:38]  INFO server:   HTTP  = [0.0.0.0:4000]
[2024-03-17 10:50:38]  INFO server:   HTTPS = []
[2024-03-17 10:50:38]  INFO server: runtime information:
[2024-03-17 10:50:38]  INFO server:   numCPU =       4
[2024-03-17 10:50:38]  INFO server:   numGoroutine = 24
[2024-03-17 10:50:38]  INFO server:   memory:
[2024-03-17 10:50:38]  INFO server:     heap =              1 MB
[2024-03-17 10:50:38]  INFO server:     sys =              13 MB
[2024-03-17 10:50:38]  INFO server:     numGC =             4
[2024-03-17 10:50:38]  INFO server: Starting server
[2024-03-17 10:50:38]  INFO server: TCP server is up and running on address 0.0.0.0:53
[2024-03-17 10:50:38]  INFO server: http server is up and running on addr/port 0.0.0.0:4000
[2024-03-17 10:50:38]  INFO server: UDP server is up and running on address 0.0.0.0:53
[2024-03-17 10:50:40]  INFO list_cache: import succeeded count=134158 source=https://cdn.jsdelivr.net/gh/hagezi/dns-blocklists@main/wildcard/multi.txt
[2024-03-17 10:50:40]  INFO list_cache: group import finished group=ads total_count=134158

and then I get these:

[2024-03-17 10:53:26] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 192.168.88.254:19412->192.168.88.1:53: i/o timeout
[2024-03-17 10:53:26] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 192.168.88.254:31107->192.168.88.1:53: i/o timeout
[2024-03-17 10:53:26] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 192.168.88.254:48381->192.168.88.1:53: i/o timeout
[2024-03-17 10:53:26] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 192.168.88.254:34525->192.168.88.1:53: i/o timeout
[2024-03-17 10:53:26] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 192.168.88.254:15692->192.168.88.1:53: i/o timeout
[2024-03-17 10:53:26] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 192.168.88.254:52251->192.168.88.1:53: i/o timeout
[2024-03-17 10:53:26] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 192.168.88.254:52061->192.168.88.1:53: i/o timeout
[2024-03-17 10:53:26] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 192.168.88.254:35815->192.168.88.1:53: i/o timeout
[2024-03-17 10:53:26] ERROR server: error on processing request:upstream 'tcp+udp:192.168.88.1': can't resolve request via upstream server tcp+udp:192.168.88.1 (192.168.88.1:53): read udp 192.168.88.254:44663->192.168.88.1:53: i/o timeout

I'm good with the Mikrotik DNS server is a problem.. but then where are those Speical entries..

But when I dig the mikrotik dns server it has answers and seems to answer in an acceptable time.

the 88.1 just forwards to the 88.254 for recursion..

(again)

without the conditional I don't have those errors..

AND

without the conditional I don't ever see 'Special' entries in the DNS anymore..

@ThinkChaos
Copy link
Collaborator

but then where are those Speical entries..

Can you please explain what you're doing, what you expect to see, and what you're seeing for this?
It seems we're just not understanding each other relating to SUDN.

the 88.1 just forwards to the 88.254 for recursion..

IIUC 88.254 is blocky. Any chance there's a query loop?
As in blocky queries Mikrotik, which queries blocky, and so on. Thus they're all waiting for each other and it times-out.

Another test you could do is change the router to not query blocky at all, but a third party resolver, and configure blocky to use the router as sole upstream.
That way we'll know if blocky can query it successfully, or if it doesn't, there's a lot more chances of a bug here.

@kwitsch
Copy link
Collaborator

kwitsch commented Mar 31, 2024

I read through this issue again and

IIUC 88.254 is blocky. Any chance there's a query loop?
As in blocky queries Mikrotik, which queries blocky, and so on. Thus they're all waiting for each other and it times-out.

Sounds the most likely to me.

Have you checked the logs of 1 and 254 for a resolution loop?

@kwitsch kwitsch added the 👋 help wanted Extra attention is needed label Mar 31, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
👋 help wanted Extra attention is needed
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@ThinkChaos @kwitsch @bcookatpcsd