Always Disconnected between OpenBSD and Android

Support
1

Clients that used to work perfectly always show “disconnected”. Please tell me what I am doing wrong. Thank you.

The logs are edited slightly. I added space characters to disable link detection.

BFMartin

On the OpenBSD side, here is the log file:

[JGMWN] 21:01:37 INFO: syncthing v0.14.17 “Dysprosium Dragonfly” (go1.8beta2 openbsd-amd64) jenkins@build.syncthing.net 2016-12-27 10:29:12 UTC [JGMWN] 21:01:37 INFO: My ID: JGMWNK7-WKSLGF2-MSFDGJQ-I3DX4SJ-DDUZKUI-HQJ4Q3N-3THBEYB-DA6FUQ6 [JGMWN] 21:01:38 INFO: Single thread hash performance is 158 MB/s using minio/sha256-simd (130 MB/s using crypto/sha256). [JGMWN] 21:01:38 INFO: Ready to synchronize “bfm” (jdahr-mox7l) (readwrite) [JGMWN] 21:01:38 INFO: Using discovery server https : //discovery-v4-2.syncthing.net/v2/?id=DVU36WY-H3LVZHW-E6LLFRE-YAFN5EL-HILWRYP-OC2M47J-Z4PE62Y-ADIBDQC [JGMWN] 21:01:38 INFO: Using discovery server https : // discovery-v4-3.syncthing.net/v2/?id=VK6HNJ3-VVMM66S-HRVWSCR-IXEHL2H-U4AQ4MW-UCPQBWX-J2L2UBK-NVZRDQZ [JGMWN] 21:01:38 INFO: Using discovery server https : //discovery-v4-4.syncthing.net/v2/?id=LYXKCHX-VI3NYZR-ALCJBHF-WMZYSPK-QG6QJA3-MPFYMSO-U56GTUK-NA2MIAW [JGMWN] 21:01:38 INFO: Using discovery server https : // discovery-v6-2.syncthing.net/v2/?id=DVU36WY-H3LVZHW-E6LLFRE-YAFN5EL-HILWRYP-OC2M47J-Z4PE62Y-ADIBDQC [JGMWN] 21:01:38 INFO: Using discovery server https : // discovery-v6-3.syncthing.net/v2/?id=VK6HNJ3-VVMM66S-HRVWSCR-IXEHL2H-U4AQ4MW-UCPQBWX-J2L2UBK-NVZRDQZ [JGMWN] 21:01:38 INFO: Using discovery server https : // discovery-v6-4.syncthing.net/v2/?id=LYXKCHX-VI3NYZR-ALCJBHF-WMZYSPK-QG6QJA3-MPFYMSO-U56GTUK-NA2MIAW [JGMWN] 21:01:38 INFO: TCP listener (0.0.0.0:22000) starting [JGMWN] 21:01:38 INFO: Completed initial scan (rw) of “bfm” (jdahr-mox7l) [JGMWN] 21:01:38 INFO: Device JGMWNK7-WKSLGF2-MSFDGJQ-I3DX4SJ-DDUZKUI-HQJ4Q3N-3THBEYB-DA6FUQ6 is “drathro.bfm.ca” at [dynamic] [JGMWN] 21:01:38 INFO: Device YLMI2X4-EJKMBPP-JKCBZOE-UQRD7HB-357FI5W-OUEDHXI-BRAVH35-6UJ3OA4 is “s4phone” at [dynamic] [JGMWN] 21:01:38 INFO: GUI and API listening on 192.168.3.5:8443 [JGMWN] 21:01:38 INFO: Access the GUI via the following URL: https : // drathro.bfm.ca:8443/ [JGMWN] 21:01:38 INFO: c.S.listenerSupervisor: Failed service ‘dynamic+https : // relays.syncthing.net/endpoint’ (1.000000 failures of 2.000000), restarting: true, error: “{dynamic+https : // relays.syncthing.net/endpoint dynamic+https : // relays.syncthing.net/endpoint} returned unexpectedly”, stacktrace: [unknown stack trace] [JGMWN] 21:01:38 INFO: c.S.listenerSupervisor: Failed service ‘dynamic+https : // relays.syncthing.net/endpoint’ (1.994699 failures of 2.000000), restarting: true, error: “{dynamic+https : // relays.syncthing.net/endpoint dynamic+https : // relays.syncthing.net/endpoint} returned unexpectedly”, stacktrace: [unknown stack trace] [JGMWN] 21:01:39 INFO: Entering the backoff state. [JGMWN] 21:01:39 INFO: c.S.listenerSupervisor: Failed service ‘dynamic+https : // relays.syncthing.net/endpoint’ (2.981990 failures of 2.000000), restarting: false, error: “{dynamic+https : // relays.syncthing.net/endpoint dynamic+https : // relays.syncthing.net/endpoint} returned unexpectedly”, stacktrace: [unknown stack trace]

====================================================

On the Android side:

--------- beginning of main 12-28 16:55:21.955 I/System.out(18912): KnoxVpnUidStorageknoxVpnSupported API value returned is false 12-28 16:55:22.065 V/RestTask(18912): Calling Rest API at https : // 127.0.0.1:8384 12-28 16:55:22.065 I/System.out(18912): (HTTPLog)-Static: isSBSettingEnabled false 12-28 16:55:22.065 I/System.out(18912): KnoxVpnUidStorageknoxVpnSupported API value returned is false 12-28 16:55:22.165 V/RestTask(18912): Calling Rest API at https : // 127.0.0.1:8384 12-28 16:55:22.165 I/System.out(18912): (HTTPLog)-Static: isSBSettingEnabled false 12-28 16:55:22.165 I/System.out(18912): KnoxVpnUidStorageknoxVpnSupported API value returned is false 12-28 16:55:22.275 V/RestTask(18912): Calling Rest API at https : // 127.0.0.1: 8384 12-28 16:55:22.275 I/System.out(18912): (HTTPLog)-Static: isSBSettingEnabled false 12-28 16:55:22.275 I/System.out(18912): KnoxVpnUidStorageknoxVpnSupported API value returned is false 12-28 16:55:22.385 V/RestTask(18912): Calling Rest API at https : // 127.0.0.1:8384 12-28 16:55:22.385 I/System.out(18912): (HTTPLog)-Static: isSBSettingEnabled false 12-28 16:55:22.385 I/System.out(18912): KnoxVpnUidStorageknoxVpnSupported API value returned is false 12-28 16:55:22.486 V/RestTask(18912): Calling Rest API at https : // 127.0.0.1:8384 12-28 16:55:22.496 I/System.out(18912): (HTTPLog)-Static: isSBSettingEnabled false 12-28 16:55:22.496 I/System.out(18912): KnoxVpnUidStorageknoxVpnSupported API value returned is false 12-28 16:55:22.596 V/RestTask(18912): Calling Rest API at https : // 127.0.0.1:8384 12-28 16:55:22.596 I/System.out(18912): (HTTPLog)-Static: isSBSettingEnabled false 12-28 16:55:22.596 I/System.out(18912): KnoxVpnUidStorageknoxVpnSupported API value returned is false 12-28 16:55:22.646 I/SyncthingRunnableIoNice(18912): ionice performed on libsyncthing.so 12-28 16:55:22.706 V/RestTask(18912): Calling Rest API at https : // 127.0.0.1:8384 12-28 16:55:22.706 I/System.out(18912): (HTTPLog)-Static: isSBSettingEnabled false 12-28 16:55:22.706 I/System.out(18912): KnoxVpnUidStorageknoxVpnSupported API value returned is false 12-28 16:55:22.806 V/RestTask(18912): Calling Rest API at https : // 127.0.0.1:8384 12-28 16:55:22.806 I/System.out(18912): (HTTPLog)-Static: isSBSettingEnabled false 12-28 16:55:22.816 I/System.out(18912): KnoxVpnUidStorageknoxVpnSupported API value returned is false 12-28 16:55:22.906 I/SyncthingNativeCode(18912): [YLMI2] 21:55:22 INFO: Single thread hash performance is 27 MB/s using minio/sha256-simd (26 MB/s using crypto/sha256). 12-28 16:55:22.916 V/RestTask(18912): Calling Rest API at https : // 127.0.0.1:8384 12-28 16:55:22.916 I/System.out(18912): (HTTPLog)-Static: isSBSettingEnabled false 12-28 16:55:22.916 I/System.out(18912): KnoxVpnUidStorageknoxVpnSupported API value returned is false 12-28 16:55:23.026 V/RestTask(18912): Calling Rest API at https : //127.0.0.1:8384 12-28 16:55:23.026 I/System.out(18912): (HTTPLog)-Static: isSBSettingEnabled false 12-28 16:55:23.026 I/System.out(18912): KnoxVpnUidStorageknoxVpnSupported API value returned is false 12-28 16:55:23.076 I/SyncthingNativeCode(18912): [YLMI2] 21:55:23 INFO: Ready to synchronize sgh-i337m-photos (readonly) 12-28 16:55:23.086 I/SyncthingNativeCode(18912): [YLMI2] 21:55:23 INFO: Using discovery server https : // discovery-v4-2.syncthing.net/v2/?id=DVU36WY-H3LVZHW-E6LLFRE-YAFN5EL-HILWRYP-OC2M47J-Z4PE62Y-ADIBDQC 12-28 16:55:23.086 I/SyncthingNativeCode(18912): [YLMI2] 21:55:23 INFO: Using discovery server https : // discovery-v4-3.syncthing.net/v2/?id=VK6HNJ3-VVMM66S-HRVWSCR-IXEHL2H-U4AQ4MW-UCPQBWX-J2L2UBK-NVZRDQZ 12-28 16:55:23.096 I/SyncthingNativeCode(18912): [YLMI2] 21:55:23 INFO: TCP listener ([::]:22000) starting 12-28 16:55:23.146 V/RestTask(18912): Calling Rest API at https : //127.0.0.1:8384 12-28 16:55:23.146 I/System.out(18912): (HTTPLog)-Static: isSBSettingEnabled false 12-28 16:55:23.166 I/System.out(18912): KnoxVpnUidStorageknoxVpnSupported API value returned is false 12-28 16:55:23.186 I/SyncthingNativeCode(18912): Using DNS servers: [2607:f798:18:10:0:640:7125:5254:53 2607:f798:18:10:0:640:7125:5253:53] 12-28 16:55:23.186 I/SyncthingNativeCode(18912): [YLMI2] 21:55:23 INFO: c.S.listenerSupervisor: Failed service ‘dynamic+https : // relays.syncthing.net/endpoint’ (1.000000 failures of 2.000000), restarting: true, error: “{dynamic+https : // relays.syncthing.net/endpoint dynamic+https : // relays.syncthing.net/endpoint} returned unexpectedly”, stacktrace: [unknown stack trace]

2

They appear unable to talk to the public relay pool. If they were previously connecting via relay that would explain it.

3

Because it looks like the address is mangled, having extra spaces in the wrong places.

4

The extra spaces are my doing. The forum interface said “new users are allowed to post only one link” so I had to insert spaces so the forum software wouldn’t interpret it as URLs

5

Never used a relay (to my knowledge)

Could it be a firewall issue? I’ve got a good one on my home network.

6

It could be, if you prevent outgoing connections on certain ports.

7

Sorry, my mistake. Not firewall. From that host, outgoing is unrestricted. Incoming ports are forwarded as per Syncthing setup instructions.

8

You should run with STTRACE=relay env var to see if it explains why it fails to connect to the relay pool. Actually you should see the error in the web ui as you hover on listeners

9

I’m trying to post the new log but UI says “new user can mention only 2 users”

Still trying

10

excerpt:

[JGMWN] 2016/12/28 18:30:08.042158 dynamic.go:86: DEBUG: DynamicClient:0xc420015f10:@dynamic+https://relays.syncthing.net/endpoint found relay://51.255.196.47:22067/?id=KRQOP3H-QQ2OHPJ-WLHLERJ-FP7EBFE-OX2GGMV-FZCJA2A-YGAM7QT-BZBQEA4&pingInterval=1m0s&networkTimeout=2m0s&sessionLimitBps=0&globalLimitBps=5242880&statusAddr=:22070&providedBy=vet - FR [JGMWN] 2016/12/28 18:30:08.042190 dynamic.go:86: DEBUG: DynamicClient:0xc420015f10:@dynamic+https://relays.syncthing.net/endpoint found relay://43.239.250.13:22067/?id=JAAG26A-Z3RIXWW-UCCYJJM-R2KMMPK-P3MIUVM-KNQJ53S-N7EDIZV-H4PDXAA&pingInterval=1m0s&networkTimeout=2m0s&sessionLimitBps=0&globalLimitBps=0&statusAddr=:22070&providedBy=HackedServer

11

Excerpt:

[JGMWN] 2016/12/28 18:30:07.336073 dynamic.go:61: DEBUG: DynamicClient:0xc420015f10:@dynamic+https://relays.syncthing.net/endpoint looking up dynamic relays [JGMWN] 2016/12/28 18:30:07.348913 main.go:787: INFO: Device JGMWNK7-WKSLGF2-MSFDGJQ-I3DX4SJ-DDUZKUI-HQJ4Q3N-3THBEYB-DA6FUQ6 is “drathro.bfm.ca” at [dynamic] [JGMWN] 2016/12/28 18:30:07.349137 main.go:787: INFO: Device YLMI2X4-EJKMBPP-JKCBZOE-UQRD7HB-357FI5W-OUEDHXI-BRAVH35-6UJ3OA4 is “s4phone” at [dynamic] [JGMWN] 2016/12/28 18:30:07.350564 gui.go:337: INFO: GUI and API listening on 192.168.3.5:8443

12

Another:

[JGMWN] 2016/12/28 18:30:09.465402 static.go:77: DEBUG: StaticClient:0xc421036280@relay://69.197.185.164:80/?id=6LWAN23-5ZAI65D-5F67VQY-E7AWU3N-PEB33LM-6CLIVYU-5GJTBZ2-5EZIEQH&pingInterval=1m0s&networkTimeout=2m0s&sessionLimitBps=0&globalLimitBps=2097152&statusAddr=:22068&providedBy=Munzy - Kansas City, MO, USA connected 69.197.185.164:80 [JGMWN] 2016/12/28 18:30:09.506022 static.go:93: INFO: Joined relay relay://69.197.185.164:80 [JGMWN] 2016/12/28 18:30:17.353092 service.go:61: INFO: Detected 0 NAT devices

13

Hovering over listeners says something like:

x509: failed to load system roots and no roots provided.

14

You’re missing the root CA certificates, so Syncthing can’t establish HTTPS connections. You need to install these according to the procedure for your operating system.

15

OK. Done.

On the OpenBSD side, I have it running in a chroot, and I missed that. Now I copied the root certs into the chroot.

GUI no longer shows x509 message, and has green 2/2 on listeners.

Still won’t connect, tho.

16

Excerpt:

[JGMWN] 2016/12/29 00:08:36.888238 dynamic.go:86: DEBUG: DynamicClient:0xc42008f180:@dynamic+https ://relays.syncthing.net/endpoint found relay://37.187.21.5:22067/?id=BORMXG4-DL72CFI-NG65OYK-2ESXSO5-TE7WFGO-2SMYVGS-I3B2JNW-B6NS4AN&pingInterval=1m0s&networkTimeout=2m0s&sessionLimitBps=0&globalLimitBps=0&statusAddr=:22070&providedBy=Micocoule [JGMWN] 2016/12/29 00:08:36.888272 dynamic.go:86: DEBUG: DynamicClient:0xc42008f180:@dynamic+https ://relays.syncthing.net/endpoint found relay://104.131.145.187:22067/?id=YYEAKEC-5WCTIDE-WUCS5YB-MHYVJAU-NHWYDFS-7PW3NR6-3XTLUCR-DII2YQL&pingInterval=1m0s&networkTimeout=2m0s&sessionLimitBps=0&globalLimitBps=5000000&statusAddr=:22070&providedBy=

17

Well that issue is solved, and micro excerpts aren’t really useful. But try some things - set the addresses statically for example, maybe discovery can’t penetrate your firewall and/or jail, it’s hard to say from here.

18

Sorry for not responding right away. The UI told me I can only post a gazillion messages in one day so it rate limited me. :slight_smile:

Thanks also to Simon for kindly pointing out how to post the log messages without problem.

Anyway, the latest log messages from OpenBSD are here:

Still “disconnected” on both ends, though the log messages seem different.

BFMartin

19

If they are on the same LAN/Wifi and not connecting you should look into your firewalls. Syncthing pretty much never fails to connect under those circumstances. I gave another thing to try above.

20

They are not on the same network segment. The OpenBSD side is a server in my home, the Android is on the cellular network.

I will try what you recommend and get back here. Thank you for your help.

BFMartin