0 byte vmx after power loss

[simon_wright]

while doing some UAT we powered down one of our new DC's (B) to test VMware HA and found that both times the same virtual machine ended up with a 0 byte vmx file and as such could not be registered.  it also happened to be a vcenter 4.1 vm. all other vm's are running centos and were fine.

I logged onto one host and uploaded a backup copy of the vmx file and left HA to get on with it and both times have been successfully working.

Has any one else seen this behavior at all ???

Also for info, I am using a Netapp Metro Cluster and all the active NFS mounts where in the DC that was not powered off (A),  the VMware HA cluster spans both datacenter's.  I have also tested pulling the power to just the blade in the same DC (B), this has resulted in the correct behavior and the vm with vcenter was correctly restarted in the other DC (A).

Any hints would also be welcome and any questions.

Thank you

Simon.

Here is the messages log for the time of the event: the red part is the point in which I think the vmx file was wiped.

Sep 26 11:15:29 Vpxa:
Sep 26 11:16:28 Hostd: [2011-09-26 11:16:28.606 35D81B90 verbose 'vm:/vmfs/volumes/0357e787-3ef36c5a/vcenter1/vcenter1.vmx' opID=1316684761-1] Time to gather config: 12429 (msecs)
Sep 26 11:16:28 Hostd: [2011-09-26 11:16:28.614 35D81B90 info 'TaskManager' opID=1316684761-1] Task Completed : haTask-48-vim.VirtualMachine.reconfigure-135322 Status error
Sep 26 11:16:28 Hostd: [2011-09-26 11:16:28.614 35D81B90 warning 'vm:/vmfs/volumes/0357e787-3ef36c5a/vcenter1/vcenter1.vmx' opID=1316684761-1] Reconfigure worker thread failed
Sep 26 11:16:28 Hostd: [2011-09-26 11:16:28.614 35BA9B90 warning 'PropertyProvider'] _GetChanges took 12435835 microseconds to lock vim.VirtualMachine:48
Sep 26 11:16:28 Hostd: [2011-09-26 11:16:28.615 35BA9B90 warning 'PropertyCollector'] ComputeGUReq took 12436368 microSec
Sep 26 11:16:28 Vpxa: [2011-09-26 11:16:28.616 116A9B90 verbose 'VpxaHalCnxHostagent'] Received callback in WaitForUpdatesDone
Sep 26 11:16:28 Vpxa: [2011-09-26 11:16:28.616 116A9B90 verbose 'VpxaHalCnxHostagent'] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 27153 to 27154 (at 27153)
Sep 26 11:16:28 Vpxa: [2011-09-26 11:16:28.616 116A9B90 verbose 'App'] [TaskInfoChannel::SetTaskInfo] task: haTask-48-vim.VirtualMachine.reconfigure-135322 for task: haTask-48-vim.VirtualMachine.reconfigure-135322
Sep 26 11:16:28 Vpxa: [2011-09-26 11:16:28.616 116A9B90 verbose 'App'] [TaskInfoChannel::NotifyWaiters] Notified for _infoVersion: 2; task: (null)
Sep 26 11:16:28 Vpxa: [2011-09-26 11:16:28.617 11460B90 verbose 'App'] [VpxLRO] Dispatching Error Handler Functor for haTask-48-vim.VirtualMachine.reconfigure-135322 which completed with an error from task-internal-24638
Sep 26 11:16:28 Vpxa: [2011-09-26 11:16:28.617 11460B90 verbose 'App'] [TaskInfoListener::~TaskInfoListener] Connection number = 9
Sep 26 11:16:28 Vpxa: [2011-09-26 11:16:28.617 114A1B90 verbose 'App' opID=1316684761-1] [FailoverAction] Error while failing over vm netfs://10.30.13.2//vol/lbu_vc01_vfi01_vol01/vcenter1/vcenter1.vmx: [N5Vmomi5Fault11SystemErrorE:0xaa9c188] (state=2)
Sep 26 11:16:28 Vpxa: [2011-09-26 11:16:28.617 11460B90 verbose 'App'] [TaskInfoChannel::SetDisconnected] task: haTask-48-vim.VirtualMachine.reconfigure-135322
Sep 26 11:16:28 Vpxa: [2011-09-26 11:16:28.617 114A1B90 verbose 'App' opID=1316684761-1] [VpxaDas::AddEventInt] Adding event VmFailoverFailedEvent: host=[], vm=[netfs://10.30.13.2//vol/lbu_vc01_vfi01_vol01/vcenter1/vcenter1.vmx]
Sep 26 11:16:28 Vpxa: [2011-09-26 11:16:28.617 11460B90 verbose 'App'] [TaskInfoPublisher::RemoveChannel] Channel (haTask-48-vim.VirtualMachine.reconfigure-135322) removed for task: haTask-48-vim.VirtualMachine.reconfigure-135322
Sep 26 11:16:28 Vpxa: [2011-09-26 11:16:28.617 114A1B90 verbose 'App' opID=1316684761-1] [VpxaInvtHost] Increment master gen. no to (7295): Das:VpxaDas::AddEventInt
Sep 26 11:16:28 Vpxa: [2011-09-26 11:16:28.617 11460B90 verbose 'App'] TaskInfoChannel destroyed for haTask-48-vim.VirtualMachine.reconfigure-135322
Sep 26 11:16:28 Vpxa: [2011-09-26 11:16:28.618 114A1B90 info 'App' opID=1316684761-1] [FailoverAction] Unregistering vm netfs://10.30.13.2//vol/lbu_vc01_vfi01_vol01/vcenter1/vcenter1.vmx that failed failover
Sep 26 11:16:28 Vpxa: [2011-09-26 11:16:28.619 114A1B90 verbose 'App' opID=1316684761-1] [VpxaHalVmLocker] VM 48 locked successfully.
Sep 26 11:16:28 Hostd: [2011-09-26 11:16:28.620 362EAB90 info 'TaskManager' opID=1316684761-1] Task Created : haTask-48-vim.VirtualMachine.unregister-135328
Sep 26 11:16:28 Hostd: [2011-09-26 11:16:28.620 35F81B90 verbose 'vm:/vmfs/volumes/0357e787-3ef36c5a/vcenter1/vcenter1.vmx' opID=1316684761-1] Unregister called on virtual machine
Sep 26 11:16:28 Hostd: [2011-09-26 11:16:28.620 35F81B90 info 'vm:/vmfs/volumes/0357e787-3ef36c5a/vcenter1/vcenter1.vmx' opID=1316684761-1] State Transition (VM_STATE_OFF -> VM_STATE_UNREGISTERING)
Sep 26 11:16:28 Hostd: [2011-09-26 11:16:28.620 35F81B90 verbose 'DatastoreBrowser' opID=1316684761-1] 48-envmgr-datastorebrowser::Destroy
Sep 26 11:16:28 Hostd: [2011-09-26 11:16:28.620 35F81B90 verbose 'vm:/vmfs/volumes/0357e787-3ef36c5a/vcenter1/vcenter1.vmx' opID=1316684761-1] RemoveFromAutoStart