Request from ... for file ... in unshared folder "..."


(Jazzl0ver) #1

Hi. I’m getting the strange GUI notice every time a folder is updated on a source host:

2017-10-11 09:58:48: Request from st01.... for file sysstates/vm-dc2/WindowsImageBackup/vm-dc2/Backup 2017-10-10 213016/22a29103-870e-11e0-a053-806e6f6e7763.vhd in unshared folder "i4udq-q2yx2"

The same message appears in the console with WARNING prefix. The source host (the sender) is permitted to send only. The folder (“i4udq-q2yx2”) is shared between that two hosts.

Please, help me to find out what’s going on.

OS on both hosts - CentOS 7 Syncthing versions - v0.14.39, Linux (64 and 32 bits)


Request from … for file … in unshared folder “…”
(Audrius Butkevicius) #2

Can you post config.xml from both sides?


(Jazzl0ver) #3

filer-1: https://paste.ee/p/nuyAz st01 - see the next reply (I’m a new user - can’t post two links)

I obfuscated the sensitive parts with “skip” word and removed lines for other folders and devices.


(Jazzl0ver) #4

st01: https://paste.ee/p/VPj5C


(Audrius Butkevicius) #5

Is this easily reproduced or a one off?


(Jazzl0ver) #6

I’m getting this notice every day ('cos I’m backing up Windows every day). I clear it up (by clicking OK button) and get the notice again on the next day:


(Audrius Butkevicius) #7

I mean if you restart syncthing, does that still happen? Is there more than one source of these files, as I suspect if there wasn’t the other device would fail to sync?


(Jazzl0ver) #8

I’ve just restarted both syncthing daemons. Will let you know tomorrow. Thank you!

No, there’s only one source of that files.


(Jazzl0ver) #9

It appears the issue has gone after restart. Thanks a lot!


(Audrius Butkevicius) #10

I suspect it’s some sort of race condition, but it’s not clear how it happens, and I’d expect sync not to work once you hit this as the message comes from the same location that checks permissions.


(Jazzl0ver) #11

Hi Audrius,

Just got that again on Oct 15:

 2017-10-15 09:59:42: Request from st01.skip for file sysstates/vm-dc1/WindowsImageBackup/vm-dc1/Backup 2017-10-14 223007/33a29103-870e-11e0-a053-806e6f6e6963.vhd in unshared folder "i4udq-q2yx2"

Any ideas how to get that fixed?


(Audrius Butkevicius) #12

I mean, you are the only one experiencing this, so there is definately something wrong with your config.

The code is here:

There is no way the file is getting synced, perhaps the folder/device is paused or something like that?


(Jazzl0ver) #13

I have one idea. 1st of all, the sub-folder “Backup 2017-10-14 223007” do not exist anymore on both hosts (source and destination). What does exist - the folder “Backup 2017-10-15 223008”: Source:

[root@filer-1 vm-dc1]# pwd
/zmir/backup/sysstates/vm-dc1/WindowsImageBackup/vm-dc1
[root@filer-1 vm-dc1]# find . -type f -ls | grep 33a29103-870e-11e0-a053-806e6f6e6963.vhd
4730735 15975399 -rwxrwxr-x   1 administrator domain users 29239443456 Oct 15 22:57 ./Backup\ 2017-10-15\ 223008/33a29103-870e-11e0-a053-806e6f6e6963.vhd

Destination:

[root@st01 vm-dc1]# pwd
/backup/filer-1/sysstates/vm-dc1/WindowsImageBackup/vm-dc1
[root@st01 vm-dc1]# find . -type f -ls | grep 33a29103-870e-11e0-a053-806e6f6e6963.vhd
230546325 17074352 -rwxr-xr-x   1 bacula   disk     29239443456 Oct 16 16:24 ./Backup\ 2017-10-15\ 223008/.syncthing.33a29103-870e-11e0-a053-806e6f6e6963.vhd.tmp
[root@st01 vm-dc1]# date
Mon Oct 16 16:25:14 UTC 2017

So, the parent folder (“i4udq-q2yx2”) is definitely in sync.

That file in the output is pretty huge - ~28GB.

What if the new backup (on the source host) has been started and removed the folder “Backup 2017-10-14 223007” before the file sync has been completed? What error message should be in this case?


(Audrius Butkevicius) #14

If you are talking about on disk folders rather than syncthing folders then it should have been something about peers having this file going away (as there is nowhere to find this file), if you are talking about syncthing folders, and you are cycling them via some automated method, then this is understandable, as you remove syncthing folders for which requests might already be in flight


(Jazzl0ver) #15

Looks like I was unclear - I apologies. The source (filer-1) shares the folder /zmir/backup with st01 (/backup/filer-1). The sysstates and underneath subfolders are not shared separately.


(Audrius Butkevicius) #16

Do you have any kind of automation attached to syncthing?


(Jazzl0ver) #17

Not sure I understand what you mean by “automation”. The only couple things I have are

  • a daily cronjob which retrieves the Syncthing errors using curl and sends out an email alarm (GET from localhost:8384/rest/system/error).
  • nightly cronjob which stops and starts syncing (POST to localhost:8384/rest/system/config) to avoid synchronization while the nightly backups are running on the source host

(Audrius Butkevicius) #18

What do you mean by stops syncthing via config? How exactly are you stopping it?


(Jazzl0ver) #19
#-- pause syncthing during backups
0 1 * * * /usr/bin/curl -s -H X-API-Key:skip -X GET 'http://localhost:8384/rest/system/config' | /usr/bin/jq '.folders[].paused=true' | /usr/bin/curl -s -H X-API-Key:skip -X POST 'http://localhost:8384/rest/system/config' -d @- --header "Content-Type: application/json"

(Audrius Butkevicius) #20

I suspect this is the cause of it, as this pauses the folder, at which point it becomes unshared with the device, but there are still requests for it in flight if the data recently changed. Better option would be to kill syncthing at that point.