Syncthing-android: Sync on Wifi not working correctly #625 not fixed really

[gerroon]

625 fix still does not work for me in 0.7.16.

It works the first time but if I start it again (because it crashed) when the wifi off the next time it still brings that "do you want to change your preferences' window, which makes no sense whatsoever

This is an Android 4.2 device.

[wweich]

when the wifi off

If you set to only sync on Wifi and you are not connected to Wifi, then this is by design.

[gerroon]

@wweich

I actually do not think so. If this is by design then I as a user find it to be a weird design choice.

Here is why it is weird.

I enable Wifi

I open Syncthing

I enable wifi only

Let it run

I restart my device for some reason

I enable wifi (I have to because ST will refuse to run as we know, even though I just want to start it now so that it can kick in by itself whenever I have wifi on)

I start ST

Sometime later my battery is getting low so I disable WIfi and I do not need Wifi for now.

I open ST to see what is going on, like checking the web server, or maybe I need the ID or change some other ST settings etc

Guess what, ST refuses to let me look around because there is no WIFI

[AudriusButkevicius]

It's still by design. It kills the syncthing process which does expensive things even if not connected to anyone.

[gerroon]

@AudriusButkevicius

I do not mind if it is killing the process. What does this have to do with me not having wifi enabled at the time of clicking on the interface?

Can't it still open the interface instead of blocking?

[AudriusButkevicius]

No, because the interface is driven by the process that is killed.

[gerroon]

So I have to have Wifi enabled at all times if I want to open the interface properly?

How do I know things are working with ST when the wifi is off? The thing is that, how would I know if ST binary process is running or not when the wifi is off? ;) I cant test out the wifi only case because as we know I am not allowed to. Because if I enable Wifi, it will start running but then this does not tell me anything about what is going on with the wifi is off situation. This is a case of catch 22 almost.

The issue is this, I am using an Ereader and things like Wifi is abit expensive on these devices, that is why I am trying to find the best use case.

[AudriusButkevicius]

Things are not working when wifi is off, so there is nothing to check. The binary ia not runnig when Wifi is off, thats what the wrapper ensures.

I don't know/understand why you are not allowed to try wifi only case, all you need to do is connect to wifi.

[gerroon]

@AudriusButkevicius

Ok you are saying thatt nothing is working when the wifi is off with the wifi only option. So I tested this on my CM12

ST is set to wifi only. I disabled wifi. After waiting some minutes, I went ahead and copied and deleted some files to one of the repos. ST has been using around %35 combined (syncthingandroid and libsyncthing.so). So either the idea of wifi only is not working as it is supposed to be or something else is wrong there. Because you said that there is nothing there when the wifi is off if I understand it correctly.

The other issue is this.

When I have wifi only enabled on my CM12 I can access the interface (no message window is shown) when the "wifi" is "off". But that is not the case onb my Android 4.2.2 If I try to open the interface when the wifi is off it shows me the "do you want to change your preferences" window.

Which behavior above is right?

[AudriusButkevicius]

Did you check that you are running the same version on both devices?

[gerroon]

Yes both devices are using the 0.7.16

[AudriusButkevicius]

Right, in which case somebody from the Android devs needs to answer. My understanding was that when wifi only is enabled, and you are not connected to wifi, there is no access to UI and the process is killed. This is the behavor I am seeing on my device. Perhaps detecting Wifi off is broken on CM.

[gerroon]

@AudriusButkevicius

Ok so the case on CM12 (which lets me access the interface when the wifi is off) is a curious case. That is why I filed this bug in the first place because the behavior was not consistent across devices.

[capi]

@gerroon First, are you sure that you were using 0.7.16 when you were testing the "WiFi off" and it was still synced? Because 0.7.14 and 0.7.15 had a bug that caused WiFi changes to be missed (the #625 which you reference).

Second, you can more easily see if Syncthing is running if you set the notification priority from "low" to "normal", so that you see the icon. If you see the icon, it is running.

I am surprised that yet another issue here pops up, I've been using a self-compiled version myself "forever", always with "Always sync in background", "If connected to power", "WiFi only". Except for the cases of 0.7.14/15 I never had issues with this and I cannot reproduce them right now.

Can you provide more information here?

[gerroon]

@capi

Both devices are using the latest Fdroid version.

Having the ST icon is not an indication of if it is running properly unfortunately. ST binary sometimes crashes in the background while the UI pretends that it is running. And the only way to know is to check the interface and open the web server once in a while to see if it is really really running. I get these hidden crashes sometimes on some of my devices and I can only find that out when the web server page says the page is not available.

This hidden crash stuff has been reported here multiple times. The hidden crash issues are lesser with the most recent versions but that crash is not wiped out from ST fully. I get this issue more often on some of my devices. I own 5+ Android devices with various Android versions. It probably is something to do with memory or sleep. I tried the wake up setting but that did not seem to help with my Android 4.4.4 and Android 4.2.2

The problem with the hidden crash is that it is hard to debug for me because I do not know when it will crash, it might take hours or days. So I have to sit down and wait infront of the adb log to see if it is crashing

[capi]

Ok, not talking about the crashes (the native binary and it's behavior under Android is not my area of expertise), but the notification at least is an indication if the app thinks that the binary should run. Can you tell me if it's behavior is as expected (i.e. if the notification is there while WiFi is disconnected, or missing if it is connected)? That would help as well.

[gerroon]

@capi

Actually it is all confusing to me.

For instance I have wifi enabled and it is connected to a router on my CM12 now, when I try to run ST first time (which had wifi only previously), it is telling me that ST is disabled and if I want ot change my settings. Why on earth? I previously reported that this behaviour was totally the oppposite this monring. I restarted my device once since then. Now I look like I am reporting random shit here instead of reporting what I am seeing here, it makes no sense. I have no idea why it is telling me that Syncthing is disabled while the Wifi is truely on.

It was not asking for preferences stuff before I restarted my device.

I do not know man, I am getting consused and frustrated now with this background sync thing;(

[scienmind]

Is this issue supposed to be fixed in 0.7.18?

I occasionally experience problems with it on 3 different devices:

ST defined to run in the background, and on WiFi only.
However, most of the times (while connected to WiFi), opening ST's ui will report that it is "off", and offer to change settings.
If then I manually toggle device's WiFi off-on, and reopen ST's ui it'll operate correctly (sometimes it takes more than one WiFi toggling cycle)

All the devices are on Android 6, ST 0.7.18

[capi]

@scienmind that's interesting, because this indicates that somehow we miss some WiFi connection/disconnection events. I'll review this part of the software to see if something jumps to my eyes.

[scienmind]

It's still happening a lot, here are some logs, that (maybe) may help:

State: WiFi is connected for quite a while, though ST is not starting up.
ST's log is empty, Android's log (exported from the ST application) is as follows:

--------- beginning of main
06-07 11:47:18.791  9101  9101 D SyncthingService: Wifi not connected
06-07 11:50:44.965  9101 13724 D OpenGLRenderer: Use EGL_SWAP_BEHAVIOR_PRESERVED: true
06-07 11:50:44.970  9101  9101 D SyncthingService: Wifi not connected
06-07 11:50:44.988  9101  9101 W FragmentManager: moveToState: Fragment state for DeviceListFragment{7cdbbc0 #1 id=0x7f0d006d android:switcher:2131558509:1} not updated inline; expected state 3 found 2
06-07 11:50:45.020  9101 13724 I Adreno  : QUALCOMM build                   : 63c06b2, I8366cd0437
06-07 11:50:45.020  9101 13724 I Adreno  : Build Date                       : 12/06/15
06-07 11:50:45.020  9101 13724 I Adreno  : OpenGL ES Shader Compiler Version: XE031.05.13.02
06-07 11:50:45.020  9101 13724 I Adreno  : Local Branch                     : mybranch17112971
06-07 11:50:45.020  9101 13724 I Adreno  : Remote Branch                    : quic/LA.BF64.1.2.9_v2
06-07 11:50:45.020  9101 13724 I Adreno  : Remote Branch                    : NONE
06-07 11:50:45.020  9101 13724 I Adreno  : Reconstruct Branch               : NOTHING
06-07 11:50:45.025  9101 13724 I OpenGLRenderer: Initialized EGL, version 1.4
06-07 11:50:47.932  9101  9101 D SyncthingService: Wifi not connected
06-07 11:50:52.791  9101  9101 D SyncthingService: Wifi not connected
06-07 11:50:52.852  9101 13724 D OpenGLRenderer: endAllStagingAnimators on 0xeb557d00 (ListView) with handle 0xea0a1380

After exporting the log above, ST app crashed, and upon reentry it did recognized the wifi and started OK, here is android's log of it: https://gist.github.com/anonymous/169a7acc3d18259af4e7dd9dde15050e

[capi]

Hmm, interestingly enough there is this in your gist:

06-07 11:52:18.503 14186 14186 D SyncthingService: SSID "whitelisted_SSID" found in whitelist

This is rather strange because this means that it both believes that it is connected to WiFi and that the WiFi is whitelisted. Still there are some exceptions about listen-address I don't know anything about.

[scienmind]

I've seen it there...

But it makes sense: the first (short) log is the one when ST refuses to ru, after log no.1 export it crashed, and when I reopened it, it started OK, then I exported log no.2, (the long one, in gist).

So it makes sense for it to mention in log no.2 the whitelisted SSID. The issue is - why it doesn't do so the first time.

And of course there's also the crash...
Interestingly enough, if I open logs while off wifi (or on blacklisted one), the first log opening attempt crash for me most of the times (showing loading logs... for a while, then crash), and if i go to the logs after the crash, logs are promptly shown, accurately describing the ongoing wifi state.

Which rises the suspicion that there might be something stuck during the automatic ST's initialization, which works fine during subsequent "manual" start.

[scienmind]

Some more logs:
State - WiFi is ON and is connected to the white-listed network, however synthing's "android" log reports the following:

--------- beginning of main
06-13 12:52:45.645 26739   569 D OpenGLRenderer: Use EGL_SWAP_BEHAVIOR_PRESERVED: true
06-13 12:52:45.653 26739 26739 D SyncthingService: Wifi not connected
06-13 12:52:45.682 26739 26739 W FragmentManager: moveToState: Fragment state for DeviceListFragment{5ae8dd5 #1 id=0x7f0d006d android:switcher:2131558509:1} not updated inline; expected state 3 found 2
06-13 12:52:45.742 26739   569 I Adreno  : QUALCOMM build                   : 63c06b2, I8366cd0437
06-13 12:52:45.742 26739   569 I Adreno  : Build Date                       : 12/06/15
06-13 12:52:45.742 26739   569 I Adreno  : OpenGL ES Shader Compiler Version: XE031.05.13.02
06-13 12:52:45.742 26739   569 I Adreno  : Local Branch                     : mybranch17112971
06-13 12:52:45.742 26739   569 I Adreno  : Remote Branch                    : quic/LA.BF64.1.2.9_v2
06-13 12:52:45.742 26739   569 I Adreno  : Remote Branch                    : NONE
06-13 12:52:45.742 26739   569 I Adreno  : Reconstruct Branch               : NOTHING
06-13 12:52:45.787 26739   569 I OpenGLRenderer: Initialized EGL, version 1.4
06-13 12:52:48.068 26739   569 D OpenGLRenderer: endAllStagingAnimators on 0xea5b7d80 (RippleDrawable) with handle 0xef3cfeb0
06-13 12:52:48.132 26739 26739 D SyncthingService: Wifi not connected
06-13 12:53:00.703 26739   569 D OpenGLRenderer: endAllStagingAnimators on 0xef2a0100 (RippleDrawable) with handle 0xdf51c440
06-13 12:53:09.346 26739 26739 D SyncthingService: Wifi not connected
06-13 12:53:09.365 26739 26739 W FragmentManager: moveToState: Fragment state for DeviceListFragment{27c4f64 #1 id=0x7f0d006d android:switcher:2131558509:1} not updated inline; expected state 3 found 2
06-13 12:53:10.806 26739 26739 D SyncthingService: Wifi not connected
06-13 12:53:15.363 26739 26739 D SyncthingService: Wifi not connected
06-13 12:53:15.522 26739   569 D OpenGLRenderer: endAllStagingAnimators on 0xef1c5800 (ListView) with handle 0xdf51c4a0

ST android application 0.7.20
OS: Android 6 (stock nexus rom)

[scienmind]

Forgot to mention:

In the situation above, if I swipe ST away from the "recents", it'll automatically relaunch properly, detecting the WiFi and starting syncthing instance as it should.

[scienmind]

The log after "swipe away": https://gist.github.com/anonymous/f965313a52c7b603525a334e269e53f5

[capi]

Can you try turning the WiFi off/on again in case this happens. I'm just curious if we missed some state-change and if it would pick this up.

[scienmind]

OK, here you go:

1. After fresh boot, WiFi is connected to the white-listed network, ST doesn't recognize it, and stays off.
   Android's log: https://gist.github.com/anonymous/1db59bcbc862cc2edc3c46c50dbb7380
   ST's log: empty, only: --------- beginning of main
2. Then turn WiFi off, ST correctly stays off:
   Android's log: https://gist.github.com/anonymous/d03ae374c7d619b6a108de5791c7fb84
   ST's log: https://gist.github.com/anonymous/ab0d559529ae9f8d27b2c084b9738544
3. Then turn WiFi on again, now ST responds to the connection, and turn's on properly:
   Android's log: https://gist.github.com/anonymous/bf434ba83f83a3ca98d0104fd1c5755c
   ST's log: https://gist.github.com/anonymous/b468fb82dcf7dc80ff8fd16c7403dd79

[capi]

Hmm, looks like we are not picking up the initial state correctly. Thanks!

[scienmind]

Related: #543

[capi]

Hmm, today I had it the first time that Syncthing did not recognize that the power got plugged-in and did not start syncing. Only manually starting it via Launcher worked.

One noticable difference is that I recently updated to 6.0.1 (from 5.1.x), so it might be related to changes in Android 6. Unfortunately I was nowhere near a computer to collect adb logs.

[capi]

Hmm, today I had the situation again as well. Played around a lot with adb log and connecting / disconnecting to/from WiFi, connecting / disconnecting charger.

What I noticed is, that no logs from NetworkReceiver showed up, indicating that we didn't receive the relevant broadcasts. Any idea what might trigger this behavior in Android 6? Could this be a side-effect of entering doze mode? Manually starting the application restored expected behavior.

The crash-log section of adb had some old crashes of Syncthing, maybe Android unregisters the receivers?

And then I noticed something else in the logs:

07-06 20:52:26.562  1181  1363 I ActivityManager: [BgDetect]chkExcessCpu doKills: true uptime: 300309
07-06 20:52:26.960  1181  1363 I ActivityManager: [BgDetect]detect excessive cpu on forked process libsyncthing.so(pid : 2758) plan to stop it 371060 during 300309
07-06 20:52:26.960  1181  1363 I ActivityManager: [BgDetect]force stop com.nutomic.syncthingandroid.debug (uid 10132)
07-06 20:52:26.965  1181  1363 I ActivityManager: Force stopping com.nutomic.syncthingandroid.debug appid=10132 user=0: from pid 1181
07-06 20:52:26.966  1181  1363 I ActivityManager: Killing 1360:com.nutomic.syncthingandroid.debug/u0a132 (adj 15): stop com.nutomic.syncthingandroid.debug
07-06 20:52:26.968  1181  1363 W ActivityManager: Scheduling restart of crashed service com.nutomic.syncthingandroid.debug/com.nutomic.syncthingandroid.syncthing.SyncthingService in 1000ms
07-06 20:52:26.968  1181  1354 V ActivityManager: killProcessGroupAsync took 1 ms for PID 1360 on thread 14
07-06 20:52:26.971  1181  6410 I libprocessgroup: Killing pid 2758 in uid 10132 as part of process group 1360
07-06 20:52:26.973  1181  6410 I libprocessgroup: Killing pid 2758 in uid 10132 as part of process group 1360
07-06 20:52:26.974  1181  1363 I ActivityManager:   Force stopping service ServiceRecord{47304c8 u0 com.nutomic.syncthingandroid.debug/com.nutomic.syncthingandroid.syncthing.SyncthingService}

And after that Syncthing didn't run any more and wasn't autostarted any more on WiFi/charger changes.

[capi]

I seem to be able to trigger this quite easily if the app is in the background and does some syncing which will cause quite some CPU usage due to decryption and hashing.

[capi]

The entire AOSP 6.0 branch doesn't have the string BgDetect, so I am afraid this is something my phone's vendor added.

[thewhitetulip]

I faced issues when I had the "sync only on wifi" option ticked. Despite the fact that the phone was connected to wifi hotspot, I got the disabled message. I removed that condition(because I don't use a datapack anywas) and voila! No issues!

[wweich]

Despite the fact that the phone was connected to wifi hotspot

If your hotspot is marked as metered in the Android settings, this is by design.

[thewhitetulip]

My apologies, I have a wifi router. It was a mistake to say that it was a hotspot. I had the phone connected to my wifi.

It appears that now my phone works even if I put the "work only with wifi", so this is an issue only during the first sync

[thewhitetulip]

@wweich It is weird now. I was able to sync things yesterday, it ran flawlessly. I had enabled the run as wifi.

Today, I connected the phone to my wifi router and have the enable on wifi on, and it tells me that it is disabled. Plus I tried by disabling the "enable on wifi" feature too, it still doesn't work.

Have we found the root cause of this issue? And if this isn't an issue, can we please show some debug tips instead of the generic "syncthing is disabled" message?

Edit: Wow, this is the cause. I was running my phone on battery saver. It doesn't work on battery saver mode. Good to know!!

[Nutomic]

This is probably fixed in 0.10.0. If you still have this problem, please open a new issue with logs.