I have a problem with one device that does not sync correctly. This is how it looks after starting the desktop (in the remote device section, local state is up to date for all folders):
If I change a file on the server it syncs to the desktop, if I change a file on the desktop it does not sync and under remote devices the server shows this one file as out of sync.
The issue affects most folders but not all, some folders sync correctly from desktop to server (looks like the ones that cause the 2% completion).
Any known issue that could cause this? Any logs with debug options enabled needed? Without debug options I do not see anything suspicious.
After restarting syncthing on the desktop everything seems to work correctly after a while. I think it started with v1.11.1 (never used v1.11.0) and is still present after upgrading to v1.12.0-rc.2. While still on v1.11.1 I tried to do --reset-deltas but it did not help.
This sounds like issue #7034, which was present in v1.11.0-rc.1, however that issue is fixed since v1.11.0-rc.2.
I don’t really understand this: When you restart the problem goes away, but it sounds like it isn’t really gone. Does it reoccur when you do something later or just spontaneously?
model debug logs to see what the index senders are doing would be helpful. However we’ll probably first have to clarify the questions in the last paragraph and then define some steps to do with model debug on to trigger events that hopefully produce helpful output.
I never used v1.11.0-rcX, only the release, also I did not pause any folders.
It usually is in this broken state after starting the computer in the morning (not sure if always, but it happens often). Restarting syncthing afterwards “fixes” it and it will work until the next start of the desktop (server stays on the whole time).
I can enable model debug on both devices and provide the logs as soon as it happens again (probably tomorrow, maybe after some later reboot of the computer or restart of syncthing, I can try to provoke it).
Also tried to reproduce a file that does not sync (called “Leer”, added on desktop), in most folders it synced but in “musik-android” it did not.
If I understand the logs correctly “desktop” never sends an index update for the new file in “musik-android”.
The file that does not sync is an unhandled config racyness issue - the remote being out-of-sync might be the same issue. Lets check once this is fixed (looking into it).
Got the latest nightly which should include your fix, the file that does not sync seems to be gone, however the server still thinks the desktop is out of sync (with different amount of items after every reboot), also from what it looks like in the GUI, index exchange seems to happen after every reboot (some MB of transfer and the amount of out of sync quickly drops over time).
About the time difference: I think my system clock on the desktop is a bit broken, some time after boot they seem to match (sync with the internet I guess), the logs here should have matching system times.
That now looks like a known, but unfortunately so far elusive problem with indexes/sequences. Starting Syncthing once with -reset-deltas on desktop should fix the problem. If the problem reliably occurs again, more detailed logs would be nice. However given this is a big production environment, this would easily be GBs of logs (with model,db facilities) - so lets first establish what exactly happens before going there.
Just fyi, as I unfortunately wasn’t able to capture logs about this. I’ve encountered this problem too after upgrading devices A + B from v1.12.0-rc.2 to v1.12.0-rc.3 a few minutes ago.
dev A showed remote dev B as “up2date”.
dev B showed remote dev A as “syncing 0%” with thousands of files mentioned below that being out of sync.
Side notes:
Before I upgraded the RC, everything was fully in sync.
I did pull up the web UI’s log window and there weren’t any errors (but I did not enable DEBUG facilities, just with default log).
After waiting 10 minutes, the “syncing 0%” did not change on dev B.
After STRG+F5 and deleting browser caches, the “syncing 0%” did not change on dev B.
After restarting Syncthing on dev B, it showed remote dev A immediately and CORRECTLY as “up2date” again.
That’s why I guess I was also hit by the above described problem.
logs contain everything since reboot including the restart of syncthing without reboot
Without much idea about how this works, but this looks weird to me (clocks do not seem to match again, similar 38s difference as before ):
[BORKF] 2020/11/18 16:19:38.680610 indexsender.go:285: DEBUG: Device AC5PIYS folder uni is not delta index compatible
[AC5PI] 2020/11/18 16:18:59.274599 indexsender.go:274: DEBUG: Device BORKF6M folder uni is delta index compatible (mlv=360277)
Desktop thinks server is delta index compatible (for this folder) while server thinks desktop is not, after the restart they agree that both are delta index compatible? (now with matching clocks)
[BORKF] 2020/11/18 16:23:10.400195 indexsender.go:274: DEBUG: Device AC5PIYS folder uni is delta index compatible (mlv=525121)
[AC5PI] 2020/11/18 16:23:10.428138 indexsender.go:274: DEBUG: Device BORKF6M folder uni is delta index compatible (mlv=0)
@Alex is testing nightlies, which includes a bugfix that is not in v1.12.0-rc.x. If you see 0% remotes and new changes not being synced, that’s likely what we already debugged and fixed.
The latest build lead to out of sync after starting the desktop this morning, restart did not fix it (only reduced the amount of items that are out of sync), only --reset-deltas did it
For now I’m back with v1.10.0 which seems to work. There is still something a bit broken, sometimes desktop resends index to server I guess the “(mlv=0)” indicates that in the line:
[AC5PI] 2020/11/19 09:33:18.461620 model.go:1090: DEBUG: Device BORKF6M folder archiv is delta index compatible (mlv=0)
but it always seems to get to “up to date” after that.
Will try to see if I can reproduce the issue with a separate instance of syncthing on the same devices (and maybe a copy of the same data), constantly having broken sync is too annoying (and possibly risky) with all my data.
First all my Synology´s, now also all my Windows 10 computers back on v1.10.0 and it runs well and smoothly again.
Starting with v1.11.x all peers were green, but some of the devices were at a high percentage level (mostly 95%-99%) and got stuck. And that was random in every time different peer(s) and more or less directories in such peer(s).
I also try to use -reset-deltas (seems not work on Synology´s) but without change. I was only able to fix this by disconnecting the affected peer(s) and reconnecting them.
Only with v1.11.1, android (Syncthing-Fork / AArch64) up to now I have no problem.
I could also reproduce it on a test setup with two devices, desktop and server, (not reliable, but it just happened at least once). The devices share 6 folders with the same content as real folders I sync (except some large files I deleted to reduce the size a bit). Both devices use syncthing v1.12.0-rc.3.dev.13.g7f63afcb.
After start of desktop, server shows out of sync for desktop again. Restarting syncthing on the desktop fixes it. I could provide logs for this case if you want but I guess it is similar to the case with the real setup.
Any other infos needed? Logs with more debugging options enabled?
I did not forget/abandon this. The logs you provided already do contain a good bit of info and I might also have found the cause. I’ll let you know when I have a PR to test. Thanks a lot for your help and patience in debugging this problem!
The log I added is actually not always correct. It should be “has no index ID for us” instead of “is not index compatible”, as while that can actually mean it’s not compatible, it can also mean it just doesn’t have any index data (-reset-deltas).
good to know, not compatible would be weird in this case (but actually it should have the index at that time since the log was from the next start after -reset-deltas and not the one where it was reset)
Will run the build with the test setup as soon as it is available. There the issue does not seem to happen that often so it may need some time to be sure that it does not happen again.
That description in the PR sounds exactly like what is happening.
“This problem likely existed for a long time” I can confirm that v1.10.0 also seems to drop indexes on one side, however it looks like they are resent so it does not matter that much.
Running the build from the PR now on the test setup, before the upgrade I had the issue once again there, so it also seems to happen quite often. Will see if it happens again, if not I will try it on the real setup in a few days.
Maybe such processes are normally under circumstances, I don’t know how it works with the indexes. I couldn’t judge that. However, there must be a more substantial difference between v1.10.0 and the following. Quiet seems returned since I downgraded all devices.
):