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:12312312########-######3322332233/########-####-####-####-########1234/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 ########-####-####-####-########1234 APD state: Healthy 2018-10-20T23:21:53.072Z info hostd[A1BF1B70] [Originator@6876 sub=VmObjectStorageMonitor] Object UUID ########-####-####-####-########7c20 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:12312312########-######3322332233/########-####-####-####-########1234/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@hostname:/vmfs/volumes/vsan:12312312########-######3322332233/########-####-####-####-########1234] 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:12312312########-######3322332233/########-####-####-####-########1234/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 (All Versions)
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.