Android frozen syncs

I outlined the actual issue under

The main issue is that the mobile clients starts syncing then they stop syncing even though it says “syncing %80” for almost 2 days (and for that node it says %30 for a while on the other node which is a desktop). The responsible nodes seems connected. So it is not a connection issue as far as I can tell

I want to provide specific details-logs on the mobiles. I hope the logs below are helpful

sys log http://www.pasteall.org/53552

mainlog http://www.pasteall.org/53553

event log http://www.pasteall.org/53554

It seems to me like the Android ST syncs about 100 files than stop syncing while pretending that it is syncing. I am using 0.4.8

Could you check if the web GUI on Android says anything unusual? The native GUI isn’t working perfectly atm.

@Nutomic

The web GUi shows the same, it pretends that it is syncing. So far it is tiny steps.

Have you checked the logs I pasted here? Do you see anything weird there?

Also could compression be the culprit here?

@calmh Another bug apparently :wink:

I have the same issue. Small repo(45MB) containing photos syncs fine. But the repository having 9.1 GB stops at around 9GB and syncs forever. I even see incoming traffic into Android. Let me know how I can send you more debug info.

Needs logs. “Syncs forever” sounds like something is failing when it writes files to disk.

Well hope this log helps

both of my devices sitting there doing nothing, same with the server(desktop node)

Here is what the main node (desktop says ) says about the shared repo which seems wrong to me

Global Repository 2061 items, ~3.27 GiB Local Repository 1965 items, ~2.75 GiB Out Of Sync 1509 items, ~2.78 GiB

one of the android node says, global 2056 local 2046

the other android global 1970 local 1970

I/ActivityManager( 1465): Start proc com.nutomic.syncthingandroid for broadcast com.nutomic.syncthingandroid/.syncthing.BatteryReceiver: pid=2031 uid=10295 gids={50295, 1028, 1015, 3003} D/ActivityThread( 2031): handleBindApplication:com.nutomic.syncthingandroid I/SyncthingService( 2031): Web GUI will be available at http://127.0.0.1:8080 W/PostTask( 2031): at com.nutomic.syncthingandroid.syncthing.PostTask.doInBackground(PostTask.java:44) W/PostTask( 2031): at com.nutomic.syncthingandroid.syncthing.PostTask.doInBackground(PostTask.java:17) W/PostTask( 2031): at android.os.AsyncTask$2.call(AsyncTask.java:288) W/PostTask( 2031): at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:231) D/BluetoothTethering( 1465): CMD_CHANNEL_HALF_CONNECTED: com.android.internal.util.AsyncChannel@43266558 I/SyncthingNativeCode( 2031): [2JOJA] 18:15:29 INFO: syncthing v0.9.7 (go1.3.1 linux-arm android) felix@T420 2014-08-23 08:52:12 UTC I/SyncthingNativeCode( 2031): [2JOJA] 18:15:29 INFO: My ID: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx I/SyncthingNativeCode( 2031): [2JOJA] 18:15:29 INFO: Starting web GUI on http://127.0.0.1:8080/ I/SyncthingService( 2031): Web GUI has come online at http://127.0.0.1:8080 I/RestApi ( 2031): Syncthing version is v0.9.7 I/SyncthingNativeCode( 2031): [2JOJA] 18:15:32 INFO: Performing initial repository scan I/SyncthingNativeCode( 2031): [2JOJA] 18:15:37 INFO: No UPnP gateway detected I/SyncthingNativeCode( 2031): [2JOJA] 18:15:37 INFO: Starting local discovery announcements I/SyncthingNativeCode( 2031): [2JOJA] 18:15:37 INFO: Starting global discovery announcements I/SyncthingNativeCode( 2031): [2JOJA] 18:15:37 OK: Ready to synchronize camera~1 (read only; no external updates accepted) I/SyncthingNativeCode( 2031): [2JOJA] 18:15:37 OK: Ready to synchronize xxxxx (read-write) I/SyncthingNativeCode( 2031): [2JOJA] 18:15:37 INFO: Node xxxxxxxxxxxxxxxxxxx is “localhost” at [dynamic] I/SyncthingNativeCode( 2031): [2JOJA] 18:15:37 INFO: Node xxxxxxxxxxxxxxxxxxx is “xxxxx” at [dynamic] I/ActivityManager( 1465): START u0 {cmp=com.nutomic.syncthingandroid/.activities.MainActivity bnds=[64,848][956,976]} from pid -1 W/ActivityManager( 1465): startActivity called from non-Activity context; forcing Intent.FLAG_ACTIVITY_NEW_TASK for: Intent { cmp=com.nutomic.syncthingandroid/.activities.MainActivity bnds=[64,848][956,976] } I/ActivityManager( 1465): Displayed com.nutomic.syncthingandroid/.activities.MainActivity: +483ms I/Timeline( 1465): Timeline: Activity_windows_visible id: ActivityRecord{42de05e8 u0 com.nutomic.syncthingandroid/.activities.MainActivity t2} time:285117 I/SyncthingNativeCode( 2031): [2JOJA] 18:15:41 INFO: Established secure connection to xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx at 192.168.4.101:48553-65.26.70.231:41304 I/SyncthingNativeCode( 2031): [2JOJA] 18:15:42 INFO: Node xxxxxxxxxxxxxxxxxxx client is "syncthing v0.9.7" I/SyncthingNativeCode( 2031): [2JOJA] 18:15:42 INFO: Node xxxxxxxxxxxxxxxxxxx hostname is "xxxxxxx" I/Timeline( 2031): Timeline: Activity_launch_request id:com.nutomic.syncthingandroid time:309909 I/ActivityManager( 1465): START u0 {cmp=com.nutomic.syncthingandroid/.activities.WebGuiActivity} from pid 2031 I/ActivityManager( 1465): Displayed com.nutomic.syncthingandroid/.activities.WebGuiActivity: +343ms I/Timeline( 1465): Timeline: Activity_windows_visible id: ActivityRecord{435fe140 u0 com.nutomic.syncthingandroid/.activities.WebGuiActivity t2} time:310602

I/SyncthingNativeCode( 2031): [2JOJA] 18:19:24 INFO: chtimes: error: “xxxxxxx” / “DELETE.tar”: chtimes /storage/emulated/0/XXXXXXXX/.syncthing.DELETE.tar: operation not permitted I/Timeline( 1465): Timeline: Activity_windows_visible id: ActivityRecord{435fe140 u0 com.nutomic.syncthingandroid/.activities.WebGuiActivity t2} time:564064 I/Timeline( 1465): Timeline: Activity_windows_visible id: ActivityRecord{435fe140 u0 com.nutomic.syncthingandroid/.activities.WebGuiActivity t2} time:694747

One other issue I see if I restart ST android is this line below.

I/SyncthingNativeCode( 2031): [2JOJA] 18:36:24 INFO: chtimes: error: “xxxxxx” / “NEX/DCIM/.thumbnails/1407904472310.jpg”: chtimes /storage/emulated/0/_MOBILE_SYNC/NEX/DCIM/.thumbnails/xxxxx.jpg: operation not permitted

I have alot of these. Not sure if such permission thing would cause actual errors.

Also ST And supposed to ignore permissions (how I set on all devices).

Soo, some clues here…

Is this configured as a “master repository”, possibly?

The phone doesn’t allow syncthing to change the modification timestamp of the file. Hence, next time it scans for changes, it’ll consider the file modified because the timestamp is newer than it should be. It’ll announce that change to it’s peers, which will sync the file back (with no changed blocks) or, in case you have them set as “master repo”, remain out of sync.

In general, something is crappy about that setup on the phone; if syncthing can’t set modification times, syncing won’t work properly.

@calmh

Yes the workstation is the middle man between those 2 android devices.

I am using Cyanogenmod11. It is not something I messed up. I myself created the master repo folder. I do not know why ST having hard time changing modif times. Please bear in mind that most sdcards on Android devices are fat32 compatible I think.

The system is able to change modif times. So I doubt that its a problem with the filesystem. Other programs read and write to the sdcard all the time as well and clearly they are able to modify time stamps. At least that is how it seems to be overall.

Here is the permissions for the sync folder drwxrwx— 14 root sdcard_r 4.0K Aug 26 13:19 _XXXXXX_SYNC

Yeah, I don’t know. Apparently there’s been some changes lately in how Android manages storage and it’s all piped through a userspace daemon; perhaps that screws something up when you’re not using the official API:s? I don’t think I can help here, not being an Android developer or having an Android device. :confused:

@calmh

it sounds like that is a good article for @Nutomic to read :frowning: It explains it fine though not touching the modif time changes.

Maybe it is failing because you are using a straight linux style time modification? I do not know how it is done with ST on android.

It might also help to ask this guy about these chtimes issues on Google+. I do not have such accounts.

Actually, this seems to be by design;

https://code.google.com/p/android/issues/detail?id=1699 https://code.google.com/p/android/issues/detail?id=1992

Making syncthing work correctly on these kinds of devices would require some compatibility code, perhaps we can record the modification time that we got when we wrote the file and remember that as the “unchanged” time.

Looks like this is also the cause for #69.

Can we do something like the “ignore permissions” setting? Or maybe as an environment variable or flag?

(#69) Looks like it, yeah. (ignore permissions) No, not that easily since the modification time is the primary indicator of whether the file has changed. Not impossible, obviously, but requires some hacking and testing.

Also it still tries to chmod on Android. Again I have thousands of these. I thought that the permissions were ignored on Android. Or some another operation is failing at the same time.

I/SyncthingNativeCode( 2031): [2JOJA] 20:20:58 INFO: mkdir: error: “xxxxx” / “data/xxxx/xxxx - xxx Words _ xxxx.db-journal”: chmod /storage/emulated/0/xxxxxx/data/xxxxxx: operation not permitted

They are ignored if the “Ignore permissions” checkbox is checked, among the repo settings.

@calmh

That is what I am saying, it is already checked and ignoring permissions is a permanent behavior with android version.

One thing is interesting that ST creates “dot” files and tries to chmod them and then it fails to chmod them. Is the dot files part of the process at all?

I delete them but they come back in a flash.

“data/xxxx/x.db-journal”: chmod /storage/emulated/0/xxxx/data/xx: operation not permitted

See in this line it says not permitted, actually the file is not there but there is a “dot” file version of it.

I/SyncthingNativeCode( 964): [2JOJA] 02:45:09 INFO: mkdir: error: “NameOfTheSync” / “data/xxx/xxxx.1-5.txt.db-journal”: chmod /storage/emulated/0/xxxx/data/xxxxx: operation not permitted

I do not even know why it is failing to create a folder since it seems to me that it is trying to deal with a file (xxx.1-5.txt.db-journal) rather than a folder .

Pretty convoluted situation