Filewatcher not updating on copied files or changed files #256
Comments
|
Hrm, can't reproduce. Didn't you change some details of how users' network shared were mapped? Could that be the cause? |
|
Yep that was me! I don't think it is the drive mapping, I've tried making changes to the real location instead of the subst drive letter and it doesn't pick up the changes there either, As I said I'm really confused by this as I'm sure it was working the only change I've made to the configuration is to change the folder path from the subst drive to the real path on the client end, The server hasn't had any configuration changes and is exhibiting the same issue! |
|
Narrowed down a bit further - its not the creating a new file that the file system watcher picks up and starts the sync, its the rename function. So it looks like only renaming a file is currently working on our system for the file system watcher! |
Must not hit production, as some of the properties being logged will throw exceptions with long paths. Related to #256
|
Had a thought as well - the laptops I have to test at the moment have been recently reinstalled and will be ~3 months out of date for windows updates, which then apply at their leisure via SCCM. Its possible that there is something in a .net framework update that could be related so I'm going to force all updates and see what happens! |
|
I've created a version with some more logging here: https://ci.appveyor.com/project/canton7/synctrayzor/build/1.1.8.339/artifacts (it will be built in about 15 mins). Probably not a good idea to run it everywhere - it won't support long paths - but it would be interesting to see if it prints anything on a test machine. |
|
No problem - I can run it on one test machine I have here and try the windows updates on the 2nd, Thanks! |
That doesn't match...
|
Your right. I was just trying to think of any differences between my test machines and somehow forgot the server was doing the same, sorry! I'll run the debug version once its built! |
|
Oh, delete events are being picked up as well, I forgot to mention that, Seem to be forgetting things too much today! Very Sorry! |
|
Here are the logs from the debug build: I can see OnCreated events firing but nothing happening with them? The OnRenamed event seems to fire the syncthing.apiclient routine? |
|
Let's see... There's an amount of dead time between receiving the notification and telling Syncthing about it: during this period, we'll take potentially many notifications and reduce them to a single (parent) path. This is to avoid spamming Syncthing if there are many notifications in quick succession. So it actually looks like it's ignoring the OnRenamed notification |
|
Here's another build with loads more logging: https://ci.appveyor.com/project/canton7/synctrayzor/build/1.1.8.340/artifacts |
|
Right! I'm leaving work in ~15 mins, if it builds and is available I'll try and test is quickly to get the logs over to you! Thanks again! My colleagues are commenting about how well you are supporting the app, better than any of our software support contacts! :) |
|
Thanks 😄 |
|
got it! case sensitivity issue! or not? just a warning, maybe jumped to conclusions as the same warn is present in the rename log! :( though it does seem to stop right after the warning, whereas the rename continues? There is a LOT more log, I've just taken the snippit before it calls the apiclient, I can upload the rest if needs be |
|
Bleh. Thanks for helping track this down! |
|
This should fix it: https://ci.appveyor.com/project/canton7/synctrayzor/build/1.1.8.341. Please let me know if it doesn't (not today, of course), and I'll include it in the next release otherwise. |
|
No problem! Looks like we did hit the issue when I changed from the subst drive (N:) to c:\localdocs\username after all, so I was right that it was working when testing previously! :) Will test first thing tomorrow, Thanks for looking into it so quickly!! |
|
One question - does build 341 contain the extra debugging which will cause long paths to fail? or has that been removed and if it does fix I can use as a general build? |
|
No, it doesn't. One question: what's the actual casing of |
|
The folder is c:\LocalDocs\MULVEEP and the path in syncthing config.xml is c:\localdocs\mulveep I'm not actually sure why the username is in all caps, it uses %username% in the subst command to create the folder, though that is in lowercase if I echo %username% in the command prompt and the actual user in AD is in CamelCase! It might be some quirk of the user management software we use to deliver the drive mappings and other settings (RES Workspace) The LocalDocs to localdocs is changes in my coding practice - powershell I wrote 2 years ago to create the folder and permissions I would use CamelCase, to powershell I wrote a few weeks ago to configure syncthing as I keep everything lowercase now. |
|
quick test and seems to be working! creating files, adding content to files and copying files are now all being picked up by the filewatcher and being synced in realtime again! So looks good! Thank you very much! :) |
|
Great, that explains it, thanks. We established a watcher at |
|
This might not be related, but we are seeing this popping up in the logs quite regularly, so far its been for unimportant files like shortcuts or desktop.ini (which we've now excluded from syncing) but I wanted to mention it as it seems like the index is not up to date as to fix it we run a rescan on the other connected node and the number of files increases and the error goes away from the remote node, I have both nodes running 1.1.8.341 with the case fix included, these are new shared folders created after updating synctrayzor I was going to put this as a new issue, but I have a slight feeling that maybe somehow these changes are not getting sent to syncthing to update its index. I've left one broken, we have syncthing configured to rescan once per hour so I'm going to check to see if that fixes it when it rescans on its own, Sorry! |
|
These files are being changed as there is an active session on both sides of the sync, Wouldn't Syncthing tell me its working as intended? As the sync is working after a rescan on a node, which is their normal behaviour without a file watcher? It could be an artifact of the inital sync, while its downloading ~5gb the files have changed before it gets to them? But shouldn't that be picked up by the file watcher to tell syncthing to update its index? Somehow the index is out of date? |
|
If they're being constantly changed, then this is expected behaviour from Syncthing: by the time the pulling side gets around to requesting the file, it's changed. I'm not sure whether Syncthing will listen for updates to the index while downloading files from it - I rather suspect it won't. |
That's what I was wondering about, it was my suspicion too based on the behaviour observed that the file watcher was telling Syncthing that a change had happened, but it was busy - as the button for rescan is disabled when in the Out-of-sync status, so I thought perhaps it couldn't accept an api request for a rescan while in that status either? Do you get a meaningful response from the api when requesting a rescan on a file / folder, actually telling you its going to do it, or can't at that time? Or just a successfully sent api request but no status? |
This |
|
There's been a lot of work recently on partial indexes, so a change to this behaviour may already be in the pipeline. |
Thought this was the most likely case!
Ah yes, there's big changes in 0.13, not really in a place for me to use live yet but I'll check that when its out of beta, If there is no status reported back from syncthing then there's nothing to work with if it ignores api calls from the file watcher and it will just have to find any missing changes during the hourly rescan (2m+ files 2.5TB in 250+ folders on the server, so frequent scanning causes pretty big io bottlenecks!). I can't imagine its actually going to happen very often in day to day operation on real files, just during the first time sync, Thanks again! |
|
Nothing has changed in terms of scanning in next release. I think scanning requests should block while there is one already running. |
|
So we'll probably have the same issue in 0.13 - is it worth putting in a feature request to Syncthing to report a status when the api rescan request is blocked? Filewatcher implementations could then queue changes to post to the api? Unfortunately my go knowledge is next to non-existent so contributing it myself would be extremely hard :( |
|
I'm still not clear on what exactly is going on here - are you sending a rescan request to a Syncthing instance which is downloading, or one which idle but has another device downloading from it? |
|
Sorry if I'm not being clear enough! We have 2 nodes with 1 folder shared between them running synctrayzor The node on our server is set up first and contains the users personal files and documents, and is fully indexed by syncthing We then log into the users laptop and start synctrayzor which begins to download the folder from the server node, Once the laptop has completed the sync we then get the error about peers going away until a rescan is performed on the server node, Does that make sense? |
|
Right, so while the server is idle and the client is downloading, a file changes on the server. This change is not picked up on the server (until you rescan). Correct? |
|
Almost - The user is logged with a drive mapped to the files on the server, while the client is downloading, which is why files change on the server while the client is downloading, but the index is up to date before we start the client and Syncthing is not scanning |
|
Wait, you didn't mention that before - that's new. What exactly is going? So there's a folder on the server, which is added to Syncthing as a folder. When a user logs in on a different machine, that folder gets mapped as a network drive, but the user also has Syncthing set up, and has that network drive added as a folder within Syncthing? |
|
OK, so we have a server that contains user home drives - these are mapped to a drive when the user logs into a network computer SyncTrayzor is running on the server and has the home drive folder which is local to the server added to Syncthing's config Syncthing is working in a normal fashion as its syncing a real folder on a device to a real folder on a device, there are no network folders configured in syncthing, It should be the same as using syncthing on a NAS with a drive mapped to a PC while also running syncthing on a laptop, which is why I didn't really go over the setup in detail, sorry again! |
|
Right, thanks for clearing that up. So my general description before was correct: the server is idle, and is notified of a change while another device is downloading. The other device does not pick up on that change until the server is manually rescanned. |
|
In other words, this:
Is not relevant: the server's Rescan button is not disabled, because the server is idle. |
|
yes, I interpreted idle as there was no user access to the files! Whoops! |
You know, I've not actually looked at the server folder status until after the download has finished and the error pops up - I'l have to check that on the next one I do, |
|
OK, so all of the assertions that the server is idle when the change notification from SyncTrayzor arrives aren't actually substantiated? |
Quite possible actually - As the initial adding of the folder, first scan and logging into the laptop and its syncing all took place within an hour (which is the rescan interval) I assumed the server status didn't change, Next one I do I'll watch the server side as well as the client and see what happens. The server does have other users folders configured as well, thinking about how I worded earlier it might be assumed its a single folder on the server, whereas its 1-1 relationship for folders, which contain the server node and the client node, but the server config contains the other users folders as well - though it shouldn't make a difference if another folder is scanning when you call for a scan on an idle folder right? Sorry about this, |
|
What I need to know is: When SyncTrayzor sends a "file changed" notification for a folder to Syncthing, what state is that folder within the Syncthing GUI? |
|
I can watch that on the next one - any change should happen in the GUI even if its very quick, right? |
|
You misunderstand: I don't want to know if SyncTrayzor's "file changed" notification triggers a change in the Syncthing GUI, I want to know whether the folder is Idle/Syncing/Scanning/Whatever at the point that SyncTrayzor sends its "file changed" notification. |
|
We've set up 2 more laptops since my last message, The first didn't exhibit the problem at all During the client download the server status changes to Syncing a few times, checking the synctrayzor log file for file watcher events its a bit too quick to see - so I've recorded the log + syncything GUI so I can play back and catch the events and we can see what the status is when SyncTrayzor triggers a rescan I did notice though that the files or the folders which contain them which had the peers went away error are not listed in any of the watcher or api calls I'll keep logging new installs to try and find one which has the same persistent problem as I found previously |
|
I managed to capture one this morning, The syncthing GUI reads "Up to Date", switching to "Syncing" or "Syncing (100%)" there is a ~100ms delay between the GUI changing and my live log viewer changing, the GUI updates first. The live log viewer has a 500ms update check by default, so I'm pretty sure that the GUI is changing as a result of the synctrayzor call. I could try and shorten the polling time if you think the accuracy is an issue. The server log is filtered for lines containing the foldername I'm syncing - otherwise its impossibly big and extremely hard to find relevant information, I don't know if this causes any issues if you have any log entries which don't contain the foldername I can find the time of the logs though and provide the full ones if needed. The server has this log during the sync (log is pretty log so I've popped it on pastebin for a week) The error on the client disappeared after this happened on the server: The client first see's the peers went away error here: |
|
Right, so SyncTrayzor is definitely telling Syncthing that the file has changed, and Syncthing is picking up on that change. Syncthing is not scanning (or doing anything else) when the change notification happened. Therefore whatever's going on is entirely a Syncthing issue. Please open an issue with Syncthing, describing the problem in full detail (I'm still a bit unclear on what exactly is happening - the story appears to have changed a few times). |
|
Fixed in v1.1.9 |
|
Thanks for all the extended checking, sorry I wasn't so clear at some points, I'll open an issue with Syncthing as you suggested, Thanks again! |
Have noticed today that copied files and changed files are no longer being picked up by the synctrayzor filewatcher when they occur,
If I then create a new file after copying or adding content to a file, the watcher kicks in and all the changed / copied / new files sync
The synctrayzor.log runs this while the files are being copied or edited
and when I create the new file this happens
running SyncTrazor version 1.1.8.329 and syncthing v0.12.22, I tried going back to v0.12.21 as that was a recent change, but it has the same issue
I'm quite confused as I'm 100% sure this was working when testing SyncTrayzor and for the first dozen users rolled out, but now I'm seeing it when trying to copy or edit files on any device.
If I run Rescan on a device with changed or copied files, it picks them up and syncs them to the other device
The text was updated successfully, but these errors were encountered: