VMware

VMware power-on is delayed on some but not all hosts, same hardware (1 second vs 16 seconds)

Leave a comment
This post was originally published on this site

I’m having a strange issue that I hope someone else has come across it, hostd.log doesn’t show any information except to confirm the boot time is slower (16 seconds!).

 

Using this script.

 

 

for ($i=1; $i -le 25; $i++)
    {
    Start-VM -VM $(Get-VM 'vHost01 Test') -Confirm:$false
    Start-VM -VM $(Get-VM 'vHost02 Test') -Confirm:$false
    Start-VM -VM $(Get-VM 'vHost03 Test') -Confirm:$false
    sleep -seconds 2
    Stop-VM -VM $(Get-VM 'vHost01 Test') -Confirm:$false
    Stop-VM -VM $(Get-VM 'vHost02 Test') -Confirm:$false
    Stop-VM -VM $(Get-VM 'vHost03 Test') -Confirm:$false
    sleep -seconds 2
    }

 

Screenshots to show consistency.

B3azV.png

fU0r2.png

EimXR.png

 

 

All systems have local nvme disks, 2.1Ghz gold procs, and are booting a new & empty vm, same hardware versions, same os patch, same everything.

 

 

Systems all running `VMware ESXi, 6.7.0, 10302608`

 

 

Each Server is configured exactly the same:

(1) SD w/ESXi installed

(1) NVMe SSD for Datastore, all datastores are local.

(2) Intel Gold 2.1Ghz 6130 Processors

768 GB of DDR4 RAM

 

 

**Host1**

 

 

12788-auto-112789-h5c:70032863-28-02-01-13-f9e3 user=vpxuser:VSPHERE.LOCALAdministrator] State Transition (VM_STATE_OFF -> VM_STATE_POWERING_ON)
2018-10-23T14:26:35.376Z info hostd[2100207] [Originator@6876 sub=Libs opID=14bb9f56-84b2-4978-9cd2-bd86db47993f-112788-auto-112789-h5c:70032863-28-02-01-13-f9e3 user=vpxuser:VSPHERE.LOCALAdministrator] SIOC: SIOC is notified not to start injector
2018-10-23T14:26:35.376Z warning hostd[2100207] [Originator@6876 sub=Hostsvc.Tpm20Provider opID=14bb9f56-84b2-4978-9cd2-bd86db47993f-112788-auto-112789-h5c:70032863-28-02-01-13-f9e3 user=vpxuser:VSPHERE.LOCALAdministrator] Unable to retrieve TPM/TXT status. TPM functionality will be unavailable. Failure reason: Unable to get node: Sysinfo error: Not foundSee VMkernel log for details..
2018-10-23T14:26:35.378Z info hostd[2100207] [Originator@6876 sub=Libs opID=14bb9f56-84b2-4978-9cd2-bd86db47993f-112788-auto-112789-h5c:70032863-28-02-01-13-f9e3 user=vpxuser:VSPHERE.LOCALAdministrator] DictionaryLoad: Cannot open file "/usr/lib/vmware/config": No such file or directory.
2018-10-23T14:26:35.378Z info hostd[2100207] [Originator@6876 sub=Libs opID=14bb9f56-84b2-4978-9cd2-bd86db47993f-112788-auto-112789-h5c:70032863-28-02-01-13-f9e3 user=vpxuser:VSPHERE.LOCALAdministrator] Could not expand environment variable HOME.
2018-10-23T14:26:35.378Z info hostd[2100207] [Originator@6876 sub=Libs opID=14bb9f56-84b2-4978-9cd2-bd86db47993f-112788-auto-112789-h5c:70032863-28-02-01-13-f9e3 user=vpxuser:VSPHERE.LOCALAdministrator] DictionaryLoad: Cannot open file "~/.vmware/config": No such file or directory.
2018-10-23T14:26:35.380Z info hostd[2100207] [Originator@6876 sub=Libs opID=14bb9f56-84b2-4978-9cd2-bd86db47993f-112788-auto-112789-h5c:70032863-28-02-01-13-f9e3 user=vpxuser:VSPHERE.LOCALAdministrator] Found vmx as /bin/vmx
2018-10-23T14:26:35.380Z info hostd[2100207] [Originator@6876 sub=Libs opID=14bb9f56-84b2-4978-9cd2-bd86db47993f-112788-auto-112789-h5c:70032863-28-02-01-13-f9e3 user=vpxuser:VSPHERE.LOCALAdministrator] Starting vmx as /bin/vmx
2018-10-23T14:26:35.380Z info hostd[2100207] [Originator@6876 sub=vm opID=14bb9f56-84b2-4978-9cd2-bd86db47993f-112788-auto-112789-h5c:70032863-28-02-01-13-f9e3 user=vpxuser:VSPHERE.LOCALAdministrator] VigorExecVMXExCommon: VM /vmfs/volumes/5b9bb253-6d8a5196-5fdc-ac1f6b0e6418/New Virtual Machine/New Virtual Machine.vmx in directory /vmfs/volumes/5b9bb253-6d8a5196-5fdc-ac1f6b0e6418/New Virtual Machine
2018-10-23T14:26:35.380Z info hostd[2100207] [Originator@6876 sub=vm opID=14bb9f56-84b2-4978-9cd2-bd86db47993f-112788-auto-112789-h5c:70032863-28-02-01-13-f9e3 user=vpxuser:VSPHERE.LOCALAdministrator] VigorExecVMXExCommon: Exec()'ing /bin/vmx /vmfs/volumes/5b9bb253-6d8a5196-5fdc-ac1f6b0e6418/New Virtual Machine/New Virtual Machine.vmx.
2018-10-23T14:26:35.381Z info hostd[2100207] [Originator@6876 sub=Libs opID=14bb9f56-84b2-4978-9cd2-bd86db47993f-112788-auto-112789-h5c:70032863-28-02-01-13-f9e3 user=vpxuser:VSPHERE.LOCALAdministrator] Vigor: VMKernel_ForkExec(/bin/vmx, detached=1): status=0 pid=2110313
2018-10-23T14:26:35.765Z info hostd[2099717] [Originator@6876 sub=Vimsvc.ha-eventmgr] Event 223 : New Virtual Machine on  localhost in ha-datacenter is powered on

 

**Host2** (and host3)

 

 

12788-auto-112789-h5c:70032863-28-01-01-82-212a user=vpxuser:VSPHERE.LOCALAdministrator] State Transition (VM_STATE_OFF -> VM_STATE_POWERING_ON)
2018-10-23T07:26:44.667Z info hostd[2099611] [Originator@6876 sub=Libs opID=14bb9f56-84b2-4978-9cd2-bd86db47993f-112788-auto-112789-h5c:70032863-28-01-01-82-212a user=vpxuser:VSPHERE.LOCALAdministrator] SIOC: SIOC is notified not to start injector
2018-10-23T07:26:44.667Z warning hostd[2099611] [Originator@6876 sub=Hostsvc.Tpm20Provider opID=14bb9f56-84b2-4978-9cd2-bd86db47993f-112788-auto-112789-h5c:70032863-28-01-01-82-212a user=vpxuser:VSPHERE.LOCALAdministrator] Unable to retrieve TPM/TXT status. TPM functionality will be unavailable. Failure reason: Unable to get node: Sysinfo error: Not foundSee VMkernel log for details..
2018-10-23T07:26:44.669Z info hostd[2099611] [Originator@6876 sub=Libs opID=14bb9f56-84b2-4978-9cd2-bd86db47993f-112788-auto-112789-h5c:70032863-28-01-01-82-212a user=vpxuser:VSPHERE.LOCALAdministrator] DictionaryLoad: Cannot open file "/usr/lib/vmware/config": No such file or directory.
2018-10-23T07:26:44.669Z info hostd[2099611] [Originator@6876 sub=Libs opID=14bb9f56-84b2-4978-9cd2-bd86db47993f-112788-auto-112789-h5c:70032863-28-01-01-82-212a user=vpxuser:VSPHERE.LOCALAdministrator] Could not expand environment variable HOME.
2018-10-23T07:26:44.669Z info hostd[2099611] [Originator@6876 sub=Libs opID=14bb9f56-84b2-4978-9cd2-bd86db47993f-112788-auto-112789-h5c:70032863-28-01-01-82-212a user=vpxuser:VSPHERE.LOCALAdministrator] DictionaryLoad: Cannot open file "~/.vmware/config": No such file or directory.
2018-10-23T07:26:44.671Z info hostd[2099611] [Originator@6876 sub=Libs opID=14bb9f56-84b2-4978-9cd2-bd86db47993f-112788-auto-112789-h5c:70032863-28-01-01-82-212a user=vpxuser:VSPHERE.LOCALAdministrator] Found vmx as /bin/vmx
2018-10-23T07:26:44.671Z info hostd[2099611] [Originator@6876 sub=Libs opID=14bb9f56-84b2-4978-9cd2-bd86db47993f-112788-auto-112789-h5c:70032863-28-01-01-82-212a user=vpxuser:VSPHERE.LOCALAdministrator] Starting vmx as /bin/vmx
2018-10-23T07:26:44.671Z info hostd[2099611] [Originator@6876 sub=vm opID=14bb9f56-84b2-4978-9cd2-bd86db47993f-112788-auto-112789-h5c:70032863-28-01-01-82-212a user=vpxuser:VSPHERE.LOCALAdministrator] VigorExecVMXExCommon: VM /vmfs/volumes/5b9bb26a-d53a0f08-9b51-ac1f6b0e6454/New Virtual Machine/New Virtual Machine.vmx in directory /vmfs/volumes/5b9bb26a-d53a0f08-9b51-ac1f6b0e6454/New Virtual Machine
2018-10-23T07:26:44.671Z info hostd[2099611] [Originator@6876 sub=vm opID=14bb9f56-84b2-4978-9cd2-bd86db47993f-112788-auto-112789-h5c:70032863-28-01-01-82-212a user=vpxuser:VSPHERE.LOCALAdministrator] VigorExecVMXExCommon: Exec()'ing /bin/vmx /vmfs/volumes/5b9bb26a-d53a0f08-9b51-ac1f6b0e6454/New Virtual Machine/New Virtual Machine.vmx.
2018-10-23T07:26:44.672Z info hostd[2099611] [Originator@6876 sub=Libs opID=14bb9f56-84b2-4978-9cd2-bd86db47993f-112788-auto-112789-h5c:70032863-28-01-01-82-212a user=vpxuser:VSPHERE.LOCALAdministrator] Vigor: VMKernel_ForkExec(/bin/vmx, detached=1): status=0 pid=2107626
2018-10-23T07:27:00.067Z info hostd[2100473] [Originator@6876 sub=Vimsvc.ha-eventmgr] Event 131 : New Virtual Machine on  localhost in ha-datacenter is powered on

Leave a Reply

This site uses Akismet to reduce spam. Learn how your comment data is processed.