Not waiting to retry shadow copy


#1

Just got an alert where backup succeeded but it has an odd error/warning message. Looks like shadow copies were being retried immediately instead of waiting the stated 30 seconds. Were the two error lines shadow copy attempts for two different things that UrBackup logged identically, or was it the original and the retry with less than one second between them? Either one looks like a bug. The second because the 30s wait failed, and the first for not saying clearly what was being shadow copied. I note the next 9 messages (info level) have the same timestamp as the first error, so a third possibility is timestamps in the error reporter are bad. Either that or UrBackup does a lot in a fraction of a second.

Client 2.3.4 on Windows 7 Pro, selecting C:\Users for file backup.
Server 2.3.8 on Windows 2008 R2 Standard.

Text of alert email:

UrBackup just did an incremental file backup of “NECD01s”.

Report:
( 16 infos, 2 warnings, 2 errors)

2019-04-21 17:02:23(info): Starting scheduled incremental file backup…
2019-04-21 17:04:54(error): backupcom->StartSnapshotSet(&dir->ref->ssetid) failed. VSS error code VSS_E_SNAPSHOT_SET_IN_PROGRESS
2019-04-21 17:04:54(warning): Retrying starting shadow copy in 30s
2019-04-21 17:04:54(error): backupcom->StartSnapshotSet(&dir->ref->ssetid) failed. VSS error code VSS_E_SNAPSHOT_SET_IN_PROGRESS
2019-04-21 17:04:54(warning): Retrying starting shadow copy in 30s
2019-04-21 17:04:54(info): CBT not enabled for volume “c:”
2019-04-21 17:04:54(info): Scanning for changed hard links on volume of “C:”…
2019-04-21 17:04:54(info): Following symbolic link at “C:\Users\All Users” to “C:\ProgramData” confirms symlink backup target “.symlink_ProgramData” to “C:\ProgramData”
2019-04-21 17:04:54(info): Indexing of “Users” done. 1 filesystem lookups 3334 db lookups and 0 db updates
2019-04-21 17:04:54(info): NECD01s: Loading file list…
2019-04-21 17:04:54(info): NECD01s: Calculating file tree differences…
2019-04-21 17:04:54(info): NECD01s: Calculating tree difference size…
2019-04-21 17:04:54(info): NECD01s: Linking unchanged and loading new files…
2019-04-21 17:05:08(info): Waiting for file transfers…
2019-04-21 17:05:19(info): Waiting for file hashing and copying threads…
2019-04-21 17:05:22(info): Writing new file list…
2019-04-21 17:05:22(info): All metadata was present
2019-04-21 17:05:23(info): Transferred 65.4441 MB - Average speed: 22.0635 MBit/s
2019-04-21 17:05:23(info): Time taken for backing up client NECD01s: 3m
2019-04-21 17:05:23(info): Backup completed with issues