v0.14.40 fails to connect


(Audrius Butkevicius) #41

With “default” addresses enabled, can you check if you have abnormally large amount of traffic leaving the machine, or something along those lines that could be causing TCP issues?


(usernamegoeshere) #42

How do I check that? Do you mean tcp traffic caused by syncthing? Nothing else has changed with this machine and this network, obviously maybe some linux patches have arrived and the normal internet out there has evolved and lived on. But the problems started with syncthing upgrading itself to 0.14.40 on all connected machines.

The broadband connection of the involved places are not overflooded or saturated if you maybe mean that or so. Nothing special except for syncthing upgrade has happened.


(Audrius Butkevicius) #43

Well, I am wondering if KCP (since .40) is so chatty that it causes issues for TCP.

You’d have to check TCP and UDP traffic.


(usernamegoeshere) #44

I dont see anything unusual methinks.

Here is some complete (little sanitized) logs from the linux machine once it restarted syncthing and runs for a while. Maybe you can make something of the differences between the various connected clients and the connection types.

2017/11/14 14:32:24.025590 monitor.go:95: INFO: Starting syncthing
[3PKT3] 2017/11/14 14:32:24.047797 main.go:649: INFO: syncthing v0.14.40 "Dysprosium Dragonfly" (go1.9.2 linux-amd64) teamcity@build.syncthing.net 2017-10-28 19:15:32 UTC
[3PKT3] 2017/11/14 14:32:24.047902 main.go:650: INFO: My ID: 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5
[3PKT3] 2017/11/14 14:32:24.980234 sha256.go:92: INFO: Single thread SHA256 performance is 175 MB/s using minio/sha256-simd (175 MB/s using crypto/sha256).
[3PKT3] 2017/11/14 14:32:25.556764 main.go:709: INFO: Hashing performance with weak hash is 150.21 MB/s
[3PKT3] 2017/11/14 14:32:26.110695 main.go:711: INFO: Hashing performance without weak hash is 171.15 MB/s
[3PKT3] 2017/11/14 14:32:26.110728 main.go:717: INFO: Weak hash enabled, as it has an acceptable performance impact.
[3PKT3] 2017/11/14 14:32:26.515746 model.go:182: INFO: Ready to synchronize "" (vapss-mhmfh) (readwrite)
[3PKT3] 2017/11/14 14:32:26.544336 model.go:182: INFO: Ready to synchronize "" (jguva-97dl5) (readwrite)
[3PKT3] 2017/11/14 14:32:27.893052 model.go:182: INFO: Ready to synchronize "" (dffqn-zecvf) (readwrite)
[3PKT3] 2017/11/14 14:32:27.982429 model.go:182: INFO: Ready to synchronize "" (pcl7x-95go2) (readwrite)
[3PKT3] 2017/11/14 14:32:28.058902 model.go:182: INFO: Ready to synchronize "" (esrlu-xmpsj) (readwrite)
[3PKT3] 2017/11/14 14:32:28.120334 model.go:182: INFO: Ready to synchronize "" (qsys7-6qp2l) (readwrite)
[3PKT3] 2017/11/14 14:32:28.158089 model.go:182: INFO: Ready to synchronize "" (yjxzj-hv9x7) (readwrite)
[3PKT3] 2017/11/14 14:32:29.243698 model.go:182: INFO: Ready to synchronize  (readwrite)
[3PKT3] 2017/11/14 14:32:29.331322 model.go:182: INFO: Ready to synchronize  (readwrite)
[3PKT3] 2017/11/14 14:32:29.333539 model.go:182: INFO: Ready to synchronize "" (7ofcj-9am2c) (readwrite)
[3PKT3] 2017/11/14 14:32:29.373718 model.go:182: INFO: Ready to synchronize "" (jhy7d-ujhua) (readwrite)
[3PKT3] 2017/11/14 14:32:29.373952 limiter.go:84: INFO: Send rate is unlimited, receive rate is unlimited
[3PKT3] 2017/11/14 14:32:29.374015 limiter.go:89: INFO: Rate limits do not apply to LAN connections
[3PKT3] 2017/11/14 14:32:29.374154 service.go:443: DEBUG: Starting listener tcp4://:22000
[3PKT3] 2017/11/14 14:32:29.374218 service.go:520: DEBUG: Starting NAT service
[3PKT3] 2017/11/14 14:32:29.374352 main.go:826: INFO: Using discovery server https://discovery-v4-2.syncthing.net/v2/?id=DVU36WY-H3LVZHW-E6LLFRE-YAFN5EL-HILWRYP-OC2M47J-Z4PE62Y-ADIBDQC
[3PKT3] 2017/11/14 14:32:29.374508 main.go:826: INFO: Using discovery server https://discovery-v4-3.syncthing.net/v2/?id=VK6HNJ3-VVMM66S-HRVWSCR-IXEHL2H-U4AQ4MW-UCPQBWX-J2L2UBK-NVZRDQZ
[3PKT3] 2017/11/14 14:32:29.374604 main.go:826: INFO: Using discovery server https://discovery-v4-4.syncthing.net/v2/?id=LYXKCHX-VI3NYZR-ALCJBHF-WMZYSPK-QG6QJA3-MPFYMSO-U56GTUK-NA2MIAW
[3PKT3] 2017/11/14 14:32:29.374695 main.go:826: INFO: Using discovery server https://discovery-v6-2.syncthing.net/v2/?id=DVU36WY-H3LVZHW-E6LLFRE-YAFN5EL-HILWRYP-OC2M47J-Z4PE62Y-ADIBDQC
[3PKT3] 2017/11/14 14:32:29.374796 main.go:826: INFO: Using discovery server https://discovery-v6-3.syncthing.net/v2/?id=VK6HNJ3-VVMM66S-HRVWSCR-IXEHL2H-U4AQ4MW-UCPQBWX-J2L2UBK-NVZRDQZ
[3PKT3] 2017/11/14 14:32:29.374866 service.go:317: DEBUG: Reconnect loop
[3PKT3] 2017/11/14 14:32:29.374903 service.go:344: DEBUG: Reconnect loop for CUHRM6P-HVZAK5M-7LHIWW7-J2TIWUW-5PE3EKQ-P36B4OE-NRFVI3K-JSDVZAF
[3PKT3] 2017/11/14 14:32:29.374932 tcp_listen.go:69: INFO: TCP listener (0.0.0.0:22000) starting
[3PKT3] 2017/11/14 14:32:29.375190 main.go:826: INFO: Using discovery server https://discovery-v6-4.syncthing.net/v2/?id=LYXKCHX-VI3NYZR-ALCJBHF-WMZYSPK-QG6QJA3-MPFYMSO-U56GTUK-NA2MIAW
[3PKT3] 2017/11/14 14:32:29.399886 folder.go:128: INFO: Completed initial scan of readwrite folder "" (7ofcj-9am2c)
[3PKT3] 2017/11/14 14:32:29.415515 folder.go:128: INFO: Completed initial scan of readwrite folder "" (jhy7d-ujhua)
[3PKT3] 2017/11/14 14:32:29.460652 folder.go:128: INFO: Completed initial scan of readwrite folder "" (jguva-97dl5)
[3PKT3] 2017/11/14 14:32:29.490545 folder.go:128: INFO: Completed initial scan of readwrite folder "" (qsys7-6qp2l)
[3PKT3] 2017/11/14 14:32:29.513133 folder.go:128: INFO: Completed initial scan of readwrite folder "" (esrlu-xmpsj)
[3PKT3] 2017/11/14 14:32:29.579581 folder.go:128: INFO: Completed initial scan of readwrite folder "" (yjxzj-hv9x7)
[3PKT3] 2017/11/14 14:32:29.665776 folder.go:128: INFO: Completed initial scan of readwrite folder 
[3PKT3] 2017/11/14 14:32:29.685717 folder.go:128: INFO: Completed initial scan of readwrite folder "" (pcl7x-95go2)
[3PKT3] 2017/11/14 14:32:29.751032 folder.go:128: INFO: Completed initial scan of readwrite folder "" (vapss-mhmfh)
[3PKT3] 2017/11/14 14:32:30.171886 folder.go:128: INFO: Completed initial scan of readwrite folder 
[3PKT3] 2017/11/14 14:32:30.257126 folder.go:128: INFO: Completed initial scan of readwrite folder "" (dffqn-zecvf)
[3PKT3] 2017/11/14 14:32:32.956545 service.go:344: DEBUG: Reconnect loop for IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB
[3PKT3] 2017/11/14 14:32:33.382750 tcp_listen.go:103: DEBUG: connect from 192.168.188.24:55375
[3PKT3] 2017/11/14 14:32:33.382789 tcp_listen.go:112: DEBUG: failed to set traffic class: operation not supported
[3PKT3] 2017/11/14 14:32:33.448732 service.go:284: INFO: Established secure connection to V2GWKZ6-FTXZOM3-4IAEVHN-YR22QSY-TRMSE7W-VRDTUPT-EZ7XK56-P3OPTAN at 192.168.188.38:22000-192.168.188.24:55375 (tcp-server) (TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305)
[3PKT3] 2017/11/14 14:32:33.449036 model.go:1485: INFO: Device V2GWKZ6-FTXZOM3-4IAEVHN-YR22QSY-TRMSE7W-VRDTUPT-EZ7XK56-P3OPTAN client is "syncthing v0.14.40" named "j-macbookpro"
[3PKT3] 2017/11/14 14:32:36.665762 service.go:400: DEBUG: dial IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB kcp://88.130.49.12:22020
[3PKT3] 2017/11/14 14:32:36.700524 main.go:871: INFO: Device 3PKT34I-LCMZM54-NCM6EN4-N43HBTD-AYV5GP7-TJNAY2H-XIZEDNR-SHIHNQ5 is "linux-smu-dpg" at [dynamic]
[3PKT3] 2017/11/14 14:32:36.700606 main.go:871: INFO: Device 44Q6XLJ-QVFS7Z6-E3UNLYK-FAMMUVF-ODVRWYO-GSFJM5Z-NU2MG47-JYY52Q5 is "surface" at [dynamic]
[3PKT3] 2017/11/14 14:32:36.700638 main.go:871: INFO: Device CUHRM6P-HVZAK5M-7LHIWW7-J2TIWUW-5PE3EKQ-P36B4OE-NRFVI3K-JSDVZAF is "smu04-sd" at [dynamic]
[3PKT3] 2017/11/14 14:32:36.700669 main.go:871: INFO: Device IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB is "SMULAP01" at [dynamic]
[3PKT3] 2017/11/14 14:32:36.700698 main.go:871: INFO: Device VWATSLP-4JSG6OI-VFKT4HH-CUVSKBV-Q7SUSTL-KA7TCXR-AUW7BFA-727NBQA is "PPBLAP01" at [dynamic]
[3PKT3] 2017/11/14 14:32:36.700728 main.go:871: INFO: Device V2GWKZ6-FTXZOM3-4IAEVHN-YR22QSY-TRMSE7W-VRDTUPT-EZ7XK56-P3OPTAN is "j-macbookpro" at [dynamic]
[3PKT3] 2017/11/14 14:32:36.700757 main.go:871: INFO: Device Y5C6IPN-6UYQGUJ-TJROKQ6-BQTCU7C-Q6O27CJ-5R6IVUU-RCK2O35-2M462A5 is "PPBLAP02" at [dynamic]
[3PKT3] 2017/11/14 14:32:36.702591 gui.go:357: INFO: GUI and API listening on 127.0.0.1:8384
[3PKT3] 2017/11/14 14:32:36.702633 gui.go:358: INFO: Access the GUI via the following URL: http://127.0.0.1:8384/
[3PKT3] 2017/11/14 14:32:40.406711 structs.go:32: INFO: New NAT port mapping: external TCP address 84.189.33.71:13762 to local address 0.0.0.0:22000.
[3PKT3] 2017/11/14 14:32:40.459706 structs.go:32: INFO: New NAT port mapping: external TCP address 84.189.33.71:51852 to local address 0.0.0.0:22000.
[3PKT3] 2017/11/14 14:32:40.459901 service.go:61: INFO: Detected 3 NAT devices
[3PKT3] 2017/11/14 14:32:46.675673 service.go:405: DEBUG: dial failed IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB kcp://88.130.49.12:22020 i/o timeout
[3PKT3] 2017/11/14 14:32:46.675781 service.go:400: DEBUG: dial IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB kcp://88.130.49.12:3931
[3PKT3] 2017/11/14 14:32:56.676647 service.go:405: DEBUG: dial failed IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB kcp://88.130.49.12:3931 i/o timeout
[3PKT3] 2017/11/14 14:32:56.676766 service.go:400: DEBUG: dial IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB kcp://[2001:16b8:46cc:6a00:718a:1d65:e8f9:518]:22020
[3PKT3] 2017/11/14 14:32:56.727253 service.go:405: DEBUG: dial failed IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB kcp://[2001:16b8:46cc:6a00:718a:1d65:e8f9:518]:22020 broken pipe
[3PKT3] 2017/11/14 14:32:56.727636 service.go:400: DEBUG: dial IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB relay://92.222.95.0:22067/?id=MV6PJJN-6YV3HLR-XC2FMLR-CCWIHMZ-HJ2EIMD-CTF5PK4-RLYCK3S-5YPKIQP&pingInterval=1m0s&networkTimeout=2m0s&sessionLimitBps=0&globalLimitBps=0&statusAddr=:22070&providedBy=@contrib - Strasbourg, FR
[3PKT3] 2017/11/14 14:32:56.938601 relay_dial.go:48: DEBUG: failed to set traffic class: operation not supported
[3PKT3] 2017/11/14 14:32:57.126780 service.go:344: DEBUG: Reconnect loop for VWATSLP-4JSG6OI-VFKT4HH-CUVSKBV-Q7SUSTL-KA7TCXR-AUW7BFA-727NBQA
[3PKT3] 2017/11/14 14:32:57.156937 service.go:284: INFO: Established secure connection to IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB at 192.168.188.38:37060-92.222.95.0:22067 (relay-client) (TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305)
[3PKT3] 2017/11/14 14:32:57.157105 model.go:1485: INFO: Device IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB client is "syncthing v0.14.40" named "SMULAP01"
[3PKT3] 2017/11/14 14:33:00.930043 service.go:344: DEBUG: Reconnect loop for Y5C6IPN-6UYQGUJ-TJROKQ6-BQTCU7C-Q6O27CJ-5R6IVUU-RCK2O35-2M462A5
[3PKT3] 2017/11/14 14:33:04.752938 service.go:344: DEBUG: Reconnect loop for 44Q6XLJ-QVFS7Z6-E3UNLYK-FAMMUVF-ODVRWYO-GSFJM5Z-NU2MG47-JYY52Q5
[3PKT3] 2017/11/14 14:33:08.639408 service.go:417: DEBUG: initial rampup; sleep 1s and update to 2s
[3PKT3] 2017/11/14 14:33:09.639744 service.go:317: DEBUG: Reconnect loop
[3PKT3] 2017/11/14 14:33:09.639846 service.go:344: DEBUG: Reconnect loop for CUHRM6P-HVZAK5M-7LHIWW7-J2TIWUW-5PE3EKQ-P36B4OE-NRFVI3K-JSDVZAF
[3PKT3] 2017/11/14 14:33:09.797963 service.go:344: DEBUG: Reconnect loop for IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB
[3PKT3] 2017/11/14 14:33:09.798048 service.go:400: DEBUG: dial IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB kcp://88.130.49.12:22020
[3PKT3] 2017/11/14 14:33:17.720066 tcp_listen.go:103: DEBUG: connect from 88.130.49.12:4022
[3PKT3] 2017/11/14 14:33:17.720171 tcp_listen.go:112: DEBUG: failed to set traffic class: operation not supported
[3PKT3] 2017/11/14 14:33:17.889615 service.go:239: DEBUG: Switching connections IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB
[3PKT3] 2017/11/14 14:33:17.889893 service.go:284: INFO: Established secure connection to IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB at 192.168.188.38:22000-88.130.49.12:4022 (tcp-server) (TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305)
[3PKT3] 2017/11/14 14:33:17.890128 model.go:1451: INFO: Replacing old connection 192.168.188.38:37060-92.222.95.0:22067/relay-client with 192.168.188.38:22000-88.130.49.12:4022/tcp-server for IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB
[3PKT3] 2017/11/14 14:33:17.890698 model.go:1210: INFO: Connection to IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB closed: reading length: read tcp 192.168.188.38:37060->92.222.95.0:22067: use of closed network connection
[3PKT3] 2017/11/14 14:33:17.890995 model.go:1485: INFO: Device IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB client is "syncthing v0.14.40" named "SMULAP01"
[3PKT3] 2017/11/14 14:33:19.798589 service.go:405: DEBUG: dial failed IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB kcp://88.130.49.12:22020 i/o timeout
[3PKT3] 2017/11/14 14:33:19.798737 service.go:400: DEBUG: dial IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB kcp://88.130.49.12:3931
[3PKT3] 2017/11/14 14:33:29.799512 service.go:405: DEBUG: dial failed IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB kcp://88.130.49.12:3931 i/o timeout
[3PKT3] 2017/11/14 14:33:29.799627 service.go:400: DEBUG: dial IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB kcp://[2001:16b8:46cc:6a00:718a:1d65:e8f9:518]:22020
[3PKT3] 2017/11/14 14:33:29.850138 service.go:405: DEBUG: dial failed IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB kcp://[2001:16b8:46cc:6a00:718a:1d65:e8f9:518]:22020 broken pipe
[3PKT3] 2017/11/14 14:33:29.850265 service.go:395: DEBUG: Not dialing using Relay Dialer as priority is less than current connection (200 >= 200)
[3PKT3] 2017/11/14 14:33:29.850333 service.go:400: DEBUG: dial IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB tcp://88.130.49.12:22000
[3PKT3] 2017/11/14 14:33:39.850701 tcp_dial.go:36: DEBUG: dial tcp 88.130.49.12:22000: i/o timeout
[3PKT3] 2017/11/14 14:33:39.851247 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 14:33:39.851676 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 14:33:39.903061 tcp_dial.go:36: DEBUG: dial tcp [2001:16b8:46cc:6a00:718a:1d65:e8f9:518]:22000: getsockopt: permission denied
[3PKT3] 2017/11/14 14:33:39.903163 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
[3PKT3] 2017/11/14 14:33:39.903213 service.go:344: DEBUG: Reconnect loop for VWATSLP-4JSG6OI-VFKT4HH-CUVSKBV-Q7SUSTL-KA7TCXR-AUW7BFA-727NBQA
[3PKT3] 2017/11/14 14:33:39.903406 service.go:344: DEBUG: Reconnect loop for Y5C6IPN-6UYQGUJ-TJROKQ6-BQTCU7C-Q6O27CJ-5R6IVUU-RCK2O35-2M462A5
[3PKT3] 2017/11/14 14:33:39.903494 service.go:344: DEBUG: Reconnect loop for 44Q6XLJ-QVFS7Z6-E3UNLYK-FAMMUVF-ODVRWYO-GSFJM5Z-NU2MG47-JYY52Q5
[3PKT3] 2017/11/14 14:33:39.903575 service.go:417: DEBUG: initial rampup; sleep 2s and update to 4s
[3PKT3] 2017/11/14 14:33:41.903899 service.go:317: DEBUG: Reconnect loop
[3PKT3] 2017/11/14 14:33:41.903995 service.go:344: DEBUG: Reconnect loop for CUHRM6P-HVZAK5M-7LHIWW7-J2TIWUW-5PE3EKQ-P36B4OE-NRFVI3K-JSDVZAF
[3PKT3] 2017/11/14 14:33:41.904314 service.go:344: DEBUG: Reconnect loop for VWATSLP-4JSG6OI-VFKT4HH-CUVSKBV-Q7SUSTL-KA7TCXR-AUW7BFA-727NBQA
[3PKT3] 2017/11/14 14:33:41.904508 service.go:344: DEBUG: Reconnect loop for Y5C6IPN-6UYQGUJ-TJROKQ6-BQTCU7C-Q6O27CJ-5R6IVUU-RCK2O35-2M462A5
[3PKT3] 2017/11/14 14:33:41.904585 service.go:344: DEBUG: Reconnect loop for 44Q6XLJ-QVFS7Z6-E3UNLYK-FAMMUVF-ODVRWYO-GSFJM5Z-NU2MG47-JYY52Q5
[3PKT3] 2017/11/14 14:33:41.904649 service.go:417: DEBUG: initial rampup; sleep 4s and update to 8s
[3PKT3] 2017/11/14 14:33:45.904973 service.go:317: DEBUG: Reconnect loop
[3PKT3] 2017/11/14 14:33:45.905070 service.go:344: DEBUG: Reconnect loop for CUHRM6P-HVZAK5M-7LHIWW7-J2TIWUW-5PE3EKQ-P36B4OE-NRFVI3K-JSDVZAF
[3PKT3] 2017/11/14 14:33:45.905247 service.go:344: DEBUG: Reconnect loop for VWATSLP-4JSG6OI-VFKT4HH-CUVSKBV-Q7SUSTL-KA7TCXR-AUW7BFA-727NBQA
[3PKT3] 2017/11/14 14:33:45.905373 service.go:344: DEBUG: Reconnect loop for Y5C6IPN-6UYQGUJ-TJROKQ6-BQTCU7C-Q6O27CJ-5R6IVUU-RCK2O35-2M462A5
[3PKT3] 2017/11/14 14:33:45.905445 service.go:344: DEBUG: Reconnect loop for 44Q6XLJ-QVFS7Z6-E3UNLYK-FAMMUVF-ODVRWYO-GSFJM5Z-NU2MG47-JYY52Q5
[3PKT3] 2017/11/14 14:33:45.905514 service.go:417: DEBUG: initial rampup; sleep 8s and update to 16s
[3PKT3] 2017/11/14 14:33:53.905861 service.go:317: DEBUG: Reconnect loop
[3PKT3] 2017/11/14 14:33:53.905962 service.go:344: DEBUG: Reconnect loop for CUHRM6P-HVZAK5M-7LHIWW7-J2TIWUW-5PE3EKQ-P36B4OE-NRFVI3K-JSDVZAF
[3PKT3] 2017/11/14 14:33:53.906170 service.go:344: DEBUG: Reconnect loop for VWATSLP-4JSG6OI-VFKT4HH-CUVSKBV-Q7SUSTL-KA7TCXR-AUW7BFA-727NBQA
[3PKT3] 2017/11/14 14:33:53.906296 service.go:344: DEBUG: Reconnect loop for Y5C6IPN-6UYQGUJ-TJROKQ6-BQTCU7C-Q6O27CJ-5R6IVUU-RCK2O35-2M462A5
[3PKT3] 2017/11/14 14:33:53.906366 service.go:344: DEBUG: Reconnect loop for 44Q6XLJ-QVFS7Z6-E3UNLYK-FAMMUVF-ODVRWYO-GSFJM5Z-NU2MG47-JYY52Q5
[3PKT3] 2017/11/14 14:33:53.906428 service.go:417: DEBUG: initial rampup; sleep 16s and update to 32s
[3PKT3] 2017/11/14 14:34:09.906715 service.go:317: DEBUG: Reconnect loop
[3PKT3] 2017/11/14 14:34:09.906809 service.go:344: DEBUG: Reconnect loop for CUHRM6P-HVZAK5M-7LHIWW7-J2TIWUW-5PE3EKQ-P36B4OE-NRFVI3K-JSDVZAF
[3PKT3] 2017/11/14 14:34:09.907009 service.go:344: DEBUG: Reconnect loop for VWATSLP-4JSG6OI-VFKT4HH-CUVSKBV-Q7SUSTL-KA7TCXR-AUW7BFA-727NBQA
[3PKT3] 2017/11/14 14:34:09.907130 service.go:344: DEBUG: Reconnect loop for Y5C6IPN-6UYQGUJ-TJROKQ6-BQTCU7C-Q6O27CJ-5R6IVUU-RCK2O35-2M462A5
[3PKT3] 2017/11/14 14:34:09.907200 service.go:344: DEBUG: Reconnect loop for 44Q6XLJ-QVFS7Z6-E3UNLYK-FAMMUVF-ODVRWYO-GSFJM5Z-NU2MG47-JYY52Q5
[3PKT3] 2017/11/14 14:34:09.907262 service.go:417: DEBUG: initial rampup; sleep 32s and update to 1m4s
[3PKT3] 2017/11/14 14:34:41.907602 service.go:317: DEBUG: Reconnect loop
[3PKT3] 2017/11/14 14:34:41.907703 service.go:344: DEBUG: Reconnect loop for CUHRM6P-HVZAK5M-7LHIWW7-J2TIWUW-5PE3EKQ-P36B4OE-NRFVI3K-JSDVZAF
[3PKT3] 2017/11/14 14:34:41.907881 service.go:344: DEBUG: Reconnect loop for VWATSLP-4JSG6OI-VFKT4HH-CUVSKBV-Q7SUSTL-KA7TCXR-AUW7BFA-727NBQA
[3PKT3] 2017/11/14 14:34:41.908000 service.go:344: DEBUG: Reconnect loop for Y5C6IPN-6UYQGUJ-TJROKQ6-BQTCU7C-Q6O27CJ-5R6IVUU-RCK2O35-2M462A5
[3PKT3] 2017/11/14 14:34:41.908081 service.go:344: DEBUG: Reconnect loop for 44Q6XLJ-QVFS7Z6-E3UNLYK-FAMMUVF-ODVRWYO-GSFJM5Z-NU2MG47-JYY52Q5
[3PKT3] 2017/11/14 14:34:41.908142 service.go:421: DEBUG: sleep until next dial 1m0s
[3PKT3] 2017/11/14 14:35:41.908469 service.go:317: DEBUG: Reconnect loop
[3PKT3] 2017/11/14 14:35:41.908663 service.go:344: DEBUG: Reconnect loop for CUHRM6P-HVZAK5M-7LHIWW7-J2TIWUW-5PE3EKQ-P36B4OE-NRFVI3K-JSDVZAF
[3PKT3] 2017/11/14 14:35:41.908933 service.go:344: DEBUG: Reconnect loop for VWATSLP-4JSG6OI-VFKT4HH-CUVSKBV-Q7SUSTL-KA7TCXR-AUW7BFA-727NBQA
[3PKT3] 2017/11/14 14:35:42.266368 service.go:344: DEBUG: Reconnect loop for Y5C6IPN-6UYQGUJ-TJROKQ6-BQTCU7C-Q6O27CJ-5R6IVUU-RCK2O35-2M462A5
[3PKT3] 2017/11/14 14:35:42.457684 service.go:344: DEBUG: Reconnect loop for 44Q6XLJ-QVFS7Z6-E3UNLYK-FAMMUVF-ODVRWYO-GSFJM5Z-NU2MG47-JYY52Q5
[3PKT3] 2017/11/14 14:35:42.457809 service.go:421: DEBUG: sleep until next dial 1m0s
[3PKT3] 2017/11/14 14:36:42.458124 service.go:317: DEBUG: Reconnect loop
[3PKT3] 2017/11/14 14:36:42.458231 service.go:344: DEBUG: Reconnect loop for CUHRM6P-HVZAK5M-7LHIWW7-J2TIWUW-5PE3EKQ-P36B4OE-NRFVI3K-JSDVZAF
[3PKT3] 2017/11/14 14:36:42.458434 service.go:344: DEBUG: Reconnect loop for VWATSLP-4JSG6OI-VFKT4HH-CUVSKBV-Q7SUSTL-KA7TCXR-AUW7BFA-727NBQA
[3PKT3] 2017/11/14 14:36:42.458602 service.go:344: DEBUG: Reconnect loop for Y5C6IPN-6UYQGUJ-TJROKQ6-BQTCU7C-Q6O27CJ-5R6IVUU-RCK2O35-2M462A5
[3PKT3] 2017/11/14 14:36:42.458773 service.go:344: DEBUG: Reconnect loop for 44Q6XLJ-QVFS7Z6-E3UNLYK-FAMMUVF-ODVRWYO-GSFJM5Z-NU2MG47-JYY52Q5
[3PKT3] 2017/11/14 14:36:42.853047 service.go:421: DEBUG: sleep until next dial 1m0s
[3PKT3] 2017/11/14 14:37:42.853378 service.go:317: DEBUG: Reconnect loop
[3PKT3] 2017/11/14 14:37:42.853477 service.go:344: DEBUG: Reconnect loop for CUHRM6P-HVZAK5M-7LHIWW7-J2TIWUW-5PE3EKQ-P36B4OE-NRFVI3K-JSDVZAF
[3PKT3] 2017/11/14 14:37:42.853663 service.go:344: DEBUG: Reconnect loop for VWATSLP-4JSG6OI-VFKT4HH-CUVSKBV-Q7SUSTL-KA7TCXR-AUW7BFA-727NBQA
[3PKT3] 2017/11/14 14:37:47.242029 service.go:344: DEBUG: Reconnect loop for Y5C6IPN-6UYQGUJ-TJROKQ6-BQTCU7C-Q6O27CJ-5R6IVUU-RCK2O35-2M462A5
[3PKT3] 2017/11/14 14:37:49.056182 service.go:344: DEBUG: Reconnect loop for 44Q6XLJ-QVFS7Z6-E3UNLYK-FAMMUVF-ODVRWYO-GSFJM5Z-NU2MG47-JYY52Q5
[3PKT3] 2017/11/14 14:37:52.728149 service.go:421: DEBUG: sleep until next dial 1m0s
[3PKT3] 2017/11/14 14:38:52.728516 service.go:317: DEBUG: Reconnect loop
[3PKT3] 2017/11/14 14:38:52.728616 service.go:344: DEBUG: Reconnect loop for CUHRM6P-HVZAK5M-7LHIWW7-J2TIWUW-5PE3EKQ-P36B4OE-NRFVI3K-JSDVZAF
[3PKT3] 2017/11/14 14:38:52.728802 service.go:344: DEBUG: Reconnect loop for VWATSLP-4JSG6OI-VFKT4HH-CUVSKBV-Q7SUSTL-KA7TCXR-AUW7BFA-727NBQA
[3PKT3] 2017/11/14 14:38:53.026888 service.go:344: DEBUG: Reconnect loop for Y5C6IPN-6UYQGUJ-TJROKQ6-BQTCU7C-Q6O27CJ-5R6IVUU-RCK2O35-2M462A5
[3PKT3] 2017/11/14 14:38:53.026998 service.go:344: DEBUG: Reconnect loop for 44Q6XLJ-QVFS7Z6-E3UNLYK-FAMMUVF-ODVRWYO-GSFJM5Z-NU2MG47-JYY52Q5
[3PKT3] 2017/11/14 14:38:53.027063 service.go:421: DEBUG: sleep until next dial 1m0s
[3PKT3] 2017/11/14 14:39:53.027349 service.go:317: DEBUG: Reconnect loop
[3PKT3] 2017/11/14 14:39:53.027687 service.go:344: DEBUG: Reconnect loop for CUHRM6P-HVZAK5M-7LHIWW7-J2TIWUW-5PE3EKQ-P36B4OE-NRFVI3K-JSDVZAF
[3PKT3] 2017/11/14 14:39:53.028046 service.go:344: DEBUG: Reconnect loop for VWATSLP-4JSG6OI-VFKT4HH-CUVSKBV-Q7SUSTL-KA7TCXR-AUW7BFA-727NBQA
[3PKT3] 2017/11/14 14:39:53.028355 service.go:344: DEBUG: Reconnect loop for Y5C6IPN-6UYQGUJ-TJROKQ6-BQTCU7C-Q6O27CJ-5R6IVUU-RCK2O35-2M462A5
[3PKT3] 2017/11/14 14:39:53.252638 service.go:344: DEBUG: Reconnect loop for 44Q6XLJ-QVFS7Z6-E3UNLYK-FAMMUVF-ODVRWYO-GSFJM5Z-NU2MG47-JYY52Q5
[3PKT3] 2017/11/14 14:39:53.547086 service.go:421: DEBUG: sleep until next dial 1m0s
[3PKT3] 2017/11/14 14:40:53.547452 service.go:317: DEBUG: Reconnect loop
[3PKT3] 2017/11/14 14:40:53.547548 service.go:344: DEBUG: Reconnect loop for CUHRM6P-HVZAK5M-7LHIWW7-J2TIWUW-5PE3EKQ-P36B4OE-NRFVI3K-JSDVZAF
[3PKT3] 2017/11/14 14:40:53.547739 service.go:344: DEBUG: Reconnect loop for VWATSLP-4JSG6OI-VFKT4HH-CUVSKBV-Q7SUSTL-KA7TCXR-AUW7BFA-727NBQA
[3PKT3] 2017/11/14 14:40:53.547865 service.go:344: DEBUG: Reconnect loop for Y5C6IPN-6UYQGUJ-TJROKQ6-BQTCU7C-Q6O27CJ-5R6IVUU-RCK2O35-2M462A5
[3PKT3] 2017/11/14 14:40:53.547942 service.go:344: DEBUG: Reconnect loop for 44Q6XLJ-QVFS7Z6-E3UNLYK-FAMMUVF-ODVRWYO-GSFJM5Z-NU2MG47-JYY52Q5
[3PKT3] 2017/11/14 14:40:53.548001 service.go:421: DEBUG: sleep until next dial 1m0s
[3PKT3] 2017/11/14 14:41:53.548321 service.go:317: DEBUG: Reconnect loop
[3PKT3] 2017/11/14 14:41:53.548415 service.go:344: DEBUG: Reconnect loop for CUHRM6P-HVZAK5M-7LHIWW7-J2TIWUW-5PE3EKQ-P36B4OE-NRFVI3K-JSDVZAF
[3PKT3] 2017/11/14 14:41:53.548613 service.go:344: DEBUG: Reconnect loop for VWATSLP-4JSG6OI-VFKT4HH-CUVSKBV-Q7SUSTL-KA7TCXR-AUW7BFA-727NBQA
[3PKT3] 2017/11/14 14:41:57.219376 service.go:344: DEBUG: Reconnect loop for Y5C6IPN-6UYQGUJ-TJROKQ6-BQTCU7C-Q6O27CJ-5R6IVUU-RCK2O35-2M462A5
[3PKT3] 2017/11/14 14:41:59.119126 service.go:344: DEBUG: Reconnect loop for 44Q6XLJ-QVFS7Z6-E3UNLYK-FAMMUVF-ODVRWYO-GSFJM5Z-NU2MG47-JYY52Q5
[3PKT3] 2017/11/14 14:41:59.119237 service.go:421: DEBUG: sleep until next dial 1m0s
[3PKT3] 2017/11/14 14:42:59.119558 service.go:317: DEBUG: Reconnect loop
[3PKT3] 2017/11/14 14:42:59.119663 service.go:344: DEBUG: Reconnect loop for CUHRM6P-HVZAK5M-7LHIWW7-J2TIWUW-5PE3EKQ-P36B4OE-NRFVI3K-JSDVZAF
[3PKT3] 2017/11/14 14:42:59.119860 service.go:344: DEBUG: Reconnect loop for VWATSLP-4JSG6OI-VFKT4HH-CUVSKBV-Q7SUSTL-KA7TCXR-AUW7BFA-727NBQA
[3PKT3] 2017/11/14 14:42:59.119983 service.go:344: DEBUG: Reconnect loop for Y5C6IPN-6UYQGUJ-TJROKQ6-BQTCU7C-Q6O27CJ-5R6IVUU-RCK2O35-2M462A5
[3PKT3] 2017/11/14 14:42:59.120059 service.go:344: DEBUG: Reconnect loop for 44Q6XLJ-QVFS7Z6-E3UNLYK-FAMMUVF-ODVRWYO-GSFJM5Z-NU2MG47-JYY52Q5
[3PKT3] 2017/11/14 14:43:02.958866 service.go:421: DEBUG: sleep until next dial 1m0s
[3PKT3] 2017/11/14 14:44:02.959172 service.go:317: DEBUG: Reconnect loop
[3PKT3] 2017/11/14 14:44:02.959279 service.go:344: DEBUG: Reconnect loop for CUHRM6P-HVZAK5M-7LHIWW7-J2TIWUW-5PE3EKQ-P36B4OE-NRFVI3K-JSDVZAF
[3PKT3] 2017/11/14 14:44:02.959520 service.go:344: DEBUG: Reconnect loop for VWATSLP-4JSG6OI-VFKT4HH-CUVSKBV-Q7SUSTL-KA7TCXR-AUW7BFA-727NBQA
[3PKT3] 2017/11/14 14:44:02.959663 service.go:344: DEBUG: Reconnect loop for Y5C6IPN-6UYQGUJ-TJROKQ6-BQTCU7C-Q6O27CJ-5R6IVUU-RCK2O35-2M462A5
[3PKT3] 2017/11/14 14:44:03.127585 service.go:344: DEBUG: Reconnect loop for 44Q6XLJ-QVFS7Z6-E3UNLYK-FAMMUVF-ODVRWYO-GSFJM5Z-NU2MG47-JYY52Q5
[3PKT3] 2017/11/14 14:44:03.127703 service.go:421: DEBUG: sleep until next dial 1m0s
[3PKT3] 2017/11/14 14:45:03.128027 service.go:317: DEBUG: Reconnect loop
[3PKT3] 2017/11/14 14:45:03.128127 service.go:344: DEBUG: Reconnect loop for CUHRM6P-HVZAK5M-7LHIWW7-J2TIWUW-5PE3EKQ-P36B4OE-NRFVI3K-JSDVZAF
[3PKT3] 2017/11/14 14:45:03.128336 service.go:344: DEBUG: Reconnect loop for VWATSLP-4JSG6OI-VFKT4HH-CUVSKBV-Q7SUSTL-KA7TCXR-AUW7BFA-727NBQA
[3PKT3] 2017/11/14 14:45:03.420533 service.go:344: DEBUG: Reconnect loop for Y5C6IPN-6UYQGUJ-TJROKQ6-BQTCU7C-Q6O27CJ-5R6IVUU-RCK2O35-2M462A5
[3PKT3] 2017/11/14 14:45:03.420574 service.go:344: DEBUG: Reconnect loop for 44Q6XLJ-QVFS7Z6-E3UNLYK-FAMMUVF-ODVRWYO-GSFJM5Z-NU2MG47-JYY52Q5
[3PKT3] 2017/11/14 14:45:03.420593 service.go:421: DEBUG: sleep until next dial 1m0s
[3PKT3] 2017/11/14 14:46:03.420925 service.go:317: DEBUG: Reconnect loop
[3PKT3] 2017/11/14 14:46:03.421035 service.go:344: DEBUG: Reconnect loop for CUHRM6P-HVZAK5M-7LHIWW7-J2TIWUW-5PE3EKQ-P36B4OE-NRFVI3K-JSDVZAF
[3PKT3] 2017/11/14 14:46:03.421251 service.go:344: DEBUG: Reconnect loop for VWATSLP-4JSG6OI-VFKT4HH-CUVSKBV-Q7SUSTL-KA7TCXR-AUW7BFA-727NBQA
[3PKT3] 2017/11/14 14:46:07.083382 service.go:344: DEBUG: Reconnect loop for Y5C6IPN-6UYQGUJ-TJROKQ6-BQTCU7C-Q6O27CJ-5R6IVUU-RCK2O35-2M462A5
[3PKT3] 2017/11/14 14:46:09.550321 service.go:344: DEBUG: Reconnect loop for 44Q6XLJ-QVFS7Z6-E3UNLYK-FAMMUVF-ODVRWYO-GSFJM5Z-NU2MG47-JYY52Q5
[3PKT3] 2017/11/14 14:46:09.852577 service.go:421: DEBUG: sleep until next dial 1m0s
[3PKT3] 2017/11/14 14:47:09.853006 service.go:317: DEBUG: Reconnect loop
[3PKT3] 2017/11/14 14:47:09.853108 service.go:344: DEBUG: Reconnect loop for CUHRM6P-HVZAK5M-7LHIWW7-J2TIWUW-5PE3EKQ-P36B4OE-NRFVI3K-JSDVZAF
[3PKT3] 2017/11/14 14:47:09.853313 service.go:344: DEBUG: Reconnect loop for VWATSLP-4JSG6OI-VFKT4HH-CUVSKBV-Q7SUSTL-KA7TCXR-AUW7BFA-727NBQA
[3PKT3] 2017/11/14 14:47:09.853432 service.go:344: DEBUG: Reconnect loop for Y5C6IPN-6UYQGUJ-TJROKQ6-BQTCU7C-Q6O27CJ-5R6IVUU-RCK2O35-2M462A5
[3PKT3] 2017/11/14 14:47:09.853502 service.go:344: DEBUG: Reconnect loop for 44Q6XLJ-QVFS7Z6-E3UNLYK-FAMMUVF-ODVRWYO-GSFJM5Z-NU2MG47-JYY52Q5
[3PKT3] 2017/11/14 14:47:09.853561 service.go:421: DEBUG: sleep until next dial 1m0s
[3PKT3] 2017/11/14 14:48:09.853951 service.go:317: DEBUG: Reconnect loop
[3PKT3] 2017/11/14 14:48:09.854056 service.go:344: DEBUG: Reconnect loop for CUHRM6P-HVZAK5M-7LHIWW7-J2TIWUW-5PE3EKQ-P36B4OE-NRFVI3K-JSDVZAF
[3PKT3] 2017/11/14 14:48:09.854280 service.go:344: DEBUG: Reconnect loop for VWATSLP-4JSG6OI-VFKT4HH-CUVSKBV-Q7SUSTL-KA7TCXR-AUW7BFA-727NBQA
[3PKT3] 2017/11/14 14:48:10.241093 service.go:344: DEBUG: Reconnect loop for Y5C6IPN-6UYQGUJ-TJROKQ6-BQTCU7C-Q6O27CJ-5R6IVUU-RCK2O35-2M462A5
[3PKT3] 2017/11/14 14:48:10.241214 service.go:344: DEBUG: Reconnect loop for 44Q6XLJ-QVFS7Z6-E3UNLYK-FAMMUVF-ODVRWYO-GSFJM5Z-NU2MG47-JYY52Q5
[3PKT3] 2017/11/14 14:48:13.587016 service.go:421: DEBUG: sleep until next dial 1m0s

(Jakob Borg) #45

Have you sanitized away successful connections? Otherwise it’s odd that it’s not even attempting a TCP connection after 14:33:39 as far as I can see.


(usernamegoeshere) #46

No havent. Only the initial scan foldernames in the “” and simplified some of the hostnames. All the loglines are there, didnt remove any.


(Audrius Butkevicius) #47

Dafuq. It looks like it thinks it’s connected. Yet it can’t be kcp related.


(Jakob Borg) #48

… because it gets connected via tcp at 14:33:17, I just didn’t read properly, sorry. Assuming it’s IOEPMYD we’re talkning about. So from that log it looks successfully connected and happy from 14:33:17 onwards.


(Florian Reitmeir) #49

my internet connection is very fast, and there is no problem with the bandwith. syncthing tcp is just not stable. where there changes to the tcp parameters? windows size?


(Audrius Butkevicius) #50

No, nothing changed in terms of tcp. We just on-boarded a new protocol along side tcp.


(usernamegoeshere) #51

nighttime here, and the linux machine is apparently the only one left alive right now on the inter network.

[3PKT3] 2017/11/15 01:28:40.250890 service.go:317: DEBUG: Reconnect loop
[3PKT3] 2017/11/15 01:28:40.250991 service.go:344: DEBUG: Reconnect loop for CUHRM6P-HVZAK5M-7LHIWW7-J2TIWUW-5PE3EKQ-P36B4OE-NRFVI3K-JSDVZAF
[3PKT3] 2017/11/15 01:28:40.251081 service.go:344: DEBUG: Reconnect loop for IOEPMYD-LL5ZH6Z-ORZL7KH-FJ4Q7KB-B2N7WTK-FELNT7A-Y5JQI3F-6HXIRAB
[3PKT3] 2017/11/15 01:28:43.453004 service.go:344: DEBUG: Reconnect loop for VWATSLP-4JSG6OI-VFKT4HH-CUVSKBV-Q7SUSTL-KA7TCXR-AUW7BFA-727NBQA
[3PKT3] 2017/11/15 01:28:43.453249 service.go:344: DEBUG: Reconnect loop for V2GWKZ6-FTXZOM3-4IAEVHN-YR22QSY-TRMSE7W-VRDTUPT-EZ7XK56-P3OPTAN
[3PKT3] 2017/11/15 01:28:43.604958 service.go:344: DEBUG: Reconnect loop for Y5C6IPN-6UYQGUJ-TJROKQ6-BQTCU7C-Q6O27CJ-5R6IVUU-RCK2O35-2M462A5
[3PKT3] 2017/11/15 01:28:43.844598 service.go:344: DEBUG: Reconnect loop for 44Q6XLJ-QVFS7Z6-E3UNLYK-FAMMUVF-ODVRWYO-GSFJM5Z-NU2MG47-JYY52Q5
[3PKT3] 2017/11/15 01:28:44.138130 service.go:421: DEBUG: sleep until next dial 1m0s

maybe i find some loglines in the morning to see if that ominous win10 IOEPMYD is connecting back. cant promise that i will be able to grab a hold of the very first loglines of that timespan when the devices come back on line.


(Audrius Butkevicius) #52

So you have multiple devices, hence it’s completely confusing what you are trying to show. It would be best if you were to post a full log and explain which specific device is failing to connect.


(usernamegoeshere) #53

Uhm no, I have always pretty extensively and thoroughly wrote from which machine I have posted the logs. The 3PKT3 is the linux machine, and that IOEPMYD is the win 10 machine on a different place that was having problems or showing status as last connected like a day ago on the day after the initial 0.14.40 release and so on. I had thought I have posted precise information in here as far as possible and to my knowledge.

Syncthing is about multiple devices. But I have had mainly only logs from the linux machine for ease of accessing the logs, and the one distant windows 10 machine that I was able to grab hold of and check its logs a bit, and I noted when I posted those excerpts.

Meanwhile I see some pull request or some bug report on github that maybe hints towards a different direction here, that the machines are not exactly disconnected from each other but not continuing to work with each other and not syncing files any more or similar to that.

Is it possible that this whole thread is rather a result of those bugs and code you guys identified in the mean time?


(Jakob Borg) #54

Unclear, but given we have at least 20k instances of 0.14.40 running, probably closer to 60k in reality, and so far a handful of complaints rather than a complete lynching, I think it’s not too systematic.


(Audrius Butkevicius) #55

So here’s some food for thought.

Range represents number of addresses, frequency is number of devices advertising number of addresses in that range.

Query
with counts as (
  select count(1) as cnt from addresses where address like 'kcp%' group by deviceid
),
bounds as (
  select max(cnt) as max, min(cnt) as min from counts
)
select range, freq from (
  select width_bucket(cnt, min, max, 19) as bucket,
    int4range(min(cnt)::int, max(cnt)::int, '[]') as range,
    count(*) as freq
  from counts, bounds
    group by bucket
    order by bucket
) w;
KCP
   range   | freq
-----------+-------
 [1,19)    | 39699
 [19,36)   |   124
 [36,53)   |    51
 [53,69)   |    22
 [70,84)   |    11
 [87,102)  |     8
 [114,115) |     1
 [126,137) |     5
 [150,152) |     2
 [160,170) |     3
 [173,189) |     3
 [191,192) |     1
 [272,273) |     1
 [318,327) |    20
 [327,328) |     4
TCP
   range   | freq
-----------+-------
 [1,11)    | 67861
 [11,21)   |    17
 [22,23)   |     1
 [36,37)   |     1
 [45,46)   |     1
 [51,52)   |     1
 [60,61)   |     1
 [185,186) |     1
Relay
   range   | freq
-----------+-------
 [1,7)     | 60371
 [7,13)    |   391
 [13,19)   |    54
 [19,25)   |    36
 [25,30)   |    14
 [30,36)   |    15
 [36,42)   |     8
 [42,48)   |     8
 [48,54)   |     7
 [54,55)   |     2
 [59,65)   |     5
 [68,70)   |     4
 [76,77)   |     1
 [77,79)   |     4
 [85,86)   |     1
 [90,94)   |     2
 [97,98)   |     1
 [104,106) |     2
 [106,109) |    11
 [111,112) |     1

There seems to be a lot more devices with many KCP addresses advertised than there is with TCP addresses, which given serial fashion of our connections, could contribute to this.

We have merged the parallel dial thing which might help a bit, yet for 50-80 addresses, I am not sure what consequences there will be.


(Jakob Borg) #56

We could skip announcement of the outside KCP address once STUN has detected an unhelpful NAT type (symmetric).


(Audrius Butkevicius) #57

It’s sad we can’t tie back the devices with many addresses to UR to see NAT types.

This has a table explaining who can connect to what,yet I suspect you are right, udp firewall or symmetric nat should skip advertising.

http://www.raknet.net/raknet/manual/natpunchthrough.html


(Jakob Borg) #58

That is what makes it anonymous usage reporting. :slight_smile:


(Dingho) #59

Having the same sync issue on v0.14.40.

[XXXXX] 12:36:37 INFO: Device YYYYYYY client is “syncthing v0.14.40” named “PC-B” [XXXXX] 12:36:45 INFO: kcp://0.0.0.0:22020 detected NAT type: Port restricted NAT [XXXXX] 12:36:45 INFO: kcp://0.0.0.0:22020 resolved external address kcp://111.111.11.11:22020 (via stun.sipgate.net:3478) [XXXXX] 12:36:51 INFO: Joined relay relay://111.221.44.148:17607 [XXXXX] 12:37:19 INFO: Established secure connection to YYYYYYY at 192.168.1.2:22000-207.154.86.145:55053 (tcp-server) (XXXXXX) [XXXXX] 12:37:19 INFO: Replacing old connection >[::]:22020-222.222.22.222:22020/kcp->client with 192.168.1.2:22000-222.222.22.222:55053/tcp-server for YYYYYYY [XXXXX] 12:37:19 INFO: Connection to YYYYYYY closed: reading length: broken pipe [XXXXX] 12:37:19 INFO: Device YYYYYYY client is “syncthing v0.14.40” named “PC-B”


(Jakob Borg) #60

So, according to the log it is connected. What happens then, or what is the actual problem you are experiencing?