UrBackup Server 2.1.1 beta/Client 2.1.1 beta

uroni · September 29, 2016, 7:17pm

Major changes with server 2.1.x beta

Groups for client settings
Ability to reconnect during indexing if connection is broken
Define which volumes need to be snapshotted together (snapshot groups)

Major changes with client 2.1.x beta

Ability to reconnect during indexing if connection is broken
Improved image backup performance
Windows Backup API support (tested backup and restore with Microsoft SQL, tested backup with Microsoft Exchange and Hyper V)
File backups and restores use the change block data from the change block tracking driver now (you can install the beta client over a CBT client and this will work)
Define which volumes need to be snapshotted together (snapshot groups)

Changes with server 2.1.1 beta

Fix statistics table missing first column on copy/export
Show Windows components configuration on web interface in advanced
Show “Enable internet mode” group setting
Start off with global settings as default when creating new group
Start scheduled backups only if in backup window
Release session before client download to prevent web interface lock-up for the user
Use X-Forwarded-For as remote address if present
Add internet server and server URL validation
Log about backup being scheduled/manually started
Do not use group settings as global settings
CoW-raw Image backups with zfs snapshots
Increase async index timeout to 10min
Skip empty client on status screen
Fix symbolic link to file deletion on Windows

Changes with client 2.1.1 beta

Do not finish CBT if it is not available
Do not count interrupted sleep to prevent early image timeouts
Fix btrfs snapshots and use btrfs snapshots for btrfs file systems even if LVM/dattobd are configured
Exclude datto and overlay files everywhere not just in root
Added Linux uninstall script ( uninstall_urbackupclient ) – untested
Show where Linux client it is going to be installed
Disable Windows asking for Windows Backup after UrBackup client installation via registry key

Upgrade process

As always: Replace the executables (via the installers) and the database of the server/client will be updated on first running it.

Place the files from the update directory into C:\Program Files\UrBackupServer\urbackup or /var/urbackup to auto-update clients. Disable Download client from update server in the server settings to prevent the server from downloading the current version.

On Linux e.g. with:

cd /var/urbackup && wget -r -l1 --no-parent --reject "index.html*" -nH -nd -N "https://ssl.webpack.de/beta.urbackup.org/Client/2.1.1%20beta/update/"

Downgrade process (server)

Stop the UrBackup server, restore C:\Program Files\UrBackupServer\urbackup or /var/urbackup from a backup before upgrade and then install the previous version over the beta release.

Downloads

hippy1970 · September 29, 2016, 7:39pm

Sounds fantastic.
Great work, thanks.

ssemone · September 29, 2016, 10:28pm

Nice! I’ll get to testing this!

ssemone · September 29, 2016, 11:33pm

Never mind… I’m an idiot. It was just my browser caching the old version number. Carry on.

tarakesh · September 30, 2016, 8:17am

How?
Option for Raw Image is not visible altough ZFS is running

uroni · September 30, 2016, 8:32am

It needs to be able to create ZFS snapshots, so a FreeNAS jail is probably out (run it directly in FreeNAS).
Put the dataset name into /etc/urbackup/dataset (echo "tank/images" > /etc/urbackup/dataset) – should best be separate from the normal UrBackup storage dataset.
Run urbackup_snapshot_helper test to try if it works. Then you must unfortunately run UrBackup as root – at least on Linux. Otherwise mounting the ZFS snapshots does not work.
FreeBSD may be less effective because it does not implement file hole punching, so ZFSOnLinux is currently best used with this.

TomTomGo · September 30, 2016, 9:05am

Great, it works fine now, groups is really an awesome feature !

Which values are suitable for this field ?

I’m going to test this on a 2.0.35-cbt client updated to 2.1.1 beta with 2 volumes, feedback soon …

Many thanks for your hard work @Uroni !

Regards

mjyu51 · September 30, 2016, 6:15pm

What is difference between 2.0.35 and 2.1.1? Does this mean there will be two branches in the future?
Thanks,

ssemone · September 30, 2016, 6:32pm

My testing so far has been going well but I seem to be unable to get OS X clients to update silently (the Windows clients silently upgraded perfectly). I wonder if this is for a reason similar to the one I see when I try to download and install the OS X client from the server. I end up with a file like…

UrBackup Client (cas-bob-01).sh

If I try to execute that from the command line it fails. I end up renaming it by removing the parenthesis and spaces. I’ve also had to chmod a+x.

This is under OS X 10.12 (Sierra)

Let me know if there are any logs / etc I can provide.

TomTomGo · October 1, 2016, 1:22pm

Clients with more than one volume are not backed up correctly with server 2.1.1 / client 2.1.1.

What i’ve done :

Fresh server 2.1.1 install on Debian 8 with BTRFS storage,
Configuring server with my options,
Fresh install of 2.0.35-cbt client on a new client Windows 2012 R2 with 2 volumes (C: and S:),
Configuring the client on the server,
Upgrading 2.0.35-cbt client to 2.1.1.

Client configuration :

Doing an image backup of the client with this configuration backup only the S: volume.
I try to set “Volumes to snapshot in groups during image backups” and "Volumes to backup " both with values C,S but it doesn’t help, it backups in this case only the C: volume

Server side log :

2016-10-01 15:05:12: Starting unscheduled full image backup...
2016-10-01 15:05:12: Backing up SYSVOL...
2016-10-01 15:05:12: Starting unscheduled full image backup...
2016-10-01 15:05:24: Transferred 286.909 MB - Average speed: 205.707 MBit/s
2016-10-01 15:05:24: Script does not exist urbackup/post_full_imagebackup
2016-10-01 15:05:24: Updating statistics...
2016-10-01 15:05:24: Updating image stats...
2016-10-01 15:05:24: Updating file statistics...
2016-10-01 15:05:24: Done updating statistics.
2016-10-01 15:05:25: Backing up SYSVOL done.
2016-10-01 15:05:25: Backing up EFI System Partition...
2016-10-01 15:05:25: Starting unscheduled full image backup...
2016-10-01 15:05:25: Request of EFI System Partition failed. Reason: Not found
2016-10-01 15:05:25: Transferred 140 bytes - Average speed: 74.664 KBit/s
2016-10-01 15:05:25: Script does not exist urbackup/post_full_imagebackup
2016-10-01 15:05:25: msg=WAKEUP
2016-10-01 15:05:26: Backing up EFI System Partition done.
2016-10-01 15:05:26: Basing image backup on last incremental or full image backup
2016-10-01 15:05:26: Creating writable snapshot of previous image backup...
2016-10-01 15:05:26: msg=WAKEUP
2016-10-01 15:06:07: Change block tracking active. Max 277 MB have changed.
2016-10-01 15:06:07: Image backup is being backed up in a snapshot group together with volumes s:\
2016-10-01 15:06:18: Starting trimming image file (if possible)
2016-10-01 15:06:18: Trimmed 512 KB
2016-10-01 15:06:23: Transferred 194.027 MB - Average speed: 28.7189 MBit/s
2016-10-01 15:06:23: Script does not exist urbackup/post_full_imagebackup
2016-10-01 15:06:23: Time taken for backing up client SVGITEST3: 1m 11s
2016-10-01 15:06:23: Backup succeeded

Client side log :

2016-10-01 15:04:52: ClientService cmd: PONG
2016-10-01 15:05:12: ClientService cmd: #Ig0KMWKGy8ZqzeqwxWeEn#MBR driveletter=SYSVOL
2016-10-01 15:05:12: ClientService cmd: #Ig0KMWKGy8ZqzeqwxWeEn#2PING RUNNING pc_done=0&status_id=29&speed_bpms=0&total_
bytes=-1&done_bytes=0#token=158YTMONjujIdlXC3OtS
2016-10-01 15:05:12: rc=0 hasError=true state=0
2016-10-01 15:05:12: ClientService cmd: #Ig0KMWKGy8ZqzeqwxWeEn#FULL IMAGE letter=SYSVOL&token=158YTMONjujIdlXC3OtS&chec
ksum=1&bitmap=1&status_id=29&running_jobs=1
2016-10-01 15:05:12: Filesystem type is ntfs (\\?\Volume{f88dcaca-c6ad-11e5-80c2-806e6f6e6963})
2016-10-01 15:05:12: TotalNumberOfClusters=89599 numberOfClusters=89599 n_clusters=11200 StartingLcn=0 BitmapSize=89599
 r_bytes=11216
2016-10-01 15:05:12: FSINFO: blocksize=4096 size=367001088 has_error=false used_space=300220416
2016-10-01 15:05:13: ClientService cmd: STATUS#pw=iFs5AT69g8lYRlOviVmp6YvvdoUFlV
2016-10-01 15:05:20: rc=0 hasError=true state=4
2016-10-01 15:05:20: Sending full image done
2016-10-01 15:05:22: ClientService cmd: #Ig0KMWKGy8ZqzeqwxWeEn#2PING RUNNING pc_done=100&status_id=29&speed_bpms=0&tota
l_bytes=300220416&done_bytes=255287296#token=158YTMONjujIdlXC3OtS
2016-10-01 15:05:25: ClientService cmd: #Ig0KMWKGy8ZqzeqwxWeEn#MBR driveletter=ESP
2016-10-01 15:05:25: ClientService cmd: #Ig0KMWKGy8ZqzeqwxWeEn#2PING RUNNING pc_done=0&status_id=30&speed_bpms=0&total_
bytes=-1&done_bytes=0#token=158YTMONjujIdlXC3OtS
2016-10-01 15:05:25: rc=0 hasError=true state=0
2016-10-01 15:05:25: ClientService cmd: #Ig0KMWKGy8ZqzeqwxWeEn#FULL IMAGE letter=ESP&token=158YTMONjujIdlXC3OtS&checksu
m=1&bitmap=1&status_id=30&running_jobs=1
2016-10-01 15:05:25: ERROR: Not found
2016-10-01 15:05:25: rc=0 hasError=true state=0
2016-10-01 15:05:26: ClientService cmd: #Ig0KMWKGy8ZqzeqwxWeEn#MBR driveletter=C
2016-10-01 15:05:26: ClientService cmd: #Ig0KMWKGy8ZqzeqwxWeEn#2PING RUNNING pc_done=0&status_id=28&speed_bpms=0&total_
bytes=-1&done_bytes=0#token=158YTMONjujIdlXC3OtS
2016-10-01 15:05:26: rc=0 hasError=true state=0
2016-10-01 15:05:26: ClientService cmd: #Ig0KMWKGy8ZqzeqwxWeEn#INCR IMAGE letter=C:&hashsize=3909664&token=158YTMONjujI
dlXC3OtS&checksum=1&bitmap=1&status_id=28&running_jobs=1&cbitmapsize=1954860
2016-10-01 15:05:26: Script "C:\Program Files\UrBackup\preimagebackup.bat" does not exist
2016-10-01 15:05:26: Creating shadowcopy of "C:"...
2016-10-01 15:05:27: Number of Writers: 12
2016-10-01 15:05:27: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:27: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:27: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:27: Writer System Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:27: Writer WIDWriter has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:27: Writer SqlServerWriter has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:27: Writer Shadow Copy Optimization Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:27: Writer ASR Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:27: Writer Registry Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:27: Writer COM+ REGDB Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:27: Writer IIS Config Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:27: Writer WMI Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:27: ClientService cmd: STATUS#pw=iFs5AT69g8lYRlOviVmp6YvvdoUFlV
2016-10-01 15:05:28: Number of Writers: 12
2016-10-01 15:05:28: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:28: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:28: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:28: Writer System Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:28: Writer WIDWriter has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:28: Writer SqlServerWriter has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:28: Writer Shadow Copy Optimization Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:28: Writer ASR Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:28: Writer Registry Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:28: Writer COM+ REGDB Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:28: Writer IIS Config Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:28: Writer WMI Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:05:32: rc=0 hasError=true state=0
2016-10-01 15:05:35: rc=0 hasError=true state=0
2016-10-01 15:05:36: ClientService cmd: #Ig0KMWKGy8ZqzeqwxWeEn#2PING RUNNING pc_done=0&status_id=28&speed_bpms=0&total_
bytes=-1&done_bytes=0#token=158YTMONjujIdlXC3OtS
2016-10-01 15:05:46: ClientService cmd: #Ig0KMWKGy8ZqzeqwxWeEn#2PING RUNNING pc_done=0&status_id=28&speed_bpms=0&total_
bytes=-1&done_bytes=0#token=158YTMONjujIdlXC3OtS
2016-10-01 15:05:52: ClientService cmd: PONG
2016-10-01 15:05:56: ClientService cmd: #Ig0KMWKGy8ZqzeqwxWeEn#2PING RUNNING pc_done=0&status_id=28&speed_bpms=0&total_
bytes=-1&done_bytes=0#token=158YTMONjujIdlXC3OtS
2016-10-01 15:06:06: ClientService cmd: #Ig0KMWKGy8ZqzeqwxWeEn#2PING RUNNING pc_done=0&status_id=28&speed_bpms=0&total_
bytes=-1&done_bytes=0#token=158YTMONjujIdlXC3OtS
2016-10-01 15:06:06: Number of Writers: 12
2016-10-01 15:06:06: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:06:06: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:06:06: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-01 15:06:06: Writer System Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-01 15:06:06: Writer WIDWriter has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-01 15:06:06: Writer SqlServerWriter has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-01 15:06:06: Writer Shadow Copy Optimization Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with e
rror S_OK.
2016-10-01 15:06:06: Writer ASR Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-01 15:06:06: Writer Registry Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-01 15:06:06: Writer COM+ REGDB Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-01 15:06:06: Writer IIS Config Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-01 15:06:06: Writer WMI Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-01 15:06:06: Shadowcopy path: \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy11
2016-10-01 15:06:06: Shadowcopy path: \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy12
2016-10-01 15:06:06: done.
2016-10-01 15:06:06: Change block tracking reports 14.5 MB have changed on shadow copy \\?\GLOBALROOT\Device\HarddiskVo
lumeShadowCopy11
2016-10-01 15:06:06: Zeroing image hash data of volume C:...
2016-10-01 15:06:07: Change block tracking active on volume C:
2016-10-01 15:06:07: Zeroing file hash data of volume C:...
2016-10-01 15:06:07: Filesystem type is ntfs (\\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy11)
2016-10-01 15:06:07: TotalNumberOfClusters=15638527 numberOfClusters=15638527 n_clusters=1954816 StartingLcn=0 BitmapSi
ze=15638527 r_bytes=1954832
2016-10-01 15:06:07: Trying to exclude contents of file \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy11\HIBERFIL.SYS f
rom backup...
2016-10-01 15:06:07: Error opening file handle to \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy11\HIBERFIL.SYS
2016-10-01 15:06:07: Trying to exclude contents of file \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy11\pagefile.sys f
rom backup...
2016-10-01 15:06:07: Trying to exclude contents of file \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy11\swapfile.sys f
rom backup...
2016-10-01 15:06:07: Error opening file handle to \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy11\swapfile.sys
2016-10-01 15:06:07: Trying to exclude contents of file \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy11\System Volume
Information\{3808876b-c176-4e48-b7ae-04046e6cc752} from backup...
2016-10-01 15:06:07: FSINFO: blocksize=4096 size=64055410176 has_error=false used_space=58561830912
2016-10-01 15:06:08: Block did change: 1536 mixed=true
(...)
2016-10-01 15:06:18: Block did change: 11689984 mixed=false
2016-10-01 15:06:18: Sending image done
2016-10-01 15:06:18: rc=0 hasError=true state=4
2016-10-01 15:06:18: Deleting shadowcopy for path "\\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy11\" -2
2016-10-01 15:06:18: ClientService cmd: STATUS#pw=iFs5AT69g8lYRlOviVmp6YvvdoUFlV
2016-10-01 15:06:19: Deleting Shadowcopy for dir "C:\"
2016-10-01 15:06:19: Deleting Shadowcopy for dir "s:\"
2016-10-01 15:06:20: ClientService cmd: STATUS#pw=iFs5AT69g8lYRlOviVmp6YvvdoUFlV
2016-10-01 15:06:24: ClientService cmd: #Ig0KMWKGy8ZqzeqwxWeEn#2LOGDATA 1475327183 0-1475327112-Starting unscheduled full image backup...
0-1475327126-Basing image backup on last incremental or full image backup
0-1475327126-Creating writable snapshot of previous image backup...
0-1475327167-Change block tracking active. Max 277 MB have changed.
0-1475327167-Image backup is being backed up in a snapshot group together with volumes s:\
0-1475327183-Transferred 194.027 MB - Average speed: 28.7189 MBit/s
0-1475327183-Time taken for backing up client SVGITEST3: 1m 11s
0-1475327183-Backup succeeded

2016-10-01 15:06:24: rc=0 hasError=true state=0

Any ideas ?

Regards,

uroni · October 1, 2016, 2:19pm

Thanks for testing and posting the logs. I think I found the reason why it does not work with C, SYSVOL etc. Will probably be fixed with the next version.

TomTomGo · October 1, 2016, 2:23pm

Okay thanks @Uroni, will wait for the next version and make you a feedback.

Regards,

TomTomGo · October 4, 2016, 3:47pm

Group snapshoting is working now for both volumes C: and S: with client / server beta 2.1.2, thanks for fixing !
However, it leaves a VSS snapshot on the windows client for volume S: and CBT isn’t used for volume C:

Starting image backup :

S: volume backup takes few seconds (incremental with CBT and no data changes on the client => fast)
But C: doesn’t seem to use CBT
Client is up to date and CBT active for both volumes :

Client configuration :

Client log :

2016-10-04 17:16:34: Loaded -fileserv- plugin
2016-10-04 17:16:34: Loaded -fsimageplugin- plugin
2016-10-04 17:16:34: Loaded -cryptoplugin- plugin
2016-10-04 17:16:34: urbackupserver: Server started up successfully!
2016-10-04 17:16:34: FileSrv: Backup privileges set successfully
2016-10-04 17:16:34: FileSrv: Backup privileges set successfully (SE_SECURITY_NAME)
2016-10-04 17:16:34: FileSrv: Backup privileges set successfully (SE_RESTORE_NAME)
2016-10-04 17:16:34: FileSrv: Binding UDP socket at port 35622...
2016-10-04 17:16:34: FileSrv: done.
2016-10-04 17:16:34: FileSrv: Disabling new behavior...
2016-10-04 17:16:34: FileSrv: Servername: -SVGITEST3-
2016-10-04 17:16:34: FileSrv: Server started up successfully
2016-10-04 17:16:34: FileSrv: UDP Thread startet
2016-10-04 17:16:34: Started UrBackupClient Backend...
2016-10-04 17:16:34: Filesystem. Vol="\\?\Volume{f88dcaca-c6ad-11e5-80c2-806e6f6e6963}\" Name="rÃ©servÃ© au systÃ¨me" T
ype="ntfs" VPaths=0 Size=366997504
2016-10-04 17:16:34: Bootable flag set for volume
2016-10-04 17:16:34: Found potential candidate: \\?\Volume{f88dcaca-c6ad-11e5-80c2-806e6f6e6963}\ Score: 3
2016-10-04 17:16:34: Filesystem. Vol="\\?\Volume{3b4bba87-d16c-11e5-80d1-93c1fb6a80e4}\" Name="data" Type="ntfs" VPaths
=1 Size=107371032576
2016-10-04 17:16:34: Bootable flag not set for volume
2016-10-04 17:16:34: Filesystem. Vol="\\?\Volume{f88dcacb-c6ad-11e5-80c2-806e6f6e6963}\" Name="" Type="ntfs" VPaths=1 S
ize=64055406592
2016-10-04 17:16:34: Filesystem is System partition. Skipping...
2016-10-04 17:16:34: Filesystem. Vol="\\?\Volume{f88dcacf-c6ad-11e5-80c2-806e6f6e6963}\" Name="" Type="" VPaths=1 Size=
-1
2016-10-04 17:16:34: urbackupserver: No available slots... starting new Worker
2016-10-04 17:16:34: ClientService cmd: STATUS#pw=iFs5AT69g8lYRlOviVmp6YvvdoUFlV
2016-10-04 17:16:34: Bootable flag not set for volume
2016-10-04 17:16:34: Selected volume \\?\Volume{f88dcaca-c6ad-11e5-80c2-806e6f6e6963}
2016-10-04 17:16:34: System dir: C:\Windows
2016-10-04 17:16:34: Volpath: \\.\C:
2016-10-04 17:16:34: Device is not GPT formatted (0)
2016-10-04 17:16:34: Found no EFI System Partition
2016-10-04 17:16:35: Looking for old Sessions... 0 sessions
2016-10-04 17:16:35: Internet only mode not enabled. Waiting for local server for 3:00...
2016-10-04 17:16:35: Cannot read data from device (D:\)
2016-10-04 17:16:35: Device D:\ isn't NTFS formatted
2016-10-04 17:16:42: ClientService cmd: #Iq2yRPuD4TmyhTs4CsOIf#1CHANNEL capa=65047&token=158YTMONjujIdlXC3OtS&restore_v
ersion=1
2016-10-04 17:16:42: New channel: Number of Channels: 1
2016-10-04 17:17:13: ClientService cmd: STATUS DETAIL#pw=iFs5AT69g8lYRlOviVmp6YvvdoUFlV
2016-10-04 17:17:14: ClientService cmd: STATUS DETAIL#pw=iFs5AT69g8lYRlOviVmp6YvvdoUFlV
2016-10-04 17:17:15: ClientService cmd: STATUS DETAIL#pw=iFs5AT69g8lYRlOviVmp6YvvdoUFlV
2016-10-04 17:17:16: rc=0 hasError=true state=0
2016-10-04 17:17:25: ClientService cmd: STATUS#pw=iFs5AT69g8lYRlOviVmp6YvvdoUFlV
2016-10-04 17:17:42: ClientService cmd: PONG
2016-10-04 17:17:50: ClientService cmd: #Iq2yRPuD4TmyhTs4CsOIf#2PING RUNNING pc_done=0&status_id=6&speed_bpms=0&total_b
ytes=-1&done_bytes=0#token=158YTMONjujIdlXC3OtS
2016-10-04 17:17:50: ClientService cmd: #Iq2yRPuD4TmyhTs4CsOIf#MBR driveletter=S
2016-10-04 17:17:50: rc=0 hasError=true state=0
2016-10-04 17:17:51: ClientService cmd: #Iq2yRPuD4TmyhTs4CsOIf#INCR IMAGE letter=S:&hashsize=6553440&token=158YTMONjujI
dlXC3OtS&checksum=1&bitmap=1&status_id=6&running_jobs=1&cbitmapsize=3276748
2016-10-04 17:17:51: Script "C:\Program Files\UrBackup\preimagebackup.bat" does not exist
2016-10-04 17:17:51: Creating shadowcopy of "S:"...
2016-10-04 17:17:52: ClientService cmd: STATUS#pw=iFs5AT69g8lYRlOviVmp6YvvdoUFlV
2016-10-04 17:17:53: Number of Writers: 12
2016-10-04 17:17:53: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-04 17:17:53: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-04 17:17:53: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-04 17:17:53: Writer System Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-04 17:17:53: Writer WIDWriter has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-04 17:17:53: Writer SqlServerWriter has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-04 17:17:53: Writer Shadow Copy Optimization Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with e
rror S_OK.
2016-10-04 17:17:53: Writer ASR Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-04 17:17:53: Writer IIS Config Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-04 17:17:53: Writer WMI Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-04 17:17:53: Writer COM+ REGDB Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-04 17:17:53: Writer Registry Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-04 17:17:54: Number of Writers: 12
2016-10-04 17:17:54: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-04 17:17:54: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-04 17:17:54: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-04 17:17:54: Writer System Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-04 17:17:54: Writer WIDWriter has failure state VSS_WS_STABLE with error S_OK.
2016-10-04 17:17:54: Writer SqlServerWriter has failure state VSS_WS_STABLE with error S_OK.
2016-10-04 17:17:54: Writer Shadow Copy Optimization Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-04 17:17:54: Writer ASR Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-04 17:17:54: Writer IIS Config Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-04 17:17:54: Writer WMI Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-04 17:17:54: Writer COM+ REGDB Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-04 17:17:54: Writer Registry Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-04 17:18:00: ClientService cmd: #Iq2yRPuD4TmyhTs4CsOIf#2PING RUNNING pc_done=0&status_id=6&speed_bpms=0&total_b
ytes=-1&done_bytes=0#token=158YTMONjujIdlXC3OtS
2016-10-04 17:18:10: ClientService cmd: #Iq2yRPuD4TmyhTs4CsOIf#2PING RUNNING pc_done=0&status_id=6&speed_bpms=0&total_b
ytes=-1&done_bytes=0#token=158YTMONjujIdlXC3OtS
2016-10-04 17:18:20: ClientService cmd: #Iq2yRPuD4TmyhTs4CsOIf#2PING RUNNING pc_done=0&status_id=6&speed_bpms=0&total_b
ytes=-1&done_bytes=0#token=158YTMONjujIdlXC3OtS
2016-10-04 17:18:30: ClientService cmd: #Iq2yRPuD4TmyhTs4CsOIf#2PING RUNNING pc_done=0&status_id=6&speed_bpms=0&total_b
ytes=-1&done_bytes=0#token=158YTMONjujIdlXC3OtS
2016-10-04 17:18:32: Number of Writers: 12
2016-10-04 17:18:32: Writer Task Scheduler Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-04 17:18:32: Writer VSS Metadata Store Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-04 17:18:32: Writer Performance Counters Writer has failure state VSS_WS_STABLE with error S_OK.
2016-10-04 17:18:32: Writer System Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-04 17:18:32: Writer WIDWriter has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-04 17:18:32: Writer SqlServerWriter has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-04 17:18:32: Writer Shadow Copy Optimization Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with e
rror S_OK.
2016-10-04 17:18:32: Writer ASR Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-04 17:18:32: Writer IIS Config Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-04 17:18:32: Writer WMI Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-04 17:18:32: Writer COM+ REGDB Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-04 17:18:32: Writer Registry Writer has failure state VSS_WS_WAITING_FOR_BACKUP_COMPLETE with error S_OK.
2016-10-04 17:18:33: Shadowcopy path: \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy17
2016-10-04 17:18:33: Shadowcopy path: \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy18
2016-10-04 17:18:33: done.
2016-10-04 17:18:33: Change block tracking reports 3.5 MB have changed on shadow copy \\?\GLOBALROOT\Device\HarddiskVol
umeShadowCopy17
2016-10-04 17:18:33: Zeroing image hash data of volume S:...
2016-10-04 17:18:33: Change block tracking active on volume S:
2016-10-04 17:18:33: Zeroing file hash data of volume S:...
2016-10-04 17:18:33: Filesystem type is ntfs (\\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy17)
2016-10-04 17:18:33: TotalNumberOfClusters=26213631 numberOfClusters=26213631 n_clusters=3276704 StartingLcn=0 BitmapSi
ze=26213631 r_bytes=3276720
2016-10-04 17:18:33: Trying to exclude contents of file \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy17\System Volume
Information\{3808876b-c176-4e48-b7ae-04046e6cc752} from backup...
2016-10-04 17:18:33: Trying to exclude contents of file \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy17\System Volume
Information\{b58e45db-871a-11e6-80fc-ad78307d26cc}{3808876b-c176-4e48-b7ae-04046e6cc752} from backup...
2016-10-04 17:18:33: Trying to exclude contents of file \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy17\System Volume
Information\{b58e461d-871a-11e6-80fc-ad78307d26cc}{3808876b-c176-4e48-b7ae-04046e6cc752} from backup...
2016-10-04 17:18:33: Trying to exclude contents of file \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy17\System Volume
Information\{b58e461e-871a-11e6-80fc-ad78307d26cc}{3808876b-c176-4e48-b7ae-04046e6cc752} from backup...
2016-10-04 17:18:33: FSINFO: blocksize=4096 size=107371036160 has_error=false used_space=90428526592
2016-10-04 17:18:34: ClientService cmd: #Iq2yRPuD4TmyhTs4CsOIf#MBR driveletter=SYSVOL
2016-10-04 17:18:34: ClientService cmd: #Iq2yRPuD4TmyhTs4CsOIf#2PING RUNNING pc_done=0&status_id=8&speed_bpms=0&total_b
ytes=-1&done_bytes=0#token=158YTMONjujIdlXC3OtS
2016-10-04 17:18:34: rc=0 hasError=true state=0
2016-10-04 17:18:35: ClientService cmd: #Iq2yRPuD4TmyhTs4CsOIf#FULL IMAGE letter=SYSVOL&token=158YTMONjujIdlXC3OtS&chec
ksum=1&bitmap=1&status_id=8&running_jobs=2
2016-10-04 17:18:35: Filesystem type is ntfs (\\?\Volume{f88dcaca-c6ad-11e5-80c2-806e6f6e6963})
2016-10-04 17:18:35: TotalNumberOfClusters=89599 numberOfClusters=89599 n_clusters=11200 StartingLcn=0 BitmapSize=89599
 r_bytes=11216
2016-10-04 17:18:35: FSINFO: blocksize=4096 size=367001088 has_error=false used_space=300220416
2016-10-04 17:18:35: Block did change: 0 mixed=false
2016-10-04 17:18:35: Block did change: 9984 mixed=false
[... CUT ...]
2016-10-04 17:18:38: Block did change: 3139584 mixed=false
2016-10-04 17:18:38: ClientService cmd: STATUS#pw=iFs5AT69g8lYRlOviVmp6YvvdoUFlV
2016-10-04 17:18:39: Sending image done
2016-10-04 17:18:39: rc=0 hasError=true state=4
2016-10-04 17:18:39: ClientService cmd: STATUS#pw=iFs5AT69g8lYRlOviVmp6YvvdoUFlV
2016-10-04 17:18:39: Deleting shadowcopy for path "\\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy17\" -2
2016-10-04 17:18:40: Deleting Shadowcopy for dir "S:\"
2016-10-04 17:18:40: Deleting Shadowcopy for dir "c:\"
2016-10-04 17:18:40: ClientService cmd: #Iq2yRPuD4TmyhTs4CsOIf#2PING RUNNING pc_done=100&status_id=6&speed_bpms=0&total
_bytes=27787264&done_bytes=3674112#token=158YTMONjujIdlXC3OtS
2016-10-04 17:18:42: ClientService cmd: PONG
2016-10-04 17:18:44: ClientService cmd: #Iq2yRPuD4TmyhTs4CsOIf#2PING RUNNING pc_done=94&status_id=8&speed_bpms=0&total_
bytes=300220416&done_bytes=281817088#token=158YTMONjujIdlXC3OtS
2016-10-04 17:18:46: ClientService cmd: STATUS#pw=iFs5AT69g8lYRlOviVmp6YvvdoUFlV
2016-10-04 17:18:47: Sending full image done
2016-10-04 17:18:49: ClientService cmd: #Iq2yRPuD4TmyhTs4CsOIf#2LOGDATA 1475594328 0-1475594270-Starting unscheduled in
cremental image backup...
0-1475594270-Basing image backup on last incremental or full image backup
0-1475594270-Creating writable snapshot of previous image backup...
0-1475594314-Change block tracking active. Max 26.5 MB have changed.
0-1475594314-Image backup is being backed up in a snapshot group together with volumes c:\
0-1475594328-Transferred 30.5446 MB - Average speed: 4.47667 MBit/s
0-1475594328-Time taken for backing up client SVGITEST3: 58s
0-1475594328-Backup succeeded

2016-10-04 17:18:49: rc=0 hasError=true state=0
2016-10-04 17:18:49: ClientService cmd: #Iq2yRPuD4TmyhTs4CsOIf#MBR driveletter=ESP
2016-10-04 17:18:49: ClientService cmd: #Iq2yRPuD4TmyhTs4CsOIf#2PING RUNNING pc_done=0&status_id=9&speed_bpms=0&total_b
ytes=-1&done_bytes=0#token=158YTMONjujIdlXC3OtS
2016-10-04 17:18:49: rc=0 hasError=true state=0
2016-10-04 17:18:49: ClientService cmd: #Iq2yRPuD4TmyhTs4CsOIf#FULL IMAGE letter=ESP&token=158YTMONjujIdlXC3OtS&checksu
m=1&bitmap=1&status_id=9&running_jobs=1
2016-10-04 17:18:49: ERROR: Not found
2016-10-04 17:18:49: rc=0 hasError=true state=0
2016-10-04 17:18:50: rc=0 hasError=true state=0
2016-10-04 17:18:50: ClientService cmd: #Iq2yRPuD4TmyhTs4CsOIf#2PING RUNNING pc_done=0&status_id=7&speed_bpms=0&total_b
ytes=-1&done_bytes=0#token=158YTMONjujIdlXC3OtS
2016-10-04 17:18:50: ClientService cmd: #Iq2yRPuD4TmyhTs4CsOIf#MBR driveletter=c
2016-10-04 17:18:50: rc=0 hasError=true state=0
2016-10-04 17:18:51: ClientService cmd: #Iq2yRPuD4TmyhTs4CsOIf#INCR IMAGE letter=c:&hashsize=3909664&token=158YTMONjujI
dlXC3OtS&checksum=1&bitmap=1&status_id=7&running_jobs=1&shadowid=2&cbitmapsize=1954860
2016-10-04 17:18:52: Filesystem type is ntfs (\\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy18)
2016-10-04 17:18:52: TotalNumberOfClusters=15638527 numberOfClusters=15638527 n_clusters=1954816 StartingLcn=0 BitmapSi
ze=15638527 r_bytes=1954832
2016-10-04 17:18:52: Trying to exclude contents of file \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy18\pagefile.sys f
rom backup...
2016-10-04 17:18:52: Trying to exclude contents of file \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy18\System Volume
Information\{3808876b-c176-4e48-b7ae-04046e6cc752} from backup...
2016-10-04 17:18:52: FSINFO: blocksize=4096 size=64055410176 has_error=false used_space=58503569408
2016-10-04 17:18:52: Block did change: 1536 mixed=true
2016-10-04 17:18:53: ClientService cmd: STATUS#pw=iFs5AT69g8lYRlOviVmp6YvvdoUFlV
2016-10-04 17:18:53: Block did change: 10368 mixed=false
[... CUT ...]
2016-10-04 17:40:04: Block did change: 15468928 mixed=true
2016-10-04 17:40:05: ClientService cmd: STATUS#pw=iFs5AT69g8lYRlOviVmp6YvvdoUFlV
2016-10-04 17:40:06: ClientService cmd: STATUS#pw=iFs5AT69g8lYRlOviVmp6YvvdoUFlV
2016-10-04 17:40:11: ClientService cmd: STATUS#pw=iFs5AT69g8lYRlOviVmp6YvvdoUFlV
2016-10-04 17:40:13: ClientService cmd: #Iq2yRPuD4TmyhTs4CsOIf#2PING RUNNING pc_done=99&eta_ms=1284933&status_id=7&spee
d_bpms=6.97393&total_bytes=64055410688&done_bytes=63360741376#token=158YTMONjujIdlXC3OtS
2016-10-04 17:40:15: ClientService cmd: STATUS#pw=iFs5AT69g8lYRlOviVmp6YvvdoUFlV
2016-10-04 17:40:16: ClientService cmd: STATUS#pw=iFs5AT69g8lYRlOviVmp6YvvdoUFlV
2016-10-04 17:40:21: rc=0 hasError=true state=4
2016-10-04 17:40:21: Sending image done
2016-10-04 17:40:23: rc=0 hasError=true state=0
2016-10-04 17:40:25: ClientService cmd: #Iq2yRPuD4TmyhTs4CsOIf#2LOGDATA 1475595623 0-1475594314-Starting unscheduled in
cremental image backup...
0-1475594314-Image backup is being backed up in a snapshot group together with volumes S:
0-1475594330-Basing image backup on last incremental or full image backup
0-1475594330-Creating writable snapshot of previous image backup...
0-1475595623-Transferred 376.519 MB - Average speed: 2.44532 MBit/s
0-1475595623-Time taken for backing up client SVGITEST3: 21m 48s
0-1475595623-Backup succeeded

Server log :

2016-10-04 17:17:50: msg=START IMAGE INCR
2016-10-04 17:17:50: Cannot do image backup because internet_no_images=true
2016-10-04 17:17:50: Starting unscheduled incremental image backup...
2016-10-04 17:17:50: Basing image backup on last incremental or full image backup
2016-10-04 17:17:50: Creating writable snapshot of previous image backup...
2016-10-04 17:18:34: Change block tracking active. Max 26.5 MB have changed.
2016-10-04 17:18:34: Image backup is being backed up in a snapshot group together with volumes c:\
2016-10-04 17:18:34: msg=WAKEUP
2016-10-04 17:18:34: Starting unscheduled incremental image backup...
2016-10-04 17:18:34: Image backup is being backed up in a snapshot group together with volumes S:
2016-10-04 17:18:34: Backing up SYSVOL...
2016-10-04 17:18:34: Starting unscheduled full image backup...
2016-10-04 17:18:39: Starting trimming image file (if possible)
2016-10-04 17:18:39: Trimmed 0 bytes
2016-10-04 17:18:48: Transferred 30.5446 MB - Average speed: 4.47667 MBit/s
2016-10-04 17:18:48: Script does not exist urbackup/post_incr_imagebackup
2016-10-04 17:18:48: Time taken for backing up client SVGITEST3: 58s
2016-10-04 17:18:48: Backup succeeded
2016-10-04 17:18:48: Updating statistics...
2016-10-04 17:18:48: Updating image stats...
2016-10-04 17:18:48: Updating file statistics...
2016-10-04 17:18:48: Done updating statistics.
2016-10-04 17:18:49: Transferred 286.909 MB - Average speed: 177.242 MBit/s
2016-10-04 17:18:49: Script does not exist urbackup/post_full_imagebackup
2016-10-04 17:18:49: msg=WAKEUP
2016-10-04 17:18:49: Backing up SYSVOL done.
2016-10-04 17:18:49: Backing up EFI System Partition...
2016-10-04 17:18:49: Starting unscheduled full image backup...
2016-10-04 17:18:49: Request of EFI System Partition failed. Reason: Not found
2016-10-04 17:18:49: Transferred 139 bytes - Average speed: 69.496 KBit/s
2016-10-04 17:18:49: Script does not exist urbackup/post_full_imagebackup
2016-10-04 17:18:49: Updating statistics...
2016-10-04 17:18:49: Updating image stats...
2016-10-04 17:18:49: Updating file statistics...
2016-10-04 17:18:50: Done updating statistics.
2016-10-04 17:18:50: msg=WAKEUP
2016-10-04 17:18:50: Backing up EFI System Partition done.
2016-10-04 17:18:50: Basing image backup on last incremental or full image backup
2016-10-04 17:18:50: Creating writable snapshot of previous image backup...
2016-10-04 17:18:51: msg=WAKEUP
[...]
2016-10-04 17:40:21: Starting trimming image file (if possible)
2016-10-04 17:40:21: Trimmed 0 bytes
2016-10-04 17:40:23: Transferred 376.519 MB - Average speed: 2.44532 MBit/s
2016-10-04 17:40:23: Script does not exist urbackup/post_incr_imagebackup
2016-10-04 17:40:23: Time taken for backing up client SVGITEST3: 21m 48s
2016-10-04 17:40:23: Backup succeeded
2016-10-04 17:40:23: Updating statistics...
2016-10-04 17:40:24: Updating image stats...
2016-10-04 17:40:24: Updating file statistics...
2016-10-04 17:40:24: msg=WAKEUP
2016-10-04 17:40:24: Done updating statistics.

Regards,

TomTomGo · October 7, 2016, 10:12am

@uroni

Any news about this ? Did you reproduce ?

Regards,

uroni · October 7, 2016, 12:42pm

Yes, thanks again. I think I fixed it and will release a new version soon.

Vittore_Zen · October 10, 2016, 8:03am

Any news about build i386 for Debian of this beta?

v.