[0.11 SOLVED] "pull: no available source device" on Xubuntu, even though the file exists on an Android

I have seen that similar issues have already been discussed (1894 and 1797) but I couldn’t find a solution to what I’m facing right now.

I synchronize the folder where Android places photos with my Xubuntu laptop. I’ve noticed that whenever a take a photo on my cell phone (Android) and later edit it, thus producing a copy of the original file, the folder on Xubuntu where it should sync to gets stuck, and the daemon log is periodically flooded with messages like these:

[2L7Y5] 21:27:50 WARNING: Folder "camera" isn't making progress - check logs for possible root cause. Pausing puller for 1m0s.
[2L7Y5] 21:29:27 INFO: Puller (folder "camera", file "IMG_20150410_203745734~01.jpg"): pull: no available source device

However, that file does exist on the corresponding folder on the Android device:

but on Xubuntu, it remains partially transferred:

The only way I’ve found to resync the devices is deleting the offending file. But I can’t understand why syncing gets stuck if the file is fully available at the source. This is deterministic: it always happens when I take a photo and edit it.

EDIT: ST on Android is 0.5.28 and on Xubuntu it is 0.10.30 (with ST-GTK 0.6.4)

Does it go away if you manually rescan the folder through the web UI?

The fact that it says it’s not available means that the file which was advertised is not available, and might have changed before it was synced.

This is really weird, I followed these steps quickly, one after the other without interval:

  1. Took a photo (on the Android device)
  2. Cropped and saved it
  3. Looked into the DCIM folder and saw that there were 2 files there, the original photo, and the cropped photo
  4. Looked at syncthing on the laptop (Xubuntu), and the folder was out of sync again, exactly as I first showed, and rescanning it didn’t have any effect:
  5. Rescanned the folder on the Web GUI on the Android device, but it didn’t have any effect either:

Everything was too fast for the changed file to be advertised and then changed before it could be synced. What I don’t understand is that the filename logged on the daemon log is precisely the same as the filename found on the Android file manager, so if the file is there, why isn’t it pulled/synced ?

Did you rescan on the desktop or on the phone? It could be that the file gets copied as a full photo first, then advertised, then cropped, and when we come to get the full file, it’s now cropped and hashes don’t match.

Regardless, it seems you can reproduce it easily, hence someone needs to look into this.

I rescanned both on the desktop and on the phone.

Your hypothesis makes sense:

  1. Original file is copied with new name
  2. New file (still not cropped) is advertised
  3. New file is cropped
  4. Desktop tries to pull the advertised file, but even though the name is the same, it’s now smaller, cropped, so hashes don’t match

And yes, it’s reproducible, very easily. So I guess I should open an issue on syncthing-android, right ?

I guess it’s more syncthings fault (unless inotify is to blame), but hence I’d be interested in a reproducible case on two desktops. If you can reproduce it on a desktop, I am definately interested.

If it’s on android only, then I guess you should open in the android issue tracker.

I only have 1 desktop, and then again, the Android picture editor seems to create a timing issue which I don’t know how I could mimic on a desktop, so it looks like it will be the android issue tracker.

Regardless, please tell me, @AudriusButkevicius, if this would be a valid debugging strategy:

  1. Start a logcat on Android
  2. Start syncthing on the desktop with trace. Which facilities do you think would be useful to trace for this scenario ? I’m not sure which ones would best trap the issue.
  3. Reproduce the error scenario

EDIT: I sync 3 folders with my mother’s laptop (she lives in another neighborhood), I was thinking I might borrow it from her, bring it here, and try to reproduce the error scenario. It’s midnight here right now, she will certainly be fast asleep, but I’ll phone her in the morning and see if she can bring it here.

So I think STTRACE=model,scanner on both sides should answer most of the questions.

Thanks for the tip, @AudriusButkevicius !

This gets weirder and weirder: I tried to reproduce the error, step by step again, to prepare the issue for the tracker, and it didn’t happen. The only differences from my previous attempt were: I had deleted the shared folder from both devices and recreated it, and I changed the language back from English to Portuguese. I tried a 2nd time and the error didn’t happen. But on the 3rd attempt, it happened again.

So there’s a very subtle timing issue at stake, and the issue is not so deterministic as I initially judged. I’ll keep on trying to reach an exact timing sequence that reproduces the error deterministically, so that I can start tracing to dig useful information.

When I deleted/recreated the shared folder, of course all info about it was reset on the repositories, so it occurred to me: is there a way to reset the repository on a node ? I work with IBM MQSeries and it has a mechanism to refresh the repository on a node when it gets mangled somehow and can’t work properly with other nodes anymore. In a scenario such as this one I’ve been bumping into, it would be useful to be able to simply refresh all repository information on the desktop, for instance.

EDIT: Forgot to mention: when the error happened again on my 3rd attempt some moments ago, instead of deleting the offending file, I restarted syncthing on my cell phone, and this made the desktop’s syncing failure go away: the cropped file was synced even though the failed file remained in the folder:

EDIT 2: Tried a 4th time, the error happened, but restarting syncthing on the cell phone didn’t make it go away.

There is a commandline -reset which I think will work as you say in version 0.11, before that, you can just delete the index folder from the config dir.

Not sure that will help though, as the phone thinks it still has the file, when in reality it doesn’t.

So it’s a bit strange that the file name changes while you crop it, which could be the reason of why it’s happening. STTRACE=scanner on the phone and STTRACE=model on the desktop should reveal if the rename/move/deletion gets picked up correctly and propagated correctly, as I feel this will most likely be the culprit.

Hey, great to know, I bet this will be useful to have around.

Gonna try it.

synchting-android has Debug Options, I put STTRACE=scanner there and looked around the filesystem but no trace file was created.

As this error happens spontaneously, and is easily reproduced on Android, I’m gonna open an issue on the issue tracker there.

EDIT: Removing ~/.config/syncthing/index and restarting the daemon didn’t make the syncing error go away.

It depends on which side you we’re removing the index, as it’s not clear on which side it’s corrupt. You might have to do simultaneously on both machines.

You should just put scanner rather in the field, and the log gets printed to stdout, which means you need to have adb running and get the logs via logcat. You can google around to figure out how to do this, or read debugging instructions in the android repo.

I couldn’t get the logs on the phone, I reckoned because it’s not rooted. I’ll keep trying.

In the meantime, I opened issue 351 on the android issue tracker.

I’m really grateful for your help here, @AudriusButkevicius !

Just to let you know, I never solved this issue (even with debug builds from @calmh) and had to clear the index.

This issue seems to be solved in branch 0.11, I can’t reproduce it anymore.

Installed versions here:

syncthing: 0.11.0-rc1 syncthing-gtk: 0.692 syncthing-android: v0.11.0-beta6+5-gba4a6fc, Linux (ARM)