Hi. We had a VM fail to power up for a user. It powered up on all subsquent tries. I am trying to determine why the cause was. The host it was on is good, as I test other VMs.
I highlighted in Bold the event that caused the VM to fail to power on. I have no idea what "screenshots" are. I see a lot of them for this VM. And I cant find any information on what it is. Also I cant get the user to tell me exactly what they were doing. They swear the VM was off. Which it looks like from the logs and the vCenter events. Can anyone give me any clues? This hasnt happened again, I just am curious if I have something that is going to bite me again.
2019-08-22T21:18:19.815Z info hostd[14E85B70] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/5d57076b-b2cc9e87-c0a4-a0369ff2a238/rhel7-template-ls/rhel7-template-ls.vmx opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-02-58-a7d5 user=vpxuser:vpxuser] State Transition (VM_STATE_RECONFIGURING -> VM_STATE_OFF)
2019-08-22T21:18:19.815Z verbose hostd[14E85B70] [Originator@6876 sub=PropertyProvider opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-02-58-a7d5 user=vpxuser:vpxuser] RecordOp ASSIGN: disabledMethod, 112. Sent notification immediately.
2019-08-22T21:18:19.820Z info hostd[14E85B70] [Originator@6876 sub=Vimsvc.TaskManager opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-02-58-a7d5 user=vpxuser:vpxuser] Task Completed : haTask-pool4-vim.ResourcePool.moveInto-240998200 Status success
2019-08-22T21:18:19.820Z verbose hostd[14E85B70] [Originator@6876 sub=PropertyProvider opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-02-58-a7d5 user=vpxuser:vpxuser] RecordOp ASSIGN: info, haTask-pool4-vim.ResourcePool.moveInto-240998200. Applied change to temp map.
2019-08-22T21:18:19.854Z info hostd[14DC2B70] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/5d57076b-b2cc9e87-c0a4-a0369ff2a238/rhel7-template-ls/rhel7-template-ls.vmx] State Transition (VM_STATE_OFF -> VM_STATE_CREATE_SCREENSHOT)
2019-08-22T21:18:19.854Z verbose hostd[14DC2B70] [Originator@6876 sub=PropertyProvider] RecordOp ASSIGN: disabledMethod, 112. Sent notification immediately.
2019-08-22T21:18:19.854Z warning hostd[14DC2B70] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/5d57076b-b2cc9e87-c0a4-a0369ff2a238/rhel7-template-ls/rhel7-template-ls.vmx] Failed to read PNG image buffer
2019-08-22T21:18:19.855Z info hostd[EE5FB70] [Originator@6876 sub=Vimsvc.TaskManager opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7dd user=vpxuser] Task Created : haTask-112-vim.VirtualMachine.powerOn-240998201
2019-08-22T21:18:19.855Z verbose hostd[EE5FB70] [Originator@6876 sub=PropertyProvider opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7dd user=vpxuser] RecordOp ADD: recentTask["haTask-112-vim.VirtualMachine.powerOn-240998201"], 112. Sent notification immediately.
2019-08-22T21:18:19.855Z verbose hostd[EE5FB70] [Originator@6876 sub=PropertyProvider opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7dd user=vpxuser] RecordOp ADD: recentTask["haTask-112-vim.VirtualMachine.powerOn-240998201"], ha-taskmgr. Applied change to temp map.
2019-08-22T21:18:19.855Z verbose hostd[14EC6B70] [Originator@6876 sub=PropertyProvider opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7dd user=vpxuser] RecordOp ASSIGN: info, haTask-112-vim.VirtualMachine.powerOn-240998201. Applied change to temp map.
2019-08-22T21:18:19.856Z verbose hostd[14EC6B70] [Originator@6876 sub=PropertyProvider opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7dd user=vpxuser] RecordOp REMOVE: latestPage[199055], session[522aab07-2ec9-8107-6176-2457722c1ea7]5275cff6-00ac-5131-d87a-c52346bbb714. Applied change to temp map.
2019-08-22T21:18:19.856Z verbose hostd[14EC6B70] [Originator@6876 sub=PropertyProvider opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7dd user=vpxuser] RecordOp ADD: latestPage[199065], session[522aab07-2ec9-8107-6176-2457722c1ea7]5275cff6-00ac-5131-d87a-c52346bbb714. Applied change to temp map.
2019-08-22T21:18:19.856Z verbose hostd[14EC6B70] [Originator@6876 sub=PropertyProvider opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7dd user=vpxuser] RecordOp REMOVE: latestPage[199055], session[52ce23bc-fd06-c778-cb23-39b6caa3c813]521ffcc0-3dcc-d644-9f64-6b83ff85becf. Applied change to temp map.
2019-08-22T21:18:19.856Z verbose hostd[14EC6B70] [Originator@6876 sub=PropertyProvider opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7dd user=vpxuser] RecordOp ADD: latestPage[199065], session[52ce23bc-fd06-c778-cb23-39b6caa3c813]521ffcc0-3dcc-d644-9f64-6b83ff85becf. Applied change to temp map.
2019-08-22T21:18:19.856Z verbose hostd[14EC6B70] [Originator@6876 sub=PropertyProvider opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7dd user=vpxuser] RecordOp ASSIGN: latestEvent, ha-eventmgr. Applied change to temp map.
2019-08-22T21:18:19.856Z info hostd[14EC6B70] [Originator@6876 sub=Vimsvc.ha-eventmgr opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7dd user=vpxuser] Event 199065 : rhel7-template-ls on [esxi host redacted] in ha-datacenter is resumed
2019-08-22T21:18:19.856Z error hostd[14EC6B70] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/5d57076b-b2cc9e87-c0a4-a0369ff2a238/rhel7-template-ls/rhel7-template-ls.vmx opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7dd user=vpxuser] Invalid transition requested (VM_STATE_CREATE_SCREENSHOT -> VM_STATE_POWERING_ON): Invalid state
2019-08-22T21:18:19.856Z info hostd[14EC6B70] [Originator@6876 sub=Default opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7dd user=vpxuser] AdapterServer caught exception: vim.fault.InvalidPowerState
2019-08-22T21:18:19.856Z info hostd[14EC6B70] [Originator@6876 sub=Vimsvc.TaskManager opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7dd user=vpxuser] Task Completed : haTask-112-vim.VirtualMachine.powerOn-240998201 Status error
2019-08-22T21:18:19.856Z verbose hostd[14EC6B70] [Originator@6876 sub=PropertyProvider opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7dd user=vpxuser] RecordOp ASSIGN: info, haTask-112-vim.VirtualMachine.powerOn-240998201. Applied change to temp map.
2019-08-22T21:18:19.854Z info hostd[14DC2B70] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/5d57076b-b2cc9e87-c0a4-a0369ff2a238/rhel7-template-ls/rhel7-template-ls.vmx] Screenshot operation failed: N5Vmomi5Fault11SystemError9ExceptionE(vmodl.fault.SystemError)
--> [context]zKq7AUoCAgAAAO3WcgAjaG9zdGQAAK/FLWxpYnZtYWNvcmUuc28AADJaEgAP0A0BWU8qaG9zdGQAAabMLAHEOoQB/ESEARX6LQHE/i0An8MVAPjKFQCmxxQAH98UAFrxFABydBEAQC8kAEpBJABJGiAAsqkSAKmhHwApuh8AC7wfADQQIACwEyIA9xUiAEIYIgA9ISIA4CMiAHdAJgDvcRMA+qkfAGXnHwC0Qi4CymwAbGlicHRocmVhZC5zby4wAANOSQ1saWJjLnNvLjYA[/context]
2019-08-22T21:18:19.857Z info hostd[14DC2B70] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/5d57076b-b2cc9e87-c0a4-a0369ff2a238/rhel7-template-ls/rhel7-template-ls.vmx] State Transition (VM_STATE_CREATE_SCREENSHOT -> VM_STATE_OFF)
2019-08-22T21:18:19.857Z verbose hostd[14DC2B70] [Originator@6876 sub=PropertyProvider] RecordOp ASSIGN: disabledMethod, 112. Sent notification immediately.
2019-08-22T21:18:19.857Z info hostd[F140B70] [Originator@6876 sub=Solo.ScreenHandler] Screenshot request failed: [N5Vmomi5Fault11SystemErrorE:0x14a2f478]
2019-08-22T21:18:19.859Z verbose hostd[15540B70] [Originator@6876 sub=PropertyProvider opID=d716a7e1 user=vpxuser] RecordOp ASSIGN: info, haTask--vim.event.EventHistoryCollector.readNext-240998202. Applied change to temp map.
2019-08-22T21:18:19.859Z verbose hostd[15540B70] [Originator@6876 sub=PropertyProvider opID=d716a7e1 user=vpxuser] RecordOp ASSIGN: info, haTask--vim.event.EventHistoryCollector.readNext-240998202. Applied change to temp map.
2019-08-22T21:18:19.860Z verbose hostd[15540B70] [Originator@6876 sub=PropertyProvider opID=d716a7e2 user=vpxuser] RecordOp ASSIGN: info, haTask--vim.event.EventHistoryCollector.readNext-240998203. Applied change to temp map.
2019-08-22T21:18:19.860Z verbose hostd[15540B70] [Originator@6876 sub=PropertyProvider opID=d716a7e2 user=vpxuser] RecordOp ASSIGN: info, haTask--vim.event.EventHistoryCollector.readNext-240998203. Applied change to temp map.
2019-08-22T21:18:19.862Z verbose hostd[14E85B70] [Originator@6876 sub=PropertyProvider opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7e5 user=vpxuser] RecordOp ASSIGN: info, haTask--vim.vm.NamespaceManager.queryNamespace-240998204. Applied change to temp map.
2019-08-22T21:18:19.862Z info hostd[14E85B70] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/5d57076b-b2cc9e87-c0a4-a0369ff2a238/rhel7-template-ls/rhel7-template-ls.vmx opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7e5 user=vpxuser] State Transition (VM_STATE_OFF -> VM_STATE_NAMESPACE_CHANGE)
2019-08-22T21:18:19.862Z verbose hostd[14E85B70] [Originator@6876 sub=PropertyProvider opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7e5 user=vpxuser] RecordOp ASSIGN: disabledMethod, 112. Sent notification immediately.
2019-08-22T21:18:19.863Z error hostd[14E85B70] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/5d57076b-b2cc9e87-c0a4-a0369ff2a238/rhel7-template-ls/rhel7-template-ls.vmx opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7e5 user=vpxuser] Namespace 'ovf' not found.
2019-08-22T21:18:19.863Z info hostd[14E85B70] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/5d57076b-b2cc9e87-c0a4-a0369ff2a238/rhel7-template-ls/rhel7-template-ls.vmx opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7e5 user=vpxuser] State Transition (VM_STATE_NAMESPACE_CHANGE -> VM_STATE_OFF)
2019-08-22T21:18:19.863Z verbose hostd[14E85B70] [Originator@6876 sub=PropertyProvider opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7e5 user=vpxuser] RecordOp ASSIGN: disabledMethod, 112. Sent notification immediately.
2019-08-22T21:18:19.863Z info hostd[14E85B70] [Originator@6876 sub=Default opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7e5 user=vpxuser] AdapterServer caught exception: vim.fault.NotFound
2019-08-22T21:18:19.863Z verbose hostd[14E85B70] [Originator@6876 sub=PropertyProvider opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7e5 user=vpxuser] RecordOp ASSIGN: info, haTask--vim.vm.NamespaceManager.queryNamespace-240998204. Applied change to temp map.
2019-08-22T21:18:19.863Z info hostd[14E85B70] [Originator@6876 sub=Solo.Vmomi opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7e5 user=vpxuser] Activation [N5Vmomi10ActivationE:0x15b032a8] : Invoke done [queryNamespace] on [vim.vm.NamespaceManager:ha-vm-namespace-manager]
2019-08-22T21:18:19.863Z verbose hostd[14E85B70] [Originator@6876 sub=Solo.Vmomi opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7e5 user=vpxuser] Arg vm:
--> 'vim.VirtualMachine:112'
2019-08-22T21:18:19.863Z verbose hostd[14E85B70] [Originator@6876 sub=Solo.Vmomi opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7e5 user=vpxuser] Arg name:
--> "ovf"
2019-08-22T21:18:19.863Z info hostd[14E85B70] [Originator@6876 sub=Solo.Vmomi opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7e5 user=vpxuser] Throw vim.fault.NotFound
2019-08-22T21:18:19.863Z info hostd[14E85B70] [Originator@6876 sub=Solo.Vmomi opID=acaae532-b539-420a-badf-fd872734a5fa-4352787-h5c:70110650-c5-01-01-01-01-1f-a7e5 user=vpxuser] Result:
--> (vim.fault.NotFound) {
--> faultCause = (vmodl.MethodFault) null,
--> faultMessage = <unset>
--> msg = ""
--> }
Thank you for any advice. Thanks,,,
