I’ve been running UrBackup a couple months, with the server running in a jail under FreeNAS (FreeBSD), clients on a mix of Win 7 and Win 8.1. Everything worked fine up to a week ago, when the clients were autoupdated to version 1.4.5 from 1.4.4. The server was running 1.4.5 when the problem started, though it is now on 1.4.6 and the problem is still present. I install the server from source, and not using the PBI plugin. I’ve updated the server from source 2 or 3 times since the initial installation, with no problem.
Incremental file backups run with no errors or warnings, but the only files being pushed to the server are backup_client.db (always) and open_files.dat (sometimes) under C:\Program Files\UrBackup\urbackup. A full file backup was run since the incremental backups stopped working, and it seems to have worked (pushed about 15,000 changed files).
I turned on “end-to-end verification of all file backups” then ran an incremental file backup. After about 6 hours, the backup reported about 7000 verification errors, again with only backup_client.db and open_files.dat being updated. The error count is reasonable for the # of files that were modified and should have been pushed to the server (mostly browser caching).
I turned end-to-end verification back off, and restarted the server and client with --loglevel debug. Running another incremental file backup, I get this for the server log:
2014-12-03 23:07:25: msg=START BACKUP INCR
2014-12-03 23:07:25: Starting incremental file backup...
2014-12-03 23:07:25: phil-PC: Connecting for filelist...
2014-12-03 23:07:25: Created new database connection for urbackup/backup_server.db
2014-12-03 23:07:25: phil-PC: Waiting for filelist
2014-12-03 23:07:25: Created new database connection for urbackup/backup_server.db
2014-12-03 23:08:25: Indexing of "D" done. 1 filesystem lookups 10886 db lookups and 1 db updates
2014-12-03 23:08:25: Indexing of "E" done. 1 filesystem lookups 2199 db lookups and 1 db updates
2014-12-03 23:08:25: Indexing of "C" done. 2 filesystem lookups 29388 db lookups and 2 db updates
2014-12-03 23:08:25: phil-PC: Doing backup with hashed transfer...
2014-12-03 23:08:25: phil-PC: Connecting to client...
2014-12-03 23:08:25: phil-PC: Loading file list...
2014-12-03 23:08:25: phil-PC Starting incremental backup...
2014-12-03 23:08:25: phil-PC: Calculating file tree differences...
2014-12-03 23:08:27: phil-PC: Calculating tree difference size...
2014-12-03 23:08:27: phil-PC: Linking unchanged and loading new files...
2014-12-03 23:08:28: Created new database connection for urbackup/backup_server.db
2014-12-03 23:08:29: Waiting for file transfers...
2014-12-03 23:08:31: Loading file "backup_client.db"
2014-12-03 23:08:32: GT: Loaded file "backup_client.db"
2014-12-03 23:08:32: Loading file "open_files.dat"
2014-12-03 23:08:32: PT: Hashing file "backup_client.db"
2014-12-03 23:08:32: GT: Loaded file "open_files.dat"
2014-12-03 23:08:33: Setting cachesize to 40960
2014-12-03 23:08:33: PT: Hashing file "open_files.dat"
2014-12-03 23:08:33: HT: Copying file: "/backups/phil-PC/141203-2307/C/Program Files/UrBackup/urbackup/backup_client.db"
2014-12-03 23:08:33: HT: Copying file: "/backups/phil-PC/141203-2307/C/Program Files/UrBackup/urbackup/open_files.dat"
2014-12-03 23:08:34: Writing new file list...
2014-12-03 23:08:35: Created new database connection for urbackup/backup_server.db
2014-12-03 23:08:37: Waiting for file hashing and copying threads...
2014-12-03 23:08:38: Creating symbolic links. -1
2014-12-03 23:08:38: Creating symbolic links. -2
2014-12-03 23:08:38: Symbolic links created.
2014-12-03 23:08:38: Transferred 70.3355 MB - Average speed: 42.9134 MBit/s
2014-12-03 23:08:38: Script does not exist urbackup/post_incr_filebackup
2014-12-03 23:08:38: server_prepare_hash Thread finished (exit)
2014-12-03 23:08:38: Setting cachesize to 40960
2014-12-03 23:08:38: server_hash Thread finished - normal
2014-12-03 23:08:39: Time taken for backing up client phil-PC: 1m 14s
2014-12-03 23:08:39: Backup succeeded
2014-12-03 23:08:39: Updating statistics...
2014-12-03 23:08:39: Copying files from files_new table...
2014-12-03 23:08:39: Deleting contents of files_new table...
2014-12-03 23:08:39: Updating image stats...
2014-12-03 23:08:39: Updating deleted files...
2014-12-03 23:08:39: Updating file stats...
2014-12-03 23:08:39: File processing speed: 0.000284614 files/s
2014-12-03 23:08:39: Updating files stats: 50%
2014-12-03 23:08:39: Done updating statistics.
I don’t see anything in there explaining why all the changed files were ignored. Here’s the client-side log. Again, I don’t see anything too weird, though it’s curious that the “START SC” commands always say the ShadowCopy is already present.
2014-12-03 23:07:06: FileSrv: UDP: PING received... sending PONG. Delay=41ms
2014-12-03 23:07:22: ClientService cmd: START BACKUP INCR#pw=<pw>
2014-12-03 23:07:22: rc=0 hasError=true state=0
2014-12-03 23:07:22: ClientService cmd: #<cmd>#PING RUNNING --#token=<token>
2014-12-03 23:07:22: ClientService cmd: #<cmd>#3START BACKUP#token=<token>
2014-12-03 23:07:22: Removing VSS log data...
2014-12-03 23:07:22: rc=0 hasError=true state=0
2014-12-03 23:07:22: Final path: D:\
2014-12-03 23:07:22: Final path: E:\
2014-12-03 23:07:22: Final path: C:\
2014-12-03 23:07:22: Final path: D:\
2014-12-03 23:07:22: Final path: E:\
2014-12-03 23:07:22: Final path: C:\
2014-12-03 23:07:23: ClientService cmd: STATUS#pw=<pw>
2014-12-03 23:07:23: rc=0 hasError=true state=0
2014-12-03 23:07:32: ClientService cmd: #<cmd>#2PING RUNNING pc_done=&eta_ms=1704471#token=<token>
2014-12-03 23:07:32: rc=0 hasError=true state=0
2014-12-03 23:07:34: Creating shadowcopy of "D" in indexDirs()
2014-12-03 23:07:35: Number of Writers: 11
2014-12-03 23:07:35: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:35: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:35: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:35: Writer System Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:35: Writer ASR Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:35: Writer Registry Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:35: Writer Shadow Copy Optimization Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:35: Writer MSSearch Service Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:35: Writer BITS Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:35: Writer COM+ REGDB Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:35: Writer WMI Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:35: Number of Writers: 11
2014-12-03 23:07:35: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:35: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:35: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:35: Writer System Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:35: Writer ASR Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:35: Writer Registry Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:35: Writer Shadow Copy Optimization Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:35: Writer MSSearch Service Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:35: Writer BITS Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:35: Writer COM+ REGDB Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:35: Writer WMI Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:39: ClientService cmd: PONG
2014-12-03 23:07:41: Number of Writers: 11
2014-12-03 23:07:41: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:42: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:42: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:42: Writer System Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:42: Writer ASR Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:42: Writer Registry Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:42: Writer Shadow Copy Optimization Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:42: Writer MSSearch Service Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:42: Writer BITS Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:42: Writer COM+ REGDB Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:42: Writer WMI Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:42: ClientService cmd: #<cmd>#2PING RUNNING pc_done=&eta_ms=1694464#token=<token>
2014-12-03 23:07:42: rc=0 hasError=true state=0
2014-12-03 23:07:47: Shadowcopy path: \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy374
2014-12-03 23:07:47: done.
2014-12-03 23:07:48: Scanning for changed hard links in "D"...
2014-12-03 23:07:48: Indexing "D"...
2014-12-03 23:07:52: ClientService cmd: #<cmd>#2PING RUNNING pc_done=&eta_ms=1684453#token=<token>
2014-12-03 23:07:52: rc=0 hasError=true state=0
2014-12-03 23:07:53: Indexing of "D" done. 1 filesystem lookups 10886 db lookups and 1 db updates
2014-12-03 23:07:53: Creating shadowcopy of "E" in indexDirs()
2014-12-03 23:07:53: Number of Writers: 11
2014-12-03 23:07:53: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:53: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:53: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:53: Writer System Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:53: Writer ASR Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:53: Writer Registry Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:53: Writer Shadow Copy Optimization Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:53: Writer MSSearch Service Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:53: Writer COM+ REGDB Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:53: Writer BITS Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:53: Writer WMI Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:54: Number of Writers: 11
2014-12-03 23:07:54: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:54: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:54: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:54: Writer System Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:54: Writer ASR Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:54: Writer Registry Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:54: Writer Shadow Copy Optimization Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:54: Writer MSSearch Service Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:54: Writer COM+ REGDB Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:54: Writer BITS Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:54: Writer WMI Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:57: FileSrv: UDP: PING received... sending PONG. Delay=242ms
2014-12-03 23:07:57: Number of Writers: 11
2014-12-03 23:07:58: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:58: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:58: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:07:58: Writer System Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:58: Writer ASR Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:58: Writer Registry Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:58: Writer Shadow Copy Optimization Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:58: Writer MSSearch Service Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:58: Writer COM+ REGDB Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:58: Writer BITS Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:07:58: Writer WMI Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:08:01: Shadowcopy path: \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy375
2014-12-03 23:08:01: done.
2014-12-03 23:08:02: Scanning for changed hard links in "E"...
2014-12-03 23:08:02: Indexing "E"...
2014-12-03 23:08:02: ClientService cmd: #<cmd>#2PING RUNNING pc_done=&eta_ms=1674441#token=<token>
2014-12-03 23:08:02: rc=0 hasError=true state=0
2014-12-03 23:08:04: Indexing of "E" done. 1 filesystem lookups 2199 db lookups and 1 db updates
2014-12-03 23:08:04: Creating shadowcopy of "C" in indexDirs()
2014-12-03 23:08:04: Number of Writers: 11
2014-12-03 23:08:04: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:04: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:04: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:04: Writer System Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:08:04: Writer ASR Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:08:04: Writer Shadow Copy Optimization Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:08:04: Writer COM+ REGDB Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:08:04: Writer MSSearch Service Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:08:04: Writer Registry Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:08:04: Writer BITS Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:08:04: Writer WMI Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:08:05: Number of Writers: 11
2014-12-03 23:08:05: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:05: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:05: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:05: Writer System Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:05: Writer ASR Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:05: Writer Shadow Copy Optimization Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:05: Writer COM+ REGDB Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:05: Writer MSSearch Service Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:05: Writer Registry Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:05: Writer BITS Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:05: Writer WMI Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:09: Number of Writers: 11
2014-12-03 23:08:09: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:09: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:09: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:09: Writer System Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:08:09: Writer ASR Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:08:09: Writer Shadow Copy Optimization Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:08:09: Writer COM+ REGDB Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:08:09: Writer MSSearch Service Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:08:09: Writer Registry Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:08:09: Writer BITS Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:08:09: Writer WMI Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2014-12-03 23:08:10: Shadowcopy path: \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy376
2014-12-03 23:08:10: done.
2014-12-03 23:08:11: Scanning for changed hard links in "C"...
2014-12-03 23:08:11: Indexing "C"...
2014-12-03 23:08:12: ClientService cmd: #<cmd>#2PING RUNNING pc_done=&eta_ms=1664431#token=<token>
2014-12-03 23:08:12: rc=0 hasError=true state=0
2014-12-03 23:08:20: Indexing of "C" done. 2 filesystem lookups 29388 db lookups and 2 db updates
2014-12-03 23:08:20: Deleting backup of changed dirs...
2014-12-03 23:08:22: ClientService cmd: #<cmd>#GET VSSLOG
2014-12-03 23:08:22: VSS logdata - 236 bytes
2014-12-03 23:08:22: ClientService cmd: #<cmd>#2PING RUNNING pc_done=&eta_ms=1654426#token=<token>
2014-12-03 23:08:22: rc=0 hasError=true state=0
2014-12-03 23:08:22: rc=0 hasError=true state=0
2014-12-03 23:08:22: rc=0 hasError=true state=0
2014-12-03 23:08:22: FileSrv: Info: Window size=524288
2014-12-03 23:08:22: FileSrv: Received data...
2014-12-03 23:08:22: FileSrv: Received a Packet.
2014-12-03 23:08:22: FileSrv: Sending file (normal) urbackup/filelist.ub
2014-12-03 23:08:22: FileSrv: Mapped name: C:\Program Files\UrBackup\urbackup\data\filelist.ub
2014-12-03 23:08:23: FileSrv: Reading last file part
2014-12-03 23:08:23: FileSrv: Info: File End
2014-12-03 23:08:23: FileSrv: Closed file.
2014-12-03 23:08:23: ClientService cmd: STATUS#pw=<pw>
2014-12-03 23:08:23: rc=0 hasError=true state=0
2014-12-03 23:08:25: ClientService cmd: #<cmd>#START SC "D"#token=<token>
2014-12-03 23:08:25: orig_target=D:\ volpath=\\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy374
2014-12-03 23:08:25: Shadowcopy already present.
2014-12-03 23:08:25: rc=0 hasError=true state=0
2014-12-03 23:08:26: ClientService cmd: #<cmd>#STOP SC "D"#token=<token>
2014-12-03 23:08:26: Number of Writers: 11
2014-12-03 23:08:26: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:26: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:26: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:26: Writer System Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:26: Writer ASR Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:26: Writer BITS Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:26: Writer Shadow Copy Optimization Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:26: Writer MSSearch Service Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:26: Writer WMI Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:26: Writer Registry Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:26: Writer COM+ REGDB Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:26: Deleting shadowcopy for path "\\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy374\" -2
2014-12-03 23:08:27: Deleting Shadowcopy for dir "D:\"
2014-12-03 23:08:27: rc=0 hasError=true state=0
2014-12-03 23:08:27: ClientService cmd: #<cmd>#START SC "E"#token=<token>
2014-12-03 23:08:27: orig_target=E:\ volpath=\\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy375
2014-12-03 23:08:27: Shadowcopy already present.
2014-12-03 23:08:27: rc=0 hasError=true state=0
2014-12-03 23:08:27: ClientService cmd: #<cmd>#STOP SC "E"#token=<token>
2014-12-03 23:08:28: Number of Writers: 11
2014-12-03 23:08:28: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:28: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:28: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:28: Writer System Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:28: Writer ASR Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:28: Writer COM+ REGDB Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:28: Writer MSSearch Service Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:28: Writer Shadow Copy Optimization Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:28: Writer WMI Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:28: Writer BITS Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:28: Writer Registry Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:28: Deleting shadowcopy for path "\\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy375\" -2
2014-12-03 23:08:29: Deleting Shadowcopy for dir "E:\"
2014-12-03 23:08:29: rc=0 hasError=true state=0
2014-12-03 23:08:29: ClientService cmd: #<cmd>#START SC "C"#token=<token>
2014-12-03 23:08:29: orig_target=C:\ volpath=\\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy376
2014-12-03 23:08:29: Shadowcopy already present.
2014-12-03 23:08:29: rc=0 hasError=true state=0
2014-12-03 23:08:29: FileSrv: Received data...
2014-12-03 23:08:29: FileSrv: Received a Packet.
2014-12-03 23:08:29: FileSrv: Sending file (normal) <token>|C/Program Files/UrBackup/urbackup/backup_client.db
2014-12-03 23:08:29: FileSrv: Mapped name: \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy376\\Program Files\UrBackup\urbackup\backup_client.db
2014-12-03 23:08:30: FileSrv: Reading last file part
2014-12-03 23:08:30: FileSrv: Info: File End
2014-12-03 23:08:30: FileSrv: Closed file.
2014-12-03 23:08:30: FileSrv: Received data...
2014-12-03 23:08:30: FileSrv: Received a Packet.
2014-12-03 23:08:30: FileSrv: Sending file (normal) <token>|C/Program Files/UrBackup/urbackup/open_files.dat
2014-12-03 23:08:30: FileSrv: Mapped name: \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy376\\Program Files\UrBackup\urbackup\open_files.dat
2014-12-03 23:08:30: FileSrv: Reading last file part
2014-12-03 23:08:30: FileSrv: Info: File End
2014-12-03 23:08:30: FileSrv: Closed file.
2014-12-03 23:08:30: ClientService cmd: #<cmd>#STOP SC "C"#token=<token>
2014-12-03 23:08:31: Number of Writers: 11
2014-12-03 23:08:31: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:31: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:31: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:31: Writer System Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:31: Writer ASR Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:31: Writer WMI Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:31: Writer MSSearch Service Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:31: Writer COM+ REGDB Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:31: Writer BITS Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:31: Writer Shadow Copy Optimization Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:31: Writer Registry Writer has failure state VSS_WS_STABLE with error S_OK.
2014-12-03 23:08:31: Deleting shadowcopy for path "\\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy376\" -2
2014-12-03 23:08:31: Deleting Shadowcopy for dir "C:\"
2014-12-03 23:08:32: rc=0 hasError=true state=0
2014-12-03 23:08:32: ClientService cmd: #<cmd>#DID BACKUP
2014-12-03 23:08:32: rc=0 hasError=true state=0
2014-12-03 23:08:32: ClientService cmd: #<cmd>#2PING RUNNING pc_done=100&eta_ms=1707229#token=<token>
2014-12-03 23:08:32: rc=0 hasError=true state=0
2014-12-03 23:08:36: FileSrv: Recv Error in RecvMessage
2014-12-03 23:08:36: FileSrv: Deleting Memory...
2014-12-03 23:08:36: FileSrv: done.
2014-12-03 23:08:36: ClientService cmd: #<cmd>#2LOGDATA 1417676919 0-1417676845-Starting incremental file backup...
0-1417676905-Indexing of "D" done. 1 filesystem lookups 10886 db lookups and 1 db updates
0-1417676905-Indexing of "E" done. 1 filesystem lookups 2199 db lookups and 1 db updates
0-1417676905-Indexing of "C" done. 2 filesystem lookups 29388 db lookups and 2 db updates
0-1417676905-phil-PC: Loading file list...
0-1417676905-phil-PC: Calculating file tree differences...
0-1417676907-phil-PC: Calculating tree difference size...
0-1417676907-phil-PC: Linking unchanged and loading new files...
0-1417676909-Waiting for file transfers...
0-1417676914-Writing new file list...
0-1417676917-Waiting for file hashing and copying threads...
0-1417676918-Transferred 70.3355 MB - Average speed: 42.9134 MBit/s
0-1417676919-Time taken for backing up client phil-PC: 1m 14s
0-1417676919-Backup succeeded
2014-12-03 23:08:36: rc=0 hasError=true state=0
2014-12-03 23:08:39: ClientService cmd: PONG
2014-12-03 23:08:42: FileSrv: ClientThread deleted. 1024 KB Memory freed.
Any idea what’s going on, and how to get incremental file backups working? Again, this only appeared once the clients were updated to 1.4.5. Older client backends worked fine.