In Windows there is a log file by default in the configuration directory.
yes, after update of syncthing on my PC I did see that it is not connected to server. So I did check server and there was not connection from another nodes. We want only local discovery in office so on all nodes we have enabled only “local discovery”.
“NAT traversal”, “gloval discovery” and “relaying” is disabled.
I did find out that on firewall I have open only http port and tcp 22000, so I did enable udp 21027. Then I did restart syncthing on my PC and server {synology} and after while all connection are UP.
Checking the log I can see that syncthing is opening port for KCP
syncthing[2393]: [QIKVK] INFO: TCP listener ([::]:22000) starting
syncthing[2393]: [QIKVK] INFO: KCP listener ([::]:22020) starting
and later
syncthing[2393]: [QIKVK] INFO: kcp://0.0.0.0:22020 detected NAT type: Port restricted NAT
syncthing[2393]: [QIKVK] INFO: kcp://0.0.0.0:22020 resolved external address kcp://176.116.108.197:1026 (via stun.counterpath.net:3478)
and later I can see that my PC is establised connection with server {call oblak} over 22020 port which is not open at firewall and then replacing it with connection over 22000. What does it mean?
syncthing[2393]: [QIKVK] INFO: Established secure connection to 43H33OS-...-AXSNQQX at [::]:22020-192.168.101.3:22020 (kcp-server) (TLS_ECDHE_RS
syncthing[2393]: [QIKVK] INFO: Device 43H33OS-...AXSNQQX client is "syncthing v0.14.40" named "oblak"
syncthing[2393]: [QIKVK] INFO: Connected to already connected device (43H33OS-...AXSNQQX)
syncthing[2393]: [QIKVK] INFO: Established secure connection to 43H33OS-...AXSNQQX at 192.168.101.10:22000-192.168.101.3:53044 (tcp-server) (TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305)
syncthing[2393]: [QIKVK] INFO: Replacing old connection [::]:22020-192.168.101.3:22020/kcp-server with 192.168.101.10:22000-192.168.101.3:53044/tcp-server for 43H33OS-...AXSNQQX
syncthing[2393]: [QIKVK] INFO: Connection to 43H33OS-...AXSNQQX closed: reading length: broken pipe
syncthing[2393]: [QIKVK] INFO: Device 43H33OS-...AXSNQQX client is "syncthing v0.14.40" named "oblak"That it established a KCP connection on port 22020 to begin with, then managed a TCP connection and switched to that as it’s better.
I guess this is a similar thing as what I usually see with relays: The connection is established quicker than direct (especially) local connections, so connections happen usually like this: unconnected -> relay/kcp -> direct tcp. Not ideal, but not a problem.
Hei.
Like janc1 I am using syncthing in a local environment. Thus only “Local Discovery” is activated, but I see the same entries of KCP being started on :22020 and it’s outbound connection to a stun.* domain. The domain changes, it always starts with “stun.” After that the connection is handed over from KCP to TCP.
Allow me to ask, from under my tinfoil hat, how can I persuade Syncthing to * not * start KCP? I would like Syncthing to stay private (in the sense of not announcing its presence to anybody outside this local network). At least until I choose to activate options like NAT traversal, global discovery or relaying. Maybe this could be made as an option in a future version?
I’d be ready to edit the config file or set an option in the advanced config, if that was possible?
Any solution?
Small update: Blocking the ports stun 3478 and ndmp 10000 hands over the connection from KCP to TCP, then the connection fails. Syncthing then picks it up again.
Looks roughly like this:
INFO: Established secure connection to YYYY at [::]:22020-192.168.254.21:22020 (kcp-client)
INFO: Established secure connection to YYYY at 192.168.254.34:49529-192.168.254.21:22000 (tcp-client)
INFO: Replacing old connection [::]:22020-192.168.254.21:22020/kcp-client with 192.168.254.34:49529-192.168.254.21:22000/tcp-client for YYYY
INFO: Connection to YYYY closed: reading length: broken pipe
INFO: Connected to already connected device (YYYY)specifically: and
Also:
2 Likes
Thanks! Sorry, I’ve not found those. I do not quite understand the last quote - thats for a future development, correct?
Yes, that is a suggestion how to remake the listen address field, as currently default means tcp://:22000, {relay adress}, {kcp address}.
My distant win10 x64 machine is back again with nonconnecting at all.
rebooted the syncthing and logs stop there with stun detected the kcp stuff externally
thats all it is
it never connects home to its single neighbor peer the linux machine
what the heck is wrong here? :(( syncthing is nonusable for this setup here. where can i mail in sensitive log data i dont wana post the filenames and sharenames here that hint to private and sensitive data.
is there a direct email contact for this? the main developers? thanks for helping. 0.14.40 is really dead for me, it very seldomly conncects
last contact back home to the linux machine of this win10 x64 machine was on november 10th 
0.14.40 doesn’t work for me either. 0.14.39 is fine. Wouldn’t it be relatively easy to diff the code between the versions and track down the reason for this?
We know what code has changed, that’s not the problem. We don’t know why it doesn’t work for some users.
We need to gather as many logs as possible, from both sides of devices to understand what’s happening. Reverting to an older version and not helping us debug will not make the issue go away in future releases.
2 Likes
The project maintainer or original author replied to me as private message that he wouldnt take my log files, as I wont post all my share names and internal messages onto this public board. So i am out i definitely wont post this kind of sentitive information into the public.
I can share this from the linux machine, this is what the screen window shows for the last few days as only logmessages:
[3PKT3] 04:48:46 INFO: kcp://0.0.0.0:22020 resolved external address kcp://84.189.33.5:22020 (via stun.counterpath.net:3478) [3PKT3] 05:14:50 INFO: Removing NAT port mapping: external TCP address 87.176.82.175:51852, NAT 75802409-bccb-40e7-8e6c-3810D51EDC03 is no longer available. [3PKT3] 05:14:50 INFO: New NAT port mapping: external TCP address 84.189.33.5:51852 to local address 0.0.0.0:22000. [3PKT3] 05:14:50 INFO: Removing NAT port mapping: external TCP address 87.176.82.175:13762, NAT 75802409-bccb-40e7-9f6c-3810D51EDC03 is no longer available. [3PKT3] 05:14:50 INFO: New NAT port mapping: external TCP address 84.189.33.5:13762 to local address 0.0.0.0:22000. [3PKT3] 13:31:25 INFO: Sent usage report (version 3) [3PKT3] 04:47:43 INFO: kcp://0.0.0.0:22020 resolved external address kcp://87.176.85.36:22020 (via stun.counterpath.net:3478) [3PKT3] 04:52:40 INFO: Removing NAT port mapping: external TCP address 84.189.33.5:51852, NAT 75802409-bccb-40e7-8e6c-3810D51EDC03 is no longer available. [3PKT3] 04:52:40 INFO: New NAT port mapping: external TCP address 87.176.85.36:51852 to local address 0.0.0.0:22000. [3PKT3] 04:52:40 INFO: Removing NAT port mapping: external TCP address 84.189.33.5:13762, NAT 75802409-bccb-40e7-9f6c-3810D51EDC03 is no longer available. [3PKT3] 04:52:40 INFO: New NAT port mapping: external TCP address 87.176.85.36:13762 to local address 0.0.0.0:22000. [3PKT3] 13:31:27 INFO: Sent usage report (version 3) [3PKT3] 04:46:36 INFO: kcp://0.0.0.0:22020 resolved external address kcp://84.189.33.31:22020 (via stun.counterpath.net:3478) [3PKT3] 05:00:40 INFO: Removing NAT port mapping: external TCP address 87.176.85.36:13762, NAT 75802409-bccb-40e7-9f6c-3810D51EDC03 is no longer available. [3PKT3] 05:00:40 INFO: New NAT port mapping: external TCP address 84.189.33.31:13762 to local address 0.0.0.0:22000. [3PKT3] 05:00:40 INFO: Removing NAT port mapping: external TCP address 87.176.85.36:51852, NAT 75802409-bccb-40e7-8e6c-3810D51EDC03 is no longer available. [3PKT3] 05:00:40 INFO: New NAT port mapping: external TCP address 84.189.33.31:51852 to local address 0.0.0.0:22000. [3PKT3] 08:57:58 INFO: kcp://0.0.0.0:22020 detected NAT type: Restricted NAT [3PKT3] 09:01:30 INFO: kcp://0.0.0.0:22020 detected NAT type: Full cone NAT [3PKT3] 13:31:28 INFO: Sent usage report (version 3)
the windows machine shows after a little few minutes after a restart:
[IOEPM] 15:31:26 INFO: Detected 2 NAT devices [IOEPM] 15:31:28 INFO: Joined relay relay://212.25.15.128:22067 [IOEPM] 15:31:35 INFO: kcp://0.0.0.0:22020 detected NAT type: Port restricted NAT [IOEPM] 15:31:35 INFO: kcp://0.0.0.0:22020 resolved external address kcp://88.130.49.164:38094 (via stun.voipbuster.com:3478) [IOEPM] 16:01:17 INFO: Sent usage report (version 3)
thats all and never shows anything therafter.
The windows machine gotton restarted this afternoon or so. Nothing happened. The linux machine restarted the screen right now, and these two nodes of the pack (others are involved too but all last connected on the 10th of november 2017) are connecting right now after the linux machine has restarted (syncthing process) as well
there is something wrong with the connection loop speaking in a laymans way.
run with STTRACE=connections env var on both sides, and post logs after both sides not connecting for 10-20 minutes
1 Like
These two machines I can grab hold of, are connecting right now after both sides have restarted. How is this gonna help now? Wouldnt we need “logs” from when no connection is possible?
Normal logs from right after the restart of the linux syncthing process at the end of the log it writes:
[3PKT3] 22:32:27 INFO: Established secure connection to IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB at [::]:22020-88.130.49.164:38094 (kcp-server) (TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305) [3PKT3] 22:32:27 INFO: Device IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB client is "syncthing v0.14.40" named "SMULAP01" [3PKT3] 22:32:36 INFO: New NAT port mapping: external TCP address 84.189.33.31:13762 to local address 0.0.0.0:22000. [3PKT3] 22:32:36 INFO: New NAT port mapping: external TCP address 84.189.33.31:51852 to local address 0.0.0.0:22000. [3PKT3] 22:32:36 INFO: Detected 3 NAT devices [3PKT3] 22:32:38 INFO: Joined relay relay://37.120.167.213:22067 2017-11-13 22:32:56 $ [3PKT3] 22:33:01 INFO: Established secure connection to IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB at 192.168.188.38:22000-88.130.49.164:38117 (tcp-server) (TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305) [3PKT3] 22:33:01 INFO: Replacing old connection [::]:22020-88.130.49.164:38094/kcp-server with 192.168.188.38:22000-88.130.49.164:38117/tcp-server for IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB [3PKT3] 22:33:01 INFO: Connection to IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB closed: reading length: broken pipe [3PKT3] 22:33:01 INFO: Device IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB client is "syncthing v0.14.40" named "SMULAP01"
smulap01 is the win10 x64 machine that i can admin right now remotely.
Where do I attach then rather lengthy and extensive logfiles? or is there a special mail or development address to submit to? I already asked before.
I am seeing tcp with an ipv6 address, at the end permission denied, although the linux machine does have ipv6 dual stack
[3PKT3] 2017/11/13 22:41:20.648963 service.go:400: DEBUG: dial IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB tcp://88.130.49.164:22000 [3PKT3] 2017/11/13 22:41:22.717589 structs.go:32: INFO: New NAT port mapping: external TCP address 84.189.33.31:13762 to local address 0.0.0.0:22000. [3PKT3] 2017/11/13 22:41:22.759975 structs.go:32: INFO: New NAT port mapping: external TCP address 84.189.33.31:51852 to local address 0.0.0.0:22000. [3PKT3] 2017/11/13 22:41:22.760185 service.go:61: INFO: Detected 3 NAT devices [3PKT3] 2017/11/13 22:41:24.296859 static.go:93: INFO: Joined relay relay://89.46.70.108:22067 [3PKT3] 2017/11/13 22:41:30.649346 tcp_dial.go:36: DEBUG: dial tcp 88.130.49.164:22000: i/o timeout [3PKT3] 2017/11/13 22:41:30.649457 service.go:405: DEBUG: dial failed IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB tcp://88.130.49.164:22000 dial tcp 88.130.49.164:22000: i/o timeout [3PKT3] 2017/11/13 22:41:30.649529 service.go:400: DEBUG: dial IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB tcp://[2001:16b8:46b0:8700:81d2:778a:2744:2c2e]:22000 [3PKT3] 2017/11/13 22:41:30.700418 tcp_dial.go:36: DEBUG: dial tcp [2001:16b8:46b0:8700:81d2:778a:2744:2c2e]:22000: getsockopt: permission denied [3PKT3] 2017/11/13 22:41:30.700520 service.go:405: DEBUG: dial failed IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB tcp://[2001:16b8:46b0:8700:81d2:778a:2744:2c2e]:22000 dial tcp [2001:16b8:46b0:8700:81d2:778a:2744:2c2e]:22000: getsockopt: permission denied
windows10 x64 machine:
[IOEPM] 2017/11/13 22:38:38.133852 tcp_listen.go:69: INFO: TCP listener ([::]:22000) starting [IOEPM] 2017/11/13 22:38:38.133852 service.go:317: DEBUG: Reconnect loop [IOEPM] 2017/11/13 22:38:38.133852 service.go:344: DEBUG: Reconnect loop for 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 [IOEPM] 2017/11/13 22:38:38.157890 kcp_listen.go:89: INFO: KCP listener ([::]:22020) starting [IOEPM] 2017/11/13 22:38:38.205486 main.go:871: INFO: Device IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB is "SMULAP01" at [dynamic] [IOEPM] 2017/11/13 22:38:38.205486 main.go:871: INFO: Device 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 is "linux-smu-dpg" at [dynamic] [IOEPM] 2017/11/13 22:38:38.214510 gui.go:357: INFO: GUI and API listening on 127.0.0.1:8384 [IOEPM] 2017/11/13 22:38:38.214510 gui.go:358: INFO: Access the GUI via the following URL: http://127.0.0.1:8384/ ...... [IOEPM] 2017/11/13 22:38:41.789043 service.go:400: DEBUG: dial 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 kcp://84.189.33.31:22020 [IOEPM] 2017/11/13 22:38:41.789043 kcp_dial.go:42: DEBUG: dial kcp://84.189.33.31:22020 using existing conn on [::]:22020 [IOEPM] 2017/11/13 22:38:41.940468 service.go:417: DEBUG: initial rampup; sleep 1s and update to 2s [IOEPM] 2017/11/13 22:38:41.940468 service.go:284: INFO: Established secure connection to 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 at [::]:22020-84.189.33.31:22020 (kcp-client) (TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305) [IOEPM] 2017/11/13 22:38:41.940468 model.go:1485: INFO: Device 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 client is "syncthing v0.14.40" named "linux-smu-dpg" [IOEPM] 2017/11/13 22:38:42.049747 kcp_listen.go:120: DEBUG: connect from 84.189.33.31:22020 [IOEPM] 2017/11/13 22:38:42.270805 service.go:247: INFO: Connected to already connected device (3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5) ..... [IOEPM] 2017/11/13 22:38:42.941708 service.go:317: DEBUG: Reconnect loop [IOEPM] 2017/11/13 22:38:42.941708 service.go:344: DEBUG: Reconnect loop for 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 [IOEPM] 2017/11/13 22:38:42.941708 service.go:395: DEBUG: Not dialing using KCP Dialer as priority is less than current connection (50 >= 50) [IOEPM] 2017/11/13 22:38:42.941708 service.go:395: DEBUG: Not dialing using KCP Dialer as priority is less than current connection (50 >= 50) [IOEPM] 2017/11/13 22:38:42.941708 service.go:395: DEBUG: Not dialing using Relay Dialer as priority is less than current connection (200 >= 50) [IOEPM] 2017/11/13 22:38:42.941708 service.go:395: DEBUG: Not dialing using Relay Dialer as priority is less than current connection (200 >= 50) [IOEPM] 2017/11/13 22:38:42.941708 service.go:395: DEBUG: Not dialing using Relay Dialer as priority is less than current connection (200 >= 50) [IOEPM] 2017/11/13 22:38:42.941708 service.go:400: DEBUG: dial 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 tcp://84.189.33.31:13762 [IOEPM] 2017/11/13 22:38:48.628206 service.go:61: INFO: Detected 2 NAT devices [IOEPM] 2017/11/13 22:38:52.942354 tcp_dial.go:36: DEBUG: dial tcp 84.189.33.31:13762: i/o timeout [IOEPM] 2017/11/13 22:38:52.942354 service.go:405: DEBUG: dial failed 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 tcp://84.189.33.31:13762 dial tcp 84.189.33.31:13762: i/o timeout [IOEPM] 2017/11/13 22:38:52.942354 service.go:400: DEBUG: dial 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 tcp://84.189.33.31:22000 [IOEPM] 2017/11/13 22:38:52.998662 tcp_dial.go:47: DEBUG: failed to set traffic class: operation not supported [IOEPM] 2017/11/13 22:38:53.129412 static.go:93: INFO: Joined relay relay://37.120.167.213:22067 [IOEPM] 2017/11/13 22:38:53.180006 service.go:417: DEBUG: initial rampup; sleep 2s and update to 4s [IOEPM] 2017/11/13 22:38:53.230010 model.go:1210: INFO: Connection to 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 closed: reading length: EOF [IOEPM] 2017/11/13 22:38:53.230010 service.go:284: INFO: Established secure connection to 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 at 192.168.178.37:54288-84.189.33.31:22000 (tcp-client) (TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305) [IOEPM] 2017/11/13 22:38:53.231011 model.go:1485: INFO: Device 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 client is "syncthing v0.14.40" named "linux-smu-dpg" [IOEPM] 2017/11/13 22:38:55.180448 service.go:317: DEBUG: Reconnect loop [IOEPM] 2017/11/13 22:38:55.180448 service.go:417: DEBUG: initial rampup; sleep 4s and update to 8s [IOEPM] 2017/11/13 22:38:57.515036 kcp_listen.go:247: INFO: kcp://0.0.0.0:22020 detected NAT type: Port restricted NAT [IOEPM] 2017/11/13 22:38:57.515036 kcp_listen.go:260: INFO: kcp://0.0.0.0:22020 resolved external address kcp://88.130.49.164:38094 (via stun.xten.com:3478) [IOEPM] 2017/11/13 22:38:59.180917 service.go:317: DEBUG: Reconnect loop [IOEPM] 2017/11/13 22:38:59.180917 service.go:417: DEBUG: initial rampup; sleep 8s and update to 16s [IOEPM] 2017/11/13 22:39:07.181702 service.go:317: DEBUG: Reconnect loop [IOEPM] 2017/11/13 22:39:07.181702 service.go:417: DEBUG: initial rampup; sleep 16s and update to 32s [IOEPM] 2017/11/13 22:39:23.181805 service.go:317: DEBUG: Reconnect loop [IOEPM] 2017/11/13 22:39:23.181805 service.go:417: DEBUG: initial rampup; sleep 32s and update to 1m4s [IOEPM] 2017/11/13 22:39:55.182871 service.go:317: DEBUG: Reconnect loop [IOEPM] 2017/11/13 22:39:55.182871 service.go:421: DEBUG: sleep until next dial 1m0s [IOEPM] 2017/11/13 22:40:48.806343 model.go:1210: INFO: Connection to 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 closed: reading length: read tcp 192.168.178.37:54288->84.189.33.31:22000: wsarecv: Eine vorhandene Verbindung wurde vom Remotehost geschlossen. [IOEPM] 2017/11/13 22:40:55.182878 service.go:317: DEBUG: Reconnect loop [IOEPM] 2017/11/13 22:40:55.182878 service.go:344: DEBUG: Reconnect loop for 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 [IOEPM] 2017/11/13 22:40:55.182878 service.go:400: DEBUG: dial 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 kcp://84.189.33.31:22020 [IOEPM] 2017/11/13 22:40:55.182878 kcp_dial.go:42: DEBUG: dial kcp://84.189.33.31:22020 using existing conn on [::]:22020 [IOEPM] 2017/11/13 22:41:05.183264 service.go:405: DEBUG: dial failed 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 kcp://84.189.33.31:22020 i/o timeout [IOEPM] 2017/11/13 22:41:05.183264 service.go:400: DEBUG: dial 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 kcp://[2003:d5:6bc9:1c00:e2cb:4eff:feba:599e]:22020 [IOEPM] 2017/11/13 22:41:05.183767 kcp_dial.go:42: DEBUG: dial kcp://[2003:d5:6bc9:1c00:e2cb:4eff:feba:599e]:22020 using existing conn on [::]:22020 [IOEPM] 2017/11/13 22:41:12.711411 service.go:421: DEBUG: sleep until next dial 24s [IOEPM] 2017/11/13 22:41:12.712420 service.go:284: INFO: Established secure connection to 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 at [::]:22020-[2003:d5:6bc9:1c00:e2cb:4eff:feba:599e]:22020 (kcp-client) (TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305) [IOEPM] 2017/11/13 22:41:12.712420 model.go:1485: INFO: Device 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 client is "syncthing v0.14.40" named "linux-smu-dpg" [IOEPM] 2017/11/13 22:41:36.712416 service.go:317: DEBUG: Reconnect loop [IOEPM] 2017/11/13 22:41:36.712416 service.go:344: DEBUG: Reconnect loop for 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 [IOEPM] 2017/11/13 22:41:36.712416 service.go:395: DEBUG: Not dialing using KCP Dialer as priority is less than current connection (50 >= 50) [IOEPM] 2017/11/13 22:41:36.712416 service.go:395: DEBUG: Not dialing using KCP Dialer as priority is less than current connection (50 >= 50) [IOEPM] 2017/11/13 22:41:36.712416 service.go:395: DEBUG: Not dialing using Relay Dialer as priority is less than current connection (200 >= 50) [IOEPM] 2017/11/13 22:41:36.712416 service.go:395: DEBUG: Not dialing using Relay Dialer as priority is less than current connection (200 >= 50) [IOEPM] 2017/11/13 22:41:36.712416 service.go:395: DEBUG: Not dialing using Relay Dialer as priority is less than current connection (200 >= 50) [IOEPM] 2017/11/13 22:41:36.712416 service.go:400: DEBUG: dial 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 tcp://84.189.33.31:13762 [IOEPM] 2017/11/13 22:41:46.714023 tcp_dial.go:36: DEBUG: dial tcp 84.189.33.31:13762: i/o timeout [IOEPM] 2017/11/13 22:41:46.714023 service.go:405: DEBUG: dial failed 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 tcp://84.189.33.31:13762 dial tcp 84.189.33.31:13762: i/o timeout [IOEPM] 2017/11/13 22:41:46.714023 service.go:400: DEBUG: dial 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 tcp://84.189.33.31:22000 [IOEPM] 2017/11/13 22:41:46.768765 tcp_dial.go:47: DEBUG: failed to set traffic class: operation not supported [IOEPM] 2017/11/13 22:41:46.933003 service.go:421: DEBUG: sleep until next dial 1m0s [IOEPM] 2017/11/13 22:41:46.980839 model.go:1210: INFO: Connection to 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 closed: reading length: EOF [IOEPM] 2017/11/13 22:41:46.988222 service.go:284: INFO: Established secure connection to 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 at 192.168.178.37:54303-84.189.33.31:22000 (tcp-client) (TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305) [IOEPM] 2017/11/13 22:41:46.989223 model.go:1485: INFO: Device 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 client is "syncthing v0.14.40" named "linux-smu-dpg" [IOEPM] 2017/11/13 22:42:46.933400 service.go:317: DEBUG: Reconnect loop [IOEPM] 2017/11/13 22:42:46.933400 service.go:421: DEBUG: sleep until next dial 1m0s [IOEPM] 2017/11/13 22:43:46.934117 service.go:317: DEBUG: Reconnect loop [IOEPM] 2017/11/13 22:43:46.934957 service.go:421: DEBUG: sleep until next dial 1m0s
It seems TCP connections are failing, yet it’s not obvious why.
I’ve noticed that Syncthing v0.14.40 works on my 64bit windows machine, but not my 32bit one. The 64bit machine connects to my android device and syncs fine, the 32bit machine doesn’t connect to anything. Restarting Syncthing on the 32bit machine causes it to hang, but I can exit Syncthing by closing it’s window.
I am getting errors again today on the win10 x64 machine, the ioepmyd one:
as seen from the linux machine log files messages:
[3PKT3] 2017/11/14 11:06:50.357019 service.go:400: DEBUG: dial IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB tcp://88.130.49.12:22000 [3PKT3] 2017/11/14 11:07:00.274872 tcp_listen.go:103: DEBUG: connect from 84.44.212.110:59372 [3PKT3] 2017/11/14 11:07:00.274970 tcp_listen.go:112: DEBUG: failed to set traffic class: operation not supported [3PKT3] 2017/11/14 11:07:00.357426 tcp_dial.go:36: DEBUG: dial tcp 88.130.49.12:22000: i/o timeout [3PKT3] 2017/11/14 11:07:00.357472 service.go:405: DEBUG: dial failed IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB tcp://88.130.49.12:22000 dial tcp 88.130.49.12:22000: i/o timeout [3PKT3] 2017/11/14 11:07:00.357503 service.go:400: DEBUG: dial IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB tcp://[2001:16b8:46cc:6a00:718a:1d65:e8f9:518]:22000 [3PKT3] 2017/11/14 11:07:00.410654 tcp_dial.go:36: DEBUG: dial tcp [2001:16b8:46cc:6a00:718a:1d65:e8f9:518]:22000: getsockopt: permission denied [3PKT3] 2017/11/14 11:07:00.410699 service.go:405: DEBUG: dial failed IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB tcp://[2001:16b8:46cc:6a00:718a:1d65:e8f9:518]:22000 dial tcp [2001:16b8:46cc:6a00:718a:1d65:e8f9:518]:22000: getsockopt: permission denied