[This issue has been fixed with the VMware Tools releases of ESXi 5.0 Update 2 and ESXi 5.1 Update 1.
Note that you can run more recent versions of VMware Tools to fix this on your VMs even if you haven’t updated your hosts, this is fully supported]
The Invoke-VMScript PowerCLI function provides a cool way to execute scriptcode inside guests through the VMware tools, on Linux and Windows VMs (as long as a couple of prerequisites are met). While playing with it a while ago, I noticed that on many VMs, it wouldn’t run properly, instead just spilling the error “The guest operations agent could not be contacted”. To fix this, the VMware Tools service inside the guest had to be restarted. Not thinking too much of the oddness, I left it at that since I didn’t have a real use case for the Invoke-VMScript function.
This changed later on, when I ran into the same issue again that made me finally dig a bit deeper.
Quite a few other people reported this issue on the VMTN forums since some time, but there was no solution posted. A reference to Backup Exec initiated backup operations made me curious though – had I not fought with another problem induced by it already?
I then was able to track it down to the Reload Virtual Machine operation, which Backup Exec triggers each time before removing the snapshot of a backup too. But not only that, unlike my previous issue, this problem is fully reproducible manually without any involvement of Backup Exec:
1. Confirm Invoke-VMScript works currently (restart VMware Tools if not):
Invoke-VMScript -ScriptText ‘ipconfig’ -VM $vm -GuestCredential $creds
–> Is being executed OK
2. On the ESXi shell of the host running the VM (I actually don’t know any other way to trigger the Reload-VM task manually), get the VM ID (or VMX path) with vim-cmd vmsvc/getallvms | grep -i [MyVMName]
3.Now perform a Reload-VM operation via vim-cmd vmsvc/reload [ID]
The vmware.log file of the VM will now record the following messages:
2012-11-19T15:56:59.760Z| vmx| VmdbPipeStreamsOvlError Couldn't read: OVL_STATUS_EOF, (11) Resource temporarily unavailable. 2012-11-19T15:56:59.760Z| vmx| VmdbCnxDisconnect: Disconnect: closed pipe for pub cnx '/db/connection/#6/' (-32) 2012-11-19T15:56:59.760Z| vmx| VmdbDbRemoveCnx: Removing Cnx from Db for '/db/connection/#6/' 2012-11-19T15:56:59.771Z| vmx| SOCKET 2 (78) recv detected client closed connection 2012-11-19T15:56:59.771Z| vmx| Vix: [1889886 mainDispatch.c:2984]: VMAutomation: Connection Error (4) on connection 1. 2012-11-19T15:56:59.818Z| vmx| VmdbAddConnection: cnxPath=/db/connection/#b/, cnxIx=3 2012-11-19T15:56:59.866Z| vmx| Vix: [1889886 vigorCommands.c:940]: VigorHotPlugManagerEndBatchCommandCallback: vmdbErr = -24
4. Try running an Invoke-VMScript command again and it will fail with the dreaded “The guest operations agent could not be contacted”:
D:\> Invoke-VMScript -ScriptText 'ipconfig' -VM $vm -GuestCredential $creds Invoke-VMScript : 19.11.2012 16:57:06 Invoke-VMScript The guest operations agent could not be contacted. Bei Zeile:1 Zeichen:16 + Invoke-VMScript <<<< -ScriptText 'ipconfig' -VM $vm -GuestCredential $creds + CategoryInfo : NotSpecified: (:) [Invoke-VMScript], ViError + FullyQualifiedErrorId : Client20_VmGuestServiceImpl_RunScriptInGuest_ViError,VMware.VimAutomation.ViCore.Cmdlets.Commands.InvokeVmScript
5. Restart the VMware Tools service in the VM and Invoke-VMScript will work again until the next Reload-VM takes place. vmware.log messages during tools restart:
2012-11-19T15:57:41.261Z| vcpu-0| TOOLS autoupgrade protocol version 0 2012-11-19T15:57:41.261Z| vcpu-0| TOOLS ToolsCapabilityGuestTempDirectory received 0 2012-11-19T15:57:41.265Z| vcpu-0| GuestRpc: Reinitializing Channel 0(toolbox) 2012-11-19T15:57:41.265Z| vcpu-0| GuestRpc: Channel 0 reinitialized. 2012-11-19T15:57:43.180Z| vcpu-0| GuestRpc: Channel 0, guest application toolbox. 2012-11-19T15:57:43.186Z| vcpu-0| TOOLS ToolsCapabilityGuestTempDirectory received 1 C:\Windows\TEMP\vmware-SYSTEM 2012-11-19T15:57:43.201Z| vcpu-0| TOOLS autoupgrade protocol version 2 2012-11-19T15:57:43.202Z| vcpu-0| TOOLS ToolsCapabilityGuestConfDirectory received C:\ProgramData\VMware\VMware Tools 2012-11-19T15:57:43.203Z| vcpu-0| TOOLS Received tools.set.version rpc call, version = 8389. 2012-11-19T15:57:43.203Z| vcpu-0| ToolsSetVersionWork did nothing; new tools version (8389) matches old Tools version 2012-11-19T15:57:43.204Z| vcpu-0| TOOLS unified loop capability requested by 'toolbox'; now sending options via TCLO 2012-11-19T15:57:43.205Z| vcpu-0| Guest: toolbox: Version: build-652272 2012-11-19T16:00:28.567Z| vcpu-0| TOOLS unified loop capability requested by 'toolbox-ui'; now sending options via TCLO 2012-11-19T16:00:28.567Z| vcpu-0| GuestRpc: Channel 6, guest application toolbox-ui.
This is perfectly reproducible with Windows and Linux VMs on ESXi 5.0 and 5.1, with the respective PowerCLI and VMware Tools versions, on 4.x probably too (should have been on 4.1 when I first played with Invoke-VMScript).
This issue was confirmed by VMware support too, also hinting at the following hostd.log messages:
TS [XXX info 'vm:/vmfs/volumes/<UUID>/<VM>/<VM>.vmx' opID=XXX] CheckVMStateForGuestOperation: GuestOps are not ready. TS [XXX info 'Default' opID=XXX] AdapterServer caught exception: vim.fault.GuestOperationsUnavailable
It appears that unfortunately, there is no workaround other than restarting VMware tools in the guest for now. As the VMware support pointed out, this known issue is supposed to be fixed with the soon-ish releases of 5.0 Update 2 and 5.1 Update 1.