search

syncthing / syncthing-android

Wrapper of syncthing for Android.
https://syncthing.net/
Mozilla Public License 2.0
3.37k stars 378 forks source link

Discovery issues #643

Closed Tiemichael closed 8 years ago

Tiemichael commented 8 years ago

When not connected to LAN, my android device is often unable to connect to other devices on LAN.

Here is my configuration:

The PC uses port 22001, forwarded by the router to the PC (192.168.1.100) The Raspberry used port 22000, forwarded by the router to the Raspberry (192.168.1.145) The external IP is dynamically linked (via service like dyn-dns) to myprivateip.com, and ports 22000 and 22001 of myprivateip.com are confirmed open when testing from the phone.

Detection is within a few seconds if all devices are connected by LAN, and 5 - 15 - minutes or even never if the phone is using 3G/4G. To facilitate easy detection I put this into the config.xml of the phone PHONE2, but somehow it seems not working as expected

   <device id="G5XDXXX-6RRL3KY-2TT5QSN-Z6IYI5J-ZJZIRUS-52SM35G-T6ZADOM-TKLVGGG" name="Raspberry" compression="metadata" introducer="false">
        <address>tcp://192.168.1.145:22000</address>
        <address>tcp://myprivateip.com:22000</address>
        <address>dynamic</address>
    </device>

    <device id="PJU2XXX-EUNTE6Z-IBLULNJ-YEKAVLV-FQ7PPHU-ND4T5AI-JT3IB6M-XCWFGGG" name="PC" compression="metadata" introducer="true">
        <address>tcp://192.168.1.100:22001</address>
        <address>tcp://myprivateip.com:22001</address>
        <address>dynamic</address>
    </device>

    <device id="SUWCXXX-O4VAMNC-OYSZCB7-QM7SIGF-O7YVTRE-YFXGAZS-V6PKSEI-YV3XGGG" name="PHONE2" compression="metadata" introducer="false">
        <address>dynamic</address>
AudriusButkevicius commented 8 years ago

Which implies that your port forwarding isn't actually working, and you probably end up connecting via relay after 10 minutes.

Tiemichael commented 8 years ago

Yes, that's also what I think! But why? Port forwarding seems working. A port-scan from the phone while connected via 3G4G confirms the 2 ports open. Even changing from host-name 'myprivateip.com' to the current 'external-IP' in config.xml does not change anything ...

AudriusButkevicius commented 8 years ago

A port scan doesn't prove that forwarding actually works. You can enable "connections" trace option on android and see the logs for when it dials.

Tiemichael commented 8 years ago

Ok, will try! Thank you. I use the same port-forwarding on my router for several other functions (e.g. IMAP, SMTP ...) and all is working.

AudriusButkevicius commented 8 years ago

The docs also explain that the mapping should be symetric, as in 22000 to 22000 etc. Furthermore, if you have UPnP enabled, and syncthing thinks it managed to get a port mapped via upnp, it will advertise that port instead.

Tiemichael commented 8 years ago

My understanding of 'symmetric' was that external port 22000 is forwarded to internal port 22000, and 22001 to 22001. So I forwarded external 22000 to Raspberry:22000, and 22001 to PC:22001. The Raspberry is listening to 0.0.0.0:22000 and the PC to 0.0.0.0:22001.

Tiemichael commented 8 years ago

I switched on 'net' in Debug: Not sure how to interpret this log, but it seems that IP-address, host and port is not available to Syncthing.

V/GetTask ( 9536): API call result: {"connections":{
"G5XDXXX-6RRL3KY-2TT5QSN-Z6IYI5J-ZJZIRUS-52SM35G-T6ZADOM-TKLVGGG":{"address":"","at":"0001-01-01T00:00:00Z","clientVersion":"","connected":false,"inBytesTotal":0,"outBytesTotal":0,"paused":false,"type":"direct-accept"},
"PJU2XXX-EUNTE6Z-IBLULNJ-YEKAVLV-FQ7PPHU-ND4T5AI-JT3IB6M-XCWFGGG":{"address":"","at":"0001-01-01T00:00:00Z","clientVersion":"","connected":false,"inBytesTotal":0,"outBytesTotal":0,"paused":false,"type":"direct-accept"},
"SUWCXXX-O4VAMNC-OYSZCB7-QM7SIGF-O7YVTRE-YFXGAZS-V6PKSEI-YV3XGGG":{"address":"","at":"0001-01-01T00:00:00Z","clientVersion":"","connected":false,"inBytesTotal":0,"outBytesTotal":0,"paused":false,"type":"direct-accept"}},
"total":{"address":"","at":"2016-05-15T12:15:46.085906458Z","clientVersion":"","connected":false,"inBytesTotal":0,"outBytesTotal":0,"paused":false,"type":"direct-accept"}}
AudriusButkevicius commented 8 years ago

Net is not what you want, connections is what you want. This just shows that it's not connected. You should look at syncthing log, not the app log.

Tiemichael commented 8 years ago

I switched on Discovery and Connections, and this is what I see: It seems to me that the device is discovered, 138.75.223.110 is my cuurent external IP, but still does not connect ...

13:35:51.324495 global.go:264: DEBUG: announce Reannounce-After: 1800 <nil>
13:35:51.620563 cache.go:107: DEBUG: lookup for PJU2XXX-EUNTE6Z-IBLULNJ-YEKAVLV-FQ7PPHU-ND4T5AI-JT3IB6M-XCWFGGGG at global@https://discovery-v4-1.syncthing.net/
13:35:51.620692 cache.go:108: DEBUG:   direct: [tcp://138.75.223.110:22001 tcp://138.75.223.110:8594]
13:35:51.620807 cache.go:109: DEBUG:   relays: [{relay://128.199.108.10:22067/?id=QIDAEXG-SEVXHQ3-IHWGLJQ-GKH47RL-SSXDQT7-UBUTD5N-RKAXMFZ-MW5NVQM&pingInterval=1m0s&networkTimeout=2m0s&sessionLimitBps=0&globalLimitBps=0&statusAddr=:22070&providedBy=nutomic 7}]
13:35:51.826480 global.go:237: DEBUG: announce POST: 204 No Content
13:35:51.826650 global.go:264: DEBUG: announce Reannounce-After: 1800 <nil>

13:35:53.052451 cache.go:107: DEBUG: lookup for PJU2XXX-EUNTE6Z-IBLULNJ-YEKAVLV-FQ7PPHU-ND4T5AI-JT3IB6M-XCWFGGG at global@https://discovery-v4-2.syncthing.net/
13:35:53.052558 cache.go:108: DEBUG:   direct: [tcp://138.75.223.110:8594 tcp://138.75.223.110:22001]
13:35:53.052625 cache.go:109: DEBUG:   relays: [{relay://128.199.108.10:22067/?id=QIDAEXG-SEVXHQ3-IHWGLJQ-GKH47RL-SSXDQT7-UBUTD5N-RKAXMFZ-MW5NVQM&pingInterval=1m0s&networkTimeout=2m0s&sessionLimitBps=0&globalLimitBps=0&statusAddr=:22070&providedBy=nutomic 7}]
13:35:54.105348 cache.go:107: DEBUG: lookup for PJU2XXX-EUNTE6Z-IBLULNJ-YEKAVLV-FQ7PPHU-ND4T5AI-JT3IB6M-XCWFGGG at global@https://discovery-v4-3.syncthing.net/
13:35:54.105502 cache.go:108: DEBUG:   direct: [tcp://138.75.223.110:22001 tcp://138.75.223.110:8594]
13:35:54.105587 cache.go:109: DEBUG:   relays: [{relay://128.199.108.10:22067/?id=QIDAEXG-SEVXHQ3-IHWGLJQ-GKH47RL-SSXDQT7-UBUTD5N-RKAXMFZ-MW5NVQM&pingInterval=1m0s&networkTimeout=2m0s&sessionLimitBps=0&globalLimitBps=0&statusAddr=:22070&providedBy=nutomic 7}]
13:35:54.128803 global.go:145: DEBUG: globalClient.Lookup https://discovery-v6-1.syncthing.net/?device=XXX25QQ-EUNTE6Z-IBLULNJ-YEKAVLV-FQ7PPHU-ND4T5AI-JT3IB6M-XCWFGGG Get https://discovery-v6-1.syncthing.net/?device=PJU2XXX-EUNTE6Z-IBLULNJ-YEKAVLV-FQ7PPHU-ND4T5AI-JT3IB6M-XCWFGGG: dial tcp [2001:470:28:4d6::5]:443: connect: network is unreachable
13:35:54.158826 global.go:145: DEBUG: globalClient.Lookup https://discovery-v6-2.syncthing.net/?device=XXX25QQ-EUNTE6Z-IBLULNJ-YEKAVLV-FQ7PPHU-ND4T5AI-JT3IB6M-XCWFGGG Get https://discovery-v6-2.syncthing.net/?device=PJU2XXX-EUNTE6Z-IBLULNJ-YEKAVLV-FQ7PPHU-ND4T5AI-JT3IB6M-XCWFGGG: dial tcp [2604:a880:800:10::182:a001]:443: connect: network is unreachable
13:35:54.189690 global.go:145: DEBUG: globalClient.Lookup https://discovery-v6-3.syncthing.net/?device=PJU25QQ-EUNTE6Z-IBLULNJ-YEKAVLV-FQ7PPHU-ND4T5AI-JT3IB6M-XCWFGAM Get https://discovery-v6-3.syncthing.net/?device=PJU2XXX-EUNTE6Z-IBLULNJ-YEKAVLV-FQ7PPHU-ND4T5AI-JT3IB6M-XCWFGAM: dial tcp [2400:6180:0:d0::d9:d001]:443: connect: network is unreachable
13:35:54.190928 cache.go:107: DEBUG: lookup for PJU2XXX-EUNTE6Z-IBLULNJ-YEKAVLV-FQ7PPHU-ND4T5AI-JT3IB6M-XCWFGAM at IPv4 local
13:35:54.191041 cache.go:108: DEBUG:   direct: []
13:35:54.191086 cache.go:109: DEBUG:   relays: []
13:35:54.192243 cache.go:107: DEBUG: lookup for PJU2XXX-EUNTE6Z-IBLULNJ-YEKAVLV-FQ7PPHU-ND4T5AI-JT3IB6M-XCWFGAM at IPv6 local
13:35:54.192364 cache.go:108: DEBUG:   direct: []
13:35:54.192409 cache.go:109: DEBUG:   relays: []
13:35:54.193654 cache.go:136: DEBUG: lookup results for PJU2XXX-EUNTE6Z-IBLULNJ-YEKAVLV-FQ7PPHU-ND4T5AI-JT3IB6M-XCWFGAM
13:35:54.193803 cache.go:137: DEBUG:   direct:  [tcp://138.75.223.110:22001 tcp://138.75.223.110:8594]
13:35:54.193885 cache.go:138: DEBUG:   relays:  [{relay://128.199.108.10:22067/?id=QIDAEXG-SEVXHQ3-IHWGLJQ-GKH47RL-SSXDQT7-UBUTD5N-RKAXMFZ-MW5NVQM&pingInterval=1m0s&networkTimeout=2m0s&sessionLimitBps=0&globalLimitBps=0&statusAddr=:22070&providedBy=nutomic 7}]
AudriusButkevicius commented 8 years ago

Which implies that forwarding does not work. Plus the other port is suspiciously low for a upnp mapped one.

Tiemichael commented 8 years ago

I don't understand .... tcp://138.75.223.110:22001 - is the current IP and port of my PC open for Syncthing

I took out the port from the Address-section, but does it does not change anything. It still finds tcp://138.75.223.110:22001, and the upnp-assigned ip:port has changed to tcp://138.75.223.110:50287

AudriusButkevicius commented 8 years ago

It clearly isn't being forwarded if its discovered and it still can't connect. Not sure what your intention was in removing it, because it tries all addresses anyway. I suggest you actually verify the mapping works as you expect before blaming syncthing.

Tiemichael commented 8 years ago

I removed it, just to see what happens. It's not my intention to blame Syncthing, it's simple that I don't know why it's not working ... Anyway, thank's for your help!

AudriusButkevicius commented 8 years ago

It's not working because the port forwarding is not working.

Tiemichael commented 8 years ago

Sorry to bother you again, but I am getting more and more confused and need your help to proceed ...

When ENabling my PC firewall and doing a port-check for 22001 via http://www.canyouseeme.org, my PC responds that a remote Computer (canyousee.org) at port 22001 wants to communicate with the application Syncthing. ss1

For my Raspberry: with Syncthing stopped, a port-check for 22000 via http://www.canyouseeme.org, shows port closed, with Syncthing running, a port-check for 22000 via http://www.canyouseeme.org, shows port open.

AudriusButkevicius commented 8 years ago

This tool does the same thing as your port openness scanner. It checks if the portis open, and not if it's forwarded properly. Also, given you have a local firewall that could also be the one to blame.

Tiemichael commented 8 years ago

Ok, Thanks! Could you recommend any tool to test for proper port-forwarding? Are there any specific port-forwarding requirements for Syncthing?

AudriusButkevicius commented 8 years ago

If you have shell access on both sides, use something like netcat to check, or run a webserver on port 22000 temprarily and check if you can access it. The requirements are explained in the docs site.

Tiemichael commented 8 years ago

Thank you! Using 'netcat' on my PC, and 'Simple Netcat' on my phone, I can transfer text from my phone (connected via 3G/4G) to my PC = myprivateip.com:22001.

AudriusButkevicius commented 8 years ago

And are you sure that syncthing on that machine is running on port 22001?

Tiemichael commented 8 years ago

Yes, I am quite sure - 'Sync Protocol Listen Addresses' is set to 'tcp://0.0.0.0:22001'. Also the screenshot (post #16) shows port 22001. During the test mentioned above, Syncthing was not running.

But I might completely misunderstand something ...

AudriusButkevicius commented 8 years ago

I think you need to get on IRC at some point to help you debug your issue, as something is definately misconfigured somewhere.

Tiemichael commented 8 years ago

could it be some kind of 'timeout issue'?

AudriusButkevicius commented 8 years ago

Not sure, yet from what you explain it seems it doesn't connect in general so it's not a timeout. Have your verified the web ui on both sides that it's not connecting?

Tiemichael commented 8 years ago

Thank you for your support! Connection status is the same from both sides of the GUI. Once in a while there is a connection via Relays, once in a while a direct connection.

Also this in the log of my phone seems to confirm the above:

cache.go:136: DEBUG: lookup results for GXXXXXX-6RRL3KY-2TT5QSN-Z6IYI5J-ZJZIRUS-52SM35G-T6ZADOM-TKLVGGG
cache.go:137: DEBUG:   direct:  [tcp://138.75.144.167:22000 tcp://138.75.144.167:50287 tcp://138.75.167.135:22000 tcp://138.75.167.135:50287 tcp://138.75.170.244:22000 tcp://138.75.170.244:50287 tcp://138.75.178.183:22000 tcp://138.75.178.183:50287]
cache.go:138: DEBUG:   relays:  [{relay://128.199.108.10:22067/?id=QIDAEXG-SEVXHQ3-IHWGLJQ-GKH47RL-SSXDQT7-UBUTD5N-RKAXMFZ-MW5NVQM&pingInterval=1m0s&networkTimeout=2m0s&sessionLimitBps=0&globalLimitBps=0&statusAddr=:22070&providedBy=nutomic 6}]
AudriusButkevicius commented 8 years ago

It seems that your external address is changin stupidly often (as you have 5 diffferent addresses), I discovery caching happens for 30mins so if it changes more often than that it's inevitably going to cause problems.

Tiemichael commented 8 years ago

My external IP is changing when I switch on/off or reboot my router, which happens typically once per day. Yes, while testing this issue over the last few days, I rebooted my router another few times. The IPs shown here, must be from the last 2-3 days

Testing just now, most of the time my devices connect via Relay, but just now I see a direct connection to my Raspberry using my current IP 138.75.170.244:22000.

Tiemichael commented 8 years ago

After upgrading all devices to V0.13, I get a direct connection within 1-2 minutes!