SMB delete does un-necessary directory file list

For technical support visit http://support.2brightsparks.com/
Post Reply
jmorgannz
Newbie
Newbie
Posts: 5
Joined: Wed Jan 23, 2019 3:40 am

SMB delete does un-necessary directory file list

Post by jmorgannz » Wed Jan 23, 2019 4:06 am

Hi All,

Have been a SyncBackSE user for years and generally have found the application awesome.
Recently I switched to Mozilla Firefox, and have found my backups have begun to fail.

After tracing through debug logs, running wireshark sessions, and other troubleshooting; I have come to the following conclusion:

Facts:
- The Mozilla Firefox profile cache directory has ~70,000 files in it (%AppData%\Local\Mozilla\Firefox\Profiles\*ProfileID*\cache2\entries)
- The directory is very active - contents change frequently. New files added. Old files deleted.
- A file-listing over SMB of this directory takes ~25 seconds to complete.
- SyncBackSE is running in mirror source->destination mode
- The backup profile is configured to use 'Standard Windows file copying' (although I have tried 'Windows Explorer method of file copying' too)
- COPYING each file from source to destination takes a reasonable amount of time

Issue:
- DELETING each file on the destination which no longer exist on the source takes ~25 seconds!
- This is multiplied by EACH FILE which must be deleted on the destination!

Reason:
- Wireshark investigation reveals that whichever method SyncBackSE is using to issue a DELETE on a single file, it first issues an un-necessary full directory file listing, incurring the ~25 second wait time to retrieve the list of ~70,000 files.

Comparison:
- Mapping the SMB path in question to a drive-letter and then using the command prompt to DEL one of the same files incurs the same behavior pattern - it appears the command line DEL command also issues an un-necessary full directory file-listing for each single file deleted
- Using C# to issue a System.IO.File.Delete() on the same files does NOT incur the same pattern. A full directory file-listing is NOT done, and the file is deleted instantly.

Questions:
- Has anyone else had this issue?
- SyncBack support: Is this expected behavior when set to 'Standard Windows file copying' ? I would expect it to happen if set to 'Windows Explorer method of file copying', but I would expect 'Standard Windows file copying' to use similar kernel calls as C# uses and not incur the penalty of a full directory file-listing when deleting a specific, individual file.

Addendum:
- I am not able to change to another copying method than SMB
- The firefox cache may not be important - some may say skip it - but that is not the only directory exhibiting this behavior; it is only a good example
- It is not sufficient to expect the server to return the file listing faster. This is simply not possible on all SMB implementations; and should not be necessary for deleting a single specific file

mickyj
2BrightSparks Staff
2BrightSparks Staff
Posts: 776
Joined: Mon Jan 05, 2004 6:51 pm

Re: SMB delete does un-necessary directory file list

Post by mickyj » Fri Jan 25, 2019 7:53 am


jmorgannz
Newbie
Newbie
Posts: 5
Joined: Wed Jan 23, 2019 3:40 am

Re: SMB delete does un-necessary directory file list

Post by jmorgannz » Mon Jan 28, 2019 6:52 am

Hi MickyJ

Wow, awesome - thanks for looking into this.

I have tried the beta version and unfortunately it does not help.
It appears that now between each file the SMB network connection is lost, triggering a reconnect.
At the same time, the debug log shows error messages about not being able to find the file specified.

Code: Select all

19:44:28=ProfileEngine.TRunProfile.ProcessSingleFile.9035:\doomed\12678
19:44:28=ProfileEngine.TRunProfile.DoDeleteFile.11417:\doomed\12678
19:44:28=LocationsNormal.TNormalLocation.DeleteFile.1252:\doomed\12678
19:44:28=[E]:WindowsFS.TWindowsFS.DeleteFile.2383:\\bertha-mk-iii\Archive\Backup\J-MOBILE\W10\Disk C\Users\J\AppData\Local\Mozilla\Firefox\Profiles\u9nkszsw.default\cache2\doomed\12678: The system cannot find the file specified (2)
19:44:31=[E]:FSWrapper.TFSWrapper.NonShellDeleteFile.2265:\\bertha-mk-iii\Archive\Backup\J-MOBILE\W10\Disk C\Users\J\AppData\Local\Mozilla\Firefox\Profiles\u9nkszsw.default\cache2\doomed\12678: The system cannot find the file specified (2)
19:44:31=[W]:ProfileEngine.TRunProfile.NetworkReconCallback.13070:0
19:44:31=ProfileEngine.TRunProfile.NetworkDisconnect.13050
19:44:31=NetDrive.TNetDrive.Disconnect.414:\\bertha-mk-iii\Archive
19:44:31=NetDrive.TNetDrive.Disconnect.427:Disconnecting [J-MOBILE\J]
19:44:31=ProfileEngine.TRunProfile.NetworkConnect.12986
19:44:31=NetDrive.TNetDrive.NetConnect.116:\\bertha-mk-iii\Archive\Backup\J-MOBILE\W10\Disk C\Users\J\AppData\Local\Mozilla\Firefox\Profiles\u9nkszsw.default\cache2 [-1]
19:44:31=NetDrive.TNetDrive.FConnect.206:\\bertha-mk-iii\Archive\Backup\J-MOBILE\W10\Disk C\Users\J\AppData\Local\Mozilla\Firefox\Profiles\u9nkszsw.default\cache2 [j]
19:44:31=[W]:NetDrive.TNetDrive.FConnect.220:Not already connected [This network connection does not exist]
19:44:31=NetDrive.TNetDrive.FConnect.229:Can access files [\\bertha-mk-iii\Archive\Backup\J-MOBILE\W10\Disk C\Users\J\AppData\Local\Mozilla\Firefox\Profiles\u9nkszsw.default\cache2]
19:44:31=NetDrive.TNetDrive.FConnect.301:Trying nil
19:44:31=NetDrive.TNetDrive.FConnect.326:Success [J-MOBILE\J]
19:44:36=[E]:WindowsFS.TWindowsFS.DeleteFile.2383:\\bertha-mk-iii\Archive\Backup\J-MOBILE\W10\Disk C\Users\J\AppData\Local\Mozilla\Firefox\Profiles\u9nkszsw.default\cache2\doomed\12678: The system cannot find the file specified (2)
19:44:36=[E]:FSWrapper.TFSWrapper.NonShellDeleteFile.2265:\\bertha-mk-iii\Archive\Backup\J-MOBILE\W10\Disk C\Users\J\AppData\Local\Mozilla\Firefox\Profiles\u9nkszsw.default\cache2\doomed\12678: The system cannot find the file specified (2)

mickyj
2BrightSparks Staff
2BrightSparks Staff
Posts: 776
Joined: Mon Jan 05, 2004 6:51 pm

Re: SMB delete does un-necessary directory file list

Post by mickyj » Mon Jan 28, 2019 7:31 am

Hi, looks like a variable wasn't set to FALSE. I've uploaded a new beta that should (I hope this time) fix this:

64-bit: https://www.2brightsparks.com/assets/software/new/SyncBackSE64_Setup.exe

32-bit: https://www.2brightsparks.com/assets/software/new/SyncBackSE_Setup.exe

The beta version number is V8.5.119.0

jmorgannz
Newbie
Newbie
Posts: 5
Joined: Wed Jan 23, 2019 3:40 am

Re: SMB delete does un-necessary directory file list

Post by jmorgannz » Mon Jan 28, 2019 9:47 pm

That's much better!
It still takes longer than necessary to delete a single file - but it is MUCH faster than before.
As you can see in logs below, it takes 5 seconds to delete each file - but this is far better than the 25 seconds it was taking for each file before - the backup actually has a chance of finishing now.

I can still see some error messages about not being able to find the file path - could this be slowing things down?

I will get out Wireshark and capture SMB traffic later on today to see if I can find any more useful info.

Thanks for your help!

Code: Select all

10:40:43=ProfileEngine.TRunProfile.ProcessSingleFile.9075:\entries\001AF38DD689BA1A212BFE1DB4F9A8F37044F3C0
10:40:43=ProfileEngine.TRunProfile.DoDeleteFile.11457:\entries\001AF38DD689BA1A212BFE1DB4F9A8F37044F3C0
10:40:43=LocationsNormal.TNormalLocation.DeleteFile.1252:\entries\001AF38DD689BA1A212BFE1DB4F9A8F37044F3C0
10:40:44=[E]:WindowsFS.TWindowsFS.DeleteFile.2385:\\bertha-mk-iii\Archive\Backup\J-MOBILE\W10\Disk C\Users\J\AppData\Local\Mozilla\Firefox\Profiles\u9nkszsw.default\cache2\entries\001AF38DD689BA1A212BFE1DB4F9A8F37044F3C0: The system cannot find the file specified (2)
10:40:48=[E]:FSWrapper.TFSWrapper.NonShellDeleteFile.2266:\\bertha-mk-iii\Archive\Backup\J-MOBILE\W10\Disk C\Users\J\AppData\Local\Mozilla\Firefox\Profiles\u9nkszsw.default\cache2\entries\001AF38DD689BA1A212BFE1DB4F9A8F37044F3C0: The system cannot find the file specified (2)
10:40:48=ProfileEngine.TRunProfile.ProcessSingleFile.9075:\entries\001B306836549F100E65D998575BC5E63C02F9D2
10:40:48=ProfileEngine.TRunProfile.DoDeleteFile.11457:\entries\001B306836549F100E65D998575BC5E63C02F9D2
10:40:48=LocationsNormal.TNormalLocation.DeleteFile.1252:\entries\001B306836549F100E65D998575BC5E63C02F9D2
10:40:50=[E]:WindowsFS.TWindowsFS.DeleteFile.2385:\\bertha-mk-iii\Archive\Backup\J-MOBILE\W10\Disk C\Users\J\AppData\Local\Mozilla\Firefox\Profiles\u9nkszsw.default\cache2\entries\001B306836549F100E65D998575BC5E63C02F9D2: The system cannot find the file specified (2)
10:40:50=[E]:FSWrapper.TFSWrapper.NonShellDeleteFile.2266:\\bertha-mk-iii\Archive\Backup\J-MOBILE\W10\Disk C\Users\J\AppData\Local\Mozilla\Firefox\Profiles\u9nkszsw.default\cache2\entries\001B306836549F100E65D998575BC5E63C02F9D2: The system cannot find the file specified (2)

mickyj
2BrightSparks Staff
2BrightSparks Staff
Posts: 776
Joined: Mon Jan 05, 2004 6:51 pm

Re: SMB delete does un-necessary directory file list

Post by mickyj » Tue Jan 29, 2019 2:26 am

Hi, the error is just logged, nothing is done except to record the error in the debug log.

Code: Select all

10:40:44=[E]:WindowsFS.TWindowsFS.DeleteFile.2385:\\bertha-mk-iii\Archive\Backup\J-MOBILE\W10\Disk C\Users\J\AppData\Local\Mozilla\Firefox\Profiles\u9nkszsw.default\cache2\entries\001AF38DD689BA1A212BFE1DB4F9A8F37044F3C0: The system cannot find the file specified (2)
10:40:48=[E]:FSWrapper.TFSWrapper.NonShellDeleteFile.2266:\\bertha-mk-iii\Archive\Backup\J-MOBILE\W10\Disk C\Users\J\AppData\Local\Mozilla\Firefox\Profiles\u9nkszsw.default\cache2\entries\001AF38DD689BA1A212BFE1DB4F9A8F37044F3C0: The system cannot find the file specified (2)
There is absolutely nothing to change or remove between those two calls above. In the next entry:

Code: Select all

10:40:50=[E]:WindowsFS.TWindowsFS.DeleteFile.2385:\\bertha-mk-iii\Archive\Backup\J-MOBILE\W10\Disk C\Users\J\AppData\Local\Mozilla\Firefox\Profiles\u9nkszsw.default\cache2\entries\001B306836549F100E65D998575BC5E63C02F9D2: The system cannot find the file specified (2)
10:40:50=[E]:FSWrapper.TFSWrapper.NonShellDeleteFile.2266:\\bertha-mk-iii\Archive\Backup\J-MOBILE\W10\Disk C\Users\J\AppData\Local\Mozilla\Firefox\Profiles\u9nkszsw.default\cache2\entries\001B306836549F100E65D998575BC5E63C02F9D2: The system cannot find the file specified (2)
Exact same calls, no delay at all, as expected. The delay above can only be because of debug output (it can be slow getting the name of the function to be logged, and caching is used, so the following calls will be faster). Switch off debug output and performance will be much faster.

jmorgannz
Newbie
Newbie
Posts: 5
Joined: Wed Jan 23, 2019 3:40 am

Re: SMB delete does un-necessary directory file list

Post by jmorgannz » Tue Jan 29, 2019 8:21 am

Oh ok, yes confirmed the speed is much better with debug mode turned off.
Looks like the issue is resolved with this build!

Thanks for your help.
How will I know when this is released as opposed to beta?

mickyj
2BrightSparks Staff
2BrightSparks Staff
Posts: 776
Joined: Mon Jan 05, 2004 6:51 pm

Re: SMB delete does un-necessary directory file list

Post by mickyj » Tue Jan 29, 2019 8:49 am

Hi, we announce new versions on the home page, via the mailing list and on Twitter and Facebook. Our KB article on the latest versions is also updated. You can also turn on automatic update checks withing SyncBack itself, or manually check within SyncBack.

As we've just released a new version it may be a month or two before another new version is released.

jmorgannz
Newbie
Newbie
Posts: 5
Joined: Wed Jan 23, 2019 3:40 am

Re: SMB delete does un-necessary directory file list

Post by jmorgannz » Tue Apr 30, 2019 10:22 am

Hi again,

Recently I upgraded the 'pre-release' version with the changes you looked at in this thread to the latest official version released on the website.
Since then I have just had a backup take 12 hours 42 minutes to complete.

Can you confirm that the fixes that were done are actually in the officially released version?

The version I currently have is V8.5.122.0

mickyj
2BrightSparks Staff
2BrightSparks Staff
Posts: 776
Joined: Mon Jan 05, 2004 6:51 pm

Re: SMB delete does un-necessary directory file list

Post by mickyj » Tue Apr 30, 2019 10:30 am

Yes, they're in the current official release. Thanks.

Post Reply