Syncthing-android: Syncthing walking the same folder twice

[Catfriend1]

Since upgrading the app to 0.10.5 I encountered a serious showstopper that renders the app unusable. It occurs both using experimental root and not using the experimental root feature.

Reproduction:

• Clear app data and caches (if the app was not fresh installed)
• Setup folder "/storage/emulated/0" as syncthing folder read-write with default settings and scan interval 10 minutes (you can use another scan interval as well - I used this one)
• Setup the ignore list before the first scan to ignore special folder
  (?i)/.android_secure (?i)/Android/data/**/cache (?i)/Android/data/com.nutomic.syncthingandroid/files/* (?i)/Android/data/com.nutomic.syncthingandroid.debug/files/* (?i)/com.infosysta.mobile.jirapro (?i)/DCIM/.thumbnails (?i)/Domoticz (?i)/LOST.DIR (?i)/Sygic/Maps (?i)/Tasker/log/* (?i)/TWRP/Backups
• Syncthing walks the folder - displays "Scanning"....
• Scanning reaches 100% after some seconds (Note - I have only ~ 1.500 files with the above mentioned ignore patterns) and the scan finishes.
• Folder displays state as "current" (translated from german)
• I took a note of how many files are displayed for that folder in the syncthing web GUI = 1.500 files.
• After around 10 seconds, the "scanning" appears again (I did not add, change, delete files).
• The folder is rescanned "by syncthing itself" without any user interaction
• The scan finishes again very quickly after reaching "100%"
• Folder displays state as "current" (translated from german)
• I took a note of how many files are displayed for that folder in the syncthing web GUI = 3.000 files.
• The file count is twice as high as after the first scan.
• Now the folder stays "idle" until the rescan interval passed by.
• I took a full log with STTRACE=scanner (enabled before the test, attached)

Looking at the log "as being no expert", I suspect it is scanning the folder named "." within "/storage/emulated/0" which causes the double amount of files in the web gui report of the folder. At first glance, the first "real to hash" is called for e.g. "somefolder/somefile.txt" and later, during the "second scan" for "/somefolder/somefile.txt".

Version Information

App Version: 0.10.5
Syncthing Version: v0.14.45
Android Version: Android 7.1.2 @ lg-h815 (LineAgeOS 2017-11-07)

[DrSchnagels]

[y] 21:22:01 INFO: Established secure connection to xxxxxx at 192.168.10.167:59923-192.168.10.149:22000/tcp-client (TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305)
[y] 21:22:01 INFO: Device xxxxx client is "syncthing v0.14.45" named "handy" at 192.168.10.167:59923-192.168.10.149:22000/tcp-client
[y] 21:22:01 INFO: Connection to xxxx at 192.168.10.167:59923-192.168.10.149:22000/tcp-client closed: protocol error: index update: "/Android": filename is invalid

This error is new too. I know that i have "Android" in my root folder in an ignore file. Used to work flawlessly. My OP5 is not rooted.

[prurigro]

This is happening to me too and it's not limited to /Android- I first hit it with /Camera for the default phone camera sync, so I recreated that share and everything was fine until I made a change to a file in a sub-folder called taxes, and now I'm getting the same error for /taxes. Simply removing and adding the existing share again doesn't seem to resolve the issue.

The common factor between the two cases seems to be that they were both caused by changes made to files in sub-folders, the first was a change on the phone and the second was a change on a Linux box.

I tried downgrading to 4137 (using oandbackup followed by a database reset) and still hit the error. I don't believe I had the problem prior to upgrading my other computers to v0.14.45 last night.

[imsodin]

There may be an Android component to this (why is there a scan on the absolute path /Android in the first place?), but one problem is definitely (core) Syncthings: https://github.com/syncthing/syncthing/issues/4799

[Catfriend1]

@Nutomic
Imsodin pointed out in the linked issue the slash is causing the main trouble when posted to current syncthings rest api with a folder scan request. I saw the code in https://github.com/syncthing/syncthing-android/blob/master/app/src/main/java/com/nutomic/syncthingandroid/http/PostScanRequest.java invokes the rest API. Do you think we have a chance of a quick-win fixing the Problem temporarily by a workaround until syncthing 14.46 is available where we disable the rescan post? Otherwise I'd suggest an intermediate release on gplay containing syncthing 14.43 where I had no problems before appv 0.10.5.

[prurigro]

I don't know where @DrSchnagels' /Android folder is in relation to the share, but in my case /Camera and /taxes are both subfolders at the top-level of the share, so the absolute path is in relation to the share and not the filesystem.

[Catfriend1]

Found a workaround for users with root explorer:
After updating to appv 0.10.5 via gplay, make sure syncthing is NOT running. Copy libsyncthing.so (v0.14.43) to /data/app/com.nutomic.syncthingandroid/lib/arm64/libsyncthing.so
Start syncthing, optionally enable experimental root mode and your running fine. On my phone the file count of /storage/emulated/0 is correct and there are no unexpected protocol errors or disconnects with my other 14.45 nodes.

[prurigro]

Another workaround which worked for me was to make a backup of syncthing (I used oandbackup, but the built-in backup might work too?), delete syncthing, install 0.10.4 from f-droid, restore the backup, delete the offending share, delete the folder for the offending share, then accept the offer to re-create the share and let it re-sync.

I reset the database right after restoring the backup, but the issue was still present until I recreated and re-sync'd the share so I'm not sure if that was necessary. This workaround didn't require the experimental root mode.

[Catfriend1]

Yeah, after some testing going back to 0.10.4 with the same config.xml and index-db folder removal is better. If I restart my phone, libsyncthing.so is automatically replaced by the faulty 14.45 version.

[imsodin]

@Nutomic Luckily 0.10.15 isn't released on f-droid yet - can we somehow pull that release entirely there (there is some unrelated problem with the go version on f-droid's build servers again)? In general I think this problem is bad/widespread enough to pull the 0.10.15 release on google play too if that's somehow possible.

[prurigro]

@imsodin I don't believe Android normally let's you downgrade a package, but maybe a 0.10.15.1 could be released with a compiled version of the code from 0.10.4? I fully agree that the playstore should be reverted; the issue is show-stopping (and I assume others rely on syncthing as heavily as I do).

EDIT: There might need to be a hook added that resets the database the first time the point version is loaded assuming that was a required step. If that's the case, it might turn out to be easier to simply fix the issue than create a downgrade release.

[Catfriend1]

We should go towards a 10.6 with 14.46rc1 which cleans up the mess. A database reset would cause the scanner Not Tracking creates or deletes across nodes reliably because the recent changes were not propagated and not synced across connected nodes because of the disconnection issue.

[Catfriend1]

To be more clear: scanning makes sure, each nodes knows if a file is missing because it has to be downloading or if a file got deleted and should be deleted on the other side. For the correct decision downloading or delete the one file you need a memory - the database.

[Catfriend1]

Syncthing 14.46rc1 is out for "testing"... It fixes this issue.

[novoid]

Sorry to ask that question here but I could not find it in the FAQs, not on the Syncthing (non-android) pages, and so forth.

Is there a 14.46rc1 apk somewhere that I can download to test it and give feedback or do I have to set-up a build environment to make an apk myself?

Thanks!

[Catfriend1]

I think nutomic is the only one being able to build an apk in the official Update channel. But - if you have a build Server - you can build a debug apk with your own signing keys.

[novoid]

Okay. So without Android development skills and my own build infrastructure, I can not test Syncthing 14.46rc1 and give feedback on this issue. Correct?

[Catfriend1]

@novoid:
Here is a debug build of the st-android ver 0.10.5 code including the new st-14.46-rc1.
(Removed)
EDIT : as calmh and Nutomic mentioned, this debug build force-enables usage reporting. Just you know about it.

@Nutomic: I am currently testing the debug build and the disconnect problems as well as the folder scanned twice-problems are gone since 14.46rc1.

[Nutomic]

I won't release an Android version with Syncthing RC, as that force enables usage reporting. But I can downgrade Syncthing. Can you confirm that Syncthing v0.14.44 is working correctly?

[scienmind]

v0.14.44 was never released to android, and according to calmh, it should be broken on android as well.

Also, if you're going to release a downgrade, it should be able to automatically delete the index db as well to clean up the broken state

[Catfriend1]

@Nutomic: scienmind is right, a downgrade would only help those people that did not start the app since upgrading a previous app version (and database) to 0.10.5 (14.45). I consider most people did start the app and collected the trouble in the database. Just wiping the database is insecure in relation to data security - if those broken installations could not finish syncing to "current, idle" state information crucial to syncthing create/delete operation might be lost and thus leading into wrong create/delete decision. The usage reporting thing... yeah right, I agree we should not force that on all users. There is really no way to make it opt-in?

[Nutomic]

@Catfriend1 Usage reporting is handled by Syncthing itself, so we would have to patch that out somehow.

But the problem is caused by the leading slash in file scanner calls, right? So it should be enough to remove that.

[imsodin]

@Nutomic The last release unaffected by this was 0.14.43. As I said before, the first thing I would do is to pull the 0.10.5 release to stop getting more users affected by this.
It to create a branch with 0.14.45 and the fix for this cherry-picked - it just has the obvious risk that it wasn't tested as an RC much at that point (however as 0.14.45 is broken on Android, that's probably a risk to take).

EDIT:

But the problem is caused by the leading slash in file scanner calls, right? So it should be enough to remove that.

Yes originally. The braking change is that the database now contains files with a leading slash and when these are sent to an other device, the connection gets dropped due to a protocol error. So these need to be removed from the db for anything to work again.

[Nutomic]

@imsodin There seems to be no way to disable a release on Google Play, I can only make a new release. So it seems the only options is to wait a fixed upstream release.

@calmh Any chance to release v0.14.46 with this fix earlier than scheduled?

[calmh]

No, I don’t want to toy with the release schedule for this purpose. You could take 0.14.45 with the fix cherry picked for example, or take 0.14.46-rc.1 and just call it something else so that you don’t trigger the “-rc”-specific behavior:

go run build.go -version v0.14.46-as.1 build

(“as” for Android Special, for example)

[Nutomic]

Okay I will do that as soon as I have time.

[imsodin]

If possible/not too much additional work, I would go with 0.14.45 + cherry-pick - it's just a bit safer than including all the other changes in the RC. If it's any help, I created a branch with that here (there was a tiny thing to adjust when cherry-picking): https://github.com/imsodin/syncthing/tree/androidFix

[Nutomic]

Thanks @imsodin :)

@Catfriend1 Can you verify that this version fixes the issue?

[Catfriend1]

@Nutomic: Looks good! There is now 14.45+commit in it. I restored my 0.10.4 with config and db. (Where the broken entries should have been already in from the past) upgraded to 0.10.6 apk and file count was correct and syncing with my 0.14.45 linux amd64 server :).

[Nutomic]

Thanks, great! I've published the release.

[imsodin]

@Nutomic I assume the release is "manual" on GPlay, i.e. no new tag/release on F-Droid? I mean that's fine as 0.10.5 isn't released there, I am just worrying that the F-Droid folks eventually fix the build problem there of their own accord. If that's the case, I can request removing 0.10.15 in the F-Droid repo (and fix #1035 while being at it).

[aquatix]

Is the release not live yet on GPlay? Still don't see a new version there. Thanks for resolving this issue!

[Nutomic]

@aquatix It might take a few hours until it becomes available.

[calmh]

@Catfriend1 do you have an account on forum.s.n? If not, and if you'd like to lend a helping hand during the transition period, it would be helpful if you created one.

[Catfriend1]

@calmh: Ok, I created one. Let me know how I can help.

[novoid]

I could not test https://drive.google.com/open?id=1SpOh7NgKxhcGwu_6y7CE-tSpAP7wabAM since my device ended up with both apps installed and the new one (temporary) had no shares configured and I did not want to set up everything from scratch. So I uninstalled the temporary apk.

With the 14.45+1, the issue is gone on my side.

Thanks for the fix!

[Catfriend1]

@novoid Just for clarification as you already found the correct update - If you'd like to use a debug build it is considered as a fresh installation of a new app. Be sure to export your configuration before switching over and import it again to have your shares again. But you're better with the official 14.45+1 now :)

[novoid]

@Catfriend1 Thanks for confirmation and clarification.

If this was not obvious to you so far: it was my first issue I had with Syncthing.

Maybe there should be some kind of link-able FAQ entry for this that newbies like me can learn from ;-)
So you guys are able to post an URL to a debug build APK together with the URL and you are not confronted with answering those questions all over again. I have learned this now. However, other newbies will hopefully come the same alley.