Devices on LAN won't connect any longer

Support
1

I’ve been using Syncthing for about 2 years fairly successfully to one-way-sync one Windows 10 desktop to a Synology NAS, which I then backup to Backblaze. I check the setup every few months to make sure everything is working. When I checked today I found that both the Windows machine and the NAS show “Disconnected” for the other device. I’m a little beyond my pay grade here and am hoping I can get some help figuring this out.

Both devices are on the LAN, same subnet, can ping each other and there is no firewall on the devices or the network. Both are running Syncthing 1.3.3. I also rebooted both. I don’t understand the logging options very well, but did my best and this seems to be relevant. This is from Syncthing on the Synology NAS:

2020-01-25 14:34:36 discover: Received local announcement from x.x.x.29:60247 for 63DC5KJ-PEQVRPA-R6OAKVE-OHVKXOW-H45235O-TLMXZCU-QX44ORY-YBTC5AN
2020-01-25 14:34:36 discover: Received local announcement from z.z.z.6:60247 for 63DC5KJ-PEQVRPA-R6OAKVE-OHVKXOW-H45235O-TLMXZCU-QX44ORY-YBTC5AN

x.x.x.29:60247 is the NAS static IP on the LAN z.z.z.6:60247 is the IP address of my VPN connection on the NAS 63DC5KJ is the NAS device ID

Seems like that could cause problems if the NAS is sending two announcements for different IPs? I will say that the NAS has been configured this way from the beginning, with it’s own LAN IP and the VPN IP, so I don’t know if anything changed with how Syncthing handles this.

The NAS log seems to loop through the following:

2020-01-25 14:33:24 sleep until next dial 1m0s
2020-01-25 14:33:36 addresses: [x.x.x.255 x.x.x.6]
2020-01-25 14:33:36 sent 91 bytes to x.x.x.255:21027
2020-01-25 14:33:36 sent 91 bytes to x.x.x.6:21027
2020-01-25 14:33:36 write udp [::]:39677->[ff12::8384]:21027: sendmsg: network is unreachable on write to [ff12::8384]:21027 lo
2020-01-25 14:33:36 sent 91 bytes to [ff12::8384]:21027 on eth0
2020-01-25 14:33:36 write udp [::]:39677->[ff12::8384]:21027: sendmsg: network is unreachable on write to [ff12::8384]:21027 sit0
2020-01-25 14:33:36 write udp [::]:39677->[ff12::8384]:21027: sendmsg: network is unreachable on write to [ff12::8384]:21027 tun0
2020-01-25 14:33:36 recv 91 bytes from [x::x::x:x:aa23%eth0]:39677
2020-01-25 14:33:36 discover: Received local announcement from [x::x::x:x:aa23%eth0]:39677 for 63DC5KJ-PEQVRPA-R6OAKVE-OHVKXOW-H45235O-TLMXZCU-QX44ORY-YBTC5AN
2020-01-25 14:33:36 recv 91 bytes from x.x.x.29:60247
2020-01-25 14:33:36 recv 91 bytes from x.x.x.6:60247
2020-01-25 14:33:36 discover: Received local announcement from x.x.x.29:60247 for 63DC5KJ-PEQVRPA-R6OAKVE-OHVKXOW-H45235O-TLMXZCU-QX44ORY-YBTC5AN
2020-01-25 14:33:36 discover: Received local announcement from 10.42.11.6:60247 for 63DC5KJ-PEQVRPA-R6OAKVE-OHVKXOW-H45235O-TLMXZCU-QX44ORY-YBTC5AN
2020-01-25 14:33:46 recv 91 bytes from 192.168.1.11:61225
2020-01-25 14:33:46 discover: Received local announcement from 192.168.1.11:61225 for CORYQAA-WI4GCCW-5S42YE3-TZCIEUK-ZHPEFFZ-JYZCQ2A-WT4F52O-ICDTHAE
2020-01-25 14:33:46 discover: Registering addresses for CORYQAA-WI4GCCW-5S42YE3-TZCIEUK-ZHPEFFZ-JYZCQ2A-WT4F52O-ICDTHAE
2020-01-25 14:33:46 discover: Reconstructed URL is &url.URL{Scheme:"tcp", Opaque:"", User:(*url.Userinfo)(nil), Host:"192.168.1.11:22000", Path:"", RawPath:"", ForceQuery:false, RawQuery:"", Fragment:""}
2020-01-25 14:33:46 discover: Replaced address 0.0.0.0 in tcp://0.0.0.0:22000 to get tcp://192.168.1.11:22000
2020-01-25 14:33:46 discover: Reconstructed URL is &url.URL{Scheme:"quic", Opaque:"", User:(*url.Userinfo)(nil), Host:"192.168.1.11:22000", Path:"", RawPath:"", ForceQuery:false, RawQuery:"", Fragment:""}
2020-01-25 14:33:46 discover: Replaced address 0.0.0.0 in quic://0.0.0.0:22000 to get quic://192.168.1.11:22000
2020-01-25 14:34:06 addresses: [192.168.1.255 10.42.11.6]
2020-01-25 14:34:06 sent 91 bytes to 192.168.1.255:21027
2020-01-25 14:34:06 sent 91 bytes to 10.42.11.6:21027
2020-01-25 14:34:06 write udp [::]:39677->[ff12::8384]:21027: sendmsg: network is unreachable on write to [ff12::8384]:21027 lo
2020-01-25 14:34:06 sent 91 bytes to [ff12::8384]:21027 on eth0
2020-01-25 14:34:06 write udp [::]:39677->[ff12::8384]:21027: sendmsg: network is unreachable on write to [ff12::8384]:21027 sit0
2020-01-25 14:34:06 write udp [::]:39677->[ff12::8384]:21027: sendmsg: network is unreachable on write to [ff12::8384]:21027 tun0
2020-01-25 14:34:06 recv 91 bytes from 192.168.1.29:60247
2020-01-25 14:34:06 recv 91 bytes from 10.42.11.6:60247
2020-01-25 14:34:06 discover: Received local announcement from 192.168.1.29:60247 for 63DC5KJ-PEQVRPA-R6OAKVE-OHVKXOW-H45235O-TLMXZCU-QX44ORY-YBTC5AN
2020-01-25 14:34:06 discover: Received local announcement from 10.42.11.6:60247 for 63DC5KJ-PEQVRPA-R6OAKVE-OHVKXOW-H45235O-TLMXZCU-QX44ORY-YBTC5AN
2020-01-25 14:34:06 recv 91 bytes from [fe80::211:32ff:fe12:aa23%eth0]:39677
2020-01-25 14:34:06 discover: Received local announcement from [fe80::211:32ff:fe12:aa23%eth0]:39677 for 63DC5KJ-PEQVRPA-R6OAKVE-OHVKXOW-H45235O-TLMXZCU-QX44ORY-YBTC5AN
2020-01-25 14:34:16 recv 91 bytes from 192.168.1.11:61225
2020-01-25 14:34:16 discover: Received local announcement from 192.168.1.11:61225 for CORYQAA-WI4GCCW-5S42YE3-TZCIEUK-ZHPEFFZ-JYZCQ2A-WT4F52O-ICDTHAE
2020-01-25 14:34:16 discover: Registering addresses for CORYQAA-WI4GCCW-5S42YE3-TZCIEUK-ZHPEFFZ-JYZCQ2A-WT4F52O-ICDTHAE
2020-01-25 14:34:16 discover: Reconstructed URL is &url.URL{Scheme:"tcp", Opaque:"", User:(*url.Userinfo)(nil), Host:"192.168.1.11:22000", Path:"", RawPath:"", ForceQuery:false, RawQuery:"", Fragment:""}
2020-01-25 14:34:16 discover: Replaced address 0.0.0.0 in tcp://0.0.0.0:22000 to get tcp://192.168.1.11:22000
2020-01-25 14:34:16 discover: Reconstructed URL is &url.URL{Scheme:"quic", Opaque:"", User:(*url.Userinfo)(nil), Host:"192.168.1.11:22000", Path:"", RawPath:"", ForceQuery:false, RawQuery:"", Fragment:""}
2020-01-25 14:34:16 discover: Replaced address 0.0.0.0 in quic://0.0.0.0:22000 to get quic://192.168.1.11:22000
2020-01-25 14:34:24 Reconnect loop
2020-01-25 14:34:24 lookup for CORYQAA-WI4GCCW-5S42YE3-TZCIEUK-ZHPEFFZ-JYZCQ2A-WT4F52O-ICDTHAE at IPv4 local
2020-01-25 14:34:24 addresses: [tcp://192.168.1.11:22000 quic://192.168.1.11:22000]
2020-01-25 14:34:24 lookup for CORYQAA-WI4GCCW-5S42YE3-TZCIEUK-ZHPEFFZ-JYZCQ2A-WT4F52O-ICDTHAE at IPv6 local
2020-01-25 14:34:24 addresses: []
2020-01-25 14:34:24 lookup results for CORYQAA-WI4GCCW-5S42YE3-TZCIEUK-ZHPEFFZ-JYZCQ2A-WT4F52O-ICDTHAE
2020-01-25 14:34:24 addresses:  [quic://192.168.1.11:22000 tcp://192.168.1.11:22000]
2020-01-25 14:34:24 Reconnect loop for CORYQAA-WI4GCCW-5S42YE3-TZCIEUK-ZHPEFFZ-JYZCQ2A-WT4F52O-ICDTHAE [quic://192.168.1.11:22000 tcp://192.168.1.11:22000]
2020-01-25 14:34:24 dialing CORYQAA-WI4GCCW-5S42YE3-TZCIEUK-ZHPEFFZ-JYZCQ2A-WT4F52O-ICDTHAE tcp://192.168.1.11:22000 prio 9
2020-01-25 14:34:34 dialing CORYQAA-WI4GCCW-5S42YE3-TZCIEUK-ZHPEFFZ-JYZCQ2A-WT4F52O-ICDTHAE tcp://192.168.1.11:22000 error: dial tcp 192.168.1.11:22000: i/o timeout
2020-01-25 14:34:34 failed to connect to CORYQAA-WI4GCCW-5S42YE3-TZCIEUK-ZHPEFFZ-JYZCQ2A-WT4F52O-ICDTHAE 9
2020-01-25 14:34:34 dialing CORYQAA-WI4GCCW-5S42YE3-TZCIEUK-ZHPEFFZ-JYZCQ2A-WT4F52O-ICDTHAE quic://192.168.1.11:22000 prio 99
2020-01-25 14:34:36 write udp [::]:39677->[ff12::8384]:21027: sendmsg: network is unreachable on write to [ff12::8384]:21027 lo
2020-01-25 14:34:36 sent 91 bytes to [ff12::8384]:21027 on eth0
2020-01-25 14:34:36 write udp [::]:39677->[ff12::8384]:21027: sendmsg: network is unreachable on write to [ff12::8384]:21027 sit0
2020-01-25 14:34:36 write udp [::]:39677->[ff12::8384]:21027: sendmsg: network is unreachable on write to [ff12::8384]:21027 tun0
2020-01-25 14:34:36 addresses: [192.168.1.255 10.42.11.6]
2020-01-25 14:34:36 sent 91 bytes to 192.168.1.255:21027
2020-01-25 14:34:36 sent 91 bytes to 10.42.11.6:21027
2020-01-25 14:34:36 recv 91 bytes from [fe80::211:32ff:fe12:aa23%eth0]:39677
2020-01-25 14:34:36 discover: Received local announcement from [fe80::211:32ff:fe12:aa23%eth0]:39677 for 63DC5KJ-PEQVRPA-R6OAKVE-OHVKXOW-H45235O-TLMXZCU-QX44ORY-YBTC5AN
2020-01-25 14:34:36 recv 91 bytes from 192.168.1.29:60247
2020-01-25 14:34:36 recv 91 bytes from 10.42.11.6:60247
2020-01-25 14:34:36 discover: Received local announcement from 192.168.1.29:60247 for 63DC5KJ-PEQVRPA-R6OAKVE-OHVKXOW-H45235O-TLMXZCU-QX44ORY-YBTC5AN
2020-01-25 14:34:36 discover: Received local announcement from 10.42.11.6:60247 for 63DC5KJ-PEQVRPA-R6OAKVE-OHVKXOW-H45235O-TLMXZCU-QX44ORY-YBTC5AN
2020-01-25 14:34:44 dialing CORYQAA-WI4GCCW-5S42YE3-TZCIEUK-ZHPEFFZ-JYZCQ2A-WT4F52O-ICDTHAE quic://192.168.1.11:22000 error: dial: NO_ERROR: Handshake did not complete in time
2020-01-25 14:34:44 failed to connect to CORYQAA-WI4GCCW-5S42YE3-TZCIEUK-ZHPEFFZ-JYZCQ2A-WT4F52O-ICDTHAE 99
2020-01-25 14:34:44 sleep until next dial 1m0s

Here is what seems to be the looping part from the Windows machine logs:

[CORYQ] 2020/01/25 14:55:21.882449 service.go:485: DEBUG: sleep until next dial 1m0s
[CORYQ] 2020/01/25 14:55:48.316776 broadcast.go:66: DEBUG: addresses: [x.x.x.255]
[CORYQ] 2020/01/25 14:55:48.317776 multicast.go:80: DEBUG: sent 91 bytes to [ff12::8384]:21027 on Ethernet
[CORYQ] 2020/01/25 14:55:48.317776 multicast.go:151: DEBUG: recv 91 bytes from [fe80::180b:fb15:ee2e:fe25%Ethernet 2]:61226
[CORYQ] 2020/01/25 14:55:48.317776 local.go:199: DEBUG: discover: Received local announcement from [fe80::180b:fb15:ee2e:fe25%Ethernet 2]:61226 for CORYQAA
[CORYQ] 2020/01/25 14:55:48.317776 broadcast.go:89: DEBUG: sent 91 bytes to x.x.x.255:21027
[CORYQ] 2020/01/25 14:55:48.317776 broadcast.go:122: DEBUG: recv 91 bytes from x.x.x.11:61225
[CORYQ] 2020/01/25 14:55:48.317776 multicast.go:151: DEBUG: recv 91 bytes from [fe80::180b:fb15:ee2e:fe25%Ethernet 2]:61226
[CORYQ] 2020/01/25 14:55:48.317776 local.go:199: DEBUG: discover: Received local announcement from [fe80::180b:fb15:ee2e:fe25%Ethernet 2]:61226 for CORYQAA
[CORYQ] 2020/01/25 14:55:48.317776 local.go:199: DEBUG: discover: Received local announcement from x.x.x.11:61225 for CORYQAA
[CORYQ] 2020/01/25 14:55:48.317776 multicast.go:80: DEBUG: sent 91 bytes to [ff12::8384]:21027 on Ethernet 3
[CORYQ] 2020/01/25 14:55:48.317776 multicast.go:151: DEBUG: recv 91 bytes from [fe80::180b:fb15:ee2e:fe25%Ethernet 2]:61226
[CORYQ] 2020/01/25 14:55:48.317776 multicast.go:80: DEBUG: sent 91 bytes to [ff12::8384]:21027 on Ethernet 2
[CORYQ] 2020/01/25 14:55:48.317776 local.go:199: DEBUG: discover: Received local announcement from [fe80::180b:fb15:ee2e:fe25%Ethernet 2]:61226 for CORYQAA
[CORYQ] 2020/01/25 14:55:48.317776 multicast.go:80: DEBUG: sent 91 bytes to [ff12::8384]:21027 on Loopback Pseudo-Interface 1
[CORYQ] 2020/01/25 14:55:48.317776 multicast.go:151: DEBUG: recv 91 bytes from [fe80::180b:fb15:ee2e:fe25%Ethernet 2]:61226
[CORYQ] 2020/01/25 14:55:48.317776 local.go:199: DEBUG: discover: Received local announcement from [fe80::180b:fb15:ee2e:fe25%Ethernet 2]:61226 for CORYQAA
[CORYQ] 2020/01/25 14:56:18.323711 broadcast.go:66: DEBUG: addresses: [x.x.x.255]
[CORYQ] 2020/01/25 14:56:18.324709 broadcast.go:89: DEBUG: sent 91 bytes to x.x.x.255:21027
[CORYQ] 2020/01/25 14:56:18.324709 multicast.go:151: DEBUG: recv 91 bytes from [fe80::180b:fb15:ee2e:fe25%Ethernet 2]:61226
[CORYQ] 2020/01/25 14:56:18.324709 multicast.go:80: DEBUG: sent 91 bytes to [ff12::8384]:21027 on Ethernet
[CORYQ] 2020/01/25 14:56:18.324709 broadcast.go:122: DEBUG: recv 91 bytes from x.x.x.11:61225
[CORYQ] 2020/01/25 14:56:18.324709 local.go:199: DEBUG: discover: Received local announcement from x.x.x.11:61225 for CORYQAA
[CORYQ] 2020/01/25 14:56:18.324709 local.go:199: DEBUG: discover: Received local announcement from [fe80::180b:fb15:ee2e:fe25%Ethernet 2]:61226 for CORYQAA
[CORYQ] 2020/01/25 14:56:18.324709 multicast.go:151: DEBUG: recv 91 bytes from [fe80::180b:fb15:ee2e:fe25%Ethernet 2]:61226
[CORYQ] 2020/01/25 14:56:18.324709 multicast.go:80: DEBUG: sent 91 bytes to [ff12::8384]:21027 on Ethernet 3
[CORYQ] 2020/01/25 14:56:18.324709 local.go:199: DEBUG: discover: Received local announcement from [fe80::180b:fb15:ee2e:fe25%Ethernet 2]:61226 for CORYQAA
[CORYQ] 2020/01/25 14:56:18.324709 multicast.go:151: DEBUG: recv 91 bytes from [fe80::180b:fb15:ee2e:fe25%Ethernet 2]:61226
[CORYQ] 2020/01/25 14:56:18.324709 multicast.go:80: DEBUG: sent 91 bytes to [ff12::8384]:21027 on Ethernet 2
[CORYQ] 2020/01/25 14:56:18.324709 local.go:199: DEBUG: discover: Received local announcement from [fe80::180b:fb15:ee2e:fe25%Ethernet 2]:61226 for CORYQAA
[CORYQ] 2020/01/25 14:56:18.324709 multicast.go:151: DEBUG: recv 91 bytes from [fe80::180b:fb15:ee2e:fe25%Ethernet 2]:61226
[CORYQ] 2020/01/25 14:56:18.324709 local.go:199: DEBUG: discover: Received local announcement from [fe80::180b:fb15:ee2e:fe25%Ethernet 2]:61226 for CORYQAA
[CORYQ] 2020/01/25 14:56:18.324709 multicast.go:80: DEBUG: sent 91 bytes to [ff12::8384]:21027 on Loopback Pseudo-Interface 1
[CORYQ] 2020/01/25 14:56:21.882991 service.go:357: DEBUG: Reconnect loop
[CORYQ] 2020/01/25 14:56:21.882991 cache.go:103: DEBUG: lookup for 63DC5KJ at IPv4 local
[CORYQ] 2020/01/25 14:56:21.882991 cache.go:104: DEBUG:   addresses: []
[CORYQ] 2020/01/25 14:56:21.882991 cache.go:103: DEBUG: lookup for 63DC5KJ at IPv6 local
[CORYQ] 2020/01/25 14:56:21.882991 cache.go:104: DEBUG:   addresses: []
[CORYQ] 2020/01/25 14:56:21.882991 cache.go:128: DEBUG: lookup results for 63DC5KJ
[CORYQ] 2020/01/25 14:56:21.882991 cache.go:129: DEBUG:   addresses:  []
[CORYQ] 2020/01/25 14:56:21.882991 service.go:394: DEBUG: Reconnect loop for 63DC5KJ []
[CORYQ] 2020/01/25 14:56:21.882991 service.go:485: DEBUG: sleep until next dial 1m0s

x.x.x.255:21027 - not sure what this is, as it’s not a physical device, but it’s in the LAN subnet. x.x.x.11:61225 is the Windows machine’s static IP

CORYQAA is the Windows machine device ID

I appreciate any help that can be offered.

2

I suggest you double check device ids. If there are only two devices involved, on device A there shouldn’t be announcements for device X and connection attempts to device Y.

I think getting logs with connections tracing enabled on both devices would mostly answer this. The discovery part is less interesting at this point, as from the logs it seems to be working.

3

Thanks for the reply. I had already tried adding a new device using the existing device IDs, and both the Windows machine and NAS saidlready a device with that ID already exists.

I’ll try enabling connection tracing and report back.

2 Likes
4

I tried enabling connections tracing on the Windows machine using these instructions. For the Synology NAS, I don’t know if/how I can do this as Syncthing is installed through the package manager GUI and when I SSH in I can’t find Syncthing anywhere so I just get an error when I try to start it with the STTRACE variable.

On the Windows machine the log is not showing anything new, so it seems like connections tracing did not get enabled, although I didn’t get any errors when I ran the command.

I should have noted in my original post that I’m running SyncTrayzor on the Windows machine.

5

Note that you can both set the trace options and see the logs in the web GUI, under actions -> logs.

6

Now I’m further confused, as I did have “connections” checked on the Actions>>Logs>>Debug Facilities page when the logs I previously posted were generated. What are my previous logs missing?

Right now I just have the connections trace enabled and the Windows machine log is showing:

[CORYQ] 2020/01/26 12:18:41.839834 api.go:635: INFO: Enabled debug data for "connections"
[CORYQ] 2020/01/26 12:19:17.721151 service.go:357: DEBUG: Reconnect loop
[CORYQ] 2020/01/26 12:19:17.721151 service.go:394: DEBUG: Reconnect loop for 63DC5KJ []
[CORYQ] 2020/01/26 12:19:17.721151 service.go:485: DEBUG: sleep until next dial 1m0s
[CORYQ] 2020/01/26 12:20:17.721701 service.go:357: DEBUG: Reconnect loop
[CORYQ] 2020/01/26 12:20:17.731777 service.go:394: DEBUG: Reconnect loop for 63DC5KJ []
[CORYQ] 2020/01/26 12:20:17.731777 service.go:485: DEBUG: sleep until next dial 1m0s
[CORYQ] 2020/01/26 12:21:17.741623 service.go:357: DEBUG: Reconnect loop
[CORYQ] 2020/01/26 12:21:17.741623 service.go:394: DEBUG: Reconnect loop for 63DC5KJ []
[CORYQ] 2020/01/26 12:21:17.741623 service.go:485: DEBUG: sleep until next dial 1m0s
[CORYQ] 2020/01/26 12:21:35.191193 quic_listen.go:55: INFO: quic://0.0.0.0:22000 detected NAT type: Symmetric NAT
[CORYQ] 2020/01/26 12:21:35.191193 quic_listen.go:74: INFO: quic://0.0.0.0:22000 resolved external address quic://73.217.97.226:59211 (via stun.syncthing.net:3478)
[CORYQ] 2020/01/26 12:22:17.746217 service.go:357: DEBUG: Reconnect loop
[CORYQ] 2020/01/26 12:22:17.746217 service.go:394: DEBUG: Reconnect loop for 63DC5KJ []
[CORYQ] 2020/01/26 12:22:17.746217 service.go:485: DEBUG: sleep until next dial 1m0s

63DC5KJ is the NAS

I also tried removing and re-adding both devices, but they still show as disconnected.

7

Ok, reading the logs again, it seems I was confused or was reading on a mobile and missed stuff.

In the NAS logs I can see:

2020-01-25 14:34:24 Reconnect loop for CORYQAA-WI4GCCW-5S42YE3-TZCIEUK-ZHPEFFZ-JYZCQ2A-WT4F52O-ICDTHAE [quic://192.168.1.11:22000 tcp://192.168.1.11:22000]
2020-01-25 14:34:24 dialing CORYQAA-WI4GCCW-5S42YE3-TZCIEUK-ZHPEFFZ-JYZCQ2A-WT4F52O-ICDTHAE tcp://192.168.1.11:22000 prio 9
2020-01-25 14:34:34 dialing CORYQAA-WI4GCCW-5S42YE3-TZCIEUK-ZHPEFFZ-JYZCQ2A-WT4F52O-ICDTHAE tcp://192.168.1.11:22000 error: dial tcp 192.168.1.11:22000: i/o timeout

So your NAS clearly cannot connect to the other device as seen from the logs. You most likely have a firewall in place somewhere. NAS local announcements it seems are not arriving on the other device either, most likely due to a firewall.

The fact that you can ping something somewhere doesn’t mean much as pings happen on a much lower level.

8

You can try and setup static ips from the other side I guess as a remedy.

9

Static IPs appears to have fixed it. There is no firewall on either device or either network, so I don’t know what to do about that. Thank you for your help!

10

On windows, if the network profile is public, all multicast stuff is blocked by default. Also, it could be the network equipment in between dropping multicast packets.

11

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.