I think I’ve managed to reproduce it. I have added another RPi (although arm64 this time) to the cluster and I have the same issue in other clients (in 1.6.1), although it now shows fine in the device that is out of sync (but this time 1.5.0 was the first client it had connected to). Can I somehow help you debug it?
This had shown up in logs when connecting on 1.6.1 client
[XMADT] 23:20:03 INFO: Established secure connection to DENLD7L at 192.168.1.114:22000-(ip redacted)/tcp-server/TLS1.3-TLS_AES_128_GCM_SHA256
[XMADT] 23:20:03 INFO: Device DENLD7L client is "syncthing v1.6.1" named "RPi_RU" at 192.168.1.114:22000-(ip redacted)/tcp-server/TLS1.3-TLS_AES_128_GCM_SHA256
[XMADT] 23:20:13 INFO: Failed to exchange Hello messages with DENLD7L at 192.168.1.114:22000-(ip redacted)/tcp-server/TLS1.3-TLS_AES_128_GCM_SHA256: EOF
[XMADT] 23:20:13 INFO: Failed to exchange Hello messages with DENLD7L at 192.168.1.114:22000-(ip redacted)/tcp-server/TLS1.3-TLS_AES_128_GCM_SHA256: EOF
Roughly saying, the error can occur when sharing en existing folder with a new device. “Can occur” because it isn’t consistent, it sometimes also works. So it’s either inherently racy or there’s something more about the scenario that needs to be in a certain way to reproduce (order of steps taken, connection status of remotes, …). Thus there’s two things that might help pin it down at the moment: Share as much info as possible about the steps taken and the setup while the problem occurred. Before you do something that might cause the problem again, you could enable db debug logging (env var STTRACE=db) - however beware, that will be very verbose (e.g. you probably don’t want those logs in your system log). I’ll try to reproduce myself.
It only happens to a specific folder, and it doen’t matter if the device is new, as RPi1b+ was actually the first device I’ve ever installed syncthing on. Also, can it be some sort of DB inconsistency? Firstly, syncthing ran out of disk space while syncing and couldn’t write it’s DB as I understood, but had somehow got in sync later. And to me, it happends consistently with one of the folder on all of the 1.6.1 and 1.7.0-rc1 clients, but is shown just fine on 1.5.0 and only if the device connects when it’s syncing, if I pause the folder, the progress is shown on other devices.
Hello. One of my RPis had restarted after a power loss and started syncthing again (I didn’t want it to, but I forgot do disable systemd service) and I have this problem again. (Syncing 100% 0B, but transferring data and, well, syncing)
The RPi1b was also restarted due to a power loss, but hadn’t finished its initial rescan. May that be a cause? How can I debug it until it goes away again? The folder was already added on both devices. It had just immediately started syncing after the app launched and shows that 100%, and I think the same exact thing had happened to RPi1b+, although other devices must have been in-sync and with their folders scanned. Also, RPi1b+ now shows which folders of RPi_RU are out of sync.
Also, I have optimizations from Excessive RAM usage during initial scan on RPi1b+, although the same exact thing had happened to it before I changed anything from the standard configuration.
Also is it normal that it is syncing while scanning other folders with the following:
and also pullers = 2 ?
I though it shound’t and should only work with current folder.
You have almost 2000 failed items, you should probably start by fixing those.
maxFolderConcurrency should make sure that either one scan or one sync operation is happening at the time. I don’t see any evidence in the screenshots that it doesn’t do that.
Power loss can also lead to database inconsistencies, so god knows what state things are at now. The fact that you’re running on calculator quality hardware doesn’t help either.
There was no sudden power loss, the Syncthing on RPi_RU was shut down properly beforehand. Also, it’s strange that there are failed items, as the other device should have all the files and I’d suppose this is because of some connectivity errors.
Also, you can see on second screenshot, that RPi1b+ is scanning “Documents” folder and sending files from “Desktop” to RPi_RU.
Edit: Nevermind, it just started showing progress, after connecting to other node. Could that 0B 100% have been result of those sync errors? And it was clearly transferring a lot of data (>700Mb, which seems a lot for just an index exchange)
Edit 2: Nope, it is still broken (look at local state and out of sync items, and it looks like those are the new ones it had gotten from properly working 1.5.0 node)
The limit only applies for scanning and downloading, there are no limits on sending.
It’s possible that RPi_RU is just going through the list of things it needs to do, given the failed item count is growing.
I guess wait for it to stabilise and see what state it gets to.
It’s possible that it’s all screwed up in the database, and it will never converge, which could be fixed by removing the folder and adding it back, but given the hardware at hand, that might take ages.
To me, that just looks like if the syncthing is restarted, finishes rescanning and doesn’t get to connect to other devices and then connects to 1.6.1 or newer with no changes, the progress bars gets messed up and doesn’t show local changes, although it later syncs up just fine. The exact same thing had happened to me on another node (RPi1b+) with different folder, and it had shown those 100% 0B up until it synced everything up (with no conflicts or inconsistencies) and then it had changed to Up to Date. I don’t think I would have the same exact database inconsistency on 2 different devices with different architectures which would produce the same exact problem.
It had now gotten to all of the items being out of sync, but it hadn’t shown local changes. I have restarted it, and it looks like the issue is gone, as it now shows the local changes, and the local changes are the same as the failed items.
Also, even if there are some Failed Items, shouldn’t it still properly show Out of Sync items? And RPi 3b+ isn’t really that slow imo and I’m not trying to sync that much data.
I have restarted the client several times in hopes I would have the issue again. And I have noticed, that out of sync items if shown first, and then I could see the sync errors. If it’s not shown from the beginning, it doesn’t seem to do any calculations and fix itself later and shows 100% 0B or whatever broken value until it finishes syncing.
Also I couldn’t reproduce it deliberately again, but, after several restarts, I now have Up to Date, but syncing problem again.
Again, failed items means you need to fix something.
Though the screenshots make no sense that remote device thinks the RPI is up to date, but the RPI itself thinks it’s not.
Maybe it’s easier to remove the folder on the PI, transfer the data out of bound, add the folder, let it fully rescan locally, then share it with the remote device.
I have no problems with syncing, as the last time it had happened, it had finished syncing with no issues or inconsistencies, but rather with the fact that it doesn’t show the progress while it’s doing so or that remote devices don’t show the progress.
I’d suppose that failed items mean, that RPi didn’t connect to other nodes before it had started syncing, and all those errors are “no connected device has the required version of this file”, as can be seen in one of the screenshots above and do not mean that there is a conflict or any sort of error.
I know that I can just restart the client if I want to see the progress. I don’t know if that’s the right attitude, but I just thought I can somehow be helpful and report the issue, which seems to be an obvious bug to me and maybe be helpful in finding the cause of it.
Again, I suspect it’s happening because the device is under-powered, and never gets to recalculating the metadata properly.
You can probably open chrome developer tool as it happens, and check for rest calls to /rest/db/status with that folder ID and check what numbers it’s returning.
It could also be reporting this because you have have progressUpdateIntervalS set to -1, which effectively only allows it to report full file downloads, so you have 1000 1 byte files, and 1 10GB file, your sync progress will just jump fro 0% to 100% with nothing in between.
I didn’t change progressUpdateIntervalS on RPi_RU and it does report the progress (per file). And I don’t want to be very persistent, but I don’t think that Raspberry Pi 3 (Quad-core 1.4Ghz armv8 CPU with 1Gb of RAM) is that underpowered for syncing a single 18gb folder, and even if it is, why would other clients report incorrect device state and still continue to sync? mikhail-pc has Ryzen 5 CPU and 16 Gb of RAM, so I don’t think that it’s too underpowered to sync an 18Gb folder. And even if it is the problem of the devices being under-powered, why does it randomly happen but then goes away after I restart Syncthing, and why does 1.5.0 client always report the correct state, even when 1.6.1 and 1.7.0 nodes don’t?
What value should I expect and where can I see it? It had finished syncing and now shows that everything is Up to Date, but I guess I will try to delete the data and re-sync one of the nodes again to see if I can catch it doing it again.
It is now happening again, between core i5 laptop and a desktop. (and I have also gotten inconsistency on Mikhail-PC while moving the folder on Probook and not touching anything on Mikhail-PC)
The 404 is because you need to specify the folder id (https://docs.syncthing.net/rest/db-status-get.html). Anyway that endpoint is only called when opening the web UI or changing config, otherwise status updates are event based. And in firefox’ network inspection tab I couldn’t find any indication of those. You’d need to put breakpoints in syncthingController.js (line 321) to detect those events. Or you could enable event debug logging in advanced->log to see if any folder summary events are dispatched at all.
