Shares "Out Of Sync" 1 node / 3

Support
1

Hello, I’ve had a problem for a while with only one syncthing node, two shares are out of sync.

At first, the local state was good but not the global state… On 2 other nodes, everything was good (and are still good).

Following the consultation of the page Incorrect global state on ONE node (other nodes agreeing with its local state).

I started syncthing with the command “syncthing -reset-deltas”. Since the global status is good but the folders are still out of sync.

For information, Syncthing is in version 1.3.1, Windows 10 (64 bit) on the computer that is causing the problem.

Can you help me fix the problem?

Sincerely,

Nicolas BRIN

2

If they are out of sync they should have failed items.

Check the logs on both sides.

3

And post screenshots, just to make sure there’s no misunderstandings (e.g. about terminology).

4

Sorry for my late answer.

So here is a screenshot of the problematic node:

PC-Nico

And on the other 2 nodes that work well:

NAS-Nico

NAS-Secours

And the log :

Syncthing.log (31.1 KB)

5

Did you remove lines from the log? There’s nothing regarding pulling in between those two, while there should be. If you didn’t, please enable model debug logging (actions->logs).

[7574P] 09:58:28 INFO: Completed initial scan of sendreceive folder Sauvegarde NICOLAS
[...]
[7574P] 15:49:56 INFO: Folder Sauvegarde NICOLAS isn't making sync progress - retrying in 2h51m48.6810272s.

Some likely unrelated things:

There’s a problem with a dialer address - did you manually configure addresses for your remote devices?

[7574P] 18:41:53 INFO: Parsing dialer address quic://[fe80::d449:6e3c:67bc:d2bd%25R%C3%A9seau%20FamilleBRIN]:22000: parse quic://[fe80::d449:6e3c:67bc:d2bd%25R%C3%A9seau%20FamilleBRIN]:22000: invalid URL escape "%C3"

Then there’s no problem, but the quic nat detection is too chatty in my opinion (even if their far apart, that’s not relevant to the user in my opinion):

...
[7574P] 18:52:16 INFO: quic://0.0.0.0:22000 detected NAT type: Symmetric NAT
[7574P] 18:52:16 INFO: quic://0.0.0.0:22000 resolved external address quic://2.0.150.68:22000 (via stun.syncthing.net:3478)
[7574P] 18:57:26 INFO: quic://0.0.0.0:22000 detected NAT type: Symmetric NAT
[7574P] 18:57:26 INFO: quic://0.0.0.0:22000 resolved external address quic://2.0.150.68:22000 (via stun.syncthing.net:3478)
[7574P] 19:02:36 INFO: quic://0.0.0.0:22000 detected NAT type: Symmetric NAT
[7574P] 19:02:36 INFO: quic://0.0.0.0:22000 resolved external address quic://2.0.150.68:18577 (via stun.syncthing.net:3478)
[7574P] 19:07:46 INFO: quic://0.0.0.0:22000 detected NAT type: Symmetric NAT
[7574P] 19:07:46 INFO: quic://0.0.0.0:22000 resolved external address quic://2.0.150.68:18577 (via stun.syncthing.net:3478)
...
6

  • No, I didn’t delete any lines in the log.

  • Yes, almost all my devices are in fixed ip.

  • Here is the log taken in “Actions” | “Logs” (nothing is checked in the “Debugging Tools” tab):

Journaux.log (14.3 KB)

The only error I see is:

2019-11-24 16:58:32 Folder Sauvegarde NICOLAS isn’t making sync progress - retrying in 2h47m32.0635831s.

But that doesn’t help me…

7

As there are no other errors, I asked for enabling the model debug logging (or tools) - that should give us the missing information (which shouldn’t be missing, this is a bug).

The one with this address [fe80::d449:6e3c:67bc:d2bd%25R%C3%A9seau%20FamilleBRIN]:22000 or similar is considered invalid by our quic library. Probably something about escapes. I don’t know anything about that. Please post the original address that you entered so someone knowing about this stuff can determine whether there’s a genuine problem with it or our library is misbehaving.

8

For the next error, I think I found the problem. I had a character (é) in the name of the network connector that was causing problems:

Parsing dialer address quic://[fe80::d449:6e3c:67bc:d2bd%25R%C3%A9seau_FamilleBRIN]:22000: parse quic://[fe80::d449:6e3c:67bc:d2bd%25R%C3%A9seau_FamilleBRIN]:22000: invalid URL escape “%C3”

Otherwise, by activating a little more log, I found an error on 4 files. Syncthing can’t find a file ~syncthing~<name_of_a_real_file>.tmp. Example:

blockqueue.go:22: DEBUG: open: open \?\D:\Drivers\MSI KG790 (MS-7551)\Problème Carte Son Windows 10 - 1903~syncthing~realtek_hd_audio.zip.tmp: Le fichier spécifié est introuvable.

Even after restarting Syncthing, it looks for these temporary files that do not exist…

9

That path looks broken (~syncthing~ in the middle) and that may be related to the cause of your problem (likely). However the error by itself is not a reason for the behaviour that you described. Please just enable the model debug facility and post the full logs (or the part in between these lines:

INFO: Completed initial scan of sendreceive folder Sauvegarde NICOLAS
[...]
INFO: Folder Sauvegarde NICOLAS isn't making sync progress - retrying in 2h51m48.6810272s.
10

OK, but the problem is that by activating all the logs, I’m at ~500MB for 1 hour of log and the scan takes several hours to run… even after pausing the other shares.

An attachment is limited to how many MB on this forum?

11

Wow that’s a lot for just model debug logging. Can you share the first few MBs of it?

12

Okay, sorry, I activated all the logs. I just selected just “model”. I’ll send you the log when he’s finished his scan.

13

Here is the log of “Actions” | “Logs” with “model” activated:

model.log (33.8 KB)

The complete log file is 420MB.

Note that the file “00141.MTS” is one of the 4 files mentioned above.

14

The only thing out of order is

2019-11-26 14:59:14 fsync "Photos\\365°) Pâques chez Nous (Dimanche 21 Avril 2019)" failed: sync \\?\D:\Photos\365°) Pâques chez Nous (Dimanche 21 Avril 2019): Descripteur non valide

, but that doesn’t explain why it’s not emitting any error nor updating the database. Can you run grep -i 00141.mts on the full log and post the results.

15

Here is the log with the grep -i “00141.MTS” :

Grep_00141.MTS.log (10.3 MB)

Tomorrow, I will try to delete these 4 files, to resynchronize then to copy these files…

16

Unfortunately, there’s no new clue there either… Next thing I’d like to look at would be logs with both model and db logging enabled.

17

Sorry, I can’t get the logs back. It takes too much space and the processing is too long.

If I delete the directory \Config\index-v0.14.0.db, Syncthing will rebuild the database. Can this solve my problem?

18

Yes, but you can also just remove the one folder making problems and readd it. The effect is the same, just limited to that folder only (less resource usage).

20

I did not find the file/folder that is problematic. I deleted the 4 files that were problematic but the problem persists.

The root path of the share is an entire disk (1.5TB of data). Version 1.3.2 not having solved my problem (you never know, if miracles exist), I resigned myself to delete the folder "index-v0.14.0.db’. All we have to do now is wait… it will take a few hours/days to rebuild the base…

However, I often put the computer into hibernation. Is that what could corrupt the database?

21

I meant the Syncthing folder, as in the elements on the left of the web UI - anyway doesn’t matter anymore as you’ve rebuilt the entire db.

Shouldn’t, that would be a bug with hibernation.