fsWatcher Permission Denied WebUI notification

[Catfriend1]

I'm getting an recurring error in the web gui using the file watcher on android:
2018-04-16 22:25:30: Failed to start filesystem watcher for folder "rw_lgg4_F36E-1114" (srh6g-wqh74): lstat /storage/F36E-1114/.android_secure: permission denied

My .stignore file contains this line so I guess its a bug the watcher goes in there.
(?i)/.android_secure

Syncthing Version: 14.47-rc2
Android: 7.1.2 on LG-H815 - not using root privileges.
Reference: syncthing/syncthing-android#1051

[imsodin]

I can't reproduce it on linux (uses the same backend). The only place where the notify library (source of error) is using lstat is when it cleans up the path it was told to watch. That means with your folder root of "storage/F36E-1114" it should never call lstat on "/storage/F36E-1114/.android_secure" in the first place. I am currently clueless. Maybe logs with fs and model facilities enabled would contain a clue.

[Catfriend1]

@imsodin: ok, roger that. I ll grab the logs.

[Catfriend1]

Enable logs fs and model within android app. Started fresh, imported config of my folders (no db taken over) and grabbed the log from Android/data/sync..../files/syncthing.log - 134 mb! Searched through and found those two lines repeating rapidly between normal, successful scan reports.

[imsodin]

If there is anything interesting in the logs, it should be in between two such fs watcher failure lines. However if you didn't spot anything, there probably isn't anything - I am not looking for anything specific.

I believe you can make your own android builds: I added debug statements to the notify library here: master...imsodin:debugAndroidWatch
At the least this can (dis)prove my suspected point of origin of the problem.

[Catfriend1]

@imsodin Cool, a branch for me. I'll build with this after work.

[Catfriend1]

@imsodin: I've tried building syncthing branch but failed with error

[imsodin]

@Catfriend1 Embarrassingly I pointed you to an apparently untested (and thus not building) branch. Now it should be fine: https://github.com/imsodin/syncthing/tree/debugAndroidWatch

[Catfriend1]

@imsodin Here is the log - I stripped out Lstat lines of personal files and folders far away from the fault point of the fswatcher. It is shorter and more readable now from the beginning of syncthing app start. After the error occured, I waited some secs and exited the app.

[imsodin]

@Catfriend1 There are crucial debug log lines missing, most likely because I didn't realize that fmt.Printf doesn't add a newline at the end (our logging equivalent does). In short, could you either rerun with the updated branch or add the missing newlines before [NOTIFYDEBUG] in the existing log before removing unrelated lines? Thanks!

[Catfriend1]

I added the newlines before filtering the log. Does that help you? Otherwise I would prefer making the full log available by sending it via email to you to keep it private.
Hmm I compared the logs, but could not find more info regarding the issue, maybe we just do mailing.

[AudriusButkevicius]

It seems your ignore pattern is rooted and your secure folder is a level below the root.

[Catfriend1]

@AudriusButkevicius Good point, but .android_secure is definitely some very special folder on the root of the synced SD card path. I did a ls command with root privilege on android terminal emulator and got this:
h815:/storage/F36E-1114 # ls -a -l
ls: ./.android_secure: Permission denied
total 512
.... root sdcard_rw .. ... ... .
.... root sdcard_rw .. ... ... ..
.... root sdcard_rw .. ... ... .stfolder
.... root sdcard_rw .. ... ... .stignore
.... root sdcard_rw .. ... ... .stversions
.... root sdcard_rw .. ... ... Android
.... root sdcard_rw .. ... ... DCIM
.... root sdcard_rw .. ... ... LOST.DIR
.... root sdcard_rw .. ... ... to_pc
(...)

Sidenote: Also @Nutomic had problems with that .android_secure folder in the past, for reference see syncthing/syncthing-android@fa3898f where FolderObserver got a null object. Doing some research, I've learned android keeps apps and root shell access out of this special folder and returns null objects in java. The question is, does it also return something strange in GO?

[imsodin]

The folder root is /storage/F36E-1114, so /storage/F36E-1114/.android_secure should match the rooted pattern just fine.

Unfortunately the log is again not complete, i.e. it is still missing a crucial line that would confirm that the problem is not where I suspect it is: [NOTIFYDEBUG] nonrecursiveTree.Watch (path=/storage/F36E-1114): isrec: true Or other lines confirming my theory of course, but the lack of [NOTIFYDEBUG] canonical: lstat err: ... suggests it's wrong.

Ideally you would pause all other folders and give me a full log between [HRYCQ] DEBUG: sendReceiveFolder/srh6g-wqh74@0x44201e2000 starting and [HRYCQ] WARNING: Failed to start filesystem watcher for folder "rw_lgg4_F36E-1114" (srh6g-wqh74): lstat /storage/F36E-1114/.android_secure: permission denied. Or just make the entire thing accessible via email (freisim93@gmail.com).

[Catfriend1]

@imsodin: Sent you an email with the full log.

[imsodin]

The problem is clear now: The backend doesn't just list the names in the directory before passing them on (where ignore patterns apply), but already calls lstat on all of them (well, ioutil.ReadDir does). As upstream doesn't want the ignoring anyway it's fixable - I need to change the public interface :P BS, it's not actually public.
PR: syncthing/notify#1

[Catfriend1]

@imsodin: I rebuilt the android app-debug including syncthing 3d02fcd commit and can confirm the problem from this issue got solved. No more web gui error alert.

[Catfriend1]

Hi, just wanted to ask if this fix is in the current 14.47 release - it is not mentioned in the bugfix section.

[calmh]

It is, but it’s not mentioned as it was introduced in the .47 rc.