Probing upstream nameserver timeout

[AUMakarov]

Describe the problem

I have selfhosted Netbird with 5+ internal networks and 5+ internal domains each on own network. Any connecting through one bastion. After the start of the connection process on client, there is a pause until the start of traffic transfer to the internal networks. The duration of the pause is directly proportional to the number of domains in the internal networks

To Reproduce

Steps to reproduce the behavior:

1. Install selfhosted (+Keycloak) and bastion
2. Configure 5 domains in internal network
3. Setup client on new peer
4. In terminal tail -f /var/log/netbird/client.log
5. View log

Expected behavior

No timeouts in connecting process

Are you using NetBird Cloud?

Self-host NetBird's control plane.

NetBird version

server:
  UI v2.1.2
  Manager 0.26.3
  Signal 0.26.3

basion 0.26.2

client 0.26.3

NetBird status -d output:

  Peers detail:
   bastion.netbird.selfhosted:
    NetBird IP: 100.70.55.175
    Public key: [obfuscated]
    Status: Connected
    -- detail --
    Connection type: P2P
    Direct: true
    ICE candidate (Local/Remote): host/srflx
    ICE candidate endpoints (Local/Remote): 192.168.0.15:51820/a.b.c.d:51820
    Last connection update: 2024-03-14 17:42:25
    Last WireGuard handshake: 2024-03-14 17:42:25
    Transfer status (received/sent) 175.8 KiB/206.9 KiB
    Quantum resistance: false
    Routes: 10.0.0.0/8
  
  Daemon version: 0.26.3
  CLI version: 0.26.3
  Management: Connected to https://netbird.example.com:33073
  Signal: Connected to http://netbird.example.com:10000
  Relays: 
    [stun:netbird.example.com:3478] is Available
    [turn:netbird.example.com:3478?transport=udp] is Available
  Nameservers: 
    [10.1.0.2:53] for [d1 d2 d3 d4 ... d15 ] is Available
  FQDN: client.netbird.selfhosted
  NetBird IP: 100.70.8.100/16
  Interface type: Userspace
  Quantum resistance: false
  Routes: -
  Peers count: 1/1 Connected

Additional context

Log file

2024-03-14T17:41:39+03:00 INFO client/internal/connect.go:96: starting NetBird client version 0.26.3
2024-03-14T17:41:40+03:00 INFO signal/client/grpc.go:156: connected to the Signal Service stream
2024-03-14T17:41:40+03:00 INFO client/internal/connect.go:239: Netbird engine started, my IP is: 100.70.8.100/16
2024-03-14T17:41:40+03:00 INFO management/client/grpc.go:145: connected to the Management Service stream
2024-03-14T17:41:40+03:00 WARN client/internal/routemanager/client.go:121: the network 10.0.0.0/8 has not been assigned a routing peer as no peers from the list [obfuscated] are currently connected
2024-03-14T17:41:40+03:00 INFO client/internal/dns/host_darwin.go:170: added 15 match domains to the state. Domain list: d1 d2 d3 ... d15
2024-03-14T17:41:40+03:00 INFO client/internal/dns/host_darwin.go:157: added 1 search domains to the state. Domain list: netbird.selfhosted
2024-03-14T17:41:42+03:00 WARN client/internal/dns/upstream.go:185: probing upstream nameserver 10.1.0.2:53: read udp 172.16.0.1:60499->10.1.0.2:53: i/o timeout
2024-03-14T17:41:42+03:00 WARN client/internal/dns/upstream.go:265: Upstream resolving is Disabled for 30s
2024-03-14T17:41:42+03:00 INFO [nameservers: [{10.1.0.2 udp 53}]] client/internal/dns/server.go:500: Temporarily deactivating nameservers group due to timeout
2024-03-14T17:41:42+03:00 INFO client/internal/dns/host_darwin.go:91: removing match domains from the system
2024-03-14T17:41:43+03:00 INFO client/internal/dns/host_darwin.go:157: added 1 search domains to the state. Domain list: netbird.selfhosted
2024-03-14T17:41:45+03:00 WARN client/internal/dns/upstream.go:185: probing upstream nameserver 10.1.0.2:53: read udp 172.16.0.1:52508->10.1.0.2:53: i/o timeout
2024-03-14T17:41:47+03:00 WARN client/internal/dns/upstream.go:185: probing upstream nameserver 10.1.0.2:53: read udp 172.16.0.1:65428->10.1.0.2:53: i/o timeout
2024-03-14T17:41:49+03:00 WARN client/internal/dns/upstream.go:185: probing upstream nameserver 10.1.0.2:53: read udp 172.16.0.1:65372->10.1.0.2:53: i/o timeout
2024-03-14T17:41:51+03:00 WARN client/internal/dns/upstream.go:185: probing upstream nameserver 10.1.0.2:53: read udp 172.16.0.1:56159->10.1.0.2:53: i/o timeout
2024-03-14T17:41:53+03:00 WARN client/internal/dns/upstream.go:185: probing upstream nameserver 10.1.0.2:53: read udp 172.16.0.1:50061->10.1.0.2:53: i/o timeout
2024-03-14T17:41:55+03:00 WARN client/internal/dns/upstream.go:185: probing upstream nameserver 10.1.0.2:53: read udp 172.16.0.1:56439->10.1.0.2:53: i/o timeout
2024-03-14T17:41:57+03:00 WARN client/internal/dns/upstream.go:185: probing upstream nameserver 10.1.0.2:53: read udp 172.16.0.1:65124->10.1.0.2:53: i/o timeout
2024-03-14T17:41:59+03:00 WARN client/internal/dns/upstream.go:185: probing upstream nameserver 10.1.0.2:53: read udp 172.16.0.1:52500->10.1.0.2:53: i/o timeout
2024-03-14T17:42:01+03:00 WARN client/internal/dns/upstream.go:185: probing upstream nameserver 10.1.0.2:53: read udp 172.16.0.1:53120->10.1.0.2:53: i/o timeout
2024-03-14T17:42:03+03:00 WARN client/internal/dns/upstream.go:185: probing upstream nameserver 10.1.0.2:53: read udp 172.16.0.1:55238->10.1.0.2:53: i/o timeout
2024-03-14T17:42:05+03:00 WARN client/internal/dns/upstream.go:185: probing upstream nameserver 10.1.0.2:53: read udp 172.16.0.1:62492->10.1.0.2:53: i/o timeout
2024-03-14T17:42:07+03:00 WARN client/internal/dns/upstream.go:185: probing upstream nameserver 10.1.0.2:53: read udp 172.16.0.1:49858->10.1.0.2:53: i/o timeout
2024-03-14T17:42:09+03:00 WARN client/internal/dns/upstream.go:185: probing upstream nameserver 10.1.0.2:53: read udp 172.16.0.1:62211->10.1.0.2:53: i/o timeout
2024-03-14T17:42:11+03:00 WARN client/internal/dns/upstream.go:185: probing upstream nameserver 10.1.0.2:53: read udp 172.16.0.1:59597->10.1.0.2:53: i/o timeout
2024-03-14T17:42:11+03:00 INFO client/internal/acl/manager.go:52: ACL rules processed in: 610.417µs, total rules count: 2
2024-03-14T17:42:25+03:00 INFO client/internal/peer/conn.go:358: connected to peer [obfuscated], endpoint address: a.b.c.d:51820
2024-03-14T17:42:25+03:00 INFO client/internal/routemanager/client.go:124: new chosen route is [obfuscated] with peer [obfuscated] with score 2 for network 10.0.0.0/8
2024-03-14T17:42:27+03:00 INFO client/internal/dns/upstream.go:241: upstreams [10.1.0.2:53] are responsive again. Adding them back to system
2024-03-14T17:42:27+03:00 INFO client/internal/dns/host_darwin.go:170: added 15 match domains to the state. Domain list: d1 d2 d3 ... d15
2024-03-14T17:42:27+03:00 INFO client/internal/dns/host_darwin.go:157: added 1 search domains to the state. Domain list: netbird.selfhosted

[mlsmaycon]

Hello @AUMakarov, thanks for reporting the issue. We will work on a fix for the next release.

[AUMakarov]

Hi! in version 0.26.6, the problem is repeated at the stage of checking each DNS server.
probing upstream nameserver 10.1.0.2:53: read udp 192.168.101.133:57899->10.1.0.2:53: i/o timeout

[1ndef1n1te]

+1 We faced with the same problem

2024-08-03T00:26:11+03:00 TRAC client/internal/dns/upstream.go:223: upstream check for {{dns-ip}}:53: read udp {{peer-ip}}:57895->{{dns-ip}}:53: i/o timeout
2024-08-03T00:26:11+03:00 TRAC client/internal/dns/upstream.go:230: checking connectivity with upstreams [{{dns-ip}}:53] failed. Retrying in 790.015175ms
2024-08-03T00:26:13+03:00 INFO client/internal/dns/upstream.go:240: upstreams [{{dns-ip}}:53] are responsive again. Adding them back to system

[nazarewk]

@1ndef1n1te @AUMakarov Are you still having the issue with the latest NetBird version?