Image backups stopped working on one client

client
1

The image backups now fail on my Windows system quadriga. I have re-installed the client and restarted the server with no effect.

Any hints will be appreciated.

Here’s the client log:

2016-10-20 16:59:38: ERROR: GetVolumeInformationW failed. Volume: ‘\?\Volume{ec3beb87-3953-421e-9e96-6cf34f8212d8}’
2016-10-20 16:59:38: ERROR: Error reading data from device (\?\Volume{ec3beb87-3953-421e-9e96-6cf34f8212d8})
2016-10-20 16:59:38: ERROR: Opening filesystem on device failed. Stopping.

And here’s the debug log:

2016-10-20 16:59:38: ERROR: GetVolumeInformationW failed. Volume: ‘\?\Volume{ec3beb87-3953-421e-9e96-6cf34f8212d8}’
2016-10-20 16:59:38: ERROR: Error reading data from device (\?\Volume{ec3beb87-3953-421e-9e96-6cf34f8212d8})
2016-10-20 16:59:38: ERROR: Opening filesystem on device failed. Stopping.
2016-10-20 16:59:58: ERROR: Recvfrom error in CUDPThread::UdpStep
2016-10-20 16:59:58: ERROR: Last error: 10058
2016-10-20 17:06:27: Loaded -fileserv- plugin
2016-10-20 17:06:27: Loaded -fsimageplugin- plugin
2016-10-20 17:06:27: Loaded -cryptoplugin- plugin
2016-10-20 17:06:27: urbackupserver: Server started up successfully!
2016-10-20 17:06:27: FileSrv: Backup privileges set successfully
2016-10-20 17:06:27: FileSrv: Backup privileges set successfully (SE_SECURITY_NAME)
2016-10-20 17:06:27: FileSrv: Backup privileges set successfully (SE_RESTORE_NAME)
2016-10-20 17:06:27: FileSrv: Binding UDP socket at port 35622…
2016-10-20 17:06:27: FileSrv: done.
2016-10-20 17:06:27: FileSrv: Disabling new behavior…
2016-10-20 17:06:27: FileSrv: Servername: -QUADRIGA-
2016-10-20 17:06:27: FileSrv: Server started up successfully
2016-10-20 17:06:27: FileSrv: UDP Thread startet
2016-10-20 17:06:27: Started UrBackupClient Backend…
2016-10-20 17:06:27: Filesystem. Vol="\?\Volume{2861ecd0-66f0-4b12-9a6e-fe3e4f717cc1}" Name=“data01” Type=“ntfs” VPaths=1 Size=1000068870144
2016-10-20 17:06:27: GPT formated hard disk encountered. No bootable flag. Attributes = 0
2016-10-20 17:06:27: Bootable flag not set for volume
2016-10-20 17:06:27: Filesystem. Vol="\?\Volume{dc7e0207-47b6-48c7-8066-ce398c4c23c3}" Name="" Type=“ntfs” VPaths=1 Size=186734432256
2016-10-20 17:06:27: Filesystem is System partition. Skipping…
2016-10-20 17:06:27: Filesystem. Vol="\?\Volume{af26ea0f-6cad-11e6-a89d-f0795971108e}" Name=“portable” Type=“fat32” VPaths=1 Size=15828254720
2016-10-20 17:06:27: Bootable flag set for volume
2016-10-20 17:06:27: Found potential candidate: \?\Volume{af26ea0f-6cad-11e6-a89d-f0795971108e}\ Score: 2
2016-10-20 17:06:27: Filesystem. Vol="\?\Volume{ec3beb87-3953-421e-9e96-6cf34f8212d8}" Name="" Type="" VPaths=0 Size=-1
2016-10-20 17:06:27: GPT formated hard disk encountered. No bootable flag. Attributes = -9223372036854775807
2016-10-20 17:06:27: Do not automount is set
2016-10-20 17:06:27: System partition is set
2016-10-20 17:06:27: Bootable flag set for volume
2016-10-20 17:06:27: Found potential candidate: \?\Volume{ec3beb87-3953-421e-9e96-6cf34f8212d8}\ Score: 3
2016-10-20 17:06:27: Filesystem. Vol="\?\Volume{06fbc888-c846-11e5-a7c8-f0795971108e}" Name="" Type=“fat32” VPaths=1 Size=16074391552
2016-10-20 17:06:27: Bootable flag not set for volume
2016-10-20 17:06:27: Filesystem. Vol="\?\Volume{b3d5bc8f-c844-11e5-a7c5-806e6f6e6963}" Name="" Type="" VPaths=1 Size=-1
2016-10-20 17:06:28: Bootable flag not set for volume
2016-10-20 17:06:28: Not on Physical Device ‘C’: \?\Volume{af26ea0f-6cad-11e6-a89d-f0795971108e} (E:)
2016-10-20 17:06:28: Selected volume \?\Volume{ec3beb87-3953-421e-9e96-6cf34f8212d8}
2016-10-20 17:06:28: System dir: C:\WINDOWS
2016-10-20 17:06:28: Volpath: \.\C:
2016-10-20 17:06:28: EFI partition with type UUID {C12A7328-F81F-11D2-BA4B-00A0C93EC93B}
2016-10-20 17:06:28: EFI System Partition is at \?\GLOBALROOT\Device\Harddisk2\Partition1
2016-10-20 17:06:28: urbackupserver: No available slots… starting new Worker
2016-10-20 17:06:28: ClientService cmd: STATUS#pw=lSbsOkoSGbXbUcPRwNDh0Sc7iufLtc
2016-10-20 17:06:28: Looking for old Sessions… 0 sessions
2016-10-20 17:06:28: Internet only mode not enabled. Waiting for local server for 3:00…
2016-10-20 17:06:29: ClientService cmd: #Iz8Et0bTAIHaAK2PhMCTm#1CHANNEL capa=0&token=0ykD5ujSYDT4GI9dnbEo&restore_version=1
2016-10-20 17:06:29: New channel: Number of Channels: 1
2016-10-20 17:06:40: ClientService cmd: START IMAGE INCR#pw=lSbsOkoSGbXbUcPRwNDh0Sc7iufLtc
2016-10-20 17:06:40: rc=0 hasError=true state=0
2016-10-20 17:06:40: ClientService cmd: #Iz8Et0bTAIHaAK2PhMCTm#MBR driveletter=SYSVOL
2016-10-20 17:06:40: ERROR: GetVolumeInformationW failed. Volume: ‘\?\Volume{ec3beb87-3953-421e-9e96-6cf34f8212d8}’
2016-10-20 17:06:40: ClientService cmd: #Iz8Et0bTAIHaAK2PhMCTm#2PING RUNNING pc_done=0&status_id=4&speed_bpms=0&total_bytes=-1&done_bytes=0#token=0ykD5ujSYDT4GI9dnbEo
2016-10-20 17:06:40: rc=0 hasError=true state=0
2016-10-20 17:06:40: ClientService cmd: #Iz8Et0bTAIHaAK2PhMCTm#FULL IMAGE letter=SYSVOL&token=0ykD5ujSYDT4GI9dnbEo&checksum=1&bitmap=1&status_id=4&running_jobs=1
2016-10-20 17:06:40: ERROR: Error reading data from device (\?\Volume{ec3beb87-3953-421e-9e96-6cf34f8212d8})
2016-10-20 17:06:40: ERROR: Opening filesystem on device failed. Stopping.
2016-10-20 17:06:40: Device file: “\?\Volume{ec3beb87-3953-421e-9e96-6cf34f8212d8}”
2016-10-20 17:06:40: Sending full image done
2016-10-20 17:06:41: ClientService cmd: STATUS#pw=lSbsOkoSGbXbUcPRwNDh0Sc7iufLtc
2016-10-20 17:06:44: ClientService cmd: #Iz8Et0bTAIHaAK2PhMCTm#2LOGDATA 1476997181 0-1476997180-Starting incremental image backup…
2-1476997181-Backing up System Reserved (SYSVOL) partition failed. Image backup failed
0-1476997181-Time taken for backing up client QUADRIGA:
2-1476997181-Backup failed

2016-10-20 17:06:44: rc=0 hasError=true state=0
2016-10-20 17:06:44: ClientService cmd: #Iz8Et0bTAIHaAK2PhMCTm#2LOGDATA 1476997603 0-1476997602-Starting incremental image backup…
2-1476997603-Backing up System Reserved (SYSVOL) partition failed. Image backup failed
0-1476997603-Time taken for backing up client QUADRIGA:
2-1476997603-Backup failed

2

Unfortunately it does not log the error code. Could you watch the process (UrBackupClientBackend.exe) in procmon to find that out?

3

And it would be interesting to get more information about what kind of device/partition “portable” is.

4

Portable is a usb memory stick with my portable apps (eg hwinfo, treesize) on it. I forgot to pull it out. It doesn’t seem to affect the backup either way.

When I’m home Monday, I’ll redo the tests without portable and use procmon.

Thanks for responding.

5

Enabled procmon, initiated a full image backup using the desktop app and grabbed some logs. Nothing jumps out at me.

debug.log …

2016-10-25 12:42:44: ClientService cmd: PONG
2016-10-25 12:43:44: ClientService cmd: PONG
2016-10-25 12:44:44: ClientService cmd: PONG
2016-10-25 12:45:19: ClientService cmd: FSTATUS#pw=lSbsOkoSGbXbUcPRwNDh0Sc7iufLtc
2016-10-25 12:45:21: ClientService cmd: STATUS#pw=lSbsOkoSGbXbUcPRwNDh0Sc7iufLtc
2016-10-25 12:45:44: ClientService cmd: PONG
2016-10-25 12:45:54: ClientService cmd: START IMAGE FULL#pw=lSbsOkoSGbXbUcPRwNDh0Sc7iufLtc
2016-10-25 12:45:54: rc=0 hasError=true state=0
2016-10-25 12:45:54: ClientService cmd: #IAnbfh6Zmcf7DGt3H5CuW#MBR driveletter=SYSVOL
2016-10-25 12:45:54: ERROR: GetVolumeInformationW failed. Volume: ‘\?\Volume{ec3beb87-3953-421e-9e96-6cf34f8212d8}’
2016-10-25 12:45:54: ClientService cmd: #IAnbfh6Zmcf7DGt3H5CuW#2PING RUNNING pc_done=0&status_id=64&speed_bpms=0&total_bytes=-1&done_bytes=0#token=0ykD5ujSYDT4GI9dnbEo
2016-10-25 12:45:54: rc=0 hasError=true state=0
2016-10-25 12:45:54: ClientService cmd: #IAnbfh6Zmcf7DGt3H5CuW#FULL IMAGE letter=SYSVOL&token=0ykD5ujSYDT4GI9dnbEo&checksum=1&bitmap=1&status_id=64&running_jobs=1
2016-10-25 12:45:54: ERROR: Error reading data from device (\?\Volume{ec3beb87-3953-421e-9e96-6cf34f8212d8})
2016-10-25 12:45:54: ERROR: Opening filesystem on device failed. Stopping.
2016-10-25 12:45:54: Device file: “\?\Volume{ec3beb87-3953-421e-9e96-6cf34f8212d8}”
2016-10-25 12:45:54: Sending full image done
2016-10-25 12:45:55: ClientService cmd: STATUS#pw=lSbsOkoSGbXbUcPRwNDh0Sc7iufLtc
2016-10-25 12:45:58: ClientService cmd: #IAnbfh6Zmcf7DGt3H5CuW#2LOGDATA 1477413955 0-1477413954-Starting full image backup…
2-1477413955-Backing up System Reserved (SYSVOL) partition failed. Image backup failed
0-1477413955-Time taken for backing up client QUADRIGA:
2-1477413955-Backup failed

2016-10-25 12:45:58: rc=0 hasError=true state=0
2016-10-25 12:46:04: rc=0 hasError=true state=0
2016-10-25 12:46:44: ClientService cmd: PONG
2016-10-25 12:46:46: ClientService cmd: STATUS#pw=lSbsOkoSGbXbUcPRwNDh0Sc7iufLtc
2016-10-25 12:47:38: ClientService cmd: STATUS#pw=lSbsOkoSGbXbUcPRwNDh0Sc7iufLtc
2016-10-25 12:47:44: ClientService cmd: PONG
2016-10-25 12:48:30: ClientService cmd: STATUS#pw=lSbsOkoSGbXbUcPRwNDh0Sc7iufLtc

procmon log filtered for UrBackupClientBackend.exe

Logfile_full_backup.zip (5.5 KB)

Any hints will be appreciated.

6

It cannot read from volume \?\Volume{ec3beb87-3953-421e-9e96-6cf34f8212d8} . Status code is 0x80000010 STATUS_DEVICE_OFF_LINE. Idk why this is happending on your system. Any unusual drivers?

7

The issue has been resolved. The latest incremental image backup succeeded.

The only thing I did that might have helped was, while I was investigating, I used the mountvol command and at one point I tried C:> mountvol /R. Nothing else I tried so far should have changed anything.

Thanks for your help.