"Pull: No Such File" Error

Hello!

I’m seeing this error repeating on a system which seems to steadfastly refuse to complete sync:

2019-04-08 11:11:27 Puller (folder "3. Sync" (*****-*****), file "File/Path/Here"): pull: no such file

How does this happen? If there’s no such file, surely it would get flagged in a scan on the originating machine and would get flagged as being deleted?

More details can be provided as required…

Thanks!

Surely it should. I can’t offhand think of why this would happen, other than perhaps with receive only folders (where the file might have been deleted in reality but we’re prevented by policy to let anyone know that fact).

Hi Jakob:

Thanks for chiming in quickly.

Nope - this is a send/receive folder across all devices in the cluster.

I’ve just queried the API for one of the missing files - here’s what I get:

curl -k -X GET -H "X-API-Key: ******" 'http://192.168.1.3:7070/rest/db/file?folder=*****-***&file=File/Path/Here'
{
  "availability": [
    {
      "id": "SEPDJWL-*******-*******-*******-*******-*******-*******-*******",
      "fromTemporary": false
    }
  ],
  "global": {
    "deleted": false,
    "ignored": false,
    "invalid": false,
    "localFlags": 0,
    "modified": "2019-02-25T15:54:07Z",
    "modifiedBy": "SEPDJWL",
    "mustRescan": false,
    "name": "File/Path/Here",
    "noPermissions": true,
    "numBlocks": 42,
    "permissions": "0644",
    "sequence": 1895513,
    "size": 5439245,
    "type": 0,
    "version": [
      "SEPDJWL:1",
      "UD7AGR2:2"
    ]
  },
  "local": {
    "deleted": false,
    "ignored": false,
    "invalid": false,
    "localFlags": 0,
    "modified": "2019-02-22T12:51:20Z",
    "modifiedBy": "UD7AGR2",
    "mustRescan": false,
    "name": "File/Path/Here",
    "noPermissions": true,
    "numBlocks": 42,
    "permissions": "0644",
    "sequence": 1525080,
    "size": 5432705,
    "type": 0,
    "version": [
      "UD7AGR2:2"
    ]
  }
}

For the record, both SEPDJWL and UD7AGR2 are online and apparently connected…

Does the file actually exist on disk on SEPDJWL?

I’ve only checked one of the files explicitly so far, but yes it does exist on SEPDJWL…

And it also exists on the machine that is reporting the error (which is where the API call above came from). There’s also a Syncthing .tmp file still in place here too…

FWIW, I think this error has been around for some weeks (which makes sense, according to the Modified Time of the file) - but this folder has been rescanned many times since.

…But the two files (the version on SEPDJWL and the version on the machine showing the error) hash differently it seems…

That’s expected and why it is trying to pull the file.

On both sides? The relevant one is the “sender”/SEPDJWL.

Ah right. Make sense. (Sorry - still getting my head round the details of this amazing app!)

I can’t believe it hasn’t scanned on SEPDJWL - it’s a Mac workstation which is in use most days. But I’ll get confirmation once I’m able to check on the system.

Sorry for the delay. I’ve checked, and SEPDJWL is set to scan every hour - last scanned within the hour…

Querying the API on here produces the following:

curl -k -X GET -H "X-API-Key: ******" 'http://localhost:8384/rest/db/file?folder=*****-*****&file=File/Path/Here'
{
  "availability": null,
  "global": {
    "deleted": false,
    "ignored": false,
    "invalid": false,
    "localFlags": 0,
    "modified": "2019-02-25T15:54:07Z",
    "modifiedBy": "SEPDJWL",
    "mustRescan": false,
    "name": "File/Path/Here",
    "noPermissions": true,
    "numBlocks": 42,
    "permissions": "0644",
    "sequence": 1895513,
    "size": 5439245,
    "type": 0,
    "version": [
      "SEPDJWL:1",
      "UD7AGR2:2"
    ]
  },
  "local": {
    "deleted": false,
    "ignored": false,
    "invalid": false,
    "localFlags": 0,
    "modified": "2019-02-25T15:54:07Z",
    "modifiedBy": "SEPDJWL",
    "mustRescan": false,
    "name": "File/Path/Here",
    "noPermissions": true,
    "numBlocks": 42,
    "permissions": "0644",
    "sequence": 1895513,
    "size": 5439245,
    "type": 0,
    "version": [
      "SEPDJWL:1",
      "UD7AGR2:2"
    ]
  }
}

Is that "availability": null significant?..

That looks exactly like expected, including the availability null bit. I am at a loss as to what’s happening, however you did just post in the case sensitivity topic: Are the two devices windows and mac by chance, and if so, are there any case differences? I can’t remember this kind of symptom with case problems, but anything is possible there…

Hi Simon:

Thanks for stopping by!

The cluster is 2 x Synology NAS units and a whole bunch of Macs (which is where my case sensitivity issue comes in - case-only renames get done on the Macs, which pull in duplicate copies on the NASes).

Here, the originating file is on one of the Macs, and I’m seeing the pull failure on the NAS units; however, I’m also seeing the same pull failure on at least one other Mac in the cluster - presumably more than one, but I haven’t examined the others yet.

There are 39 files spread across 3 subfolders of this shared folder which are failing to sync. I’ve examined the file paths for one of these files across four different machines and they all match as expected. There are a large number of files inside the folders containing the failed files, which have all otherwise synced successfully.

But of the two Macs and two NASes looked at, three of these machines have the old version of the file present.

Hello!

Apologies for bumping, but if there aren’t any thoughts about where it would be useful to look and diagnose further, I’ll touch the out of sync files to prompt a rescan of them - hopefully that’ll recognise their validity, and allow the sync to complete.

Is that the best course of action, or is there anything else I can do to help diagnose the underlying cause?

Thanks!

Hi, if you are hitting limits on number of open files, it can cause files to be “unopenable”, which leads to all kinds of odd stuff happening. The last update or two of syncthing I have noticed “too many open files” errors in the logs for both linux and mac computers in my cluster, which causes all manner of weird behavior. Are you seeing any “too many open files” errors in either your syncthing logs or system logs?

Ok, so with the rest excerpt you posted above it looks like Syncthing picks up on the change and sends that info to everyone, but they fail to request the data. You have also manually verified the case of the names match. Please shout if any of this is wrong. Next step would be to find out what exactly fails, i.e. enable model debug logging on the machine that has the updated file. Then pause/unpause the folder in question on another device, which does not have the updated file. There should line(s) like model@... REQ(in): *err* - *deviceid*: *folderid* / *filename* o=... s=....

Thanks Simon. I think this is the output that you’re after from the source machine (not the same file as detailed on the API calls above, but one of the other non-syncing files):

2019-04-12 09:44:54 model@0xc000136420 REQ(in): *******-*******-*******-*******-*******-*******-*******-*******: "*****-*****" / "File/Path/Here" o=786432 s=49985 t=false
2019-04-12 09:44:54 model@0xc000136420 recheckFile: *******-*******-*******-*******-*******-*******-*******-*******: "*****-*****" / "File/Path/Here" i=15: block index too far
2019-04-12 09:44:54 model@0xc000136420 REQ(in) failed validating data (<nil>): *******-*******-*******-*******-*******-*******-*******-*******: "*****-*****" / "File/Path/Here" o=786432 s=49985

The same three lines seem to be repeated for each of the failing files.

Thanks, that’s indeed good information. Did you recently change the large block setting on any/all of the devices for the involved folders?

Hi Simon - no, I haven’t touched that setting on any of the devices.

And is said setting true or false (if the folder is new enough, it’s true by default)? I am not saying that’s the reason, it’s just one parameter that’s important for trying to find the reason, given the error message.

Variable Size Blocks is off on - to my knowledge - all devices connected to this folder. All the devices were set up months ago, before VSB was a GUI option - so I’d be very surprised if it were enabled anywhere.

1 Like