VMware Workstation 无法连接到虚拟机问题排查（一）

VMware Workstation无法连接到虚拟机问题排查

近期在使用新电脑安装VMware Workstation，启动虚拟机实例的时候出现失败，提示为:“VMware Workstation 无法连接到虚拟机。请确保您有权运行该程序、访问该程序使用的所有目录以及访问所有临时文件目录。未能将管道连接到虚拟机: 系统找不到指定的文件。”；错误截图如下：

在网上查了查了一下很多网友遇到了类似问题，提出过很多的解决方案：

1. VMware服务异常。
2. 重装VMWare Workstation。
3. 重装VC运行时库。
4. 通过管理员权限启动VMWare Workstation。

通过尝试“通过管理员权限启动VMWare Workstation”确实可以正常启动（其他方案都无法生效解决该问题），但是作为一名开发人员，每次都通过管理员启动程序未免显得不太专业。因此自己跟踪和排查了一下问题，比较有典型性在此记录一下。

1. 问题概述

当打开VMWare Workstation启动虚拟机的时候整个VMWare Workstation界面出现卡住，如下：

紧接着VMWare Workstation出现错误，如下：

如果通过管理员权限启动VMWare Workstation，那么虚拟机可以正常启动；那么是什么原因导致的呢？

2. 排查思路

首先，由于VMWare Workstation出现错误，那么非常显然的一点就是先查看VMWare Workstation的日志，我们可以看到如下：

2023-03-26T01:22:10.243Z In(05) vmui wui::ipc::CUnityHelper::Connect: Creating connection-ready notification event, name: {F471AC3D-CD16-4701-B15A-EC81B0D1ABAD}
2023-03-26T01:22:10.243Z In(05) vmui wui::ipc::CUnityHelper::LaunchDaemon: Running cmd line: "C:\Program Files (x86)\VMware\VMware Workstation\vmware-unity-helper.exe" -d -e:{F471AC3D-CD16-4701-B15A-EC81B0D1ABAD}
2023-03-26T01:22:10.288Z In(05) vmui VMMKS::OnMKSDeviceInfoChanged: reset pipe name now in offline.
2023-03-26T01:22:10.288Z In(05) vmui VMMKS::OnInitVMDeviceObserverDone: done.
2023-03-26T01:22:10.305Z In(05) vmui VMMgr: Finished opening VM at /vm/#db9f5aff4db2fd97/ from C:\Virtual Machines\Ubuntu 64\Ubuntu 64.vmx
2023-03-26T01:22:10.326Z In(05) vmui CVMUIApp::OpenTabInt: opened C:\Virtual Machines\Ubuntu 64\Ubuntu 64.vmx
2023-03-26T01:22:10.326Z Wa(03) vmui CMksCtl::BindToCurrentVM: Trying to bind a current VM that its MKS is not present. Returning.
2023-03-26T01:22:10.326Z In(05) vmui CMksCtl::OnMount: uninitialize view (/vm/#db9f5aff4db2fd97/).
2023-03-26T01:22:10.326Z In(05) vmui wui::MKSScreenView::Uninitialize.
2023-03-26T01:22:10.326Z In(05) vmui cui::MKSScreenView::SetRenderTarget: hostWindow and surfaceID are none. id: 0. 
2023-03-26T01:22:10.326Z In(05) vmui cui::MKSScreenView::OnHostWindowChanged, id: 0, unsetting destination and setting is rendering to false
2023-03-26T01:22:10.327Z In(05) vmui Switched to tab: C:\Virtual Machines\Ubuntu 64\Ubuntu 64.vmx
2023-03-26T01:22:10.329Z In(05) vmui SnapshotTree: Populating (C:\Virtual Machines\Ubuntu 64\Ubuntu 64.vmx)
2023-03-26T01:22:10.350Z In(05) vmui wui::control::MKSPanel::UpdateMKSLayout: MKS view is not initialized or not rendering.
2023-03-26T01:22:10.350Z In(05) vmui wui::control::MKSPanel::UpdateMKSLayout: MKS view is not initialized or not rendering.
2023-03-26T01:22:10.352Z In(05) vmui wui::control::MKSPanel::UpdateMKSLayout: MKS view is not initialized or not rendering.
2023-03-26T01:22:10.352Z In(05) vmui wui::control::MKSPanel::UpdateMKSLayout: MKS view is not initialized or not rendering.
2023-03-26T01:22:10.371Z In(05) vmui CVMUIView::UpdateView - showMks (no).
2023-03-26T01:22:10.384Z In(05) vmui CVMUIFrame::OnGuestTopologyChanged: Passing main UI rect: 0x0 @ 0,0
2023-03-26T01:22:10.384Z In(05) vmui cui::MKSScreenWindowCoordinator::HandleGuestTopologyChange: main UI rect: 0x0 @ 0,0
2023-03-26T01:22:10.384Z In(05) vmui cui::MKSScreenWindowCoordinator::HandleGuestTopologyChange: Found 0 present screens
2023-03-26T01:22:10.384Z In(05) vmui cui::MKSScreenWindowCoordinator::HandleGuestTopologyChange: Windows for extra guest monitors will not be shown
2023-03-26T01:22:10.384Z In(05) vmui cui::MKSScreenWindowCoordinator::HandleGuestTopologyChange: setting main view to all displays
2023-03-26T01:22:10.405Z In(05) vmui CnxFSVigor: Could not get the dataFileKey
2023-03-26T01:22:10.510Z In(05) vmui VMMgr::OpenVM (cfgPath=C:\Virtual Machines\Ubuntu 64\Ubuntu 64.vmx)
2023-03-26T01:22:10.540Z In(05) vmui VMMgr::Merge: Merged open request /vm/#db9f5aff4db2fd97/ into existing VM
2023-03-26T01:22:10.960Z In(05) vmui CnxFSVigor: Could not get the dataFileKey
2023-03-26T01:22:14.020Z In(05) vmui C:\Virtual Machines\Ubuntu 64\Ubuntu 64.vmx: Reloading config state.
2023-03-26T01:22:14.028Z In(05) vmui VMHS: Transitioned vmx/execState/val to poweredOff
2023-03-26T01:22:14.036Z In(05) vigorCnx VigorOfflineGetToolsVersion: updated tools version to 0
2023-03-26T01:22:14.037Z In(05) vigorCnx Win32U_GetFileAttributes: GetFileAttributesExW("C:\Virtual Machines\Ubuntu 64\Ubuntu 64.nvram", ...) failed, error: 2
2023-03-26T01:22:14.038Z In(05) vmui Vix: [foundryVMPowerOps.c:984]: FoundryVMPowerStateChangeCallback: C:\Virtual Machines\Ubuntu 64\Ubuntu 64.vmx, vmx/execState/val = poweredOff.
2023-03-26T01:22:14.038Z In(05) vmui VMMKS::OnMKSDeviceInfoChanged: reset pipe name now in offline.
2023-03-26T01:22:14.039Z In(05) vigorCnx Win32U_GetFileAttributes: GetFileAttributesExW("C:\Virtual Machines\Ubuntu 64\Ubuntu 64.nvram", ...) failed, error: 2
2023-03-26T01:22:14.039Z In(05) vmui VMMKS::OnMKSDeviceInfoChanged: reset pipe name now in offline.
2023-03-26T01:22:14.053Z In(05) vmui SnapshotTree: Emitting refresh (C:\Virtual Machines\Ubuntu 64\Ubuntu 64.vmx)
2023-03-26T01:22:14.053Z In(05) vmui SnapshotTree: Populating (C:\Virtual Machines\Ubuntu 64\Ubuntu 64.vmx)
2023-03-26T01:22:14.085Z In(05) vmui Found vmx as C:\Program Files (x86)\VMware\VMware Workstation\x64\vmware-vmx.exe
2023-03-26T01:22:14.085Z In(05) vmui Starting vmx as C:\Program Files (x86)\VMware\VMware Workstation\x64\vmware-vmx.exe
2023-03-26T01:22:36.098Z In(05) vmui VigorExecVMXExCommon: Failed to connect the pipe: The system cannot find the file specified
2023-03-26T01:22:36.098Z In(05) vmui VigorOnline_StartAndConnectEx Failed: VMware Workstation cannot connect to the virtual machine. Make sure you have rights to run the program, access all directories the program uses, and access all directories for temporary files.
2023-03-26T01:22:36.098Z In(05)+ vmui Failed to connect pipe to virtual machine: The system cannot find the file specified.
2023-03-26T01:22:36.098Z In(05)+ vmui 
2023-03-26T01:22:36.098Z In(05) vmui C:\Virtual Machines\Ubuntu 64\Ubuntu 64.vmx: VMHSStartVmxVigorCb: vmPath=/vm/#db9f5aff4db2fd97/ status=error
2023-03-26T01:22:36.098Z In(05) vmui C:\Virtual Machines\Ubuntu 64\Ubuntu 64.vmx: VMHSStartVmxVigorCb: error vmdb=-44 msg=VMware Workstation 无法连接到虚拟机。请确保您有权运行该程序、访问该程序使用的所有目录以及访问所有临时文件目录。
2023-03-26T01:22:36.098Z In(05)+ vmui 未能将管道连接到虚拟机: 系统找不到指定的文件。
2023-03-26T01:22:36.098Z In(05)+ vmui 
2023-03-26T01:22:36.098Z In(05) vmui vm power operation abort, error = VMware Workstation 无法连接到虚拟机。请确保您有权运行该程序、访问该程序使用的所有目录以及访问所有临时文件目录。
2023-03-26T01:22:36.098Z In(05)+ vmui 未能将管道连接到虚拟机: 系统找不到指定的文件。
2023-03-26T01:22:36.098Z In(05)+ vmui  .
2023-03-26T01:22:36.098Z Wa(03) vmui VMware Workstation 无法连接到虚拟机。请确保您有权运行该程序、访问该程序使用的所有目录以及访问所有临时文件目录。
2023-03-26T01:22:36.098Z Wa(03)+ vmui 未能将管道连接到虚拟机: 系统找不到指定的文件。
2023-03-26T01:22:36.098Z Wa(03)+ vmui 
2023-03-26T01:22:36.098Z In(05) vmui DlgUI: VMware Workstation 无法连接到虚拟机。请确保您有权运行该程序、访问该程序使用的所有目录以及访问所有临时文件目录。
2023-03-26T01:22:36.098Z In(05)+ vmui 未能将管道连接到虚拟机: 系统找不到指定的文件。
2023-03-26T01:22:36.224Z In(05) vmui Win32U_GetFileAttributes: GetFileAttributesExW("C:\Virtual Machines\Ubuntu 64\Ubuntu 64.vmpl", ...) failed, error: 2
2023-03-26T01:22:36.224Z In(05) vmui C:\Virtual Machines\Ubuntu 64\Ubuntu 64.vmx: Reloading config state.
2023-03-26T01:22:36.230Z In(05) vmui VMHS: Transitioned vmx/execState/val to poweredOff

从上面的日志我们可以发现错误是：vmui VigorExecVMXExCommon: Failed to connect the pipe: The system cannot find the file specified。在这条日志附件我们可以发现：

2023-03-26T01:22:14.085Z In(05) vmui Found vmx as C:\Program Files (x86)\VMware\VMware Workstation\x64\vmware-vmx.exe
2023-03-26T01:22:14.085Z In(05) vmui Starting vmx as C:\Program Files (x86)\VMware\VMware Workstation\x64\vmware-vmx.exe
2023-03-26T01:22:36.098Z In(05) vmui VigorExecVMXExCommon: Failed to connect the pipe: The system cannot find the file specified
2023-03-26T01:22:36.098Z In(05) vmui VigorOnline_StartAndConnectEx Failed: VMware Workstation cannot connect to the virtual machine. Make sure you have rights to run the program, access all directories the program uses, and access all directories for temporary files.

这里有三条日志：

1. vmui Found vmx as C:\Program Files (x86)\VMware\VMware Workstation\x64\vmware-vmx.exe和vmui Starting vmx as C:\Program Files (x86)\VMware\VMware Workstation\x64\vmware-vmx.exe：这条日志应该是启动vmware-vmx.exe进程，然后启动虚拟机。
2. vmui VigorExecVMXExCommon: Failed to connect the pipe: The system cannot find the file specified：这条日志是在VigorExecVMXExCommon函数中应该是调用ConnectNamedPipe失败，应该是没有创建管道。
3. vmui VigorOnline_StartAndConnectEx Failed: VMware Workstation cannot connect to the virtual machine. Make sure you have rights to run the program, access all directories the program uses, and access all directories for temporary files.：这条日志是VigorOnline_StartAndConnectEx返回失败，并且开始提示。

那么ConnectNamedPipe为什么出现失败呢？该函数声明如下：

BOOL ConnectNamedPipe(
  HANDLE       hNamedPipe,
  LPOVERLAPPED lpOverlapped
);

猜测是vmware-vmx.exe子进程和服务父进程进行通信使用。

这里我们可以使用API Monitor来看一下是否有管道相关的函数出现失败呢？我们可以看到如下：

我们可以看到VMWare.exe进程在WaitNamedPipeW失败，这个是管道客户端的一个函数，等待管道服务的创建，那应该是管道并没有被创建。

那么正常情况下是否会有问题呢？我们通过管理员权限启动VMWare Workstation，正常启动，如下：

从这里可以发现WaitNamedPipeW失败两次之后就成功了，而启动失败的场景就是WaitNamedPipeW一直失败，这也是VMware Workstation启动虚拟机的时候一直卡住的原因：WaitNamedPipeW失败，一直在UI主线程尝试，导致卡住。

我们可以通过Process Explorer（或者Process Hacker）工具来查看一下正常情况下管道有哪些进程在使用，如下：

这里可以看到是通过vmware-vmx.exe创建的，我们可以看一下失败的场景下面vmware-vmx.exe进程的运行情况。我们可以通过Process Monitor来查看一下vmware-vmx.exe进程的运行情况：

我们可以看到CreateFile打开C:\Windows\System32\msvcp140.dll文件失败，如下：

我们可以看一下这个文件的属性权限信息，如下：

可以看到这个文件权限出现问题了，因此我们可以得知VMWare Workstation启动失败的原因是：文件C:\Windows\System32\msvcp140.dll权限有问题，vmware-vmx.exe无法访问该文件，导致vmware-vmx.exe无法正常启动而出现错误。

3. 问题修改

因此我们猜测，只要让C:\Windows\System32\msvcp140.dll文件可以被正常访问之后，该问题就可以解决了。

我们尝试修改C:\Windows\System32\msvcp140.dll文件的正常权限之后，VMWare Workstation虚拟机正常启动。该文件修改后的权限信息如下：

4. 总结

VMware Workstation 无法连接到虚拟机。请确保您有权运行该程序、访问该程序使用的所有目录以及访问所有临时文件目录。未能将管道连接到虚拟机: 系统找不到指定的文件问题虽然比较简单，但是整个排查过程还是比较有意思的，算是一个典型问题的排查过程，在此记录一下作为一个平常开发中问题排查的思路借鉴。

当然当你遇到VMware Workstation 无法连接到虚拟机。请确保您有权运行该程序、访问该程序使用的所有目录以及访问所有临时文件目录。未能将管道连接到虚拟机: 系统找不到指定的文件问题时，可以检查：

1. C:\Windows\System32\msvcp140.dll 文件是否存在。
2. C:\Windows\System32\msvcp140.dll文件权限是否正常。
3. 参考检测其他依赖文件是否正常并且权限是否正常。

当然你也可以参考本文思路（或者其他思路），排查该问题产生的其他原因，如果有其他原因和思路也欢迎大家留言。