canonical / canonical/multipass
[Windows] New-VM fails when a default "configuration store" is defined and inaccessible (observed first in Enterprise Hyper-V)
- Dominant language
- C++
- Stars
- 9.2k
- Forks
- 828
- Avg merge
- 3d 1h
- Merged PRs (30d)
- 44
Description
**Issue describe:**
When execute command multipass launch XXX, it return VM create fail message.
**Command verbose output:**
```
PS C:\Development\Multipass\data\vault\instances> multipass launch docker -vvvv
[2023-01-04T14:24:48.230] [trace] [Hyper-V Health Check] PowerShell arguments: -NoProfile, -NoExit, -Command, -
[2023-01-04T14:24:48.230] [trace] [Hyper-V Health Check] PowerShell working dir ''
[2023-01-04T14:24:48.230] [trace] [Hyper-V Health Check] PowerShell program 'powershell.exe'
[2023-01-04T14:24:48.230] [trace] [Hyper-V Health Check] [0] PowerShell state changed to Starting
[2023-01-04T14:24:48.230] [trace] [Hyper-V Health Check] [0] PowerShell state changed to Running
[2023-01-04T14:24:48.230] [debug] [powershell.exe] [19168] started: powershell.exe -NoProfile -NoExit -Command -
[2023-01-04T14:24:48.230] [debug] [Hyper-V Health Check] [19168] Cmdlet: 'Get-ItemProperty -Path 'HKLM:\Software\Microsoft\Windows NT\CurrentVersion' | Select-Object -ExpandProperty CurrentMajorVersionNumber'
[2023-01-04T14:24:48.478] [trace] [client cert store] Verifying cert:
-----BEGIN CERTIFICATE-----
MIIBizCCATECBBKm/F0wCgYIKoZIzj0EAwIwUDELMAkGA1UEBhMCVVMxEjAQBgNV
BAoMCUNhbm9uaWNhbDEtMCsGA1UEAwwkZDBlNjcyNmUtNDMyNi00MzMxLTg2Zjkt
MmRiN2FjNmVkNjVlMB4XDTIzMDEwMzAyMjMyM1oXDTI0MDEwMzAyMjMyM1owUDEL
MAkGA1UEBhMCVVMxEjAQBgNVBAoMCUNhbm9uaWNhbDEtMCsGA1UEAwwkZDBlNjcy
NmUtNDMyNi00MzMxLTg2ZjktMmRiN2FjNmVkNjVlMFkwEwYHKoZIzj0CAQYIKoZI
zj0DAQcDQgAERayLOtBqR2m2CUec1iPSDmPZOZjehJC/kc6aLwr2jvMvvqtgdjMW
oL9bD0C17G/u+dig4sf633SapZSjfi+dCzAKBggqhkjOPQQDAgNIADBFAiEAzJJn
yYuSojDH8r0ZyQCMIGruvPtF0QSRxn+MTnxxUXQCIADmUKSYwazkZldLvTZTa0wL
VRgIR/Hv+Mb6bF939bv8
-----END CERTIFICATE-----
[2023-01-04T14:24:48.594] [trace] [Hyper-V Health Check] 10
[2023-01-04T14:24:48.594] [trace] [Hyper-V Health Check] [19168] Output: 10
[2023-01-04T14:24:48.594] [debug] [Hyper-V Health Check] [19168] Cmdlet exit status is 'true'
[2023-01-04T14:24:48.594] [debug] [Hyper-V Health Check] [19168] Cmdlet: 'Get-ItemProperty -Path 'HKLM:\Software\Microsoft\Windows NT\CurrentVersion' | Select-Object -ExpandProperty ReleaseId'
[2023-01-04T14:24:48.616] [trace] [Hyper-V Health Check] 2009
[2023-01-04T14:24:48.616] [trace] [Hyper-V Health Check] [19168] Output: 2009
[2023-01-04T14:24:48.616] [debug] [Hyper-V Health Check] [19168] Cmdlet exit status is 'true'
[2023-01-04T14:24:48.616] [debug] [Hyper-V Health Check] [19168] Cmdlet: 'Get-CimInstance Win32_ComputerSystem | Select-Object -ExpandProperty HypervisorPresent'
[2023-01-04T14:24:48.733] [trace] [Hyper-V Health Check] True
[2023-01-04T14:24:48.733] [trace] [Hyper-V Health Check] [19168] Output: True
[2023-01-04T14:24:48.733] [debug] [Hyper-V Health Check] [19168] Cmdlet exit status is 'true'
[2023-01-04T14:24:48.733] [debug] [Hyper-V Health Check] [19168] Cmdlet: 'Get-WindowsOptionalFeature -Online -FeatureName Microsoft-Hyper-V | Select-Object -ExpandProperty State'
[2023-01-04T14:24:49.418] [trace] [Hyper-V Health Check] Enabled
[2023-01-04T14:24:49.419] [trace] [Hyper-V Health Check] [19168] Output: Enabled
[2023-01-04T14:24:49.419] [debug] [Hyper-V Health Check] [19168] Cmdlet exit status is 'true'
[2023-01-04T14:24:49.420] [debug] [Hyper-V Health Check] [19168] Cmdlet: 'Get-WindowsOptionalFeature -Online -FeatureName Microsoft-Hyper-V-Hypervisor | Select-Object -ExpandProperty State'
[2023-01-04T14:24:49.782] [trace] [Hyper-V Health Check] Enabled
[2023-01-04T14:24:49.782] [trace] [Hyper-V Health Check] [19168] Output: Enabled
[2023-01-04T14:24:49.782] [debug] [Hyper-V Health Check] [19168] Cmdlet exit status is 'true'
[2023-01-04T14:24:49.782] [debug] [Hyper-V Health Check] [19168] Cmdlet: 'Get-Service -Name vmms | Select-Object -ExpandProperty Status'
[2023-01-04T14:24:49.797] [trace] [Hyper-V Health Check] Running
[2023-01-04T14:24:49.797] [trace] [Hyper-V Health Check] [19168] Output: Running
[2023-01-04T14:24:49.797] [debug] [Hyper-V Health Check] [19168] Cmdlet exit status is 'true'
[2023-01-04T14:24:49.803] [trace] [Hyper-V Health Check] [19168] PowerShell state changed to NotRunning
[2023-01-04T14:24:49.803] [debug] [Hyper-V Health Check] [19168] PowerShell finished successfully
[2023-01-04T14:24:50.452] [debug] [qemu-img] [12724] started: qemu-img info C:/Development/Multipass/cache/vault/images/jammy-20221214/ubuntu-22.04-server-cloudimg-amd64.vhdx
[2023-01-04T14:24:50.484] [trace] [client cert store] Verifying cert:
-----BEGIN CERTIFICATE-----
MIIBizCCATECBBKm/F0wCgYIKoZIzj0EAwIwUDELMAkGA1UEBhMCVVMxEjAQBgNV
BAoMCUNhbm9uaWNhbDEtMCsGA1UEAwwkZDBlNjcyNmUtNDMyNi00MzMxLTg2Zjkt
MmRiN2FjNmVkNjVlMB4XDTIzMDEwMzAyMjMyM1oXDTI0MDEwMzAyMjMyM1owUDEL
MAkGA1UEBhMCVVMxEjAQBgNVBAoMCUNhbm9uaWNhbDEtMCsGA1UEAwwkZDBlNjcy
NmUtNDMyNi00MzMxLTg2ZjktMmRiN2FjNmVkNjVlMFkwEwYHKoZIzj0CAQYIKoZI
zj0DAQcDQgAERayLOtBqR2m2CUec1iPSDmPZOZjehJC/kc6aLwr2jvMvvqtgdjMW
oL9bD0C17G/u+dig4sf633SapZSjfi+dCzAKBggqhkjOPQQDAgNIADBFAiEAzJJn
yYuSojDH8r0ZyQCMIGruvPtF0QSRxn+MTnxxUXQCIADmUKSYwazkZldLvTZTa0wL
VRgIR/Hv+Mb6bF939bv8
-----END CERTIFICATE-----
[2023-01-04T14:24:50.499] [trace] [docker] PowerShell arguments: Resize-VHD, -Path, C:/Development/Multipass/data/vault/instances/docker/ubuntu-22.04-server-cloudimg-amd64.vhdx, -SizeBytes, 42949672960
[2023-01-04T14:24:50.499] [trace] [docker] PowerShell working dir ''
[2023-01-04T14:24:50.499] [trace] [docker] PowerShell program 'powershell.exe'
[2023-01-04T14:24:50.499] [trace] [docker] [0] PowerShell state changed to Starting
[2023-01-04T14:24:50.499] [trace] [docker] [0] PowerShell state changed to Running
[2023-01-04T14:24:50.499] [debug] [powershell.exe] [23964] started: powershell.exe Resize-VHD -Path C:/Development/Multipass/data/vault/instances/docker/ubuntu-22.04-server-cloudimg-amd64.vhdx -SizeBytes 42949672960
[2023-01-04T14:24:51.476] [trace] [client cert store] Verifying cert:
-----BEGIN CERTIFICATE-----
MIIBizCCATECBBKm/F0wCgYIKoZIzj0EAwIwUDELMAkGA1UEBhMCVVMxEjAQBgNV
BAoMCUNhbm9uaWNhbDEtMCsGA1UEAwwkZDBlNjcyNmUtNDMyNi00MzMxLTg2Zjkt
MmRiN2FjNmVkNjVlMB4XDTIzMDEwMzAyMjMyM1oXDTI0MDEwMzAyMjMyM1owUDEL
MAkGA1UEBhMCVVMxEjAQBgNVBAoMCUNhbm9uaWNhbDEtMCsGA1UEAwwkZDBlNjcy
NmUtNDMyNi00MzMxLTg2ZjktMmRiN2FjNmVkNjVlMFkwEwYHKoZIzj0CAQYIKoZI
zj0DAQcDQgAERayLOtBqR2m2CUec1iPSDmPZOZjehJC/kc6aLwr2jvMvvqtgdjMW
oL9bD0C17G/u+dig4sf633SapZSjfi+dCzAKBggqhkjOPQQDAgNIADBFAiEAzJJn
yYuSojDH8r0ZyQCMIGruvPtF0QSRxn+MTnxxUXQCIADmUKSYwazkZldLvTZTa0wL
VRgIR/Hv+Mb6bF939bv8
-----END CERTIFICATE-----
[2023-01-04T14:24:52.473] [trace] [client cert store] Verifying cert:
-----BEGIN CERTIFICATE-----
MIIBizCCATECBBKm/F0wCgYIKoZIzj0EAwIwUDELMAkGA1UEBhMCVVMxEjAQBgNV
BAoMCUNhbm9uaWNhbDEtMCsGA1UEAwwkZDBlNjcyNmUtNDMyNi00MzMxLTg2Zjkt
MmRiN2FjNmVkNjVlMB4XDTIzMDEwMzAyMjMyM1oXDTI0MDEwMzAyMjMyM1owUDEL
MAkGA1UEBhMCVVMxEjAQBgNVBAoMCUNhbm9uaWNhbDEtMCsGA1UEAwwkZDBlNjcy
NmUtNDMyNi00MzMxLTg2ZjktMmRiN2FjNmVkNjVlMFkwEwYHKoZIzj0CAQYIKoZI
zj0DAQcDQgAERayLOtBqR2m2CUec1iPSDmPZOZjehJC/kc6aLwr2jvMvvqtgdjMW
oL9bD0C17G/u+dig4sf633SapZSjfi+dCzAKBggqhkjOPQQDAgNIADBFAiEAzJJn
yYuSojDH8r0ZyQCMIGruvPtF0QSRxn+MTnxxUXQCIADmUKSYwazkZldLvTZTa0wL
VRgIR/Hv+Mb6bF939bv8
-----END CERTIFICATE-----
[2023-01-04T14:24:52.914] [trace] [docker] [23964] PowerShell state changed to NotRunning
[2023-01-04T14:24:52.914] [debug] [docker] [23964] PowerShell finished successfully
[2023-01-04T14:24:52.914] [trace] [docker] [23964] Output:
[2023-01-04T14:24:52.914] [trace] [docker] PowerShell arguments: -NoProfile, -NoExit, -Command, -
[2023-01-04T14:24:52.914] [trace] [docker] PowerShell working dir ''
[2023-01-04T14:24:52.914] [trace] [docker] PowerShell program 'powershell.exe'
[2023-01-04T14:24:52.914] [trace] [docker] [0] PowerShell state changed to Starting
[2023-01-04T14:24:52.914] [trace] [docker] [0] PowerShell state changed to Running
[2023-01-04T14:24:52.914] [debug] [powershell.exe] [23580] started: powershell.exe -NoProfile -NoExit -Command -
[2023-01-04T14:24:52.914] [debug] [docker] [23580] Cmdlet: 'Get-VM -Name docker'
[2023-01-04T14:24:53.478] [trace] [client cert store] Verifying cert:
-----BEGIN CERTIFICATE-----
MIIBizCCATECBBKm/F0wCgYIKoZIzj0EAwIwUDELMAkGA1UEBhMCVVMxEjAQBgNV
BAoMCUNhbm9uaWNhbDEtMCsGA1UEAwwkZDBlNjcyNmUtNDMyNi00MzMxLTg2Zjkt
MmRiN2FjNmVkNjVlMB4XDTIzMDEwMzAyMjMyM1oXDTI0MDEwMzAyMjMyM1owUDEL
MAkGA1UEBhMCVVMxEjAQBgNVBAoMCUNhbm9uaWNhbDEtMCsGA1UEAwwkZDBlNjcy
NmUtNDMyNi00MzMxLTg2ZjktMmRiN2FjNmVkNjVlMFkwEwYHKoZIzj0CAQYIKoZI
zj0DAQcDQgAERayLOtBqR2m2CUec1iPSDmPZOZjehJC/kc6aLwr2jvMvvqtgdjMW
oL9bD0C17G/u+dig4sf633SapZSjfi+dCzAKBggqhkjOPQQDAgNIADBFAiEAzJJn
yYuSojDH8r0ZyQCMIGruvPtF0QSRxn+MTnxxUXQCIADmUKSYwazkZldLvTZTa0wL
VRgIR/Hv+Mb6bF939bv8
-----END CERTIFICATE-----
[2023-01-04T14:24:53.632] [trace] [docker] Get-VM : Hyper-V �Ҳ�������Ϊ��docker������������
����λ�� ��:1 �ַ�: 1
+ Get-VM -Name docker
+ ~~~~~~~~~~~~~~~~~~~
+ CategoryInfo : InvalidArgument: (docker:String) [Get-VM]��VirtualizationException
+ FullyQualifiedErrorId : InvalidParameter,Microsoft.HyperV.PowerShell.Commands.GetVM
[2023-01-04T14:24:53.632] [trace] [docker] [23580] Output: Get-VM : Hyper-V �Ҳ�������Ϊ��docker������������
����λ�� ��:1 �ַ�: 1
+ Get-VM -Name docker
+ ~~~~~~~~~~~~~~~~~~~
+ CategoryInfo : InvalidArgument: (docker:String) [Get-VM]��VirtualizationException
+ FullyQualifiedErrorId : InvalidParameter,Microsoft.HyperV.PowerShell.Commands.GetVM
[2023-01-04T14:24:53.632] [debug] [docker] [23580] Cmdlet exit status is 'false'
[2023-01-04T14:24:53.632] [debug] [docker] [23580] Cmdlet: '$switch = Get-VMSwitch -Id C08CB7B8-9B3C-408E-8E30-5E16A3AEB444'
[2023-01-04T14:24:53.833] [trace] [docker]
[2023-01-04T14:24:53.833] [trace] [docker] [23580] Output:
[2023-01-04T14:24:53.833] [debug] [docker] [23580] Cmdlet exit status is 'true'
[2023-01-04T14:24:53.833] [debug] [docker] [23580] Cmdlet: 'New-VM -Name docker -Generation 2 -VHDPath "C:/Development/Multipass/data/vault/instances/docker/ubuntu-22.04-server-cloudimg-amd64.vhdx" -BootDevice VHD -SwitchName $switch.Name -MemoryStartupBytes 4294967296'
[2023-01-04T14:24:54.034] [trace] [docker] New-VM : ���½���������
��docker����ʵ�֡�(������ ID 7CF25B58-C1CA-490B-9C44-AF1E02DCEC62)
���������ô洢: ϵͳ�Ҳ���ָ����·���� (0x80070003)��
����λ�� ��:1 �ַ�: 1
+ New-VM -Name docker -Generation 2 -VHDPath "C:/Development/Multipass/ ...
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
+ CategoryInfo : ObjectNotFound: (:) [New-VM], VirtualizationException
+ FullyQualifiedErrorId : ObjectNotFound,Microsoft.HyperV.PowerShell.Commands.NewVM
[2023-01-04T14:24:54.034] [trace] [docker] [23580] Output: New-VM : ���½���������
��docker����ʵ�֡�(������ ID 7CF25B58-C1CA-490B-9C44-AF1E02DCEC62)
���������ô洢: ϵͳ�Ҳ���ָ����·���� (0x80070003)��
����λ�� ��:1 �ַ�: 1
+ New-VM -Name docker -Generation 2 -VHDPath "C:/Development/Multipass/ ...
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
+ CategoryInfo : ObjectNotFound: (:) [New-VM], VirtualizationException
+ FullyQualifiedErrorId : ObjectNotFound,Microsoft.HyperV.PowerShell.Commands.NewVM
[2023-01-04T14:24:54.034] [debug] [docker] [23580] Cmdlet exit status is 'false'
[2023-01-04T14:24:54.049] [trace] [docker] [23580] PowerShell state changed to NotRunning
[2023-01-04T14:24:54.049] [debug] [docker] [23580] PowerShell finished successfully
[2023-01-04T14:24:54.049] [trace] [docker] PowerShell arguments: Remove-VM, -Name, docker, -Force
[2023-01-04T14:24:54.049] [trace] [docker] PowerShell working dir ''
[2023-01-04T14:24:54.049] [trace] [docker] PowerShell program 'powershell.exe'
[2023-01-04T14:24:54.049] [trace] [docker] [0] PowerShell state changed to Starting
[2023-01-04T14:24:54.049] [trace] [docker] [0] PowerShell state changed to Running
[2023-01-04T14:24:54.049] [debug] [powershell.exe] [16520] started: powershell.exe Remove-VM -Name docker -Force
[2023-01-04T14:24:54.582] [trace] [docker] [16520] PowerShell state changed to NotRunning
[2023-01-04T14:24:54.582] [warning] [docker] [16520] PowerShell finished abnormally: Process returned exit code: 1
[2023-01-04T14:24:54.582] [trace] [docker] [16520] Output:
Remove-VM : Hyper-V �Ҳ�������Ϊ��docker������������
����λ�� ��:1 �ַ�: 1
+ Remove-VM -Name docker -Force
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
+ CategoryInfo : ObjectNotFound: (:) [Remove-VM], VirtualizationException
+ FullyQualifiedErrorId : ObjectNotFound,Microsoft.HyperV.PowerShell.Commands.RemoveVM
launch failed: Could not create VM
````
When VM creating, VM folder and disk file was appear in a short time:
```
PS C:\Development\Multipass\data\vault\instances> dir
Directory: C:\Development\Multipass\data\vault\instances
---- ------------- ------ ----
d----- 1/4/2023 2:24 PM docker
PS C:\Development\Multipass\data\vault\instances> dir docker
Directory: C:\Development\Multipass\data\vault\instances\docker
Mode LastWriteTime Length Name
---- ------------- ------ ----
-a---- 1/4/2023 2:24 PM 57344 cloud-init-config.iso
-a---- 1/4/2023 2:24 PM 1736441856 ubuntu-22.04-server-cloudimg-amd64.vhdx
PS C:\Development\Multipass\data\vault\instances> dir docker
Directory: C:\Development\Multipass\data\vault\instances\docker
Mode LastWriteTime Length Name
---- ------------- ------ ----
-a---- 1/4/2023 2:24 PM 57344 cloud-init-config.iso
-a---- 1/4/2023 2:24 PM 1736441856 ubuntu-22.04-server-cloudimg-amd64.vhdx
PS C:\Development\Multipass\data\vault\instances> dir docker
dir : Cannot find path 'C:\Development\Multipass\data\vault\instances\docker' because it does not exist.
At line:1 char:1
+ dir docker
+ ~~~~~~~~~~
+ CategoryInfo : ObjectNotFound: (C:\Development\...nstances\docker:String) [Get-ChildItem], ItemNotFound
Exception
+ FullyQualifiedErrorId : PathNotFound,Microsoft.PowerShell.Commands.GetChildItemCommand
PS C:\Development\Multipass\data\vault\instances>
```
**Windows Event Logs:** [Multipass-event-logs.zip](https://github.com/canonical/multipass/files/10341981/Multipass-event-logs.zip)
**Additional information:**
```
PS C:\Development\Multipass\data\vault\instances> multipass list
No instances found.
PS C:\Development\Multipass\data\vault\instances> multipass version
multipass 1.10.1+win
multipassd 1.10.1+win
PS C:\Development\Multipass\data\vault\instances> Get-ItemProperty -Path 'HKLM:\Software\Microsoft\Windows NT\CurrentVersion'
SystemRoot : C:\windows
BaseBuildRevisionNumber : 1
BuildBranch : vb_release
BuildGUID : ffffffff-ffff-ffff-ffff-ffffffffffff
BuildLab : 19041.vb_release.191206-1406
BuildLabEx : 19041.1.amd64fre.vb_release.191206-1406
CompositionEditionID : Enterprise
CurrentBuild : 19045
CurrentBuildNumber : 19045
CurrentMajorVersionNumber : 10
CurrentMinorVersionNumber : 0
CurrentType : Multiprocessor Free
CurrentVersion : 6.3
EditionID : Enterprise
EditionSubManufacturer :
EditionSubstring :
EditionSubVersion :
InstallationType : Client
InstallDate : 1603854297
ProductName : Windows 10 Enterprise
ReleaseId : 2009
SoftwareType : System
UBR : 2364
PathName : C:\Windows
ProductId : 00329-00000-00003-AA381
DigitalProductId : {164, 0, 0, 0...}
DigitalProductId4 : {248, 4, 0, 0...}
PendingInstall : 0
RegisteredOrganization :
RegisteredOwner : 1
InstallTime : 132483278972324579
DisplayVersion : 22H2
PSPath : Microsoft.PowerShell.Core\Registry::HKEY_LOCAL_MACHINE\Software\Microsoft\Windows
NT\CurrentVersion
PSParentPath : Microsoft.PowerShell.Core\Registry::HKEY_LOCAL_MACHINE\Software\Microsoft\Windows NT
PSChildName : CurrentVersion
PSDrive : HKLM
PSProvider : Microsoft.PowerShell.Core\Registry
```
Contributor guide
Research direction
Start with the Windows path exercised by `multipass launch XXX -vvvv` and the logged PowerShell `New-VM` command. Investigate how the Hyper-V configuration store is selected when its default path is inaccessible; done means VM creation succeeds in that setup and the failure is covered by an appropriate test or reproducible verification.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- cpp, powershell
- Domain
- infrastructure, operating-systems
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Quiet
- Clarity
- Mostly clear
- Newbie friendliness
- 48/100