search

netbirdio / netbird

Connect your devices into a secure WireGuard®-based overlay network with SSO, MFA and granular access controls.
https://netbird.io
BSD 3-Clause "New" or "Revised" License
10.5k stars 472 forks source link

NetBird disconnects after a couple of seconds on Windows Server 2016 #2281

Closed Mntz closed 1 month ago

Mntz commented 1 month ago

Describe the problem Bringing the service up connects the client to the control plane but then loses connection after a couple of seconds. Other devices are connecting just fine using both SSO and setup key.

To Reproduce Restarting the service or using the netbird up command.

Expected behavior The connection should stay active.

Are you using NetBird Cloud? No, selfhosted.

NetBird version 0.28.4 on Windows Server 2016 Core

NetBird status -d output:

2024-07-17T09:57:01+02:00 DEBG client/internal/login.go:93: connecting to the Management service https://netbird.ourdomain.com:33073
2024-07-17T09:57:01+02:00 DEBG client/internal/login.go:63: connected to the Management service https://netbird.ourdomain.com:33073
2024-07-17T09:57:02+02:00 DEBG client/internal/login.go:93: connecting to the Management service https://netbird.ourdomain.com:33073
2024-07-17T09:57:02+02:00 DEBG client/internal/login.go:63: connected to the Management service https://netbird.ourdomain.com:33073
2024-07-17T09:57:03+02:00 INFO client/internal/connect.go:119: starting NetBird client version 0.28.4 on windows/amd64
2024-07-17T09:57:03+02:00 DEBG client/internal/connect.go:180: connecting to the Management service netbird.ourdomain.com:33073
2024-07-17T09:57:03+02:00 DEBG client/internal/connect.go:188: connected to the Management service netbird.ourdomain.com:33073
2024-07-17T09:57:03+02:00 DEBG signal/client/grpc.go:92: connected to Signal Service: netbird.ourdomain.com:10000
2024-07-17T09:57:03+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:343: Route for 0.0.0.0: interface &{6 1500 Ethernet0 00:50:56:a8:ec:73 up|broadcast|multicast|running} nexthop 192.168.254.250, preferred source 192.168.254.6
2024-07-17T09:57:03+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:343: Route for ::: interface &{5 1280 Teredo Tunneling Pseudo-Interface 00:00:00:00:00:00:00:e0 up|pointtopoint|multicast|running} nexthop <nil>, preferred source 2001:0:2851:782c:2027:370e:3f57:1f9
2024-07-17T09:57:03+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:352: No next hop found for IP ::, using preferred source 2001:0:2851:782c:2027:370e:3f57:1f9
2024-07-17T09:57:03+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:343: Route for ##.##.##.##: interface &{6 1500 Ethernet0 00:50:56:a8:ec:73 up|broadcast|multicast|running} nexthop 192.168.254.250, preferred source 192.168.254.6
2024-07-17T09:57:03+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:144: Found next hop 192.168.254.250 for prefix ##.##.##.##/32 with interface 192.168.254.250
2024-07-17T09:57:03+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:162: Adding a new route for prefix ##.##.##.##/32 with next hop 192.168.254.250
2024-07-17T09:57:03+02:00 INFO client/internal/routemanager/manager.go:133: Routing setup complete
2024/07/17 09:57:03 Using existing driver 0.14
2024/07/17 09:57:03 Creating adapter
2024-07-17T09:57:04+02:00 DEBG iface/tun_windows.go:153: adding address 100.110.46.169 to interface: wt0
2024-07-17T09:57:04+02:00 DEBG iface/wg_configurer_usp.go:39: adding Wireguard private key
2024-07-17T09:57:04+02:00 DEBG iface/tun_windows.go:100: device is ready to use: wt0
2024-07-17T09:57:04+02:00 DEBG signal/client/grpc.go:137: signal connection state READY
2024-07-17T09:57:04+02:00 INFO signal/client/grpc.go:158: connected to the Signal Service stream
2024-07-17T09:57:04+02:00 DEBG client/internal/engine.go:683: connecting to Management Service updates stream
2024-07-17T09:57:04+02:00 INFO client/internal/connect.go:267: Netbird engine started, the IP is: 100.110.46.169/16
2024-07-17T09:57:04+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:343: Route for 0.0.0.0: interface &{6 1500 Ethernet0 00:50:56:a8:ec:73 up|broadcast|multicast|running} nexthop 192.168.254.250, preferred source 192.168.254.6
2024-07-17T09:57:04+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:343: Route for ::: interface &{2 1280 isatap.{1ED947B0-49BE-4012-9809-569CAA0BA099} 00:00:00:00:00:00:00:e0 pointtopoint|multicast} nexthop <nil>, preferred source 2001:0:2851:782c:2027:370e:3f57:1f9
2024-07-17T09:57:04+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:352: No next hop found for IP ::, using preferred source 2001:0:2851:782c:2027:370e:3f57:1f9
2024-07-17T09:57:04+02:00 DEBG client/internal/networkmonitor/monitor_generic.go:43: Network monitor: IPv4 default route: 192.168.254.250, interface: Ethernet0
2024-07-17T09:57:04+02:00 DEBG client/internal/networkmonitor/monitor_generic.go:46: Network monitor: IPv6 default route: 2001:0:2851:782c:2027:370e:3f57:1f9, interface: isatap.{1ED947B0-49BE-4012-9809-569CAA0BA099}
2024-07-17T09:57:07+02:00 DEBG client/internal/networkmonitor/monitor_windows.go:40: Network monitor: initial IPv4 neighbor: &{192.168.254.250 EC-67-94-68-7C-80 5 2 6 Ethernet0}, IPv6 neighbor: <nil>
2024-07-17T09:57:07+02:00 DEBG management/client/grpc.go:123: management connection state READY
2024-07-17T09:57:07+02:00 INFO management/client/grpc.go:164: connected to the Management Service stream
2024-07-17T09:57:07+02:00 DEBG management/client/grpc.go:261: got an update message from Management Service
2024-07-17T09:57:07+02:00 DEBG client/internal/engine.go:709: got TURNs update from Management Service, updating
2024-07-17T09:57:07+02:00 DEBG client/internal/engine.go:691: got STUNs update from Management Service, updating
2024-07-17T09:57:07+02:00 WARN client/internal/engine.go:587: running SSH server is not permitted
2024-07-17T09:57:07+02:00 DEBG client/internal/engine.go:754: got peers update from Management Service, total peers to connect to = 0
2024-07-17T09:57:07+02:00 DEBG client/internal/engine.go:440: removing all peer connections
2024-07-17T09:57:07+02:00 DEBG client/internal/dns/service_memory.go:51: dns service listening on: 100.110.255.254
2024-07-17T09:57:07+02:00 INFO client/internal/dns/host_windows.go:111: configured 100.110.255.254:53 as main DNS forwarder for this peer
2024-07-17T09:57:07+02:00 INFO client/internal/dns/host_windows.go:149: added 2 match domains to the state. Domain list: [.company.local .netbird.company]
2024-07-17T09:57:07+02:00 INFO client/internal/dns/host_windows.go:176: updated the search domains in the registry with 2 domains. Domain list: [company.local netbird.company]
2024-07-17T09:57:07+02:00 INFO client/internal/acl/manager.go:52: ACL rules processed in: 0s, total rules count: 0
2024-07-17T09:57:17+02:00 DEBG client/internal/networkmonitor/monitor_windows.go:133: network monitor: found matching default route: Nexthop: 192.168.254.250, Interface: Ethernet0
2024-07-17T09:57:17+02:00 INFO client/internal/networkmonitor/monitor_windows.go:154: network monitor: default route for 2001:0:2851:782c:2027:370e:3f57:1f9 (isatap.{1ED947B0-49BE-4012-9809-569CAA0BA099}) is gone or changed
2024-07-17T09:57:18+02:00 INFO client/internal/engine.go:1505: Network monitor detected network change, restarting engine
2024-07-17T09:57:18+02:00 INFO client/internal/engine.go:252: Network monitor: stopped
2024-07-17T09:57:18+02:00 DEBG signal/client/grpc.go:389: stream canceled (usually indicates shutdown)
2024-07-17T09:57:18+02:00 DEBG signal/client/grpc.go:164: signal connection context has been canceled, this usually indicates shutdown
2024-07-17T09:57:18+02:00 DEBG management/client/grpc.go:257: disconnected from Management Service sync stream: rpc error: code = Canceled desc = context canceled
2024-07-17T09:57:18+02:00 DEBG management/client/grpc.go:175: management connection context has been canceled, this usually indicates shutdown
2024-07-17T09:57:18+02:00 DEBG client/internal/engine.go:681: stopped receiving updates from Management Service
2024-07-17T09:57:18+02:00 DEBG client/internal/engine.go:440: removing all peer connections
2024-07-17T09:57:18+02:00 INFO client/internal/routemanager/manager.go:168: Routing cleanup complete
2024-07-17T09:57:18+02:00 DEBG client/internal/engine.go:1236: removing Netbird interface wt0
2024-07-17T09:57:19+02:00 INFO client/internal/engine.go:269: stopped Netbird Engine
2024-07-17T09:57:19+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:343: Route for 0.0.0.0: interface &{6 1500 Ethernet0 00:50:56:a8:ec:73 up|broadcast|multicast|running} nexthop 192.168.254.250, preferred source 192.168.254.6
2024-07-17T09:57:19+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:343: Route for ::: interface &{5 1280 Teredo Tunneling Pseudo-Interface 00:00:00:00:00:00:00:e0 up|pointtopoint|multicast|running} nexthop <nil>, preferred source 2001:0:2851:782c:2027:370e:3f57:1f9
2024-07-17T09:57:19+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:352: No next hop found for IP ::, using preferred source 2001:0:2851:782c:2027:370e:3f57:1f9
2024-07-17T09:57:19+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:343: Route for ##.##.##.##: interface &{6 1500 Ethernet0 00:50:56:a8:ec:73 up|broadcast|multicast|running} nexthop 192.168.254.250, preferred source 192.168.254.6
2024-07-17T09:57:19+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:144: Found next hop 192.168.254.250 for prefix ##.##.##.##/32 with interface 192.168.254.250
2024-07-17T09:57:19+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:162: Adding a new route for prefix ##.##.##.##/32 with next hop 192.168.254.250
2024-07-17T09:57:19+02:00 INFO client/internal/routemanager/manager.go:133: Routing setup complete
2024/07/17 09:57:19 Using existing driver 0.14
2024/07/17 09:57:19 Creating adapter
2024-07-17T09:57:19+02:00 DEBG iface/tun_windows.go:153: adding address 100.110.46.169 to interface: wt0
2024-07-17T09:57:19+02:00 DEBG iface/wg_configurer_usp.go:39: adding Wireguard private key
2024-07-17T09:57:19+02:00 DEBG iface/tun_windows.go:100: device is ready to use: wt0
2024-07-17T09:57:19+02:00 DEBG client/internal/engine.go:683: connecting to Management Service updates stream
2024-07-17T09:57:19+02:00 DEBG signal/client/grpc.go:137: signal connection state READY
2024-07-17T09:57:19+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:343: Route for 0.0.0.0: interface &{6 1500 Ethernet0 00:50:56:a8:ec:73 up|broadcast|multicast|running} nexthop 192.168.254.250, preferred source 192.168.254.6
2024-07-17T09:57:19+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:343: Route for ::: interface &{2 1280 isatap.{85CBBD5A-A8E4-4AEB-AECC-97D995BC5EC0} 00:00:00:00:00:00:00:e0 pointtopoint|multicast} nexthop <nil>, preferred source 2001:0:2851:782c:2027:370e:3f57:1f9
2024-07-17T09:57:19+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:352: No next hop found for IP ::, using preferred source 2001:0:2851:782c:2027:370e:3f57:1f9
2024-07-17T09:57:19+02:00 DEBG client/internal/networkmonitor/monitor_generic.go:43: Network monitor: IPv4 default route: 192.168.254.250, interface: Ethernet0
2024-07-17T09:57:19+02:00 DEBG client/internal/networkmonitor/monitor_generic.go:46: Network monitor: IPv6 default route: 2001:0:2851:782c:2027:370e:3f57:1f9, interface: isatap.{85CBBD5A-A8E4-4AEB-AECC-97D995BC5EC0}
2024-07-17T09:57:19+02:00 INFO signal/client/grpc.go:158: connected to the Signal Service stream
2024-07-17T09:57:22+02:00 DEBG client/internal/networkmonitor/monitor_windows.go:40: Network monitor: initial IPv4 neighbor: &{192.168.254.250 EC-67-94-68-7C-80 5 2 6 Ethernet0}, IPv6 neighbor: <nil>
2024-07-17T09:57:22+02:00 DEBG management/client/grpc.go:123: management connection state READY
2024-07-17T09:57:22+02:00 INFO management/client/grpc.go:164: connected to the Management Service stream
2024-07-17T09:57:22+02:00 DEBG management/client/grpc.go:261: got an update message from Management Service
2024-07-17T09:57:22+02:00 DEBG client/internal/engine.go:709: got TURNs update from Management Service, updating
2024-07-17T09:57:22+02:00 DEBG client/internal/engine.go:691: got STUNs update from Management Service, updating
2024-07-17T09:57:22+02:00 WARN client/internal/engine.go:587: running SSH server is not permitted
2024-07-17T09:57:22+02:00 DEBG client/internal/engine.go:754: got peers update from Management Service, total peers to connect to = 0
2024-07-17T09:57:22+02:00 DEBG client/internal/engine.go:440: removing all peer connections
2024-07-17T09:57:22+02:00 DEBG client/internal/dns/service_memory.go:51: dns service listening on: 100.110.255.254
2024-07-17T09:57:22+02:00 INFO client/internal/dns/host_windows.go:111: configured 100.110.255.254:53 as main DNS forwarder for this peer
2024-07-17T09:57:22+02:00 INFO client/internal/dns/host_windows.go:149: added 2 match domains to the state. Domain list: [.company.local .netbird.company]
2024-07-17T09:57:22+02:00 INFO client/internal/dns/host_windows.go:176: updated the search domains in the registry with 2 domains. Domain list: [company.local netbird.company]
2024-07-17T09:57:22+02:00 INFO client/internal/acl/manager.go:52: ACL rules processed in: 0s, total rules count: 0
2024-07-17T09:57:32+02:00 DEBG client/internal/networkmonitor/monitor_windows.go:133: network monitor: found matching default route: Nexthop: 192.168.254.250, Interface: Ethernet0
2024-07-17T09:57:32+02:00 INFO client/internal/networkmonitor/monitor_windows.go:154: network monitor: default route for 2001:0:2851:782c:2027:370e:3f57:1f9 (isatap.{85CBBD5A-A8E4-4AEB-AECC-97D995BC5EC0}) is gone or changed
2024-07-17T09:57:33+02:00 INFO client/internal/engine.go:1505: Network monitor detected network change, restarting engine
2024-07-17T09:57:33+02:00 INFO client/internal/engine.go:252: Network monitor: stopped
2024-07-17T09:57:33+02:00 DEBG client/internal/engine.go:440: removing all peer connections
2024-07-17T09:57:33+02:00 DEBG management/client/grpc.go:257: disconnected from Management Service sync stream: rpc error: code = Canceled desc = context canceled
2024-07-17T09:57:33+02:00 DEBG management/client/grpc.go:175: management connection context has been canceled, this usually indicates shutdown
2024-07-17T09:57:33+02:00 DEBG client/internal/engine.go:681: stopped receiving updates from Management Service
2024-07-17T09:57:33+02:00 DEBG signal/client/grpc.go:389: stream canceled (usually indicates shutdown)
2024-07-17T09:57:33+02:00 DEBG signal/client/grpc.go:164: signal connection context has been canceled, this usually indicates shutdown
2024-07-17T09:57:34+02:00 INFO client/internal/routemanager/manager.go:168: Routing cleanup complete
2024-07-17T09:57:34+02:00 DEBG client/internal/engine.go:1236: removing Netbird interface wt0
2024-07-17T09:57:34+02:00 INFO client/internal/engine.go:269: stopped Netbird Engine
2024-07-17T09:57:34+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:343: Route for 0.0.0.0: interface &{6 1500 Ethernet0 00:50:56:a8:ec:73 up|broadcast|multicast|running} nexthop 192.168.254.250, preferred source 192.168.254.6
2024-07-17T09:57:34+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:343: Route for ::: interface &{5 1280 Teredo Tunneling Pseudo-Interface 00:00:00:00:00:00:00:e0 up|pointtopoint|multicast|running} nexthop <nil>, preferred source 2001:0:2851:782c:2027:370e:3f57:1f9
2024-07-17T09:57:34+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:352: No next hop found for IP ::, using preferred source 2001:0:2851:782c:2027:370e:3f57:1f9
2024-07-17T09:57:34+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:343: Route for ##.##.##.##: interface &{6 1500 Ethernet0 00:50:56:a8:ec:73 up|broadcast|multicast|running} nexthop 192.168.254.250, preferred source 192.168.254.6
2024-07-17T09:57:34+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:144: Found next hop 192.168.254.250 for prefix ##.##.##.##/32 with interface 192.168.254.250
2024-07-17T09:57:34+02:00 DEBG client/internal/routemanager/systemops/systemops_generic.go:162: Adding a new route for prefix ##.##.##.##/32 with next hop 192.168.254.250
2024-07-17T09:57:34+02:00 INFO client/internal/routemanager/manager.go:133: Routing setup complete
2024/07/17 09:57:34 Using existing driver 0.14
2024/07/17 09:57:34 Creating adapter
2024-07-17T09:57:34+02:00 DEBG iface/tun_windows.go:153: adding address 100.110.46.169 to interface: wt0
2024-07-17T09:57:34+02:00 DEBG iface/wg_configurer_usp.go:39: adding Wireguard private key
2024-07-17T09:57:34+02:00 ERRO client/internal/engine.go:352: failed to pull up wgInterface [wt0]: ICEBind has not been initialized yet
2024-07-17T09:57:34+02:00 INFO client/internal/routemanager/manager.go:168: Routing cleanup complete
2024-07-17T09:57:34+02:00 DEBG client/internal/engine.go:1236: removing Netbird interface wt0
2024-07-17T09:57:34+02:00 ERRO client/internal/engine.go:1473: Failed to start engine: up wg interface: ICEBind has not been initialized yet
pascal-fischer commented 1 month ago

Hi @Mntz, thank you for reporting the issue. We noticed a problem with ISATAP devices and our network monitor causing false restarts. We are currently working on a fix to avoid those. In the meantime could you disable the network monitor by running netbird up --network-monitor=false once? This will make the agent operational again until the fix is released. You only need to set the flag once during up command, after that it is stored in the config.

Mntz commented 1 month ago

Great, that fixed it. Thanks!

pascal-fischer commented 1 month ago

Hi @Mntz, today we released version 0.28.5. This should fix the network monitor. You should be save to re-enable it for the best experience.

Mntz commented 1 month ago

Just upgraded and enabled the network monitor but then the tunnel goes down again after a couple of seconds. The work-around still works fine with 0.28.5.

mlsmaycon commented 1 month ago

Hello @Mntz can you enable the network monitor and run the following command to get the new logs?

netbird -A debug for 2m

This will generate an anonymized log file.

Mntz commented 1 month ago

Sure, hope this helps: netbird.debug.1880172993.zip

ismail0234 commented 1 month ago

@mlsmaycon I have the same problem, after installation it restarts itself every 2-3 seconds.

ismail0234 commented 1 month ago

But after installation I restarted the computer and the problem was fixed.

mlsmaycon commented 1 month ago

Hello, @Mntz @ismail0234, we have a new implementation that covers the case when the ISATAP and TEREDO interfaces are not present.

If you are willing to give it a try, you can download the build package here: https://github.com/netbirdio/netbird/actions/runs/10042608221/artifacts/1726240177

once you download the and extract the file and copy the netbird.exe to C:\Program Files\NetBird\netbird.exe, for that you need to stop the service: Powershell with admin

netbird service stop

once you copy the file you can start again with:

netbird service start
ldaroczi commented 1 month ago

Hello @mlsmaycon

I have a similar problem, but on Windows 11 23H2 (OS Build 22631.3888). I have downloaded and installed the latest version of Netbird (netbird_installer_0.28.6_windows_amd64.exe). If I set the network-monitor to false the connection is not reset.

netbird.debug.317635943.zip

Mntz commented 1 month ago

Hi @mlsmaycon,

I've tested your build and can confirm the connection is now not dropping anymore when the network monitor is active. Thanks!