We are trying to use Invoke-VMScript to configure a VM without network connectivity.
When using Invoke-VMScript cmdlet we get the error "Could not locate "Powershell" script interpreter in any of the expected locations. Probably you do not have enough permissions to execute command within guest."
We are using the local administrator account on the vm. We’ve tested running the same script on the VM, and it works.
Can you share the Invoke-VMScript command you are using?
Which PowerCLI version are you using?
Did you check if there is anything in the vmware.log file?
You could also enable debugging for VMware Tools (see KB1007873), and check if that if that provides more info in the log.
Blog: lucd.info Twitter: @LucD22 Co-author PowerCLI Reference
Hi LucD,
I was hoping I would hear from you on this but I figured you would be at VMworld.
We are running VMware PowerCLI 11.3.0 build 13990089.
We tail vmware.log and this is all that's logged.
2019-08-27T19:20:32.078Z| vmx| I125: VigorTransportProcessClientPayload: opID=2bb59b0-1-5484 seq=408585: Receiving GuestOps.CreateTemporaryFile request.
2019-08-27T19:20:32.162Z| vcpu-0| I125: VigorTransport_ServerSendResponse opID=2bb59b0-1-5484 seq=408585: Completed GuestOps request.
2019-08-27T19:20:32.600Z| vmx| I125: VigorTransportProcessClientPayload: opID=606ada00-e6-548d seq=408600: Receiving GuestOps.DeleteFile request.
2019-08-27T19:20:32.664Z| vcpu-0| I125: VigorTransport_ServerSendResponse opID=606ada00-e6-548d seq=408600: Completed GuestOperations request.
Here is the script we are trying to run.
param(
[parameter()]
[System.String]
$VM = "Test3",
[parameter()]
[System.String]
$GuestUser = "sysop",
[parameter(mandatory = $true)]
[System.String]
$GuestPassword
)
Set-StrictMode -Version Latest
$ErrorActionPreference = "Stop"
$GuestCredential = New-Object -TypeName System.Management.Automation.PSCredential -ArgumentList $GuestUser, ($GuestPassword | ConvertTo-SecureString -AsPlainText -Force)
$HostCredential = Get-Credential -Message "Host Credential"
Write-Host -ForegroundColor Green "Connecting to VIServer"
Connect-VIServer -server $VIServer -credential $HostCredential
$InvokeSettings = @{
ScriptText = "Get-ChildItem"
VM = $vm
GuestCredential = $GuestCredential
Server = "$vCenter"
}
Invoke-VMScript @InvokeSettings
Are you sure that VM is running a Windows guest OS with powershell installed?
If it is a Linux guest OS, you will have to use ScriptType 'bash' and start pwsh in the code you send.
See something similar in Invoke-VMScript not working on Debian 9
Blog: lucd.info Twitter: @LucD22 Co-author PowerCLI Reference
Can you try the following variation.
It waits till the GuestOperationsReady property says $true
[parameter()]
[System.String]
$VM = "Test3",
[parameter()]
[System.String]
$GuestUser = "sysop",
[parameter(mandatory = $true)]
[System.String]
$GuestPassword
)
Set-StrictMode -Version Latest
$ErrorActionPreference = "Stop"
$GuestCredential = New-Object -TypeName System.Management.Automation.PSCredential -ArgumentList $GuestUser, ($GuestPassword | ConvertTo-SecureString -AsPlainText -Force)
$HostCredential = Get-Credential -Message "Host Credential"
Write-Host -ForegroundColor Green "Connecting to VIServer"
Connect-VIServer -server $VIServer -credential $HostCredential
$vmObj = Get-VM -Name $VM
while (-not $vmObj.ExtensionData.Guest.GuestOperationsReady) {
sleep 5
$vmObj = Get-VM -Name $VM
}
$InvokeSettings = @{
ScriptText = "Get-ChildItem"
VM = $vmObj
GuestCredential = $GuestCredential
Server = "$vCenter"
}
Invoke-VMScript @InvokeSettings
Blog: lucd.info Twitter: @LucD22 Co-author PowerCLI Reference
We tried the suggestion but received the same result.
Checking the $vmObj.ExtensionData.Guest.GuestOperationsReady variable, it was already True, so the script skipped the wait loop.
Did you enable VMware Tools debugging (the KB I linked to earlier)?
It might give some more info.
Blog: lucd.info Twitter: @LucD22 Co-author PowerCLI Reference
Did you already try adding the -ScriptType PowerShell parameter to the Invoke-VMScript cmdlet?
Blog: lucd.info Twitter: @LucD22 Co-author PowerCLI Reference
It failed with this error.
Invoke-VMScript : 9/3/2019 12:01:38 PM Invoke-VMScript An error occurred while sending the request.
At line:1 char:1
+ Invoke-VMScript @InvokeSettings -ScriptType Powershell
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
+ CategoryInfo : NotSpecified: (:) [Invoke-VMScript], ViError
+ FullyQualifiedErrorId : Client20_VmGuestServiceImpl_DownloadFileFromGuest_DownloadError,VMware.VimAutomation.ViCore.Cmdlets.Commands.InvokeVmScript
Are you sure that port 902 between the guest OS in that VM and the ESXi node on which the VM is running is open?
That is the port used to communicate for the GuestOperations.
Perhaps try disabling the FW in the guest OS as a test.
Blog: lucd.info Twitter: @LucD22 Co-author PowerCLI Reference
We are automating our server build process and at the moment the VM has no network connectivity. We are trying to use Invoke-VMScript to configure the NIC to bring it online and continue the build.
Sorry, I stated that incorrect, I meant port 902 between the station where you run Invoke-VMScript and the ESXi node where the VM is hosted.
The guest OS itself doesn't need network connectivity
Blog: lucd.info Twitter: @LucD22 Co-author PowerCLI Reference
I've verified that TCP/UDP 902 are open from the machine running Invoke-VMScript to the ESXi host where the guest resides that we are trying to interact with.
That log you attached earlier, is that the vmware.log for that VM?
Blog: lucd.info Twitter: @LucD22 Co-author PowerCLI Reference
It's the VMware Tools vmsvc debug log from within the guest.
Could also have a look, or attach, the vmware.log file.
You find that in the VM's folder on the datastore.
Blog: lucd.info Twitter: @LucD22 Co-author PowerCLI Reference
We ran the script while tail vmware.log and captured 4 lines.
vmware.log
2019-09-03T20:20:53.996Z| vmx| I125: VigorTransportProcessClientPayload: opID=730a5939-b1-fa24 seq=671536: Receiving GuestOps.CreateTemporaryFile request.
2019-09-03T20:20:54.125Z| vcpu-0| I125: VigorTransport_ServerSendResponse opID=730a5939-b1-fa24 seq=671536: Completed GuestOps request.
2019-09-03T20:20:54.382Z| vmx| I125: VigorTransportProcessClientPayload: opID=7663c460-b1-fa2d seq=671551: Receiving GuestOps.DeleteFile request.
2019-09-03T20:20:54.423Z| vcpu-0| I125: VigorTransport_ServerSendResponse opID=7663c460-b1-fa2d seq=671551: Completed GuestOperations request.
vmsvc.log
[Sep 03 14:20:38.850] [ debug] [vmsvc] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:20:40.716] [ debug] [vmsvc] RpcIn: received 5 bytes, content:"ping\00"
[Sep 03 14:20:40.716] [ debug] [vmsvc] RpcIn: sending 3 bytes
[Sep 03 14:20:43.904] [ debug] [vmsvc] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:20:47.700] [ debug] [vmsvc] RpcIn: received 152 bytes, content:"Vix_1_Relayed_Command "10c6cb9924e7f4ed"\00\01\00\0dÐ\05\00o\00\00\003\00\00\00\1f\00\00\00\1d\00\00\00\0dµ\00\00\00\00\01\00\00..."
[Sep 03 14:20:47.700] [ message] [vix] VixTools_ProcessVixCommand: command 181
[Sep 03 14:20:47.701] [ debug] [VCGA] VGAuth_CreateHandleForUsername: Created handle 0000000001DEE1D0
[Sep 03 14:20:47.727] [ debug] [VCGA] [function VGAuthLoadUserProfile, file d:/build/ob/bora-8059742/bora-vmsoft/vgauth/lib/impersonateWin32.c, line 123], Loaded profile for user 'sysop'
[Sep 03 14:20:47.727] [ debug] [vix] VixToolsImpersonateUser: successfully impersonated user sysop
[Sep 03 14:20:47.727] [ debug] [vix] VixToolsCreateTempFile: User: sysop
[Sep 03 14:20:47.727] [ debug] [vix] VixToolsCreateTempFile: returning 'C:\Users\sysop\AppData\Local\Temp\powerclivmware123'
[Sep 03 14:20:47.727] [ debug] [VCGA] [function VGAuthUnloadUserProfile, file d:/build/ob/bora-8059742/bora-vmsoft/vgauth/lib/impersonateWin32.c, line 156], Unloaded profile for user 'sysop'
[Sep 03 14:20:47.727] [ debug] [VCGA] VGAuth_UserHandleFree: Freed handle 0000000001DEE1D0
[Sep 03 14:20:47.727] [ message] [vix] VixToolsCreateTempFile: opcode 181 returning 0
[Sep 03 14:20:47.727] [ debug] [vix] ToolsDaemonTcloReceiveVixCommand: command 181, additionalError = 0
[Sep 03 14:20:47.727] [ debug] [vmsvc] RpcIn: sending 59 bytes
[Sep 03 14:20:48.025] [ debug] [vmsvc] RpcIn: received 181 bytes, content:"Vix_1_Relayed_Command "10c6cb9a1ae04501"\00\01\00\0dÐ\05\00Œ\00\00\003\00\00\00<\00\00\00\1d\00\00\00\05Â\00\00\00\00\01\00\00ÿÿ..."
[Sep 03 14:20:48.025] [ message] [vix] VixTools_ProcessVixCommand: command 194
[Sep 03 14:20:48.025] [ debug] [VCGA] VGAuth_CreateHandleForUsername: Created handle 0000000001DEE1D0
[Sep 03 14:20:48.025] [ debug] [VCGA] [function VGAuthLoadUserProfile, file d:/build/ob/bora-8059742/bora-vmsoft/vgauth/lib/impersonateWin32.c, line 123], Loaded profile for user 'sysop'
[Sep 03 14:20:48.025] [ debug] [vix] VixToolsImpersonateUser: successfully impersonated user sysop
[Sep 03 14:20:48.025] [ debug] [vix] VixToolsDeleteObject: User: sysop path: 'C:\Users\sysop\AppData\Local\Temp\powerclivmware123'
[Sep 03 14:20:48.025] [ debug] [VCGA] [function VGAuthUnloadUserProfile, file d:/build/ob/bora-8059742/bora-vmsoft/vgauth/lib/impersonateWin32.c, line 156], Unloaded profile for user 'sysop'
[Sep 03 14:20:48.025] [ debug] [VCGA] VGAuth_UserHandleFree: Freed handle 0000000001DEE1D0
[Sep 03 14:20:48.025] [ message] [vix] VixToolsDeleteObject: opcode 194 returning 0
[Sep 03 14:20:48.025] [ debug] [vix] ToolsDaemonTcloReceiveVixCommand: command 194, additionalError = 0
[Sep 03 14:20:48.025] [ debug] [vmsvc] RpcIn: sending 8 bytes
[Sep 03 14:20:49.000] [ debug] [vmsvc] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:20:50.452] [ debug] [guestinfo] Entered guest info stats poll.
[Sep 03 14:20:50.452] [ debug] [guestinfo] Exiting guest info stats poll: gather thread woken.
[Sep 03 14:20:50.452] [ debug] [guestinfo] GuestInfoStatProviderWorker: Stat worker refreshing
[Sep 03 14:20:50.484] [ debug] [guestinfo] GuestInfoStatProviderWorker: Stat worker serializing
[Sep 03 14:20:50.484] [ debug] [guestinfo] GuestInfoStatProviderWorker: Stat worker responding
[Sep 03 14:20:50.484] [ debug] [guestinfo] GuestInfoStatProviderWorker: Stat worker queuing response
[Sep 03 14:20:50.484] [ debug] [guestinfo] Entered guest info stats reporter.
[Sep 03 14:20:50.484] [ debug] [guestinfo] Entered update vmdb: 8.
[Sep 03 14:20:50.484] [ debug] [guestinfo] Sending GuestMemInfo message.
[Sep 03 14:20:50.484] [ debug] [vmsvc] RpcChannel: Sending: 322 bytes
[Sep 03 14:20:50.484] [ debug] [vmsvc] VSockChan: Sending request for conn 576, reqLen=322
[Sep 03 14:20:50.484] [ debug] [vmsvc] SimpleSock: Sent 354 bytes from socket 576
[Sep 03 14:20:50.486] [ debug] [vmsvc] SimpleSock: Recved 4 bytes from socket 576
[Sep 03 14:20:50.486] [ debug] [vmsvc] SimpleSock: Recved 14 bytes from socket 576
[Sep 03 14:20:50.486] [ debug] [vmsvc] VSockOut: recved 2 bytes for conn 576
[Sep 03 14:20:50.486] [ debug] [vmsvc] RpcChannel: Recved 0 bytes
[Sep 03 14:20:50.486] [ debug] [guestinfo] GuestMemInfo sent successfully.
[Sep 03 14:20:50.486] [ debug] [guestinfo] Returning after updating guest information: 8
[Sep 03 14:20:50.486] [ debug] [guestinfo] Reported 0x00000132 stat bytes.
[Sep 03 14:20:50.486] [ debug] [guestinfo] Exiting guest info stats reporter.
vmusr.username.log
[Sep 03 14:20:33.324] [ debug] [vmusr] RpcChannel: Sending: 28 bytes
[Sep 03 14:20:33.324] [ debug] [vmusr] VSockChan: Sending request for conn 524, reqLen=28
[Sep 03 14:20:33.324] [ debug] [vmusr] SimpleSock: Sent 60 bytes from socket 524
[Sep 03 14:20:33.324] [ debug] [vmusr] SimpleSock: Recved 4 bytes from socket 524
[Sep 03 14:20:33.324] [ debug] [vmusr] SimpleSock: Recved 15 bytes from socket 524
[Sep 03 14:20:33.324] [ debug] [vmusr] VSockOut: recved 3 bytes for conn 524
[Sep 03 14:20:33.324] [ debug] [vmusr] RpcChannel: Recved 1 bytes
[Sep 03 14:20:36.029] [ debug] [vmusr] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:20:41.104] [ debug] [vmusr] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:20:46.199] [ debug] [vmusr] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:20:47.962] [ debug] [vmusr] RpcIn: received 5 bytes, content:"ping\00"
[Sep 03 14:20:47.962] [ debug] [vmusr] RpcIn: sending 3 bytes
[Sep 03 14:20:51.291] [ debug] [vmusr] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:20:56.366] [ debug] [vmusr] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:21:01.421] [ debug] [vmusr] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:21:03.009] [ debug] [vmusr] RpcIn: received 5 bytes, content:"ping\00"
[Sep 03 14:21:03.009] [ debug] [vmusr] RpcIn: sending 3 bytes
[Sep 03 14:21:06.480] [ debug] [vmusr] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:21:11.513] [ debug] [vmusr] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:21:16.546] [ debug] [vmusr] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:21:18.014] [ debug] [vmusr] RpcIn: received 5 bytes, content:"ping\00"
[Sep 03 14:21:18.014] [ debug] [vmusr] RpcIn: sending 3 bytes
[Sep 03 14:21:21.573] [ debug] [vmusr] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:21:26.586] [ debug] [vmusr] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:21:31.672] [ debug] [vmusr] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:21:33.113] [ debug] [vmusr] RpcIn: received 5 bytes, content:"ping\00"
[Sep 03 14:21:33.113] [ debug] [vmusr] RpcIn: sending 3 bytes
[Sep 03 14:21:33.323] [ debug] [vmusr] RpcChannel: Sending: 28 bytes
[Sep 03 14:21:33.323] [ debug] [vmusr] VSockChan: Sending request for conn 524, reqLen=28
[Sep 03 14:21:33.323] [ debug] [vmusr] SimpleSock: Sent 60 bytes from socket 524
[Sep 03 14:21:33.323] [ debug] [vmusr] SimpleSock: Recved 4 bytes from socket 524
[Sep 03 14:21:33.323] [ debug] [vmusr] SimpleSock: Recved 15 bytes from socket 524
[Sep 03 14:21:33.323] [ debug] [vmusr] VSockOut: recved 3 bytes for conn 524
[Sep 03 14:21:33.323] [ debug] [vmusr] RpcChannel: Recved 1 bytes
[Sep 03 14:21:36.694] [ debug] [vmusr] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:21:41.743] [ debug] [vmusr] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:21:46.813] [ debug] [vmusr] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:21:48.150] [ debug] [vmusr] RpcIn: received 5 bytes, content:"ping\00"
[Sep 03 14:21:48.150] [ debug] [vmusr] RpcIn: sending 3 bytes
[Sep 03 14:21:51.847] [ debug] [vmusr] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:21:56.948] [ debug] [vmusr] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:22:02.044] [ debug] [vmusr] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:22:03.182] [ debug] [vmusr] RpcIn: received 5 bytes, content:"ping\00"
[Sep 03 14:22:03.182] [ debug] [vmusr] RpcIn: sending 3 bytes
[Sep 03 14:22:07.166] [ debug] [vmusr] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:22:12.226] [ debug] [vmusr] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:22:17.311] [ debug] [vmusr] RpcIn: received 0 bytes, empty TCLO poll
[Sep 03 14:22:18.103] [ debug] [dndcp] PointerUpdatePointerLoop: grabbed
[Sep 03 14:22:18.212] [ debug] [vmusr] RpcIn: received 5 bytes, content:"ping\00"
[Sep 03 14:22:18.212] [ debug] [vmusr] RpcIn: sending 3 bytes
[Sep 03 14:22:18.509] [ debug] [dndcp] CopyPaste_GetBackdoorSelections: enter
[Sep 03 14:22:18.509] [ debug] [dndcp] CopyPaste_GetSelectionBD: get selection from host
[Sep 03 14:22:18.509] [ debug] [dndcp] CopyPaste_GetSelectionBD: Host selection len 579: [2019-09-03T20:20:53.996Z| vmx| I125: VigorTransportProcessClientPayload: opID=730a5939-b1-fa24 seq=671536: Receiving GuestOps.CreateTemporaryFile request.
2019-09-03T20:20:54.125Z| vcpu-0| I125: VigorTransport_ServerSendResponse opID=730a5939-b1-fa24 seq=671536: Completed GuestOps request.
2019-09-03T20:20:54.382Z| vmx| I125: VigorTransportProcessClientPayload: opID=7663c460-b1-fa2d seq=671551: Receiving GuestOps.DeleteFile request.
2019-09-03T20:20:54.423Z| vcpu-0| I125: VigorTransport_ServerSendResponse opID=7663c460-b1-fa2d seq=671551: Completed GuestOperations request.]
The transfer of the files to/from the VM seems to be ok.
Could you try to run a batch script. Change ScriptType and ScriptText
-ScriptType Bat -ScriptText "cd"
Blog: lucd.info Twitter: @LucD22 Co-author PowerCLI Reference