Unable to restore VM from backup (case ref 00628962)

[gregwatson]

I wonder if you good folks might be able to assist. I have logged a support ticket but I'm not getting anything useful back from the US so far (just vague comments about there being a limit on datastores even though other restores have worked OK, followed by silence)

Anyway - I'm trying to restore from a backup - there's a single backup job that contains 3 exchange servers. One of them restored fine, the other two both fail just after "registering restored VM" with a very vague error about being unable to create a snapshot. You can see that ESXi reported an error as well - again a very vague unhelpful generic error about snapshotting.

Digging in the esxi hostd.log I have found this line:

Code: Select all

/var/log # grep -i 4e03a hostd.log | more
2014-09-01T14:58:39.446Z [70B40B70 info 'Vmsvc.vm:/vmfs/volumes/540309a2-7ce651ff-b3c9-74867ae0ee3a/AmidaSBS/AmidaSBS.vmx'] CacheDatastores: fileBacking [] /vmfs/volumes/4e03af2a-da69ea25-ed13-0023aeff5f02/isos/sbs2011.iso has null datastore reference 2014-09-01T14:58:55.657Z [FFCB55C0 info 'Vmsvc.vm:/vmfs/volumes/540309a2-7ce651ff-b3c9-74867ae0ee3a/AmidaSBS/AmidaSBS.vmx' opID=4b7366d5-a5 user=vpxuser] CacheDatastores: fileBacking [] /vmfs/volumes/4e03af2a-da69ea25-ed13-0023aeff5f02/isos/sbs2011.iso has null datastore reference

Basically it seems there is an entry in the AmidaSBS.vmx file that references the 4e03...f02 filesystem, which is the original filesystem on the source host and obviously doesn't exist on the target host. For some reason that has not been correctly mapped to the destination host (which is a totally different server). It's odd that one of the three exchange server worked fine, so the mapping to the new datastore worked for that one - also I have restored another 9 or so VMs from the same original site onto the new host and they all worked fine. It's just these two exchange servers that are failing to restore, and as far as I can tell it's because the vmx file is still referencing the old datastore filesystem.

It's Veeam 07 patch 4 at both ends...

It's not a severity one because the production servers aren't down but it is urgent because it's holding up a move to the new datacentre which we need to do ASAP for performance reasons...
Any ideas?

[gregwatson]

It looks to me like it's the CD being linked to the install CD, so I thought it would be that - but the server that restored fine also has its CD mapped to an ISO (albeit a different ISO) so I reckoned it couldn't be that.

[gregwatson]

Her's some of the other text from the hostd.log file. Again it references the same datastore filesystem from the source that doesn't exist on the target.

Code: Select all

2014-09-01T15:11:54.173Z [70B40B70 verbose 'Default' opID=4d61e74d-60 user=vpxuser] AdapterServer: target='vim.VirtualMachine:4', method='createSnapshot'
2014-09-01T15:11:54.173Z [70B40B70 info 'Vimsvc.TaskManager' opID=4d61e74d-60 user=vpxuser] Task Created : haTask-4-vim.VirtualMachine.createSnapshot-348536051
2014-09-01T15:11:54.173Z [FFD18B70 verbose 'Vmsvc.vm:/vmfs/volumes/540309a2-7ce651ff-b3c9-74867ae0ee3a/AmidaSBS/AmidaSBS.vmx' opID=4d61e74d-60 user=vpxuser] Create Snapshot: VEEAM RESTORE SNAPSHO
2014-09-01T15:11:54.173Z [FFD18B70 info 'Vmsvc.vm:/vmfs/volumes/540309a2-7ce651ff-b3c9-74867ae0ee3a/AmidaSBS/AmidaSBS.vmx' opID=4d61e74d-60 user=vpxuser] State Transition (VM_STATE_OFF -> VM_STAT
2014-09-01T15:11:54.173Z [FFD18B70 verbose 'Hostsvc.HaHost' opID=4d61e74d-60 user=vpxuser] ModeMgr::Begin: op = normal, current = normal, count = 0
2014-09-01T15:11:54.175Z [FFD18B70 info 'Libs' opID=4d61e74d-60 user=vpxuser] SNAPSHOT: SnapshotConfigInfoReadEx: Creating new snapshot dictionary, '/vmfs/volumes/540309a2-7ce651ff-b3c9-74867ae0e
[color=#FF0000]2014-09-01T15:11:54.182Z [FFD18B70 warning 'Libs' opID=4d61e74d-60 user=vpxuser] File_GetFreeSpace: Couldn't statfs /vmfs/volumes/4e03af2a-da69ea25-ed13-0023aeff5f02/vm-snapshots/.[/color]
2014-09-01T15:11:54.182Z [FFD18B70 info 'Libs' opID=4d61e74d-60 user=vpxuser] SNAPSHOT: SnapshotCheckSpaceAndSnapshotNum: Error getting the free space on the storage disk
2014-09-01T15:11:54.182Z [FFD18B70 info 'Libs' opID=4d61e74d-60 user=vpxuser] SnapshotVigorTake: Failed to take snapshot: Error (3)
2014-09-01T15:11:54.182Z [FFD18B70 verbose 'Vmsvc.vm:/vmfs/volumes/540309a2-7ce651ff-b3c9-74867ae0ee3a/AmidaSBS/AmidaSBS.vmx' opID=4d61e74d-60 user=vpxuser] Create Snapshot translated error to vi
2014-09-01T15:11:54.182Z [FFD18B70 info 'Vmsvc.vm:/vmfs/volumes/540309a2-7ce651ff-b3c9-74867ae0ee3a/AmidaSBS/AmidaSBS.vmx' opID=4d61e74d-60 user=vpxuser] Create Snapshot failed: vim.fault.Generic
2014-09-01T15:11:54.182Z [FFD18B70 verbose 'Vmsvc.vm:/vmfs/volumes/540309a2-7ce651ff-b3c9-74867ae0ee3a/AmidaSBS/AmidaSBS.vmx' opID=4d61e74d-60 user=vpxuser] Create Snapshot message: An 

Anyone got any ideas? At this stage I am not convinced it's a vmware issue, because it all depends on what vmware is being asked to do!

[tsightler]

I've seen this issue before and it appears to me that this VM was configured to redirect snapshot images to another datastore using the workingDir parameter (the fact that the path includes vm-snapshots, exactly as this is outlined in the VMware KB article is the tell). Since you are attempting to restore to a host where that datastore doesn't exist, Veeam restores the VMX, registers the VM, and creates the shell VMDKs, however when we instruct VMware to create a snapshot so that we can start the restore process, it fails because the workingDir that this VM has been manually configured to use to store it's delta files does not exist.

Please see VMware KB article 1002929 which describes the settings that cause this. Specifically you are looking for "workingDir" and, if your ESXi version is higher than 5.x, the snapshot.redoNotWithParent = "true" parameter as well.

As for a workaround, I'm assuming when the restore fails you're left with a VM that is configured largely correctly, but the disks couldn't be restored because of the snapshot failure. You can edit the improperly restored VM to correct the workingDir and snapshot.redoNotWithParent options as required. Once you have this "shell VM" fixed so that taking a snapshot works correctly, you can manually restore just the VM disks using the "Restore VM Disks" option rather than attempting to restore the entire VM (which would restore the incorrectly configured VMX file again). When you choose only to restore the VM disks, you can map those to the VM that you have now fixed.

Other options would be to simply using the "Restore VM Files" feature to restore the VMX and VMDK file to a datastore, then manually register and "fix" the VM.

[gregwatson]

Makes sense. I'm sure you're right. Thanks.

In terms of whether it's esxi 4 or 5.1 or 5.5 - I presume I edit the vmx file based on the version of the source host, rather than the destination host?

[gregwatson]

If I do it the last way - restore the vm files, then edit the vmx to remove the workingdir reference - then register the VM - won't I be missing something out? In other words, what is it that Veeam does when it is restoring the VM that requires snapshotting? Because the way we're proposing to do it, we aren't taking any snapshots (yet)...

[gregwatson]

Ah. I can't just remove the workingdir reference because there is a delta file in the vmsnapshot folder (as well as the swap file, but that's probably less important).

If Veeam is unable to recognise the presence of alternate snapshot folders like this, won't it have completely ignored the AmidaSBS-000002 vmdk and deltas file that were in the vm-snapshots folder on the original? Or has it somehow copied those across? Where to? Is that the whole reason why it's trying to do a snapshot, to get rid of the delta file?

[gregwatson]

OK weird.
I tried to start the VM after noticing that Veeam seems to have taken care of the delta file and that there were three vmdks in the folder. The first time I tried to start the VM (after the copy or move question I chose "I moved it") it errored and said

Cannot power on AmidaSBS on 172.17.61.11. I/O
error accessing change tracking file
error

The detail said that it couldn't access the AmidaSBS_2.vmdk or its snapshot disk.

I went to do some more investigation, came back, and it seems to have booted anyway. Which I hadn't expected.

I must have missed somethign in the vmx that needed editing. Should I be worried about the initial error relating to the AmidaSBS_2 disk or snapshot location? It seems to have all of its hard drives present and correct (although it keeps rebooting, possibly because in needs reactivating or something???)

I am working on local copies of all the backup files, so I can reset and try again any time I like - I just need to get the procedure correct for the final restore.

[gregwatson]

OK.

If I look at the three vmdk files that were in the Veeam backup (by restoring VM files) they include the following:

First hard drive vmdk file:
# Extent description
RW 536870912 VMFS "AmidaSBS-flat.vmdk"
# Change Tracking File
changeTrackPath="AmidaSBS-ctk.vmdk"


Second hard drive vmdk file:
# Extent description
RW 838860800 VMFS "AmidaSBS_1-flat.vmdk"
# Change Tracking File
changeTrackPath="AmidaSBS_1-ctk.vmdk"



Third hard drive vmdk file:
# Extent description
RW 536870912 VMFS "AmidaSBS_2-flat.vmdk"

# Change Tracking File
changeTrackPath="AmidaSBS-ctk.vmdk" (THIS LOOKS WRONG, SHOULD THIS NOT BE AMIDASBS_2-CTK.VMDK ??)

that parameter looks wrong somehow to me, in the sense that it doesn't follow the pattern of the other two.

I'm definitely stuck again now so I'll shut up now pending some more help, which would be gratefully received....