vMotion fails at 74% with the error, “The VM failed to resume on the destination during early power on”.
search cancel

vMotion fails at 74% with the error, “The VM failed to resume on the destination during early power on”.

book

Article ID: 326930

calendar_today

Updated On:

Products

VMware vSAN

Issue/Introduction

Symptoms:
  • In the hostd.log you see messages similar to:
2018-10-20T23:21:53.072Z info hostd[A1BF1B70] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/vsan:1231231231231231-2233223322332233/12312345-cccc-bbbb-aaaa-123123451234/test-vm.vmx] Checking for all objects accessibility (VM's current state: VM_STATE_EMIGRATING, stable? false)
2018-10-20T23:21:53.072Z info hostd[A1BF1B70] [Originator@6876 sub=VmObjectStorageMonitor] Object UUID 12312345-cccc-bbbb-aaaa-123123451234 APD state: Healthy
2018-10-20T23:21:53.072Z info hostd[A1BF1B70] [Originator@6876 sub=VmObjectStorageMonitor] Object UUID 12989b58-2a11-87d5-65f5-246e963e7c20 APD state: Healthy
2018-10-20T23:21:53.073Z info hostd[A1BF1B70] [Originator@6876 sub=Vcsvc.VMotionSrc (5422550518507384986)] ResolveCb: VMX reports needsUnregister = false for migrateType MIGRATE_TYPE_VMOTION
2018-10-20T23:21:53.073Z info hostd[A1BF1B70] [Originator@6876 sub=Vcsvc.VMotionSrc (5422550518507384986)] ResolveCb: Failed with fault: (vim.fault.GenericVmConfigFault) {
-->    faultCause = (vmodl.MethodFault) null,
-->    faultMessage = (vmodl.LocalizableMessage) [
-->       (vmodl.LocalizableMessage) {
-->          key = "msg.migrate.fail.dst",
-->          message = "The source detected that the destination failed to resume.",
-->       }
-->    ],
-->    reason = "The source detected that the destination failed to resume.",
-->    messageInfo = (vim.vm.Message) [
-->       (vim.vm.Message) {
-->          id = "msg.migrate.fail.dst",
-->          text = "The source detected that the destination failed to resume.",
-->       }
-->    ]
-->    msg = "The source detected that the destination failed to resume.
--> "
--> }
2018-10-20T23:21:53.076Z info hostd[A1BF1B70] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/vsan:1231231231231231-2233223322332233/12312345-cccc-bbbb-aaaa-123123451234/test-vm.vmx] State Transition (VM_STATE_EMIGRATING -> VM_STATE_ON)
  • In the vmkernel.log you see messages similar to:
2018-10-21T03:12:42.047Z cpu13:857334255)WARNING: Migrate: 5454: 5422550532447652106 S: Migration considered a failure by the VMX.  It is most likely a timeout, but check the VMX log for the true error.
2018-10-21T03:24:06.563Z cpu17:420159321)WARNING: Migrate: 5454: 5422550533132847308 S: Migration considered a failure by the VMX.  It is most likely a timeout, but check the VMX log for the true error.
2018-10-21T03:26:49.173Z cpu28:946706621)WARNING: Migrate: 5454: 5422550533291405060 S: Migration considered a failure by the VMX.  It is most likely a timeout, but check the [root@sewvxrail2:/vmfs/volumes/vsan:1231231231231231-2233223322332233/12312345-cccc-bbbb-aaaa-123123451234] 
In the vmware.log of test-vm VM you see messages similar to:

2018-10-21T01:51:50.472Z| vmx| I125: Msg_Post: Error
2018-10-21T01:51:50.472Z| vmx| I125: [msg.nvram.wback1] Could not create '/vmfs/volumes/vsan:1231231231231231-2233223322332233/12312345-cccc-bbbb-aaaa-123123451234/test-vm.nv
ram': Failed to lock the file
2018-10-21T01:51:50.472Z| vmx| I125: ----------------------------------------
2018-10-21T01:51:50.474Z| vmx| I125: Vigor_MessageRevoke: message 'msg.nvram.wback1' (seq 47059135) is revoked
2018-10-21T01:51:50.474Z| vmx| W115: NVRAMMGR: Failed to create default NVRAM file (test-vm.nvram)
2018-10-21T01:51:50.474Z| vmx| I125: Module Nvman power on failed.
2018-10-21T01:51:50.474Z| vmx| I125: VMX_PowerOn: ModuleTable_PowerOn = 0
2018-10-21T01:51:50.474Z| vmx| I125: MigrateSetStateFinished: type=2 new state=12
2018-10-21T01:51:50.474Z| vmx| I125: MigrateSetState: Transitioning from state 11 to 12.
2018-10-21T01:51:50.474Z| vmx| I125: Migrate: Caching migration error message list:
2018-10-21T01:51:50.474Z| vmx| I125: [msg.migrate.resume.fail] The VM failed to resume on the destination during early power on.
2018-10-21T01:51:50.474Z| vmx| I125: Msg_Post: Error
2018-10-21T01:51:50.474Z| vmx| I125: [msg.migrate.resume.fail] The VM failed to resume on the destination during early power on.
2018-10-21T01:51:50.474Z| vmx| I125: ----------------------------------------
2018-10-21T01:51:50.475Z| vmx| I125: Vigor_MessageRevoke: message 'msg.migrate.resume.fail' (seq 47059136) is revoked
2018-10-21T01:51:50.481Z| vmx| I125: ToolsISO: Selected Tools ISO 'windows.iso' for 'windows7srv-64' guest.
2018-10-21T01:51:50.483Z| vmx| I125: Tools: ToolsRunningStatus_Exit, delayedRequest is 0x0
2018-10-21T01:51:50.483Z| vmx| I125: VMXVmdb_SetToolsVersionStatus: status value set to 'ok', 'current', install possible
2018-10-21T01:51:50.483Z| vmx| I125: SVMotion_PowerOff: Not running Storage vMotion. Nothing to do
2018-10-21T01:51:50.484Z| svga| I125: SVGA thread is alive
2018-10-21T01:51:50.484Z| svga| I125: SVGA thread is exiting
2018-10-21T01:51:50.484Z| vmx| I125: Destroying virtual dev for scsi0:0 vscsi=10775
2018-10-21T01:51:50.484Z| vmx| I125: VMMon_VSCSIStopVports: No such target on adapter
2018-10-21T01:51:50.484Z| mks| I125: MKS PowerOff
2018-10-21T01:51:50.484Z| mks| I125: MKS thread is exiting
2018-10-21T01:51:50.484Z| vmx| I125: Migrate: cleaning up migration state.


Environment

VMware vSAN 6.5.x
VMware vSAN 7.0.x
VMware vSAN 6.x
VMware vSAN 8.0.x

Cause

The vMotion failed due to nvram lock not being released. This happens due to the host not being able to release the lock on NVRAM - Capacity disk on which VM is running. It can be due to an older version of firmware on NVRAM or older controller driver firmware or both.

Resolution



Workaround:
  • Shutdown / Power off VM and then power on the VM to clear the nvram lock then vMotion should work fine. 
  • If the above steps does not resolve the issue then you would need to refer the below KB to investigate if there is any other lock on virtual machines. 
For more details, refer to KB Article Investigating virtual machine file locks on ESXi (10051)