Extremely long delay during Windows 10 (EFI) boot

[ibauer]

Hello,

I am using Workstation Pro 12.5.2. Both the Host and Guest operating system is Windows 10 Pro x64. When starting this VM, there is a delay about 5-6 seconds before the VMware logo appears. Then there is an additional delay about 15-16 seconds before the VMware logo is replaced with the Windows logo and the Windows is starting to boot. Apart from that, there is no problem with this particular VM, everything appears to work well.

I also noticed that when I restart the guest OS, the VMware logo is displayed almost instantly and the second delay is reduced to 5 seconds or so.

I attached the vmware.log to this message. Please help.

[wila]

Hi,

Looks like the delay is on initializing bluetooth for the guest.

FWIW, the delay is in this part of the log:

2017-01-16T19:59:01.938+01:00| vcpu-0| I125: Guest: EFI ROM version: VMW71.00V.0.B64.1507021939 (64-bit RELEASE)
some lines removed...
2017-01-16T19:59:02.560+01:00| mks| I125: GDI-Backend: successfully started by HWinMux to do window composition.
2017-01-16T19:59:02.560+01:00| mks| I125: MKS-HWinCompMux: Started GDI presentation backend
2017-01-16T19:59:02.560+01:00| mks| I125: MKS-SWB: Number of MKSWindows changed: 0 rendering MKSWindow(s) of total 1.
2017-01-16T19:59:02.576+01:00| mks| I125: MKS-SWB: Number of MKSWindows changed: 1 rendering MKSWindow(s) of total 2.
2017-01-16T19:59:03.376+01:00| vmx| I125: VMXAIOMGR: Disallowing USB connect.  2730900 us since last reopen
2017-01-16T19:59:03.431+01:00| vmx| I125: USB: Connecting device desc:name:Virtual\ Bluetooth\ Adapter vid:0e0f pid:0008 speed:full family:wireless,bluetooth deviceType:virtual-bluetooth info:0000001 version:3 id:0x600000010e0f0008
2017-01-16T19:59:03.431+01:00| vmx| I125: Policy_GetUSBDevAccess: checking usb devices at policy path: /vm/#_VMX/mvm/policyState/val/policySet/usbDevices/#
2017-01-16T19:59:03.431+01:00| vmx| I125: Policy_GetUSBDevAccess: allowConnect = YES
2017-01-16T19:59:03.431+01:00| vmx| W115: Bluetooth host backend not available.
2017-01-16T19:59:05.435+01:00| vmx| I125: USB: Connecting device desc:name:Virtual\ Bluetooth\ Adapter vid:0e0f pid:0008 speed:full family:wireless,bluetooth deviceType:virtual-bluetooth info:0000001 version:3 id:0x600000010e0f0008
2017-01-16T19:59:05.435+01:00| vmx| I125: Policy_GetUSBDevAccess: checking usb devices at policy path: /vm/#_VMX/mvm/policyState/val/policySet/usbDevices/#
2017-01-16T19:59:05.435+01:00| vmx| I125: Policy_GetUSBDevAccess: allowConnect = YES
2017-01-16T19:59:05.435+01:00| vmx| W115: Bluetooth host backend not available.
2017-01-16T19:59:11.179+01:00| vcpu-0| I125: UHCI: Global Reset
2017-01-16T19:59:15.437+01:00| vmx| I125: USB: Connecting device desc:name:Virtual\ Bluetooth\ Adapter vid:0e0f pid:0008 speed:full family:wireless,bluetooth deviceType:virtual-bluetooth info:0000001 version:3 id:0x600000010e0f0008
2017-01-16T19:59:15.437+01:00| vmx| I125: Policy_GetUSBDevAccess: checking usb devices at policy path: /vm/#_VMX/mvm/policyState/val/policySet/usbDevices/#
2017-01-16T19:59:15.437+01:00| vmx| I125: Policy_GetUSBDevAccess: allowConnect = YES
2017-01-16T19:59:15.437+01:00| vmx| W115: Bluetooth host backend not available.
2017-01-16T19:59:16.335+01:00| vcpu-0| I125: AHCI-VMM:HBA reset issued on sata0.

See also:

Re: Using EFI instead of BIOS in VM = slow ... why?

--

Wil

[ibauer]

Dear Wil,

Thanks for the reply.

There is no bluetooth adapter on the host. I have just tried to disable the Bluetooth support in this VM (unchecking the VM > Settings > Hardware > USB Controller > Share Bluetooth devices with the virtual machine option), but it had absolutely no effect on the boot delay.

I have also followed the advices presented in the thread you pointed me at, but no success at all. The CD/DVD was already set to NOT connect at power on. There is no floppy in this VM.  There is an USB card reader device, but I made sure it is connected to the host, and not the guest. The delays are still there.

I believe that the delay you were referring to occurs before the VMware logo is displayed, but I'm more concerned about the other delay that occurs after that. This one takes 15-17 seconds, then I can see a white dotted bar underneath the WMware logo, but it progresses very quickly (less than 1 second). Then the Windows logo appears and the rest of the booting process appears to be normal.

Any other idea?

[wila]

Hi,

No I'm sorry, I have no more ideas on why it would be slightly slow  there and if it can be addressed.

FWIW, the log snippet I pointed out was taking 15 seconds which is why I thought it was related to your issue.

You'll have to wait a bit and hope that dariusd‌ has time to look at your issue. He knows a lot about the subject.

--

Wil

[ibauer]

Dear Wil,

My apologies, your log snippet is indeed related to my initial boot delay. The total time between the start of this VM and booting into Windows (the time when the Windows logo first appears) is about 22 seconds, which is probably indicated by the "Tools heartbeat timeout" line in the log snippet below:

2017-01-16T19:59:17.702+01:00| vcpu-0| I125: SCSI0: RESET BUS
2017-01-16T19:59:17.702+01:00| vcpu-0| I125: SCSI0: RESET BUS
2017-01-16T19:59:17.919+01:00| vcpu-0| I125: SCSI DEVICE (scsi0:0): REQUEST SENSE without CheckCondition status.
2017-01-16T19:59:17.946+01:00| vcpu-0| I125: SCSI DEVICE (scsi0:0): REQUEST SENSE without CheckCondition status.
2017-01-16T19:59:17.959+01:00| vcpu-0| I125: DISKUTIL: scsi0:0 : capacity=167772160 logical sector size=512
2017-01-16T19:59:18.426+01:00| vcpu-0| I125: SCSI DEVICE (scsi0:1): REQUEST SENSE without CheckCondition status.
2017-01-16T19:59:18.454+01:00| vcpu-0| I125: SCSI DEVICE (scsi0:1): REQUEST SENSE without CheckCondition status.
2017-01-16T19:59:18.467+01:00| vcpu-0| I125: DISKUTIL: scsi0:1 : capacity=33554432 logical sector size=512
2017-01-16T19:59:22.088+01:00| vcpu-0| I125: Tools: Tools heartbeat timeout.
2017-01-16T19:59:41.386+01:00| vcpu-1| I125: CPU reset: soft (mode 2)
2017-01-16T19:59:43.586+01:00| vcpu-0| I125: Guest: About to do EFI boot: Windows Boot Manager

Thanks for your help so far. I hope dariusd will notice this thread and jump in.

Ivo

[dariusd]

Noticed! And jumped in!

Thanks for providing the log, Ivo.  WhiteKnight (in the other thread) has forwarded their vmware.log to me for investigation, so I now have a bit more information to work with.  The symptom appears roughly identical at first glance.  It's super helpful to have two independent reports of the same problem... now we can start the process of trying to find common factors.

I've been a touch busy lately, but I'll try to keep this on my to-do list and let you know what I can find out.

(And thanks to Wil, as always, for ensuring that I get connected to the discussion threads which matter to me. :smileycool:)

Cheers,

--

Darius

[ibauer]

Dear Darius,

I'm glad you have joined this discussion! Should you want me to provide you with any follow-up info that may help you solve this issue, just please ask.

Ivo