Folder shows as "Up to Date" but global and local states do not match

As stated in the title, I have a problem with one folder, which shows as “Up to Date” despite its local state not matching the global state. I have only noticed it as some of the files, which I needed, had not been synced.

image

Rescanning the folder or restarting Syncthing does not help. The folder itself is shared between 4 devices total, but only 2 of them have been active in the last few weeks. The local state is reported correctly on the other device.

The configuration in question is Syncthing x64 1.3.3 under Windows 10 Enterprise 2016 LTSB. The other computer, where the state is correct, runs the same version of Syncthing under Windows 10 Enterprise 2019 LTSC.

I have found a similar thread (https://forum.syncthing.net/t/out-of-sync-items-and-mismatched-file-folder-counts), where there were also mismatches in the global and local states, but I am not sure whether these problems are related. In that thread, enabling model , db and protocol debug facilities on both sides was recommended, so I have done just that on my two devices.

I am not really good at debugging this kind of stuff though. What can I do more to find the cause of the issue?

I know that I can “fix” it by resetting the database, but I have not done that yet. I possibly had a similar problem with a completely different folder and devices a few weeks ago, but I just reset the database then, and thus have no logs. This time, if possible, I would like to know the culprit.

1 Like

I have triggered GET /rest/db/status for the folder, and also GET /rest/db/file for one of the missing files.

GET /rest/db/status of Folder on PC 1 (correct local state)
{
  "errors": 0,
  "globalBytes": 23830805496,
  "globalDeleted": 5881,
  "globalDirectories": 494,
  "globalFiles": 8868,
  "globalSymlinks": 0,
  "globalTotalItems": 15243,
  "ignorePatterns": false,
  "inSyncBytes": 23830805496,
  "inSyncFiles": 8868,
  "invalid": "",
  "localBytes": 23830805496,
  "localDeleted": 558,
  "localDirectories": 494,
  "localFiles": 8868,
  "localSymlinks": 0,
  "localTotalItems": 9920,
  "needBytes": 0,
  "needDeletes": 0,
  "needDirectories": 0,
  "needFiles": 0,
  "needSymlinks": 0,
  "needTotalItems": 0,
  "pullErrors": 0,
  "sequence": 36726,
  "state": "idle",
  "stateChanged": "2020-01-30T14:24:28.586386+09:00",
  "version": 36726
}
GET /rest/db/status of Folder on PC 2 (incorrect local state)
{
  "errors": 0,
  "globalBytes": 23830805496,
  "globalDeleted": 5881,
  "globalDirectories": 494,
  "globalFiles": 8868,
  "globalSymlinks": 0,
  "globalTotalItems": 15243,
  "ignorePatterns": false,
  "inSyncBytes": 23830805496,
  "inSyncFiles": 8868,
  "invalid": "",
  "localBytes": 23033722390,
  "localDeleted": 5705,
  "localDirectories": 494,
  "localFiles": 8847,
  "localSymlinks": 0,
  "localTotalItems": 15046,
  "needBytes": 0,
  "needDeletes": 0,
  "needDirectories": 0,
  "needFiles": 0,
  "needSymlinks": 0,
  "needTotalItems": 0,
  "pullErrors": 0,
  "sequence": 36727,
  "state": "idle",
  "stateChanged": "2020-01-30T06:25:30.1344987+01:00",
  "version": 36727
}
GET /rest/db/file of File on PC 1 (existing)
{
  "availability": [
    {
      "id": "TLFGVKC-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX",
      "fromTemporary": false
    }
  ],
  "global": {
    "deleted": false,
    "ignored": false,
    "invalid": false,
    "localFlags": 0,
    "modified": "2019-10-29T21:08:38.427952+09:00",
    "modifiedBy": "D4DZUGP",
    "mustRescan": false,
    "name": "missingfile",
    "noPermissions": true,
    "numBlocks": 4,
    "sequence": 12217,
    "size": 484864,
    "type": "FILE",
    "version": [
      "D4DZUGP:2"
    ]
  },
  "local": {
    "deleted": false,
    "ignored": false,
    "invalid": false,
    "localFlags": 0,
    "modified": "2019-10-29T21:08:38.427952+09:00",
    "modifiedBy": "D4DZUGP",
    "mustRescan": false,
    "name": "missingfile",
    "noPermissions": true,
    "numBlocks": 4,
    "sequence": 12217,
    "size": 484864,
    "type": "FILE",
    "version": [
      "D4DZUGP:2"
    ]
  }
}
GET /rest/db/file of File on PC 2 (missing)
{
  "availability": [
    {
      "id": "D4DZUGP-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX",
      "fromTemporary": false
    }
  ],
  "global": {
    "deleted": false,
    "ignored": false,
    "invalid": false,
    "localFlags": 0,
    "modified": "2019-10-29T13:08:38.427952+01:00",
    "modifiedBy": "D4DZUGP",
    "mustRescan": false,
    "name": "missingfile",
    "noPermissions": true,
    "numBlocks": 4,
    "sequence": 12217,
    "size": 484864,
    "type": "FILE",
    "version": [
      "D4DZUGP:2"
    ]
  },
  "local": {
    "deleted": true,
    "ignored": false,
    "invalid": false,
    "localFlags": 0,
    "modified": "2019-10-29T13:08:38.427952+01:00",
    "modifiedBy": "D4DZUGP",
    "mustRescan": false,
    "name": "missingfile",
    "noPermissions": false,
    "numBlocks": 0,
    "permissions": "0",
    "sequence": 20535,
    "size": 0,
    "type": "FILE",
    "version": [
      "D4DZUGP:2"
    ]
  }
}

Now, below are the differences between the folders and the file on the two computers. The differences in the modified times are due to different time zones, so I have omitted them.

Folder on PC 1 vs Folder on PC 2

***** Folder-PC1.XML
   13:    "localBytes": 23830805496,
   14:    "localDeleted": 558,
   16:    "localFiles": 8868,
   18:    "localTotalItems": 9920,
***** Folder-PC2.xml
   13:    "localBytes": 23033722390,
   14:    "localDeleted": 5705,
   16:    "localFiles": 8847,
   18:    "localTotalItems": 15046,
*****

File on PC 1 vs File on PC 2

***** File-PC1.xml
   26:    "local": {
   27:      "deleted": false,
   35:      "noPermissions": true,
   36:      "numBlocks": 4,
   37:      "sequence": 12217,
   38:      "size": 484864,
***** File-PC2.XML
   26:    "local": {
   27:      "deleted": true,
   35:      "noPermissions": false,
   36:      "numBlocks": 0,
   37:      "permissions": "0",
   38:      "sequence": 20535,
   39:      "size": 0,
*****

I am no expert, but obviously the file is reported as "deleted": true, and there is also "noPermissions": false and `“permissions”: “0”, which I am not sure what means exactly. The folder itself is set to “Ignore Permissions” on both computers.

Can anyone provide any more information or explanation about this problem? Is there any other data that I could provide?

I have also checked the logs after enabling model, db and protocol, but I am not seeing anything special there.

You should post the full API responses from both sides for one of those files

Do you mean the full responses from GET /rest/db/file? They are included at the very beginning of my previous post.

Yes

Weird stuff. Second rest extract (“GET /rest/db/file of File on PC 2 (missing)”) shows a file with local/global version same, yet metadata different (deleted vs not). That shouldn’t happen.

1 Like

It would be helpful to see the full index databases from the two devices… Privately, if you wish.

Do you mean the whole index-v0.14.0.db folders?

If yes, then I should be able to do it tomorrow. How can I contact you privately? I suppose that it is all right to remove all the other folders from Syncthing first, and leave only the problematic one?

Yes, and sure. Let me know in PM, it depends on how large the zip files or such become.

I have removed all the other folders, and also narrowed everything down to just 21 files, which are missing from the other computer. The files themselves are nothing special - mostly just some program installers.

PC1 (no problems)

PC2 (missing files)

image

I have packed the database and sent you the links via PM. I hope that there is something in there that would help explain this problem. Please let me know if you need any additional files or information.

I will refrain from resetting the database, so that the folder is kept in this state for now.

So the indexes show the same as the REST output, but doesn’t explain how we came to be in this situation unfortunately. It looks like D4DZUGP has sent updates and then forgot about them, reusing the same version again for the next update. This happened in parallel with files that were missing at one point becoming restored? The only non-buggy cause for this I can imagine is if D4DZUGP were a VM and you restored a backup of the entire VM at some point, causing it to travel back in time. (Time travel is not supported.)

I don’t think the database itself is trashed for whatever reason because it’s all internally consistent, it’s just … wrong. We’d have to have an odd bug where we read a file entry from the database and parts of it are correct (modtimes etc. which are copied over to the delete entry) and parts are wrong (the not updated version vector). All things can happen, but I don’t see how this would be the case.

1 Like

First of all, thank you for checking the databases.

Hmm, there is definitely no VM involved, as both D4DZUGP and TLFGVKC are physical desktop computers.

One thing, which has come to my mind just now, is that D4DZUGP was recently upgraded (reinstalled) from Windows 7 to Windows 10. Syncthing configuration itself was backed up and restored in the process. I am not sure whether the incomplete file updates took place in the same time frame though, as I only noticed them 2 days ago.

I have also noticed that Syncthing reports local system time instead of UTC, at least when using the REST API. Would starting it with incorrect time or time zone set in the OS possibly cause such issues?

I think the config restore (which likely included the database) is most definitely the culprit here. The database cannot usefully be “restored” because state about it is already recorded on connected peers.

Time zone thing is just for presentation, internally it’s all UTC seconds. And not really used to determine much other than what date to stamp a file with when it gets synced.

2 Likes

Well, I normally have Syncthing set up with all the synced folders using relative paths and stored on a separate partition, so that it would survive Windows reinstallations. This time, however, I was experimenting with RAID and thus had to move it elsewhere, and then move back.

I normally skip the whole database folder in my automatic nightly backups, but during that Windows reinstallation it was likely manually moved back and forth together with the Syncthing program files.

Thank you for all the help! I will now remove and re-add the folder on the other computer to rebuild the database, and report back in case there are still issues with it.

1 Like

I am sorry for writing again, but the problem has come back.

Screenshot from PC2:

image

Screenshot from PC1:

What happened was that 4 days ago I deleted and re-added the folder on the other computer, and set it to “Receive Only” to be sure that everything syncs correctly. After the initial scanning and synchronisation, both the global and local states were reported correctly on both computers.

After doing that, I forgot to change the folder state, so it was left as “Receive Only” for a few days. Today, on the same computer, several files and folders were modified and/or deleted. I then realised that the folder state was still “Receive Only”, so I changed it to “Send & Receive” in order to propagate the aforementioned changes. On purpose, I did not press the “Revert local changes” button, as I wanted the changes to propagate.

The screenshot shows the state right after the above operations. Both computers report the folder as “Up to Date”, but the changes made while the folder was in “Receive Only” state in the end did not propagate to the other computer.

I will try to reproduce this with a default Syncthing configuration and report back, either here, or as a bug report on GitHub.

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.