9.5 U4 VM Backup fails Full Backup. Lower case disk file names.

[stuartmacgreen]

I'll write this to share the problem I faced and the solution with anyone else, who falls upon this strange scenario. It opens up a couple of extra questions but here it is.

Details
3 Virtual Machines out of 60 VM Backups fail Active Full backups (at weekend.)
2 days prior Veeam Backup & Replication 9.5 U3 is upgraded to U4. Subsequent scheduled incremental VM backups are all successful. The following scheduled Full VM Backups fail with the following detail logged.

I will provide the Session Error line detail for 1 of the VM Backups that failed.

Session Details (log)

Code: Select all

..
18/02/2019 06:22:29 :: Processing BARNEY Error: Invalid record index [0], it maps to table index [0:0]. Existing tables count: [0]
Failed to backup text locally. Backup: [VBK: 'veeamfs:4:077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-49035)\barney.vmdk@E:\Prod\BARNEY.vm-49035_244DD2019-02-18T060036.vbk'].
Agent failed to process method {DataTransfer.BackupText}.
Agent failed to process method {DataTransfer.BackupText}...

Retries are attempted and run out of max retry count but during this different error is displayed.

Code: Select all

18/02/2019 06:47:50 :: Processing BARNEY Error: The specified item was already backed up or backup was not completed.
Failed to download disk.
Shared memory connection was closed.
Failed to upload disk.
Agent failed to process method {DataTransfer.SyncDisk}.

Subsequent Incremental backups of the VM's now fail also. I start to investigate.

Investigation
A search of the forums reveals this post from 2010.
veeam-backup-replication-f2/job-failure ... t5576.html

It mentions:

The problem was that the diskfiles on the different LUNs had the same name "server1.vmdk".

This got me thinking....
I fired up RVTools utility which is great for seeing VM Infrastructure in tabulated form. And for comparing VM Settings in particular - for finding patterns.

The failed VM Backup Virtual Machines all had something in common.

The BARNEY VM has 2 virtual disks. Here are there filesystem locations on ESXi:

[Datastore-t2-b.2] barney/barney.vmdk
[Datastore-t2-b.2] barney/BARNEY.vmdk



I used the RVTools tables to check the other 2 failed VM's

Sure enough.
They each had similar characteristics.

The parent folder for the virtual machine files and disk files were lower case.
And the situation whereby you had two virtual hard disks that unique to the VM but were the same name but one was lower and other was upper case.

Solution
I proceeded to Storage vMotion the VM in vSphere to a different datastore.

The subsequent filesystem locations were now the following, which would be more acceptable and expected:

[Datastore-t2-a.2] BARNEY/BARNEY.vmdk
[Datastore-t2-a.2] BARNEY/BARNEY_1.vmdk

Attempt Active Full backup of the VM. SUCCESS.


Follow Up
Q: How did some of my VM's in vSphere get into this predicament?
All VM's in vSphere are stored in a folder thats upper case.
And .vmdk files are named with uppercase formatting.
How were some of mine lower case.

In the lower and similar named files under 9.5 U3 it just worked.
9.5 U4 has identified this now.

Hope this helps anyone else.

[HannesK]

Hello Stuart,
thanks for sharing that information. Do you maybe have a support case number that I can do some further investigations?

Thanks,
Hannes

[stuartmacgreen]

Didnt log support case. As I solved this myself.

[HannesK]

Hello,
if you have a few minutes, it would be helpful if you could open a case and upload the log files.

It would help us to fix the issue. I could not reproduce it in my lab.

[Datastore]/zzz_empty1/ZZZ_EMPTY1.vmdk
[Datastore]/zzz_empty1/zzz_empty1.vmdk

It worked for me for backup.

Best regards,
Hannes

[stuartmacgreen]

Support case opened:
[ID# 03422733] 9.5u4 VM backup with lower and upper case named virtual disks fails.

I went back and was able to reproduce with a FRESH VM. Here was my method:

Create/clone a VM and give that VM a lower case name during deployment wizard into vSphere and name it 'lowercase11'
It has 2 virtual hard disks.
Once the VM completes deployment into Virtual Infrastructure. You will have the following:

HDD1 = [Datastore]lowercase11/lowercase11.vmdk
HDD2 = [Datastore]lowercase11/lowercase11_1.vmdk

Now rename the VM into uppercase - so we now have VM name in vSphere displaying 'LOWERCASE11'
Next add a third hard disk to this VM.

You will additionally now have:
HDD3 = [Datastore]lowercase11/LOWERCASE11.vmdk

Next perform a Active Full backup of this VM. Result: FAILED.

Session Action Detail
19/02/2019 09:46:40 :: Job started at 2/19/2019 9:46:40 AM
19/02/2019 09:46:41 :: Building list of machines to process
19/02/2019 09:46:56 :: VM size: 37.0 GB
19/02/2019 09:46:56 :: Changed block tracking is enabled
19/02/2019 09:46:59 :: Queued for processing at 2/19/2019 9:47:00 AM
19/02/2019 09:46:59 :: Required backup infrastructure resources have been assigned
19/02/2019 09:47:30 :: Creating storage snapshot
19/02/2019 09:47:36 :: Processing LOWERCASE11 Error: The specified item was already backed up or backup was not completed.
Failed to download disk.
Shared memory connection was closed.
Failed to upload disk.
Agent failed to process method {DataTransfer.SyncDisk}.

19/02/2019 09:47:41 :: All VMs have been queued for processing
19/02/2019 09:48:11 :: Unexporting storage snapshots
19/02/2019 09:48:33 :: Deleting storage snapshot
19/02/2019 09:48:38 :: Load: Source 98% > Proxy 0% > Network 16% > Target 0%
19/02/2019 09:48:38 :: Primary bottleneck: Source
19/02/2019 09:48:38 :: Job finished with error at 2/19/2019 9:48:39 AM

Session VM Action Detail
19/02/2019 09:47:14 :: Creating VM snapshot
19/02/2019 09:47:18 :: Collecting disk files location data
19/02/2019 09:47:32 :: Removing VM snapshot
19/02/2019 09:47:36 :: Queued for processing at 2/19/2019 9:47:37 AM
19/02/2019 09:47:37 :: Required backup infrastructure resources have been assigned
19/02/2019 09:47:41 :: VM processing started at 2/19/2019 9:47:42 AM
19/02/2019 09:47:41 :: VM size: 37.0 GB
19/02/2019 09:47:45 :: Saving [Datastore] lowercase11/lowercase11.vmx
19/02/2019 09:47:45 :: Saving [Datastore] lowercase11/lowercase11.nvram
19/02/2019 09:47:46 :: Using backup proxy bart.kwikemart.com for retrieving Hard disk 1 data from storage snapshot
19/02/2019 09:47:46 :: Using backup proxy bart.kwikemart.com for retrieving Hard disk 2 data from storage snapshot
19/02/2019 09:47:46 :: Using backup proxy bart.kwikemart.com for retrieving Hard disk 3 data from storage snapshot
19/02/2019 09:47:59 :: Hard disk 3 (3.0 GB) 0.0 B read at 0 KB/s [CBT]
19/02/2019 09:47:59 :: Hard disk 1 (0.0 B) 0.0 B read at 0 KB/s [CBT]
19/02/2019 09:47:59 :: Hard disk 2 (2.0 GB) 18.0 MB read at 18 MB/s [CBT]
19/02/2019 09:48:09 :: Error: The specified item was already backed up or backup was not completed.
Failed to download disk.
Shared memory connection was closed.
Failed to upload disk.
Agent failed to process method {DataTransfer.SyncDisk}.

19/02/2019 09:48:09 :: Busy: Source 98% > Proxy 0% > Network 16% > Target 0%
19/02/2019 09:48:10 :: Primary bottleneck: Source
19/02/2019 09:48:10 :: Network traffic verification detected no corrupted blocks
19/02/2019 09:48:10 :: Processing finished with errors at 2/19/2019 9:48:11 AM

--------
My vSphere versions are below:
vCenter Server 6.5.0 build-9451637
ESXi 6.5.0 build-10884925
--------
With Veeam B&R 9.5 Update3a this scenario worked fine.

[HannesK]

Hello,
thank you for your detailed description. That helps us fixing that issue.

Thanks again for bringing it up,
Hannes

[andyb]

I just wanted to thank you for this post, we had a similar issue with a VM after updating to U4. In our case the VM had two disks residing on the same datastore, named very similarly. For example one was in all caps "VIRTUALMACHINE.vmdk" and the other was named like so: "VirtualMachine.vmdk".

I used vmotion to move the disk "VirtualMachine.vmdk" to another datastore and it became "VIRTUALMACHINE_2.vmdk". Backups are now working without issue.

[HannesK]

good to hear that the workaround works - we also plan a fix for that issue

[stuartmacgreen]

Can confirm that 9.5 Update 4a addresses this situation.

Many Thanks for fixing this.