Recurring issue of "Syncing 95%, 0B" after file rename

Hello,

I’m hitting the same issue that several folks here seem to have had, but I have a reproducible case that I haven’t seen mentioned here (sorry if I’ve missed it).

In short, I’m syncing a directory of photographs between two computers over a somewhat flaky & slow ADSL line. Syncthing works great, however if I rename images (with exiftool, which I think does a rename() under the hood) while the sync is progressing, then syncthing seems to think the original & now deleted files still need syncing. Receiver shows up in Sender’s devices with the usual “Syncing, 95%, 0B” status, and on the receiver, the deleted files show up as needing sync but failed with “no such file”. None of these files are affected by any .stignore rule.

In any case, the syncing of actual files is performed flawlessly, rsyncing them shows no changes required.

To solve the issue, I can delete & re-add the folder on either end, or reset the DB on one of the two ends. Is this considered poor use of Syncthing, or is this a (admittedly cosmetic) bug? Any tips on how I can prevent this from happening?

Receiver “failed items”

Receiver’s “device” entry “out of sync items” on Sender (a.k.a kdmhome) (i.e. recv’s listing on bottom right of web ui on sender)

Are you making case-only renames?

Nope, the renames simply add an ISO8601 capture date to the start, e.g. 029AXXXX.CR2 -> 2020-02-02_029AXXXX.CR2

Can you hop into the logs, enable model debugging and paste output after it’s retried this? There should be entries relating to the files. Deleting a nonexistent file should be fine, but there may be some issue here around the rename, it wanting to reuse the file into the new but the old file is no longer there and that’s unexpected…

Did you click (or hover) the “no such file” msg in UI? That should provide connect on where the error happened. Also which version are you on?

@imsodin the “no such file” tooltip is “syncing: pull: no such file”

@calmh I’ve attached the log, but there’s a lot of:

[XXXX] 2020/02/03 20:39:23.083866 folder_sendrecv.go:1472: DEBUG: request: FOLDERID library/2020/2020-02-99_misc-around-home/029A9288.CR2 1703936 131072 returned error: no such file
[XXXX] 2020/02/03 20:39:23.189703 folder_sendrecv.go:1472: DEBUG: request: FOLDERID library/2020/2020-02-99_misc-around-home/029A9288.CR2 15990784 131072 returned error: no such file
[XXXX] 2020/02/03 20:39:23.298242 folder_sendrecv.go:1472: DEBUG: request: FOLDERID library/2020/2020-02-99_misc-around-home/029A9288.CR2 917504 131072 returned error: no such file

st.log (74.1 KB)

It’s trying to get data for those files, i.e. it believes the global/newest version isn’t deleted and the other device has that version. This could also be explained by missing sequence entries on the sending device: It then just never sent the deletion index and when the invalid request comes in and out rechecks the file everything looks fine, because the regular entry isn’t missing.

Can you either query the rest/db/need for one of those files on both sides, or share the db (index-v… dir in the config dir), or build the stindex tool from syncthings source and run stindex -mode idxchk. sorry for being a bit terse, typing on phone

@imsodin Nothing relevant to the folder in question shows up when running stindex -mode idxck on the reciever, and I can’t access the sender right now.

For “my theory”, that’s expected, as I suspect the problem on the sending side. However even if unrelated, any output of stindex is bad and relevant (except for maybe an informational line that all is good, don’t remember) - please share :slight_smile:

Minor point, but idxck will currently report missing need entry for ignored files announced by other devices. That’s expected. Other complaints are probably genuine and indicate things to look closer at…

1 Like

@imsodin OK, on the receiver the single error from idxck was: Missing need entry for needed file "ignoredpath/ignoredfile.jpg", folder "not-the-same-folder-id", which I assume is what @calmh was noting above. Nothing shows up on the sender when running stindex -mode idxck

Any other clues?

Interesting. Can you query https://docs.syncthing.net/rest/db-file-get.html for one file on both ends (or just the one end you have access to right now for starters).

Hmmm, I’m getting a 404 error when I try doing that. Could you post an example command? I gave: curl -X POST -H "X-API-Key: KEY" 'http://localhost:8384/rest/db/file?folder=FOLDERID&file=library%2Fdatabase.msg' (for file library/database.msg). Is that correct?

EDIT: remove extraneous backslashes

Just use single quotation marks, that’s simpler in my opinion: curl -X POST -H "X-API-Key: KEY" 'http://localhost:8384/rest/db/file?folder=FOLDERID&file=library/database.msg'

Hmm, still getting a 404 page not found. I must be missing something. FolderID is something like abcde-fhijk and the API key worked the other day for a database reset command

Ah I missed the POST and just copy-pastad it, that endpoint is a GET. And I assume you spotted the single quotation mark I missed at the end (corrected now).

Shouldn’t it be possible to return a 405 Method Not Allowed for cases like that? Seems like it would be a useful hint.

1 Like

The admittedly lazy answer is that’s just the default behaviour of go’s http library (see last paragraph of https://golang.org/pkg/net/http/#ServeMux.Handler). Maybe that’s not even just lazy and there’s a good reason the standard library does it. Anyway lets not further sidetrack this issue, please open a new thread if you consider this worth discussing.

Ah, whoops, works now. Here you go:

  "availability": null,
  "global": {
    "deleted": true,
    "ignored": false,
    "invalid": false,
    "localFlags": 0,
    "modified": "2020-01-30T02:40:30+11:00",
    "modifiedBy": "SENDERID",
    "mustRescan": false,
    "name": "library/2020/2020-02-99_misc-around-home/029A9286.CR2",
    "noPermissions": false,
    "numBlocks": 0,
    "permissions": "0",
    "sequence": 253598,
    "size": 0,
    "type": 0,
    "version": [
      "SENDERID:2"
    ]
  },
  "local": {
    "deleted": true,
    "ignored": false,
    "invalid": false,
    "localFlags": 0,
    "modified": "2020-01-30T02:40:30+11:00",
    "modifiedBy": "SENDERID",
    "mustRescan": false,
    "name": "library/2020/2020-02-99_misc-around-home/029A9286.CR2",
    "noPermissions": false,
    "numBlocks": 0,
    "permissions": "0",
    "sequence": 253598,
    "size": 0,
    "type": 0,
    "version": [
      "SENDERID:2"
    ]
  }
}

Gentle reminder about this thread: I’ve uploaded the database dumps for the offending files.