Hello Folks,
I have UrBackup Server installed Ubuntu
urbackup-server/xenial,now 2.2.11.2193-1ubuntu1~xenial amd64 [installed]
I have Urbackup windows client 2.2.6 installed on Windows Server 2012 R2.
While the image level backup works on windows client for disk (both incr & full)
The file backup fails to start…
Any help I can get on this is very much appreciated.
On the client, after enabling debugging, I see this messages -
I am attempting to do a full file backup on “C:\OS Images” which contains a few text files.
2018-11-12 13:45:18: rc=0 hasError=true state=0
2018-11-12 13:45:18: Internet mode not enabled
2018-11-12 13:45:19: FileSrv: Stopping CUPDThread...
2018-11-12 13:45:52: ClientService cmd: STATUS#pw=LumOOK06A5MLI8M9poS5CP5WfxtDoD
2018-11-12 13:46:09: CUDPThread exited.
2018-11-12 13:46:09: FileSrv: Backup privileges set successfully
2018-11-12 13:46:09: FileSrv: Backup privileges set successfully (SE_SECURITY_NAME)
2018-11-12 13:46:09: FileSrv: Backup privileges set successfully (SE_RESTORE_NAME)
2018-11-12 13:46:09: FileSrv: Binding UDP socket at port 35622...
2018-11-12 13:46:09: FileSrv: done.
2018-11-12 13:46:09: FileSrv: Disabling new behavior...
2018-11-12 13:46:09: FileSrv: Servername: -ps-dell-mgr-
2018-11-12 13:46:09: FileSrv: Server started up successfully
2018-11-12 13:46:09: FileSrv: UDP Thread startet
2018-11-12 13:46:09: Final path: C:\OS Images
2018-11-12 13:46:09: Final path: C:\Windows\System32\Tasks
2018-11-12 13:46:09: Final path: C:\Windows\Tasks
2018-11-12 13:46:09: Final path: C:\Windows\System32\inetsrv\config
2018-11-12 13:46:09: Final path: C:\Windows\System32\wbem\Repository
2018-11-12 13:46:19: FileSrv: Stopping CUPDThread...
2018-11-12 13:46:44: ClientService cmd: STATUS#pw=LumOOK06A5MLI8M9poS5CP5WfxtDoD
2018-11-12 13:47:09: CUDPThread exited.
2018-11-12 13:47:09: FileSrv: Backup privileges set successfully
2018-11-12 13:47:09: FileSrv: Backup privileges set successfully (SE_SECURITY_NAME)
2018-11-12 13:47:09: FileSrv: Backup privileges set successfully (SE_RESTORE_NAME)
2018-11-12 13:47:09: FileSrv: Binding UDP socket at port 35622...
2018-11-12 13:47:09: FileSrv: done.
2018-11-12 13:47:09: FileSrv: Disabling new behavior...
2018-11-12 13:47:09: FileSrv: Servername: -ps-dell-mgr-
2018-11-12 13:47:09: FileSrv: Server started up successfully
2018-11-12 13:47:09: FileSrv: UDP Thread startet
2018-11-12 13:47:09: Final path: C:\OS Images
2018-11-12 13:47:09: Final path: C:\Windows\System32\Tasks
2018-11-12 13:47:09: Final path: C:\Windows\Tasks
2018-11-12 13:47:09: Final path: C:\Windows\System32\inetsrv\config
2018-11-12 13:47:09: Final path: C:\Windows\System32\wbem\Repository
2018-11-12 13:47:11: Internet mode not enabled
2018-11-12 13:47:36: ClientService cmd: STATUS#pw=LumOOK06A5MLI8M9poS5CP5WfxtDoD
2018-11-12 13:48:28: ClientService cmd: STATUS#pw=LumOOK06A5MLI8M9poS5CP5WfxtDoD
2018-11-12 13:49:05: ClientService cmd: #ILPQixBlg6roBydtK8wKU#ADD IDENTITY
2018-11-12 13:49:05: rc=0 hasError=true state=0
2018-11-12 13:49:05: ClientService cmd: #ILPQixBlg6roBydtK8wKU#GET CHALLENGE
2018-11-12 13:49:05: rc=0 hasError=true state=0
2018-11-12 13:49:05: ClientService cmd:
2018-11-12 13:49:05: rc=0 hasError=true state=0
2018-11-12 13:49:05: ClientService cmd: #Ifm8wHbE5tCO7gwoLDmuB#CAPA
2018-11-12 13:49:06: Cannot read data from device (D:\)
2018-11-12 13:49:06: Cannot read data from device (E:\)
2018-11-12 13:49:06: Device D:\ isn't NTFS formatted
2018-11-12 13:49:06: Device E:\ isn't NTFS formatted
2018-11-12 13:49:06: rc=0 hasError=true state=0
2018-11-12 13:49:06: FileSrv: Info: Window size=65536
2018-11-12 13:49:06: FileSrv: Received data...
2018-11-12 13:49:06: ClientService cmd: #Ifm8wHbE5tCO7gwoLDmuB#1CHANNEL capa=0&token=rxWKiaWFHGTFyKna4oW3&restore_version=1&virtual_client=
2018-11-12 13:49:06: FileSrv: Received a Packet.
2018-11-12 13:49:06: New channel: Number of Channels: 1
2018-11-12 13:49:06: FileSrv: Sending file (normal) urbackup/settings.cfg metadata_id=0
2018-11-12 13:49:06: FileSrv: Mapped name: C:\Program Files\UrBackup\urbackup\data\settings.cfg
2018-11-12 13:49:06: FileSrv: Reading last file part
2018-11-12 13:49:06: FileSrv: Info: File End
2018-11-12 13:49:06: FileSrv: Closed file.
2018-11-12 13:49:06: FileSrv: Received data...
2018-11-12 13:49:06: FileSrv: Received a Packet.
2018-11-12 13:49:06: Received flush.
2018-11-12 13:49:06: FileSrv: Recv Error in RecvMessage
2018-11-12 13:49:06: FileSrv: Deleting Memory...
2018-11-12 13:49:06: FileSrv: done.
2018-11-12 13:49:06: ClientService cmd: #Ifm8wHbE5tCO7gwoLDmuB#SETTINGS update_freq_incr_def=18000
update_freq_full_def=2592000
update_freq_image_full_def=1209600
update_freq_image_incr_def=86400
max_file_incr_def=100
min_file_incr_def=40
max_file_full_def=10
min_file_full_def=2
min_image_incr_def=0
max_image_incr_def=14
min_image_full_def=0
max_image_full_def=1
startup_backup_delay_def=0
backup_window_incr_file_def=1-7/0-24
backup_window_full_file_def=1-7/0-24
backup_window_incr_image_def=1-7/0-24
backup_window_full_image_def=1-7/0-24
exclude_files_def=
include_files_def=
computername_def=ps-dell-mgr
virtual_clients_def=
default_dirs_def=C:\OS Images
allow_config_paths_def=true
allow_starting_full_file_backups_def=true
allow_starting_incr_file_backups_def=true
allow_starting_full_image_backups_def=true
allow_starting_incr_image_backups_def=true
allow_pause_def=true
allow_log_view_def=true
allow_overwrite_def=true
allow_tray_exit_def=true
image_letters_def=C
internet_server_def=
internet_server_port_def=55415
internet_authkey_def=S7E7xBn4iP
internet_speed_def=0
local_speed_def=0
internet_image_backups_def=false
internet_full_file_backups_def=false
internet_encrypt_def=true
internet_compress_def=true
internet_mode_enabled_def=false
silent_update_def=false
client_quota_def=
local_full_file_transfer_mode_def=hashed
internet_full_file_transfer_mode_def=raw
local_incr_file_transfer_mode_def=hashed
internet_incr_file_transfer_mode_def=blockhash
local_image_transfer_mode_def=hashed
internet_image_transfer_mode_def=raw
end_to_end_file_backup_verification_def=false
internet_calculate_filehashes_on_client_def=true
internet_parallel_file_hashing_def=false
image_file_format_def=vhd
internet_connect_always_def=false
server_url_def=
verify_using_client_hashes_def=false
internet_readd_file_entries_def=true
background_backups_def=true
local_incr_image_style_def=to-full
local_full_image_style_def=full
internet_incr_image_style_def=to-last
internet_full_image_style_def=synthetic
create_linked_user_views_def=false
max_running_jobs_per_client_def=1
cbt_volumes_def=ALL
cbt_crash_persistent_volumes_def=-
ignore_disk_errors_def=false
vss_select_components_def=
allow_file_restore_def=true
allow_component_restore_def=true
allow_component_config_def=true
file_snapshot_groups_def=
image_snapshot_groups_def=
internet_file_dataplan_limit_def=5242880000
internet_image_dataplan_limit_def=20971520000
alert_script_def=1
alert_params_def=
2018-11-12 13:49:06: rc=0 hasError=true state=0
2018-11-12 13:49:06: ClientService cmd: #Ifm8wHbE5tCO7gwoLDmuB#INCRINTERVALL "54003"
2018-11-12 13:49:06: rc=0 hasError=true state=0
2018-11-12 13:49:06: ClientService cmd: #Ifm8wHbE5tCO7gwoLDmuB#VERSION 207
2018-11-12 13:49:06: Server has new version 207 (client version: 0). Updating...
2018-11-12 13:49:06: rc=0 hasError=true state=0
2018-11-12 13:49:06: ClientService cmd: #Ifm8wHbE5tCO7gwoLDmuB#CAPA
2018-11-12 13:49:06: Device D:\ isn't NTFS formatted
2018-11-12 13:49:06: Device E:\ isn't NTFS formatted
2018-11-12 13:49:06: Device D:\ isn't NTFS formatted
2018-11-12 13:49:06: Device E:\ isn't NTFS formatted
2018-11-12 13:49:06: rc=0 hasError=true state=0
2018-11-12 13:49:06: ClientService cmd: #ILPQixBlg6roBydtK8wKU#GET CHALLENGE
2018-11-12 13:49:06: rc=0 hasError=true state=0
2018-11-12 13:49:06: ClientService cmd:
2018-11-12 13:49:06: rc=0 hasError=true state=0
2018-11-12 13:49:06: ClientService cmd: #I6UEXOn4Ay0WDsY2cXdDD#2PING RUNNING pc_done=&status_id=2&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=rxWKiaWFHGTFyKna4oW3
2018-11-12 13:49:06: ClientService cmd: #I6UEXOn4Ay0WDsY2cXdDD#3START FULL BACKUP group=0&running_jobs=1&sha=528&with_permissions=1&with_scripts=1&with_orig_path=1&with_sequence=1&with_proper_symlinks=1&status_id=2&async=1#token=rxWKiaWFHGTFyKna4oW3
2018-11-12 13:49:06: Async index 840751f300b42aa629725c04109b77fe
2018-11-12 13:49:06: rc=0 hasError=true state=0
2018-11-12 13:49:06: ClientService cmd: #I6UEXOn4Ay0WDsY2cXdDD#WAIT FOR INDEX async_id=840751f300b42aa629725c04109b77fe#token=rxWKiaWFHGTFyKna4oW3
2018-11-12 13:49:06: Wait for async index 840751f300b42aa629725c04109b77fe
2018-11-12 13:49:08: ClientService cmd: STATUS#pw=LumOOK06A5MLI8M9poS5CP5WfxtDoD
2018-11-12 13:49:16: FileSrv: ClientThread deleted. 1024 KB Memory freed.
2018-11-12 13:49:16: FileSrv: Stopping CUPDThread...
2018-11-12 13:49:16: ClientService cmd: #I6UEXOn4Ay0WDsY2cXdDD#2PING RUNNING pc_done=&status_id=2&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=rxWKiaWFHGTFyKna4oW3
2018-11-12 13:49:25: ERROR: Recvfrom error in CUDPThread::UdpStep
2018-11-12 13:49:25: ERROR: Last error: 10058
2018-11-12 13:49:25: CUDPThread exited.
2018-11-12 13:49:25: FileSrv: Backup privileges set successfully
2018-11-12 13:49:25: FileSrv: Backup privileges set successfully (SE_SECURITY_NAME)
2018-11-12 13:49:25: FileSrv: Backup privileges set successfully (SE_RESTORE_NAME)
2018-11-12 13:49:25: FileSrv: Binding UDP socket at port 35622...
2018-11-12 13:49:25: FileSrv: done.
2018-11-12 13:49:25: FileSrv: Disabling new behavior...
2018-11-12 13:49:25: FileSrv: Servername: -ps-dell-mgr-
2018-11-12 13:49:25: FileSrv: Server started up successfully
2018-11-12 13:49:25: FileSrv: UDP Thread startet
2018-11-12 13:49:25: Final path: C:\OS Images
2018-11-12 13:49:25: Final path: C:\Windows\System32\Tasks
2018-11-12 13:49:25: Final path: C:\Windows\Tasks
2018-11-12 13:49:25: Final path: C:\Windows\System32\inetsrv\config
2018-11-12 13:49:25: Final path: C:\Windows\System32\wbem\Repository
2018-11-12 13:49:25: Removing VSS log data...
2018-11-12 13:49:25: Final path: C:\OS Images
2018-11-12 13:49:25: Final path: C:\Windows\System32\Tasks
2018-11-12 13:49:25: Final path: C:\Windows\Tasks
2018-11-12 13:49:25: Final path: C:\Windows\System32\inetsrv\config
2018-11-12 13:49:25: Final path: C:\Windows\System32\wbem\Repository
2018-11-12 13:49:25: Script list at "C:\Program Files\UrBackup\backup_scripts\list.bat" does not exist. Skipping.
2018-11-12 13:49:25: Deleting files... doing full index...
2018-11-12 13:49:25: Final path: C:\OS Images
2018-11-12 13:49:25: Final path: C:\Windows\System32\Tasks
2018-11-12 13:49:25: Final path: C:\Windows\Tasks
2018-11-12 13:49:25: Final path: C:\Windows\System32\inetsrv\config
2018-11-12 13:49:25: Final path: C:\Windows\System32\wbem\Repository
2018-11-12 13:49:25: Removing deleted directories from index...
2018-11-12 13:49:25: Removing unconfirmed VSS path ".symlink_Task Scheduler Writer_{D61D61C8-D73A-4EEE-8CDD-F6F9786B7124}_TasksStore_files00000000" to "C:\Windows\System32\Tasks
2018-11-12 13:49:25: Removing unconfirmed VSS path ".symlink_Task Scheduler Writer_{D61D61C8-D73A-4EEE-8CDD-F6F9786B7124}_TasksStore_files00000001" to "C:\Windows\Tasks
2018-11-12 13:49:25: Removing unconfirmed VSS path ".symlink_IIS Config Writer_{2A40FD15-DFCA-4AA8-A654-1F8C654603F6}_IISCONFIG_files00000000" to "C:\Windows\System32\inetsrv\config
2018-11-12 13:49:25: Removing unconfirmed VSS path ".symlink_WMI Writer_{A6AD56C2-B509-4E6C-BB19-49D8F43532F0}_WMI_files00000000" to "C:\Windows\System32\wbem\Repository
2018-11-12 13:49:25: Creating shadowcopy of "OS Images" in indexDirs()
2018-11-12 13:49:26: ClientService cmd: #I6UEXOn4Ay0WDsY2cXdDD#2PING RUNNING pc_done=&status_id=2&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=rxWKiaWFHGTFyKna4oW3
2018-11-12 13:49:26: Number of Writers: 12
2018-11-12 13:49:26: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:26: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:26: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:26: Writer System Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:26: Writer SqlServerWriter has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2018-11-12 13:49:26: Writer ASR Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:26: Writer COM+ REGDB Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:26: Writer Shadow Copy Optimization Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2018-11-12 13:49:26: Writer IIS Config Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2018-11-12 13:49:26: Writer BITS Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:26: Writer Registry Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:26: Writer WMI Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2018-11-12 13:49:26: Preparing change block tracking reset for volume c: failed: Incorrect function. (code: 1)
2018-11-12 13:49:27: Number of Writers: 12
2018-11-12 13:49:27: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:27: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:27: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:27: Writer System Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:27: Writer SqlServerWriter has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:27: Writer ASR Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:27: Writer COM+ REGDB Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:27: Writer Shadow Copy Optimization Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:27: Writer IIS Config Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:27: Writer BITS Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:27: Writer Registry Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:27: Writer WMI Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:34: Number of Writers: 12
2018-11-12 13:49:35: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:35: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:35: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:35: Writer System Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2018-11-12 13:49:35: Writer SqlServerWriter has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2018-11-12 13:49:35: Writer ASR Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2018-11-12 13:49:35: Writer COM+ REGDB Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2018-11-12 13:49:35: Writer Shadow Copy Optimization Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2018-11-12 13:49:35: Writer IIS Config Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2018-11-12 13:49:35: Writer BITS Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2018-11-12 13:49:35: Writer Registry Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2018-11-12 13:49:35: Writer WMI Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2018-11-12 13:49:35: Shadowcopy path: \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy32
2018-11-12 13:49:35: done.
2018-11-12 13:49:35: Disabling CBT on volume "C:"
2018-11-12 13:49:35: Indexing "OS Images"...
2018-11-12 13:49:35: Indexing of "OS Images" done. 1 filesystem lookups 0 db lookups and 0 db updates
2018-11-12 13:49:35: Deleting backup of changed dirs...
2018-11-12 13:49:35: Script "C:\Program Files\UrBackup\postfileindex.bat" does not exist
2018-11-12 13:49:35: Async index 840751f300b42aa629725c04109b77fe finished with "done"
2018-11-12 13:49:35: ClientService cmd: #I6UEXOn4Ay0WDsY2cXdDD#GET VSSLOG
2018-11-12 13:49:35: VSS logdata - 775 bytes
2018-11-12 13:49:35: rc=0 hasError=true state=0
2018-11-12 13:49:35: rc=0 hasError=true state=0
2018-11-12 13:49:35: FileSrv: Info: Window size=65536
2018-11-12 13:49:35: FileSrv: Received data...
2018-11-12 13:49:35: FileSrv: Received a Packet.
2018-11-12 13:49:35: FileSrv: Sending file (normal) urbackup/filelist.ub metadata_id=0
2018-11-12 13:49:35: FileSrv: Mapped name: C:\Program Files\UrBackup\urbackup\data\filelist.ub
2018-11-12 13:49:35: FileSrv: Reading last file part
2018-11-12 13:49:35: FileSrv: Info: File End
2018-11-12 13:49:35: FileSrv: Closed file.
2018-11-12 13:49:35: FileSrv: Received data...
2018-11-12 13:49:35: FileSrv: Received a Packet.
2018-11-12 13:49:35: Received flush.
2018-11-12 13:49:36: FileSrv: Received data...
2018-11-12 13:49:36: FileSrv: Received a Packet.
2018-11-12 13:49:36: FileSrv: Sending file (normal) urbackup/tokens_rxWKiaWFHGTFyKna4oW3.properties metadata_id=0
2018-11-12 13:49:36: FileSrv: Mapped name: C:\Program Files\UrBackup\urbackup\data\tokens_rxWKiaWFHGTFyKna4oW3.properties
2018-11-12 13:49:36: FileSrv: Reading last file part
2018-11-12 13:49:36: FileSrv: Info: File End
2018-11-12 13:49:36: FileSrv: Closed file.
2018-11-12 13:49:36: FileSrv: Received data...
2018-11-12 13:49:36: FileSrv: Received a Packet.
2018-11-12 13:49:36: Received flush.
2018-11-12 13:49:36: FileSrv: Recv Error in RecvMessage
2018-11-12 13:49:36: FileSrv: Deleting Memory...
2018-11-12 13:49:36: FileSrv: done.
2018-11-12 13:49:36: rc=0 hasError=true state=0
2018-11-12 13:49:37: ClientService cmd: #I6UEXOn4Ay0WDsY2cXdDD#2LOGDATA 1542048576 0-1542048546-Starting scheduled full file backup...
0-1542048576-Removing unconfirmed VSS path ".symlink_Task Scheduler Writer_{D61D61C8-D73A-4EEE-8CDD-F6F9786B7124}_TasksStore_files00000000" to "C:\Windows\System32\Tasks
0-1542048576-Removing unconfirmed VSS path ".symlink_Task Scheduler Writer_{D61D61C8-D73A-4EEE-8CDD-F6F9786B7124}_TasksStore_files00000001" to "C:\Windows\Tasks
0-1542048576-Removing unconfirmed VSS path ".symlink_IIS Config Writer_{2A40FD15-DFCA-4AA8-A654-1F8C654603F6}_IISCONFIG_files00000000" to "C:\Windows\System32\inetsrv\config
0-1542048576-Removing unconfirmed VSS path ".symlink_WMI Writer_{A6AD56C2-B509-4E6C-BB19-49D8F43532F0}_WMI_files00000000" to "C:\Windows\System32\wbem\Repository
0-1542048576-Indexing of "OS Images" done. 1 filesystem lookups 0 db lookups and 0 db updates
0-1542048576-ps-dell-mgr: Loading file list...
2-1542048576-Error creating clientlist for client ps-dell-mgr
2-1542048576-Backup had an early error. Deleting partial backup.
2018-11-12 13:49:37: rc=0 hasError=true state=0
2018-11-12 13:49:45: FileSrv: ClientThread deleted. 1024 KB Memory freed.
2018-11-12 13:49:57: ClientService cmd: #I6UEXOn4Ay0WDsY2cXdDD#2PING RUNNING pc_done=&status_id=4&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=rxWKiaWFHGTFyKna4oW3
2018-11-12 13:49:57: ClientService cmd: #I6UEXOn4Ay0WDsY2cXdDD#3START FULL BACKUP group=0&running_jobs=1&sha=528&with_permissions=1&with_scripts=1&with_orig_path=1&with_sequence=1&with_proper_symlinks=1&status_id=4&async=1#token=rxWKiaWFHGTFyKna4oW3
2018-11-12 13:49:57: Async index 581f658e82761fbc92b274b328f307ee
2018-11-12 13:49:57: Removing VSS log data...
2018-11-12 13:49:57: rc=0 hasError=true state=0
2018-11-12 13:49:57: ClientService cmd: #I6UEXOn4Ay0WDsY2cXdDD#WAIT FOR INDEX async_id=581f658e82761fbc92b274b328f307ee#token=rxWKiaWFHGTFyKna4oW3
2018-11-12 13:49:57: Wait for async index 581f658e82761fbc92b274b328f307ee
2018-11-12 13:49:57: Final path: C:\OS Images
2018-11-12 13:49:57: Script list at "C:\Program Files\UrBackup\backup_scripts\list.bat" does not exist. Skipping.
2018-11-12 13:49:57: Deleting files... doing full index...
2018-11-12 13:49:57: Final path: C:\OS Images
2018-11-12 13:49:57: Removing deleted directories from index...
2018-11-12 13:49:57: Creating shadowcopy of "OS Images" in indexDirs()
2018-11-12 13:49:57: WARNING: Restarting shadow copy of C:\ because it was started by this server
2018-11-12 13:49:57: Releasing OS Images orig_target=C:\OS Images target=\\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy32\OS Images
2018-11-12 13:49:57: Deleting shadowcopy for path "\\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy32\OS Images" -2
2018-11-12 13:49:58: Number of Writers: 12
2018-11-12 13:49:58: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:58: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:58: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:58: Writer System Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:58: Writer SqlServerWriter has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:58: Writer Shadow Copy Optimization Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:58: Writer WMI Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:58: Writer ASR Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:58: Writer Registry Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:58: Writer BITS Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:58: Writer IIS Config Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:58: Writer COM+ REGDB Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:58: Deleting Shadowcopy for dir "C:\"
2018-11-12 13:49:59: ClientService cmd: STATUS#pw=LumOOK06A5MLI8M9poS5CP5WfxtDoD
2018-11-12 13:49:59: Number of Writers: 12
2018-11-12 13:49:59: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:59: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:59: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:59: Writer System Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:59: Writer SqlServerWriter has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:59: Writer BITS Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:59: Writer ASR Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:59: Writer Shadow Copy Optimization Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:59: Writer COM+ REGDB Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:59: Writer IIS Config Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:59: Writer Registry Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:59: Writer WMI Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:49:59: Preparing change block tracking reset for volume c: failed: Incorrect function. (code: 1)
2018-11-12 13:50:00: Number of Writers: 12
2018-11-12 13:50:00: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:50:00: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:50:00: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:50:00: Writer System Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:50:00: Writer SqlServerWriter has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:50:00: Writer BITS Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:50:00: Writer ASR Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:50:00: Writer Shadow Copy Optimization Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:50:00: Writer COM+ REGDB Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:50:00: Writer IIS Config Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:50:00: Writer Registry Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:50:00: Writer WMI Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:50:04: Number of Writers: 12
2018-11-12 13:50:05: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:50:05: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:50:05: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2018-11-12 13:50:05: Writer System Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2018-11-12 13:50:05: Writer SqlServerWriter has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2018-11-12 13:50:06: Writer BITS Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2018-11-12 13:50:06: Writer ASR Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2018-11-12 13:50:06: Writer Shadow Copy Optimization Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2018-11-12 13:50:06: Writer COM+ REGDB Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2018-11-12 13:50:06: Writer IIS Config Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2018-11-12 13:50:06: Writer Registry Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2018-11-12 13:50:06: Writer WMI Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2018-11-12 13:50:06: Shadowcopy path: \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy33
2018-11-12 13:50:06: done.
2018-11-12 13:50:06: Disabling CBT on volume "C:"
2018-11-12 13:50:06: Indexing "OS Images"...
2018-11-12 13:50:06: Indexing of "OS Images" done. 1 filesystem lookups 0 db lookups and 0 db updates
2018-11-12 13:50:06: Deleting backup of changed dirs...
2018-11-12 13:50:06: ClientService cmd: PONG
2018-11-12 13:50:06: rc=0 hasError=true state=3
2018-11-12 13:50:06: ClientService cmd: #I6UEXOn4Ay0WDsY2cXdDD#1CHANNEL capa=0&token=rxWKiaWFHGTFyKna4oW3&restore_version=1&virtual_client=
2018-11-12 13:50:06: New channel: Number of Channels: 1
2018-11-12 13:50:06: Script "C:\Program Files\UrBackup\postfileindex.bat" does not exist
2018-11-12 13:50:06: Async index 581f658e82761fbc92b274b328f307ee finished with "done"
2018-11-12 13:50:06: ClientService cmd: #I6UEXOn4Ay0WDsY2cXdDD#GET VSSLOG
2018-11-12 13:50:06: VSS logdata - 189 bytes
2018-11-12 13:50:06: rc=0 hasError=true state=0
2018-11-12 13:50:06: rc=0 hasError=true state=0
2018-11-12 13:50:06: FileSrv: Info: Window size=65536
2018-11-12 13:50:06: FileSrv: Received data...
2018-11-12 13:50:06: FileSrv: Received a Packet.
2018-11-12 13:50:06: FileSrv: Sending file (normal) urbackup/filelist.ub metadata_id=0
2018-11-12 13:50:06: FileSrv: Mapped name: C:\Program Files\UrBackup\urbackup\data\filelist.ub
2018-11-12 13:50:06: FileSrv: Reading last file part
2018-11-12 13:50:06: FileSrv: Info: File End
2018-11-12 13:50:06: FileSrv: Closed file.
2018-11-12 13:50:06: FileSrv: Received data...
2018-11-12 13:50:06: FileSrv: Received a Packet.
2018-11-12 13:50:06: Received flush.
2018-11-12 13:50:06: FileSrv: Received data...
2018-11-12 13:50:06: FileSrv: Received a Packet.
2018-11-12 13:50:06: FileSrv: Sending file (normal) urbackup/tokens_rxWKiaWFHGTFyKna4oW3.properties metadata_id=0
2018-11-12 13:50:06: FileSrv: Mapped name: C:\Program Files\UrBackup\urbackup\data\tokens_rxWKiaWFHGTFyKna4oW3.properties
2018-11-12 13:50:06: FileSrv: Reading last file part
2018-11-12 13:50:06: FileSrv: Info: File End
2018-11-12 13:50:06: FileSrv: Closed file.
2018-11-12 13:50:06: FileSrv: Received data...
2018-11-12 13:50:06: FileSrv: Received a Packet.
2018-11-12 13:50:06: Received flush.
2018-11-12 13:50:06: FileSrv: Recv Error in RecvMessage
2018-11-12 13:50:06: FileSrv: Deleting Memory...
2018-11-12 13:50:06: FileSrv: done.
2018-11-12 13:50:07: rc=0 hasError=true state=0
2018-11-12 13:50:08: ClientService cmd: #I6UEXOn4Ay0WDsY2cXdDD#2LOGDATA 1542048607 0-1542048597-Starting unscheduled full file backup...
1-1542048606-Restarting shadow copy of C:\ because it was started by this server
0-1542048606-Indexing of "OS Images" done. 1 filesystem lookups 0 db lookups and 0 db updates
0-1542048606-ps-dell-mgr: Loading file list...
2-1542048606-Error creating clientlist for client ps-dell-mgr
2-1542048607-Backup had an early error. Deleting partial backup.
2018-11-12 13:50:08: rc=0 hasError=true state=0
2018-11-12 13:50:16: FileSrv: ClientThread deleted. 1024 KB Memory freed.
2018-11-12 13:50:51: ClientService cmd: STATUS#pw=LumOOK06A5MLI8M9poS5CP5WfxtDoD
2018-11-12 13:51:06: ClientService cmd: PONG
On the server, I see these errors -
2018-11-13 09:52:47: Starting scheduled full file backup...
2018-11-13 09:52:47: ps-dell-mgr: Connecting for filelist...
2018-11-13 09:52:47: ps-dell-mgr: Waiting for filelist
2018-11-13 09:52:47: ps-dell-mgr: Connecting for filelist (async)...
2018-11-13 09:53:02: Indexing of "OS Images" done. 1 filesystem lookups 0 db lookups and 0 db updates
2018-11-13 09:53:02: ps-dell-mgr: Doing backup with hashed transfer...
2018-11-13 09:53:02: ps-dell-mgr: Loading file list...
2018-11-13 09:53:02: Flushing FileClient...
2018-11-13 09:53:02: Flushing FileClient...
2018-11-13 09:53:02: ERROR: Error creating clientlist for client ps-dell-mgr
2018-11-13 09:53:07: ERROR: Backup had an early error. Deleting partial backup.
2018-11-13 09:53:08: msg=WAKEUP
2018-11-13 09:53:08: WARNING: Exponential backoff: Waiting at least 21h 20m before next file backup
2018-11-13 09:53:08: server_prepare_hash Thread finished (exit)
2018-11-13 09:53:08: server_hash Thread finished - normal