Can't sync since 0.14.17


(Ethan Thornburg) #1

v0.14.17 has broken my syncs. Everything was working prior to this version. I am now on 0.14.18 but it is also not working correctly.

I am syncing between 2 windows computers. I have tried deleting the folders on both sides, deleting the entire users/appdata/local/syncthing on both sides, and resharing everything but not luck.

It gets stuck syncing and leaves a tmp file that doesn’t finish…(so I know it’s not just a ui issue)

Client-side logs: https://hastebin.com/kuzasumeco.log

Client-side ui:

Client-side temporary file in windows explorer:

Server-side logs: https://hastebin.com/huhazezeto.log

Server-side ui:


(Jakob Borg) #2

So if you expand the folder on the left, is there an error of some kind displayed?


(Ethan Thornburg) #3

No, I don’t see any errors in the UI. It’s just not syncing anymore 0 b/s

Edit: Client side it’s munching on my CPU too, consistent 50%

The client-side log has the following, which might be why that file is stuck…but I don’t see why another process would be using this file.

[W42I3] 20:01:29 INFO: Puller: final: rename \\?\C:\OmniwarSync2\FPSGame\Content\Paks\~syncthing~FPSGame-WindowsNoEditor.pak.tmp \\?\C:\OmniwarSync2\FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak: The process cannot access the file because it is being used by another process.
[W42I3] 20:02:14 INFO: Puller (folder "rznc5-ue5k5", file "FPSGame\\Content\\Paks\\FPSGame-WindowsNoEditor.pak"): dst create: open \\?\C:\OmniwarSync2\FPSGame\Content\Paks\~syncthing~FPSGame-WindowsNoEditor.pak.tmp: The file exists.

(Jakob Borg) #4

Nevertheless that seems to be the case. Windows debugging 101 - disable antivirus?


(Ethan Thornburg) #5

I’m only using Windows Defender, so I would be pretty surprised if that was it. Especially since everything was syncing fine in previous versions of syncthing.


(Jakob Borg) #6

I hear you, but Syncthing here is just reporting the reason it gets back from the OS for why it can’t access the file.


(Ethan Thornburg) #7

Okay, I actually can’t disable antivirus on this computer, but I will try and figure out what process could be accessing the file.


(Ethan Thornburg) #8

According to Resouce Monitor, the only process that is accessing either FPSGame-WindowsNoEditor.pak or the tmp file is syncthing.exe


(Ethan Thornburg) #9

Here is my client side log when I enable STTRACE model

https://hastebin.com/jetatiyada.log


(Ethan Thornburg) #10

Even when I set STTRACE to all on both client and server side it looks like it might be trying to sync but it’s just going very very slow on this one file that is stuck…

Not sure what else to check :confused:

I keep getting a lot of this in the logs…

[W42I3] 2017/01/05 08:55:13.463014 protocol.go:665: DEBUG: wrote 117 bytes on the wire (2 bytes length, 2 bytes header, 4 bytes message length, 109 bytes message), err=<nil>
[W42I3] 2017/01/05 08:55:13.463515 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14882
[W42I3] 2017/01/05 08:55:13.464518 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14881
[W42I3] 2017/01/05 08:55:13.465520 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14880
[W42I3] 2017/01/05 08:55:13.466023 sharedpullerstate.go:261: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak pullNeeded start -> 2
[W42I3] 2017/01/05 08:55:13.466522 model.go:1658: DEBUG: model@0xc042062500 REQ(out): YPYQVJJ-FFJGI5N-RU7VRQW-DA2FFTX-ZBI7NIN-3OJM6UA-I5O2JCL-DD6UCQU: "rznc5-ue5k5" / "FPSGame\\Content\\Paks\\FPSGame-WindowsNoEditor.pak" o=1192493056 s=131072 h=64734862be8e07df8d9d9a5c08dad66d6a0475b483a4526f1b71e92d1f8bfe39 ft=false
[W42I3] 2017/01/05 08:55:13.466522 protocol.go:665: DEBUG: wrote 117 bytes on the wire (2 bytes length, 2 bytes header, 4 bytes message length, 109 bytes message), err=<nil>
[W42I3] 2017/01/05 08:55:13.466522 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14878
[W42I3] 2017/01/05 08:55:13.467024 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14877
[W42I3] 2017/01/05 08:55:13.467525 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14876
[W42I3] 2017/01/05 08:55:13.468026 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14875
[W42I3] 2017/01/05 08:55:13.468528 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14874
[W42I3] 2017/01/05 08:55:13.469029 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14873
[W42I3] 2017/01/05 08:55:13.470030 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14872
[W42I3] 2017/01/05 08:55:13.470532 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14871
[W42I3] 2017/01/05 08:55:13.673476 sync.go:152: DEBUG: RWMutex held for 202.9446ms. Locked at model\sharedpullerstate.go:230 unlocked at model\sharedpullerstate.go:236
[W42I3] 2017/01/05 08:55:13.673979 protocol.go:340: DEBUG: read Response message
[W42I3] 2017/01/05 08:55:13.674479 protocol.go:340: DEBUG: read Response message
[W42I3] 2017/01/05 08:55:13.674479 sharedpullerstate.go:271: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak pullNeeded done -> 1
[W42I3] 2017/01/05 08:55:13.674981 sharedpullerstate.go:271: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak pullNeeded done -> 0
[W42I3] 2017/01/05 08:55:13.674981 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14870
[W42I3] 2017/01/05 08:55:13.675985 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14869
[W42I3] 2017/01/05 08:55:13.676486 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14868
[W42I3] 2017/01/05 08:55:13.676988 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14867
[W42I3] 2017/01/05 08:55:13.677489 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14866
[W42I3] 2017/01/05 08:55:13.677990 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14865
[W42I3] 2017/01/05 08:55:13.678993 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14864
[W42I3] 2017/01/05 08:55:13.680001 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14863
[W42I3] 2017/01/05 08:55:13.680996 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14862
[W42I3] 2017/01/05 08:55:13.681497 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14861
[W42I3] 2017/01/05 08:55:13.682500 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14860
[W42I3] 2017/01/05 08:55:13.683001 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14859
[W42I3] 2017/01/05 08:55:13.684004 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14858
[W42I3] 2017/01/05 08:55:13.684505 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14857
[W42I3] 2017/01/05 08:55:13.685508 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14856
[W42I3] 2017/01/05 08:55:13.686010 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14855
[W42I3] 2017/01/05 08:55:13.686511 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14854
[W42I3] 2017/01/05 08:55:13.687043 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14853
[W42I3] 2017/01/05 08:55:13.687543 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14852
[W42I3] 2017/01/05 08:55:13.688044 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14851
[W42I3] 2017/01/05 08:55:13.916915 sync.go:152: DEBUG: RWMutex held for 228.3711ms. Locked at model\sharedpullerstate.go:230 unlocked at model\sharedpullerstate.go:236
[W42I3] 2017/01/05 08:55:13.917417 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14850
[W42I3] 2017/01/05 08:55:13.918921 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14849
[W42I3] 2017/01/05 08:55:13.919924 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14848
[W42I3] 2017/01/05 08:55:13.920927 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14847
[W42I3] 2017/01/05 08:55:13.921427 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14846
[W42I3] 2017/01/05 08:55:13.921929 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14845
[W42I3] 2017/01/05 08:55:13.922931 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14844
[W42I3] 2017/01/05 08:55:13.923934 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14843
[W42I3] 2017/01/05 08:55:13.925437 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14842
[W42I3] 2017/01/05 08:55:13.926441 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14841
[W42I3] 2017/01/05 08:55:13.927945 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14840
[W42I3] 2017/01/05 08:55:13.928950 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14839
[W42I3] 2017/01/05 08:55:13.929450 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14838
[W42I3] 2017/01/05 08:55:13.929951 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14837
[W42I3] 2017/01/05 08:55:13.931956 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14836
[W42I3] 2017/01/05 08:55:13.932993 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14835
[W42I3] 2017/01/05 08:55:13.933488 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14834
[W42I3] 2017/01/05 08:55:13.934462 sharedpullerstate.go:235: DEBUG: sharedPullerState rznc5-ue5k5 FPSGame\Content\Paks\FPSGame-WindowsNoEditor.pak copyNeeded -> 14833
[W42I3] 2017/01/05 08:55:13.984596 global.go:229: DEBUG: announce POST: 204 No Content

(Ethan Thornburg) #11

When I compare the file size of FPSGame-WindowsNoEditor.pak on the server and the tmp file on the client they match. So that leads me to believe that it has actually finished syncing. And it is having issues overwritting FPSGame-WindowsNoEditor.pak with the tmp file…


(Jakob Borg) #12

One possible thing to try; open up the advanced settings (Action -> Advanced), expand the folder in question, find the option called something about disabling weak hashes, set it so that it’s disabled, restart Syncthing. This is on the receiving side, where you see the locking error.


(Ethan Thornburg) #13

disableWeakHash was already disabled by default


(Antony Male) #14

I think @calmh meant that you should check that box?

That is, weak hashing should be disabled, rather than the box next to ‘disableWeakHash’.


(Ethan Thornburg) #15

Ahh okay I see, sorry I misunderstood on first read. I will try that now.


(Jakob Borg) #16

Yes, check it. Thinking more about I doubt it has any effect but it’s one thing that opens the file in addition to the “usual” ones.


(Audrius Butkevicius) #17

From the log, its just downloading the file


(Ethan Thornburg) #18

Checking “disableWeakHash” on the receiving side looks to have resolved the issue.

I was left with a conflict file on both sides

However, the tmp file is gone and the pak file is up to date.

Both the UI on the receiving and sending side now read Up To Date and I’ve verified the contents of the sync.

I will do another build later tonight and ensure that it syncs correctly and then I will verify with another computer off this network.

Thank you


(Ethan Thornburg) #19

It looks like disableWeakHash was introduced in this commit

Which was in v0.14.17. This was when my syncs stopped working, so this timeline matches.

Is Windows a part of the normal QA process?


(Adam Piggott) #20

Yup.