canonical / canonical/multipass

[Windows] New-VM fails when a default "configuration store" is defined and inaccessible (observed first in Enterprise Hyper-V)

Open
#2,867 12 comments 0 reactions 0 assignees View on GitHub
windows
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

Open the contributing 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

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.