Connection going on and off, v13 bug

Hi, I managed to get a small trace of this on two clients. The connection will constantly connect and disconnect, switching between using relay and using direct connection. This did not happen before 0.13.x upgrade. Seems the only way to fix this is to stop both clients, rerun them, and hope it does not happen.

[TB344] is a remote Linux server. It’s port-forwarded, and has configured: <listenAddress>relay://my.relay:443/?id=XXXXX</listenAddress><listenAddress>tcp://0.0.0.0:41666</listenAddress>. I am using the default discovery server.

[3536Q] is my local Windows client. It’s not port-forwarded, and uses the same config as above, but using port 22666 instead.

0.12.x worked fine; 0.13.x (on .1 now, I never tried .0) seems to cause some weird loop in my setup. The loop is like “two clients connect using the relay, switch connection to direct TCP, close both connections and get really confused”?

Linux’s side of log:

[TB344] 14:21:54 INFO: Established secure connection to 3536QRY at IP.server:50011-IP.relay:443 (Relay (Server))
[TB344] 14:21:54 INFO: Device 3536QRY client is "syncthing v0.13.1" named "Windows-PC"
[TB344] 14:21:56 INFO: Connection to 3536QRY closed: switching connections
[TB344] 14:21:57 INFO: Established secure connection to 3536QRY at IP.server:41666-IP.windows:64548 (TCP (Server))
[TB344] 14:21:57 INFO: Device 3536QRY client is "syncthing v0.13.1" named "Windows-PC"
[TB344] 14:21:57 INFO: Connection to 3536QRY closed: read tcp IP.server:50011->IP.relay:443: use of closed network connection
[TB344] 14:21:57 INFO: Connection to 3536QRY closed: read tcp IP.server:41666->IP.windows:64548: use of closed network connection
[TB344] 14:22:00 INFO: Established secure connection to 3536QRY at IP.server:50014-IP.relay:443 (Relay (Server))
[TB344] 14:22:00 INFO: Device 3536QRY client is "syncthing v0.13.1" named "Windows-PC"
[TB344] 14:22:05 INFO: Connection to 3536QRY closed: switching connections
[TB344] 14:22:05 INFO: Connection to 3536QRY closed: write tcp IP.server:50014->IP.relay:443: write: connection reset by peer
[TB344] 14:22:06 INFO: Established secure connection to 3536QRY at IP.server:41666-IP.windows:54537 (TCP (Server))
[TB344] 14:22:06 INFO: Device 3536QRY client is "syncthing v0.13.1" named "Windows-PC"
[TB344] 14:22:06 INFO: Connection to 3536QRY closed: write tcp IP.server:41666->IP.windows:54537: use of closed network connection
[TB344] 14:22:15 INFO: Established secure connection to 3536QRY at IP.server:50019-IP.relay:443 (Relay (Server))
[TB344] 14:22:15 INFO: Device 3536QRY client is "syncthing v0.13.1" named "Windows-PC"
[TB344] 14:22:32 INFO: Connection to 3536QRY closed: switching connections
[TB344] 14:22:32 INFO: Connection to 3536QRY closed: write tcp IP.server:50019->IP.relay:443: write: broken pipe
[TB344] 14:22:38 INFO: Established secure connection to 3536QRY at IP.server:41666-IP.windows:51441 (TCP (Server))
[TB344] 14:22:38 INFO: Device 3536QRY client is "syncthing v0.13.1" named "Windows-PC"
[TB344] 14:22:39 INFO: Connection to 3536QRY closed: write tcp IP.server:41666->IP.windows:51441: use of closed network connection
[TB344] 14:23:32 INFO: Established secure connection to 3536QRY at IP.server:50028-IP.relay:443 (Relay (Server))
[TB344] 14:23:32 INFO: Device 3536QRY client is "syncthing v0.13.1" named "Windows-PC"
[TB344] 14:23:33 INFO: Connection to 3536QRY closed: switching connections
[TB344] 14:23:34 INFO: Established secure connection to 3536QRY at IP.server:41666-IP.windows:60295 (TCP (Server))
[TB344] 14:23:34 INFO: Device 3536QRY client is "syncthing v0.13.1" named "Windows-PC"
[TB344] 14:23:34 INFO: Connection to 3536QRY closed: read tcp IP.server:50028->IP.relay:443: use of closed network connection
[TB344] 14:23:34 INFO: Connection to 3536QRY closed: write tcp IP.server:41666->IP.windows:60295: write: connection reset by peer

Windows side of log:

[3536Q] 20:21:57 INFO: Established secure connection to TB3442P at 192.168.1.64:54280-IP.relay:443 (Relay (Client))
[3536Q] 20:21:57 INFO: Device TB3442P client is "syncthing v0.13.1" named "Linux-Server"
[3536Q] 20:21:59 INFO: Connection to TB3442P closed: switching connections
[3536Q] 20:21:59 INFO: Connection to TB3442P closed: write tcp 192.168.1.64:54280->IP.relay:443: use of closed network connection
[3536Q] 20:21:59 INFO: Connection to TB3442P closed: switching connections
[3536Q] 20:21:59 INFO: Established secure connection to TB3442P at 192.168.1.64:54281-IP.server:41666 (TCP (Client))
[3536Q] 20:21:59 INFO: Device TB3442P client is "syncthing v0.13.1" named "Linux-Server"
[3536Q] 20:21:59 INFO: Connection to TB3442P closed: write tcp 192.168.1.64:54281->IP.server:41666: wsasend: An existing connection was forcibly closed by the remote host.
[3536Q] 20:22:00 INFO: Detected 0 NAT devices
[3536Q] 20:22:02 INFO: Established secure connection to TB3442P at 192.168.1.64:54283-IP.relay:443 (Relay (Client))
[3536Q] 20:22:02 INFO: Device TB3442P client is "syncthing v0.13.1" named "Linux-Server"
[3536Q] 20:22:07 INFO: Connection to TB3442P closed: switching connections
[3536Q] 20:22:07 INFO: Connection to TB3442P closed: write tcp 192.168.1.64:54283->IP.relay:443: use of closed network connection
[3536Q] 20:22:07 INFO: Connection to TB3442P closed: switching connections
[3536Q] 20:22:07 INFO: Established secure connection to TB3442P at 192.168.1.64:54284-IP.server:41666 (TCP (Client))
[3536Q] 20:22:07 INFO: Device TB3442P client is "syncthing v0.13.1" named "Linux-Server"
[3536Q] 20:22:08 INFO: Connection to TB3442P closed: write tcp 192.168.1.64:54284->IP.server:41666: wsasend: An existing connection was forcibly closed by the remote host.
[3536Q] 20:22:17 INFO: Established secure connection to TB3442P at 192.168.1.64:54290-IP.relay:443 (Relay (Client))
[3536Q] 20:22:17 INFO: Device TB3442P client is "syncthing v0.13.1" named "Linux-Server"
[3536Q] 20:22:34 INFO: Connection to TB3442P closed: switching connections
[3536Q] 20:22:34 INFO: Connection to TB3442P closed: write tcp 192.168.1.64:54290->IP.relay:443: use of closed network connection
[3536Q] 20:22:34 INFO: Connection to TB3442P closed: switching connections
[3536Q] 20:22:35 INFO: Established secure connection to TB3442P at 192.168.1.64:54298-IP.server:41666 (TCP (Client))
[3536Q] 20:22:35 INFO: Device TB3442P client is "syncthing v0.13.1" named "Linux-Server"
[3536Q] 20:22:41 INFO: Connection to TB3442P closed: write tcp 192.168.1.64:54298->IP.server:41666: wsasend: An existing connection was forcibly closed by the remote host.
[3536Q] 20:23:34 INFO: Established secure connection to TB3442P at 192.168.1.64:54318-IP.relay:443 (Relay (Client))
[3536Q] 20:23:34 INFO: Device TB3442P client is "syncthing v0.13.1" named "Linux-Server"
[3536Q] 20:23:36 INFO: Connection to TB3442P closed: switching connections
[3536Q] 20:23:36 INFO: Established secure connection to TB3442P at 192.168.1.64:54319-IP.server:41666 (TCP (Client))
[3536Q] 20:23:36 INFO: Device TB3442P client is "syncthing v0.13.1" named "Linux-Server"
[3536Q] 20:23:36 INFO: Connection to TB3442P closed: read tcp 192.168.1.64:54318->IP.relay:443: use of closed network connection
[3536Q] 20:23:36 INFO: Connection to TB3442P closed: write tcp 192.168.1.64:54319->IP.server:41666: use of closed network connection

Hopefully I didn’t make it too confusing with obfuscating; IP.server is the global IP of the Linux server, IP.windows is the global IP of the Windows client, IP.relay is my relay’s IP, and 192.168.1.64 is the local IP of my Windows client.

Thanks, please let me know if there’s something more I can do to debug!

Yeah, there is some sort of race here definately, open a bug on github. Also if you could get logd with STTRACE=connections, that would be nice.

I think it also could be due to the fact that it managed to connect directly, but the connection got dropped immediately afterwards.

Is this persistent?

Yeah, I wasn’t sure if I should have made a report or not. Sent now at Race condition with relay/direct dial · Issue #3118 · syncthing/syncthing · GitHub . Hopefully that’s a bit better! :slight_smile:

1 Like

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