The support forum

Issues with Flushing Write Cache (Local External USB 3.0 --> Network Mounted Drive)

User910590 :

Jul 09, 2017

Hello,

I just downloaded Bvckup 2 trial after hearing about it  potentially being a replacement to my trusty Microsoft Synctoy 2.1. I'm trying to create a weekly backup of my external drive to a Network Mounted Google Drive (using NetDrive) for large files (videos, sometimes in excess of 10GB each).

Synctoy was having issues writing fast enough to my Network Drive. With Bvckup, I notice that the file copies very fast, but then it gets stuck on Flushing Write Cache after every single file. This can last anywhere from 10sec for 100mb files to upwards of a a few minutes for large files. This is obviously very slow compared to just straight copying from Explorer to my Network drive.

Is there anyway you can think of that could help me speed this up? I have tried opening the individual settings file for my backup (after app is closed) and altering the below 4 lines, but whenever I reopen Bvckup, it reverts the Flushing line items to "2". The max_io_buffers do seem to stick though.

        conf.copying.async.max_io_buffers  2
        conf.copying.delta.max_io_buffers   2
        conf.copying.async.flushing  0
        conf.copying.delta.flushing  0

I am not sure what is faster - delta copying or full copies as I'm still doing my initial copy. I have it on Delta for now but can switch to full copy if you guys advise for speed sake when doing Local --> Network.

Any help really with the flushing write cache issue would be greatly appreciated. This is the only thing holding me back from purchasing the pro edition right this moment.

Alex Pankratov :

Jul 09, 2017

It should be

        conf.copying.async.flushing  1
        conf.copying.delta.flushing  1

1 is "Flushing is Off"
2 is "Flushing is Off unless it's a removable drive"
3 is "Flushing is On"

I am not sure what is faster - delta copying or full copies as I'm still doing my initial copy. I have it on Delta for now but can switch to full copy if you guys advise for speed sake when doing Local --> Network.


Depends on whether you have a fair amount of larger files getting _updated_ between the runs. Conversely, if you are just adding new files to the backup with each run, there's no point in delta copying.

PS. I hid your other post in "Release 72" thread.

User910590 :

Jul 10, 2017

Thanks Alex. I guess my issue was I was using "0" instead of "1" haha. I purchased the software regardless, as its awesome.

Two questions:

1. Is there any risk to turning off flushing? I don't truly understand the reason for it or what it does, but if there is no risk, I will turn it off to speed up my backups.

2. I have a large amount of 5GB+ files (~1000 files) and a lot of 200-1000MB files (~10,000), plus many thousands of very small files (less than 2mb). With that said, I do update a good mix of the 5GB+ and 200MB-1000MB files. Keep in mind these are all video files. Would you recommend I still use delta copying or full copying in this case? I know there is no difference between delta or full when adding files, so it is only relevant to my updates of these large media files.

Alex Pankratov :

Jul 10, 2017

1. Is there any risk to turning off flushing?


Flushing ensures that all data that the is _queued_ to be written is actually written out.

Normally, Windows would accept write requests and actually put them through to the device a bit later on - this is called "write caching". This presents a problem if the device is removed or disconnected right after a program (like Bvckup 2) reports that the writing is completed, whereby in reality Windows is still busy writing stuff out to the device.

2. Would you recommend I still use delta copying or full copying in this case?


Generally, yes, this sounds like a good case for delta copying, but you can evaluate it yourself - run the backup, look at the last entry in "Running the backup" section of the log and compare "read" and "wrote" counters:

        Completed in 52 min 33 sec with no errors
                Read 256 GB, wrote 1.08 GB, throughput ...

If they are substantially different, then delta copying is beneficial. But if they are nearly the same, then it's not.

User910590 :

Jul 10, 2017

great, so i guess the only issue with turning off flushing is as follows:

I turn it off, and say there is something still in the writing cache and the network drive (destination drive) disconnects from a network error, or my source (external USB) disconnects from accidentally bumping the USB cord.

Bvckup will report that the write has been done, but Windows may have actually not written it as its in the cache. This would cause issues ONLY at the destination (network drive) where the backup is being stored.

Would just rerunning the backup detect this failure and just overwrite it? Therefore there is no real risk if you are running a consistent backup schedule?

Alex, this is incredible software btw. I used Hamachi dearly back in the day. People like you make real differences in the world.

User910590 :

Jul 10, 2017

Another issue I'm having - I have set the two commands below to "1" for one of my two backups.

        conf.copying.async.flushing  1
        conf.copying.delta.flushing  1

I made sure to close app, change settings then reopen app, and ran the backup, but it still is adding a large amount of time for flushing the write cache. Any idea what could be happening?

Alex Pankratov :

Jul 11, 2017

Would just rerunning the backup detect this failure and just overwrite it?


It will.

Therefore there is no real risk if you are running a consistent backup schedule?


The risk is with potentially having a backup in inconsistent state after an aborted run and before the next one.

I made sure to close app, change settings then reopen app, and ran the backup, but it still is adding a large amount of time for flushing the write cache.


If you don't see xxx.flushing entries reverting to 2 after the app is restarted, then there are in effect and there should be no explicit "flushing" state.

Also, if you've switched bvckup2 into service mode, you will need to stop bvckup2 service as well before changing the INIs.

... but it still is adding a large amount of time for flushing the write cache.


What are the exact symptoms that make you say this?

galileo :

Jul 12, 2017

Alex:

How are NAS and network (LAN) drives treated with respect to this setting - i.e. removable or fixed?

galileo

Alex Pankratov :

Jul 14, 2017



They should be recognized as fixed. You can check this by looking in bvckup2.log:

2017.05.18 ... en | Enumerating drives ...
2017.05.18 ... en | Drive C -> type 3, rem n, bitlocked 0, tc 0, [], ...

It's the "rem(ovable) n(o)" part.

galileo :

Jul 16, 2017

Ahh yes...found and verified...thx

The reason for my question has to do with an ongoing issue that I have not been able to resolve:  

After a reboot and before manually "accessing" any mapped NAS shares, bvckup2 will always generate a "destination not accessible" error when attempting to backup to the share on the NAS device.  I have tried this both with and without adding the logon credentials within bvckup2.  The shares are persistently mapped.  If I have manually accessed any of the network shares on the NAS prior to bvckup2 attempting to run against the share, then bvckup2 finds the share.  The NAS is a QNAP device with the latest firmware.  My OS environment is Win 10 Pro with CU (1703) fully updated.

Basically, the issue is that if the system performs an overnight reboot, then bvckup2 will not find the network share when trying to run the next morning...at least until I have manually accessed the NAS device after the reboot.

Alex Pankratov :

Jul 16, 2017



I believe this has to do with how Windows caches/stores share credentials. In recent Windows versions (Vista+) there appears to be some logic that requires an interactive access to a share to "unlock" its credentials from the protected storage and establish an actual SMB connection.

That said, Bvckup2 has a piece of code that attempts to resuscitate mapped drives using poorly documented Wnet function. It *used* to work fine, when I last checked it a couple of years ago, but Microsoft might've patched thing up since then.

Take a look in bvckup2.log for entries starting with "Netmon". These are added by the "network monitoring" module, which is also responsible for the drive resuscitation. This module kicks in when the app needs to check the status of a network share or a mapped drive referenced in a backup job. See if you have anything interesting logged, in particular any errors for WNetRestoreSingleConnection() and WNetAddConnection2() functions.

Finally, the ultimate fix for this is to switch from using mapped drives to using explicit network paths + specifying logon credentials in the app itself - https://bvckup2.com/support/forum/topic/413

galileo :

Jul 27, 2017

Thanks for the reply...sorry for my delay in "returning serve"...

Regarding explicit network credentials, that is what I have been doing and the problem still persists.  

The "backup to" path is:       \\QNAP\Storage\Backups\ATL\Users\

...don't waste too much time on this...my fix is just to make sure that I have accessed the network shares at least once after a reboot...not optimal but functional nonetheless...

Alex Pankratov :

Jul 28, 2017



Hrm. This should not be happening.

I'd rather have a close look at this and have it properly resolved. When you get a chance, please send me an email at support@pipemetrics.com. I'd like to have a look at your %LocalAppData%\Bvckup2\bvckup2.log.

galileo :

Aug 02, 2017

Alex, I have forwarded the log and further comments via email.  Hopefully this will not be another endless do-loop due to MS networking issues.....ya never know....

Alex Pankratov :

Aug 02, 2017



Got it. It's a misconfiguration issue + the lack of detection of this sort of issues on bvckup's side.

Basically, there are several backups that use \\abc\xyz share and all, but one have share credentials specified. But the one without credentials is the first job on the list, so bvckup's network monitoring module ends up trying to access this share without credentials.

A proper fix for this will be in the next release.

User910590 :

Aug 11, 2017

Hi, still having issues with two things:

1) Bvckup 2 is still getting constantly stuck on flushing write cache even though the settings have been changed in the config. Any idea of what could be changed in Bvckup 2 or Windows or the cloud storage provider (Google) that could fix this?

2) Many files are losing attributes when getting copied, causing reduplication of files in a full-copy mode. It says "updating" for these files, but really what is happening is the entire file is being copied over instead of just changing of the attribute. Any idea how to prevent this? it's happening to more and more files and causing really long copy lengths.

Alex Pankratov :

Aug 11, 2017



1) As per my reply above - if you are seeing an explicit mention of "flushing" when running a backup, then your overrides are not applied correctly.

Instead of editing settings.ini you can try and add respective changes to a new text file called override.ini, place it alongside settings.ini and then restart the program.

If you _don't_ see any flushing messages, then I'm not sure how you know that it gets stuck in the "flushing write cache" stage.

2) Attributes not being in sync do NOT trigger file re-copying. Bvckup 2 will merely reset the attributes as required.

The only thing that triggers recopying is the difference in [ created-time, last-modified-time, file-size ] triplet between source and backup copies of a file.

Moreover, if you are seeing "Resetting the delta state" messages in the log, then it means that some other program is changing timestamps _on backup copies_ between the backups.

You can suppress the attribute sync in Backup Settings > More Options > Copy Also section, but it sounds like its not just the attributes that are being touched on your backup files.

User910590 :

Aug 13, 2017

I am having a new issue that bvckup 2 will get fully stuck on flushing write cache.

User910590 :

Aug 13, 2017

okay, i will try the override.ini. Any instructions on exactly what to put in that file?

User910590 :

Aug 13, 2017

regarding you post:

1) yes, there is an explicit message on each backup that its flushing the write cache. It takes a long time for larger files, and recently it's started to get fulled stuck on the backups on NetDrive that mounts Google Drive.

I will try the override functionality, but below are backup settings for one run. I'm pretty sure it's correct.

conf._description                                 Videos
conf.alerts.email.to                              
conf.alerts.post_backup                            1
conf.alerts.post_backup.keepalive                  0:0
conf.alerts.post_backup.on_cancel                  0
conf.allow_1h_offset                               1
conf.archive                                       $Archive (Bvckup 2)
conf.archive_changed_tag                           " ($date, $time)"
conf.archive_deleted_tag                           " ($date, $time)"
conf.archive_modified                              0
conf.archive_overwrite                             0
conf.archive_trim                                  1
conf.archive_trim_age                              8:2
conf.archive_trim_interval                         6:1
conf.archive_trim_last                             0000-00-00 00:00:00.000
conf.attr_comp_mask                                27
conf.backup_semantics                              1
conf.check_file_size                               1
conf.command_post                                  
conf.command_post_crit                             0
conf.command_post_rc                               0
conf.command_post_timeout                          6:1
conf.command_post_type                             3
conf.command_post_window                           1
conf.command_pre                                  
conf.command_pre_crit                              0
conf.command_pre_rc                                0
conf.command_pre_timeout                           6:1
conf.command_pre_type                              3
conf.command_pre_window                            1
conf.compare_sec_info                              1
conf.copy                                          2
conf.copy_extras                                   ctime, atime, attributes
conf.copy_extras.include_root                      0
conf.copying.async.flushing                        1
conf.copying.async.max_io_buffers                  0
conf.copying.async.read_bytes                      0
conf.copying.async.write_bytes                     0
conf.copying.async.write_through                   0
conf.copying.delta.block_alg1                      1
conf.copying.delta.block_alg2                      2
conf.copying.delta.block_size                      32768
conf.copying.delta.file_alg                        3
conf.copying.delta.flush_crc                       0
conf.copying.delta.flushing                        1
conf.copying.delta.hasher_threads                  0
conf.copying.delta.hashes_per_io                   131072
conf.copying.delta.max_io_buffers                  0
conf.copying.delta.max_recent_age                  7:30
conf.copying.delta.min_file_size                   3342336
conf.copying.delta.min_recent_size                 2097152
conf.copying.delta.read_blocks                     0
conf.copying.delta.thread_priority                 -1
conf.copying.delta.weak_ts_check                   0
conf.copying.delta.write_bytes                     0
conf.copying.delta.write_through                   0
conf.copying.general.dst_sharing                   1
conf.copying.general.open_retries                  1
conf.copying.general.src_sharing                   3
conf.copying.staged.write_through                  0
conf.copying.use_null_copier                       1
conf.copying.use_raw_enc_copier                    0
conf.copying.use_staged_copier                     1
conf.copying.use_system_copier                     0
conf.ctime_gran                                    0
conf.ctime_match                                   2
conf.deleted                                       0
conf.deletion                                      1
conf.detect                                        f
conf.diff                                          1
conf.disabled                                      0
conf.dst                                           \\[GDRIVE MOUNTED via NETDRIVE]\Videos\
conf.dst.filters.0.type                            1
conf.dst.filters.as_source                         0
conf.dst_eject_device                              0
conf.dst_eject_media                               0
conf.dst_eject_media_lock                          2
conf.dst_eject_media_prep                          3
conf.dst_eject_when                                2
conf.dst_net_cancel                                2
conf.dst_net_login                                 0
conf.dst_net_pass                                  
conf.dst_net_user                                  
conf.dst_track                                     1
conf.dst_track_arg                                
conf.dst_track_on_run                              1
conf.exclude_etc                                   1
conf.filters.0.type                                1

User910590 :

Aug 13, 2017

conf.filters.2.manual                              0 00000010 00000000 \hiberfil.sys
conf.filters.2.manual                              0 00000010 00000000 \pagefile.sys
conf.filters.2.manual                              0 00000010 00000000 \swapfile.sys
conf.filters.2.manual                              0 00000010 00000000 \Windows\bootstat.dat
conf.filters.2.manual                              0 00000010 00000000 ~*.tmp
conf.filters.2.manual                              0 00000012 00000002 found.???
conf.filters.2.manual                              0 00000012 00000002 .tickle
conf.filters.2.manual                              0 00000012 00000002 \$dcsys$
conf.filters.2.manual                              0 00000010 00000010 \System Volume Information
conf.filters.2.manual                              0 00000010 00000010 \Recycler
conf.filters.2.manual                              0 00000010 00000010 \$Recycle.bin
conf.filters.2.manual                              0 00000010 00000010 \Windows\CSC
conf.filters.2.manual                              0 00000010 00000010 \Windows\System32\LogFiles\WMI\RtBackup
conf.filters.2.manual                              0 00000010 00000010 \Windows\System32\Microsoft\Protect\Recovery
conf.filters.2.manual                              0 00000010 00000010 \Windows\WinSxS
conf.filters.2.manual                              0 00000010 00000010 \ProgramData\Microsoft\Crypto
conf.filters.2.manual                              0 00000010 00000010 \ProgramData\Microsoft\Diagnosis
conf.filters.2.manual                              0 00000010 00000010 \ProgramData\Microsoft\Microsoft Antimalware\Scans\History\CacheManager
conf.filters.2.manual                              0 00000010 00000010 \ProgramData\Microsoft\Windows\LocationProvider
conf.filters.2.manual                              0 00000010 00000010 \ProgramData\TempDR
conf.filters.2.manual                              0 00000010 00000010 C:\Users\[user]\AppData\Local\Temp
conf.filters.2.manual                              0 00000010 00000010 C:\Users\[user]\AppData\Local\Bvckup2\
conf.filters.2.manual                              0 00000010 00000010 C:\ProgramData\Bvckup2
conf.filters.2.manual                              0 00000010 00000010 Temporary Internet Files
conf.filters.2.manual                              0 00000010 00000010 CryptNetUrlCache
conf.filters.2.manual                              0 00000010 00000010 Mozilla\Firefox\Profiles\*\Cache*
conf.filters.2.manual                              0 00000010 00000010 Google\Chrome\User Data\*\Cache
conf.filters.2.manual                              0 00000010 00000010 Microsoft\Internet Explorer\Recovery
conf.filters.2.manual                              0 00000010 00000010 Microsoft\Windows\INetCache
conf.filters.2.manual                              0 00000010 00000010 Microsoft\Windows\Explorer\IconCacheToDelete
conf.fs_1st_scan_pause                             4:2
conf.fs_change_pause                               4:5
conf.fsw.loc.fallback                              0:0
conf.fsw.net.fallback                              4:300
conf.fsw.net.retries                               2
conf.log_compress                                  1
conf.log_compress_tdb                              1
conf.log_options                                   9974
conf.log_rotate_count                              1
conf.log_rotate_first                              0000-00-00 00:00:00.000
conf.log_rotate_intvl                              0:0
conf.log_rotate_size                               16777216
conf.missed_run.alert.email                        0
conf.missed_run.alert.ui                           1
conf.missed_run.grace_period                       0:0
conf.missed_run.register_on_launch                 1
conf.missed_run.register_on_wakeup                 1
conf.mtime_gran                                    0
conf.net_logon.retry.count                         0
conf.net_logon.retry.pause                         4:1
conf.netmon.interval                               4:5
conf.no_space_no_copy                              0
conf.post_backup_pause                             6:24
conf.post_create_pause                             4:2
conf.post_update_pause                             4:2
conf.queue_name                                    

User910590 :

Aug 13, 2017

conf.root_excl                                     Recycler
conf.root_excl                                     $Recycle.bin
conf.root_excl                                     System Volume Information
conf.scan_options                                  0
conf.scan_symlinks                                 0
conf.scan_threads.local                            0
conf.scan_threads.remote                           8
conf.scanning.cap_memory_use                       1
conf.scanning.compress_snapshot                    1
conf.scanning.max_snapshot_age                     0:0
conf.scanning.retry.count                          1
conf.scanning.retry.except                         5
conf.scanning.retry.inclusive                      1
conf.scanning.retry.pause                          4:1
conf.scanning.rp_as_normal.d                       80000005
conf.scanning.rp_as_normal.d                       80000007
conf.scanning.rp_as_normal.d                       8000000a
conf.scanning.rp_as_normal.d                       80000013
conf.scanning.rp_as_normal.f                       80000005
conf.scanning.rp_as_normal.f                       80000007
conf.scanning.rp_as_normal.f                       8000000a
conf.scanning.rp_as_normal.f                       80000013
conf.scanning.rp_to_ignore.d                       80000008
conf.scanning.rp_to_ignore.d                       80000015
conf.scanning.rp_to_ignore.d                       80000018
conf.scanning.rp_to_ignore.f                       80000008
conf.scanning.rp_to_ignore.f                       80000015
conf.scanning.rp_to_ignore.f                       80000018
conf.scanning.skip_empty_folders                   0
conf.scanning.snapshot_io_buf                      8388608
conf.simulate_deps_cap                             50
conf.src                                           E:Videos\
conf.src_eject_device                              0
conf.src_eject_media                               0
conf.src_eject_media_lock                          2
conf.src_eject_media_prep                          3
conf.src_eject_when                                2
conf.src_net_cancel                                2
conf.src_net_login                                 0
conf.src_net_pass                                  
conf.src_net_user                                  
conf.src_track                                     3
conf.src_track_arg                                 [XXXXXXX].NTFS.100000.74702300000.VK0YNE7Y________
conf.src_track_on_run                              1
conf.system_sleep                                  2
conf.thread_priority                               -1
conf.trim_filters                                  1
conf.ui.position                                   100
conf.ui.tray_alert_on_failed_runs                  1
conf.vss                                           2
conf.vss_pedantic                                  0
conf.vss_timeout_sec                               300
conf.wait_for_dst                                  1
conf.wait_for_src                                  1
conf.when                                          2
conf.when_first                                    2017-07-10 05:00:00.325
conf.when_fs_flags                                 27
conf.when_interval                                 7:1
conf.when_missed                                   0
filesys.dst.api_mask                               1
filesys.dst.attrs_dot                              27
filesys.dst.attrs_reg                              27
filesys.dst.cgran                                  1
filesys.dst.cgran_a                                0
filesys.dst.cgran_p                                1
filesys.dst.ctime                                  0
filesys.dst.max_file_size                          0
filesys.dst.mgran                                  10000000
filesys.dst.mgran_a                                0
filesys.dst.mgran_p                                10000000
filesys.dst.probed                                 1

User910590 :

Aug 13, 2017

filesys.dst.type                                   ndfs
filesys.dst.vol_flags                              86
filesys.dst.vol_serial                             0
filesys.src.api_mask                               1
filesys.src.attrs_dot                              27
filesys.src.attrs_reg                              27
filesys.src.cgran                                  1
filesys.src.cgran_a                                1
filesys.src.cgran_p                                1
filesys.src.ctime                                  1
filesys.src.max_file_size                          18446744073709551615
filesys.src.mgran                                  1
filesys.src.mgran_a                                1
filesys.src.mgran_p                                1
filesys.src.probed                                 1
filesys.src.type                                   NTFS
filesys.src.vol_flags                              3e702ef
filesys.src.vol_serial                             ea63b7ff
last.abort_err                                     0
last.abort_loc                                     0
last.attempted                                     2017-08-13 05:00:00.000
last.changes                                       0
last.ctime_diff                                    0
last.dst.avail                                     1
last.dst.bytes                                     4716302449796
last.dst.dirs                                      852
last.dst.files                                     840
last.errors                                        0
last.finished                                      2017-08-12 05:00:00.046
last.mtime_diff                                    201238608
last.result                                        3
last.run_id                                        62
last.src.avail                                     1
last.src.bytes                                     4788533403613
last.src.dirs                                      853
last.src.files                                     850
last.started                                       2017-08-12 05:00:00.030
misc.version                                       1.77.13.0
state.delete_delta_state                           0
state.delete_snapshot                              0
state.email_alert.last                             0000-00-00 00:00:00.000
state.ignore_ctimes_once                           0
state.in_progress                                  0
state.log_rotated                                  0000-00-00 00:00:00.000
state.prune_crc_empties                            0
state.snapshot_created                             2017-08-11 07:53:44.499
state.was_running                                  0
stats.bytes_read                                   10081639516760
stats.bytes_written                                10051978707740
stats.files_scanned                                3056
stats.runs                                         57
stats.started                                      2017-07-08 20:07:47.395

Alex Pankratov :

Aug 13, 2017

Your override is correct.

If you are still seeing "flushing" message, then it means that the app ends up waiting for your file system stack to process a _close_ request for the file handle (rather than an explicit _flush_ request, which you did suppress successfully).

To explain - a typical flow of working with files is to first "open" a file, whereby you'd pass a file name to the OS and get back an opaque "handle". You'd then use this handle to submit read/write requests to the OS. You can also ask the OS to write out all data that it might've accumulated in its cache (this is "cache flushing" or "flushing"). Finally, when you are done with the file, you ask the OS to release ("close") the handle.

The "close" operation is generally *very* fast, in the order of microseconds.

In your case it appears to take seconds and this is not normal. I have no answer for you as to what might be causing it, but if I were to guess this is likely some sort of blocking write cache maintenance on part of "NetDrive" software. Your best bet would be to check with them as there's not much you can tweak in Bvckup 2 in order to speed up file closing.

User910590 :

Aug 14, 2017

Hmm, that is very helpful. I'm going to see if there is another alternative to NetDrive that may not have this constant issue.

Thank you again for all your help though, I appreciate it very much!

New topic

Create
Made by Pipemetrics in Switzerland
Support


Follow
Twitter
Dev blog
Miscellanea Press resources
Testimonials
On robocopy
Company
Imprint

Legal Terms
Privacy