multipass icon indicating copy to clipboard operation
multipass copied to clipboard
verified publisher icon canonical

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

Open gzOne2Free opened this issue 3 years ago • 11 comments

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

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

gzOne2Free avatar Jan 04 '23 06:01 gzOne2Free

Hi @gzOne2Free, thanks for reporting. Puzzling. It looks like one of two things is happening; either

  1. there is a problem in the conversion of PowerShell commands to UTF-8, or
  2. your PowerShell is not handling UTF-8 properly.

This normally works, so do you have any custom encoding settings in your PowerShell? What PS version do you have?

ricab avatar Jan 09 '23 10:01 ricab

And do you see it consistently, or was it a one-off?

ricab avatar Jan 09 '23 10:01 ricab

Hi @ricab , Sorry for late reply. It always run into same result with same error on my office lap top computer. I have uninstall the old version 1.10.1 and install latest version 1.11.1, also set the Windows system wide encoding to UTF8 to let PowerShell display correctly. And then relaunch multipass command to create VM, it fail with this output:

multipass launch jammy -vvvv
[2023-03-30T14:15:24.073] [trace] [url downloader] Found https://codeload.github.com/canonical/multipass-blueprints/zip/refs/heads/main in cache: true
[2023-03-30T14:15:25.159] [trace] [url downloader] Found https://cdimage.ubuntu.com/ubuntu-core/16/stable/current/SHA256SUMS in cache: true
[2023-03-30T14:15:25.795] [trace] [url downloader] Found https://cdimage.ubuntu.com/ubuntu-core/18/stable/current/SHA256SUMS in cache: true
[2023-03-30T14:15:26.634] [trace] [url downloader] Found https://cdimage.ubuntu.com/ubuntu-core/20/stable/current/SHA256SUMS in cache: true
[2023-03-30T14:15:27.289] [trace] [url downloader] Found https://cdimage.ubuntu.com/ubuntu-core/22/stable/current/SHA256SUMS in cache: true
[2023-03-30T14:15:27.927] [trace] [url downloader] Found https://cloud-images.ubuntu.com/buildd/releases/bionic/release/SHA256SUMS in cache: true
[2023-03-30T14:15:28.573] [trace] [url downloader] Found https://cloud-images.ubuntu.com/buildd/releases/focal/release/SHA256SUMS in cache: true
[2023-03-30T14:15:29.242] [trace] [url downloader] Found https://cloud-images.ubuntu.com/buildd/releases/jammy/release/SHA256SUMS in cache: true
[2023-03-30T14:15:30.087] [trace] [url downloader] Found https://cloud-images.ubuntu.com/buildd/daily/kinetic/current/SHA256SUMS in cache: true
[2023-03-30T14:15:30.755] [trace] [url downloader] Found https://cloud-images.ubuntu.com/releases/streams/v1/index.json in cache: false
[2023-03-30T14:15:30.768] [trace] [url downloader] Found https://cloud-images.ubuntu.com/releases/streams/v1/com.ubuntu.cloud:released:download.json in cache: true
[2023-03-30T14:15:30.928] [trace] [url downloader] Found https://cdimage.ubuntu.com/ubuntu-core/appliances/streams/v1/index.json in cache: true
[2023-03-30T14:15:30.931] [trace] [url downloader] Found https://cdimage.ubuntu.com/ubuntu-core/appliances/streams/v1/com.ubuntu.appliances:released:download.json in cache: true
[2023-03-30T14:15:30.932] [trace] [Hyper-V Health Check] PowerShell arguments: -NoProfile, -NoExit, -Command, -
[2023-03-30T14:15:30.932] [trace] [Hyper-V Health Check] PowerShell working dir ''
[2023-03-30T14:15:30.932] [trace] [Hyper-V Health Check] PowerShell program 'powershell.exe'
[2023-03-30T14:15:30.932] [trace] [Hyper-V Health Check] [0] PowerShell state changed to Starting
[2023-03-30T14:15:30.937] [trace] [Hyper-V Health Check] [0] PowerShell state changed to Running
[2023-03-30T14:15:30.937] [debug] [powershell.exe] [9580] started: powershell.exe -NoProfile -NoExit -Command -
[2023-03-30T14:15:30.938] [debug] [Hyper-V Health Check] [9580] Cmdlet: 'Get-ItemProperty -Path 'HKLM:\Software\Microsoft\Windows NT\CurrentVersion' | Select-Object -ExpandProperty CurrentMajorVersionNumber'
[2023-03-30T14:15:31.612] [trace] [Hyper-V Health Check] 10
[2023-03-30T14:15:31.612] [trace] [Hyper-V Health Check] [9580] Output: 10
[2023-03-30T14:15:31.612] [debug] [Hyper-V Health Check] [9580] Cmdlet exit status is 'true'
[2023-03-30T14:15:31.613] [debug] [Hyper-V Health Check] [9580] Cmdlet: 'Get-ItemProperty -Path 'HKLM:\Software\Microsoft\Windows NT\CurrentVersion' | Select-Object -ExpandProperty ReleaseId'
[2023-03-30T14:15:31.627] [trace] [Hyper-V Health Check] 2009
[2023-03-30T14:15:31.627] [trace] [Hyper-V Health Check] [9580] Output: 2009
[2023-03-30T14:15:31.627] [debug] [Hyper-V Health Check] [9580] Cmdlet exit status is 'true'
[2023-03-30T14:15:31.627] [debug] [Hyper-V Health Check] [9580] Cmdlet: 'Get-CimInstance Win32_ComputerSystem | Select-Object -ExpandProperty HypervisorPresent'
[2023-03-30T14:15:31.716] [trace] [Hyper-V Health Check] True
[2023-03-30T14:15:31.716] [trace] [Hyper-V Health Check] [9580] Output: True
[2023-03-30T14:15:31.717] [debug] [Hyper-V Health Check] [9580] Cmdlet exit status is 'true'
[2023-03-30T14:15:31.717] [debug] [Hyper-V Health Check] [9580] Cmdlet: 'Get-WindowsOptionalFeature -Online -FeatureName Microsoft-Hyper-V | Select-Object -ExpandProperty State'
[2023-03-30T14:15:32.393] [trace] [Hyper-V Health Check] Enabled
[2023-03-30T14:15:32.393] [trace] [Hyper-V Health Check] [9580] Output: Enabled
[2023-03-30T14:15:32.393] [debug] [Hyper-V Health Check] [9580] Cmdlet exit status is 'true'
[2023-03-30T14:15:32.393] [debug] [Hyper-V Health Check] [9580] Cmdlet: 'Get-WindowsOptionalFeature -Online -FeatureName Microsoft-Hyper-V-Hypervisor | Select-Object -ExpandProperty State'
[2023-03-30T14:15:32.767] [trace] [Hyper-V Health Check] Enabled
[2023-03-30T14:15:32.767] [trace] [Hyper-V Health Check] [9580] Output: Enabled
[2023-03-30T14:15:32.767] [debug] [Hyper-V Health Check] [9580] Cmdlet exit status is 'true'
[2023-03-30T14:15:32.768] [debug] [Hyper-V Health Check] [9580] Cmdlet: 'Get-Service -Name vmms | Select-Object -ExpandProperty Status'
[2023-03-30T14:15:32.783] [trace] [Hyper-V Health Check] Running
[2023-03-30T14:15:32.783] [trace] [Hyper-V Health Check] [9580] Output: Running
[2023-03-30T14:15:32.784] [debug] [Hyper-V Health Check] [9580] Cmdlet exit status is 'true'
[2023-03-30T14:15:32.801] [trace] [Hyper-V Health Check] [9580] PowerShell state changed to NotRunning
[2023-03-30T14:15:32.801] [debug] [Hyper-V Health Check] [9580] PowerShell finished successfully
[2023-03-30T14:17:29.362] [trace] [url downloader] Found https://cloud-images.ubuntu.com/releases/server/releases/jammy/release-20230302/ubuntu-22.04-server-cloudimg-amd64.img in cache: false
[2023-03-30T14:17:38.096] [debug] [qemu-img] [21868] started: qemu-img info C:/ProgramData/Multipass/cache/vault/images/jammy-20230302/ubuntu-22.04-server-cloudimg-amd64.vhdx
[2023-03-30T14:17:38.133] [trace] [notable-chigger] PowerShell arguments: Resize-VHD, -Path, C:/ProgramData/Multipass/data/vault/instances/notable-chigger/ubuntu-22.04-server-cloudimg-amd64.vhdx, -SizeBytes, 5368709120
[2023-03-30T14:17:38.133] [trace] [notable-chigger] PowerShell working dir ''
[2023-03-30T14:17:38.133] [trace] [notable-chigger] PowerShell program 'powershell.exe'
[2023-03-30T14:17:38.133] [trace] [notable-chigger] [0] PowerShell state changed to Starting
[2023-03-30T14:17:38.138] [trace] [notable-chigger] [0] PowerShell state changed to Running
[2023-03-30T14:17:38.138] [debug] [powershell.exe] [21652] started: powershell.exe Resize-VHD -Path C:/ProgramData/Multipass/data/vault/instances/notable-chigger/ubuntu-22.04-server-cloudimg-amd64.vhdx -SizeBytes 5368709120
[2023-03-30T14:17:40.083] [trace] [notable-chigger] [21652] PowerShell state changed to NotRunning
[2023-03-30T14:17:40.083] [debug] [notable-chigger] [21652] PowerShell finished successfully
[2023-03-30T14:17:40.083] [trace] [notable-chigger] [21652] Output:

[2023-03-30T14:17:40.083] [trace] [notable-chigger] PowerShell arguments: -NoProfile, -NoExit, -Command, -
[2023-03-30T14:17:40.083] [trace] [notable-chigger] PowerShell working dir ''
[2023-03-30T14:17:40.083] [trace] [notable-chigger] PowerShell program 'powershell.exe'
[2023-03-30T14:17:40.083] [trace] [notable-chigger] [0] PowerShell state changed to Starting
[2023-03-30T14:17:40.083] [trace] [notable-chigger] [0] PowerShell state changed to Running
[2023-03-30T14:17:40.083] [debug] [powershell.exe] [1604] started: powershell.exe -NoProfile -NoExit -Command -
[2023-03-30T14:17:40.083] [debug] [notable-chigger] [1604] Cmdlet: 'Get-VM -Name notable-chigger'
[2023-03-30T14:17:41.282] [trace] [notable-chigger] Get-VM : Hyper-V was unable to find a virtual machine with name "notable-chigger".
At line:1 char:1
+ Get-VM -Name notable-chigger
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    + CategoryInfo          : InvalidArgument: (notable-chigger:String) [Get-VM], VirtualizationException
    + FullyQualifiedErrorId : InvalidParameter,Microsoft.HyperV.PowerShell.Commands.GetVM
[2023-03-30T14:17:41.282] [trace] [notable-chigger] [1604] Output: Get-VM : Hyper-V was unable to find a virtual machine with name "notable-chigger".
At line:1 char:1
+ Get-VM -Name notable-chigger
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    + CategoryInfo          : InvalidArgument: (notable-chigger:String) [Get-VM], VirtualizationException
    + FullyQualifiedErrorId : InvalidParameter,Microsoft.HyperV.PowerShell.Commands.GetVM
[2023-03-30T14:17:41.283] [debug] [notable-chigger] [1604] Cmdlet exit status is 'false'
[2023-03-30T14:17:41.283] [debug] [notable-chigger] [1604] Cmdlet: '$switch = Get-VMSwitch -Id C08CB7B8-9B3C-408E-8E30-5E16A3AEB444'
[2023-03-30T14:17:41.629] [trace] [notable-chigger]
[2023-03-30T14:17:41.629] [trace] [notable-chigger] [1604] Output:
[2023-03-30T14:17:41.630] [debug] [notable-chigger] [1604] Cmdlet exit status is 'true'
[2023-03-30T14:17:41.630] [debug] [notable-chigger] [1604] Cmdlet: 'New-VM -Name notable-chigger -Generation 2 -VHDPath "C:/ProgramData/Multipass/data/vault/instances/notable-chigger/ubuntu-22.04-server-cloudimg-amd64.vhdx" -BootDevice VHD -SwitchName $switch.Name -MemoryStartupBytes 1073741824'
[2023-03-30T14:17:41.986] [trace] [notable-chigger] New-VM : Failed to create a new virtual machine.
'notable-chigger' failed to realize. (Virtual machine ID 79D48B54-FEBD-44FA-8C65-BB95B27C37C8)
Failed to access configuration store: The system cannot find the path specified. (0x80070003).
At line:1 char:1
+ New-VM -Name notable-chigger -Generation 2 -VHDPath "C:/ProgramData/M ...
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    + CategoryInfo          : ObjectNotFound: (:) [New-VM], VirtualizationException
    + FullyQualifiedErrorId : ObjectNotFound,Microsoft.HyperV.PowerShell.Commands.NewVM
[2023-03-30T14:17:41.986] [trace] [notable-chigger] [1604] Output: New-VM : Failed to create a new virtual machine.
'notable-chigger' failed to realize. (Virtual machine ID 79D48B54-FEBD-44FA-8C65-BB95B27C37C8)
Failed to access configuration store: The system cannot find the path specified. (0x80070003).
At line:1 char:1
+ New-VM -Name notable-chigger -Generation 2 -VHDPath "C:/ProgramData/M ...
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    + CategoryInfo          : ObjectNotFound: (:) [New-VM], VirtualizationException
    + FullyQualifiedErrorId : ObjectNotFound,Microsoft.HyperV.PowerShell.Commands.NewVM
[2023-03-30T14:17:41.986] [debug] [notable-chigger] [1604] Cmdlet exit status is 'false'
[2023-03-30T14:17:41.988] [trace] [notable-chigger] [1604] PowerShell state changed to NotRunning
[2023-03-30T14:17:41.988] [debug] [notable-chigger] [1604] PowerShell finished successfully
[2023-03-30T14:17:42.004] [trace] [notable-chigger] PowerShell arguments: Remove-VM, -Name, notable-chigger, -Force
[2023-03-30T14:17:42.004] [trace] [notable-chigger] PowerShell working dir ''
[2023-03-30T14:17:42.004] [trace] [notable-chigger] PowerShell program 'powershell.exe'
[2023-03-30T14:17:42.004] [trace] [notable-chigger] [0] PowerShell state changed to Starting
[2023-03-30T14:17:42.009] [trace] [notable-chigger] [0] PowerShell state changed to Running
[2023-03-30T14:17:42.010] [debug] [powershell.exe] [22136] started: powershell.exe Remove-VM -Name notable-chigger -Force
[2023-03-30T14:17:42.593] [trace] [notable-chigger] [22136] PowerShell state changed to NotRunning
[2023-03-30T14:17:42.593] [warning] [notable-chigger] [22136] PowerShell finished abnormally: Process returned exit code: 1
[2023-03-30T14:17:42.594] [trace] [notable-chigger] [22136] Output:
Remove-VM : Hyper-V was unable to find a virtual machine with name "notable-chigger".
At line:1 char:1
+ Remove-VM -Name notable-chigger -Force
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    + CategoryInfo          : ObjectNotFound: (:) [Remove-VM], VirtualizationException
    + FullyQualifiedErrorId : ObjectNotFound,Microsoft.HyperV.PowerShell.Commands.RemoveVM
launch failed: Could not create VM

Any idea?

gzOne2Free avatar Mar 30 '23 06:03 gzOne2Free

Additional information:

I try to execute PS command follow the debug output, and found 2 errors. Step #1

qemu-img info C:/ProgramData/Multipass/cache/vault/images/focal-20230209/ubuntu-20.04-server-cloudimg-amd64.vhdx                                                      file format: vhdx
virtual size: 2.2 GiB (2361393152 bytes)
disk size: 1.46 GiB
cluster_size: 16777216

Step #2

Resize-VHD -Path C:/ProgramData/Multipass/data/vault/instances/merry-mudskipper/ubuntu-20.04-server-cloudimg-amd64.vhdx -SizeBytes 5368709120
Resize-VHD : 'C:/ProgramData/Multipass/data/vault/instances/merry-mudskipper/ubuntu-20.04-server-cloudimg-amd64.vhdx' is not an existing virtual hard disk file.
At line:1 char:1
+ Resize-VHD -Path C:/ProgramData/Multipass/data/vault/instances/merry- ...
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    + CategoryInfo          : InvalidArgument: (:) [Resize-VHD], VirtualizationException
    + FullyQualifiedErrorId : InvalidParameter,Microsoft.Vhd.PowerShell.Cmdlets.ResizeVhd

Here is the error #1. I notice that the vhdx generated in step 1 is in C:/ProgramData/Multipass/cache/vault/images/focal-20230209 folder, but the step 2 parameter is in C:/ProgramData/Multipass/data/vault/instances/merry-mudskipper/ folder. I did not find any copy or move command to generate file in destination folder. Then I copy vhdx file from cache folder to data folder, and rerun step 2 succeed.

Step #3

$switch = Get-VMSwitch -Id C08CB7B8-9B3C-408E-8E30-5E16A3AEB444

To validate:
Get-VMSwitch -Id C08CB7B8-9B3C-408E-8E30-5E16A3AEB444

Name           SwitchType NetAdapterInterfaceDescription
----           ---------- ------------------------------
Default Switch Internal

Step #4

New-VM -Name merry-mudskipper -Generation 2 -VHDPath "C:/ProgramData/Multipass/data/vault/instances/merry-mudskipper/ubuntu-20.04-server-cloudimg-amd64.vhdx" -BootDevice VHD -SwitchName $switch.Name -MemoryStartupBytes 1073741824
New-VM : Failed to create a new virtual machine.
'merry-mudskipper' failed to realize. (Virtual machine ID F852B718-2A36-442D-85F4-BE59D853CBF0)
Failed to access configuration store: The system cannot find the path specified. (0x80070003).
At line:1 char:1
+ New-VM -Name merry-mudskipper -Generation 2 -VHDPath "C:/ProgramData/ ...
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    + CategoryInfo          : ObjectNotFound: (:) [New-VM], VirtualizationException
    + FullyQualifiedErrorId : ObjectNotFound,Microsoft.HyperV.PowerShell.Commands.NewVM

Here is the error #2. VM create failed because of file not found error. But, when I try to list captioned file:

ls C:/ProgramData/Multipass/data/vault/instances/merry-mudskipper/ubuntu-20.04-server-cloudimg-amd64.vhdx


    Directory: C:\ProgramData\Multipass\data\vault\instances\merry-mudskipper


Mode                 LastWriteTime         Length Name
----                 -------------         ------ ----
-a----         3/30/2023   2:44 PM     1719664640 ubuntu-20.04-server-cloudimg-amd64.vhdx

The file exist. That's so strange. Finally, process halt on this step and can not continue.

gzOne2Free avatar Mar 30 '23 07:03 gzOne2Free

Hey @gzOne2Free, strange indeed! The issue appears to be limited to step 4. A few questions to try to sort this out:

  1. Do you have special access policies for any of the parent folders? (you managed to copy the file in, so I suppose it's ok, but better be sure)
  2. Any sandboxing app that could be preventing access?
  3. How much space do you have left on drive C?
  4. Could you try, in an admin PowerShell, to copy the image file to a couple of totally different folders (e.g. "My Documents", a different drive) and try New-VM with those?
  5. Can you create any VMs from the Hyper-V Manager graphical app?

For the record, Multipass does copy the file you needed in step 2 (not with PowerShell), and so that step worked fine for Multipass:

[2023-03-30T14:17:38.138] [debug] [powershell.exe] [21652] started: powershell.exe Resize-VHD -Path C:/ProgramData/Multipass/data/vault/instances/notable-chigger/ubuntu-22.04-server-cloudimg-amd64.vhdx -SizeBytes 5368709120
[2023-03-30T14:17:40.083] [trace] [notable-chigger] [21652] PowerShell state changed to NotRunning
[2023-03-30T14:17:40.083] [debug] [notable-chigger] [21652] PowerShell finished successfully

ricab avatar Mar 30 '23 11:03 ricab

Hi @ricab ,

Thanks for your reply. After check with your suggestion, I found that the multipass error should be cause by HyperV. When I try to create a new VM, it pop up this error message:

The server encountered an error while creating Test.
Failed to create a new virtual machine.
'Test' failed to realize.
(Virtual machine lDF3010084-8D11-4183-9595-0CAE6BCB8C3C1
Failed to access configuration store: The system cannot find the path specified. (0x80070003).

So this is a HyperV issue, but nor related to multipass.

gzOne2Free avatar Apr 03 '23 03:04 gzOne2Free

OK, thanks for letting us know @gzOne2Free. I will be closing this now, please reopen if you need to.

ricab avatar Apr 03 '23 10:04 ricab

I also encountered this issue, after tons of clueless research, I found the reason and workaround embarassingly simple, and I truly think this is something multipass could improve on.

First the workaround:

  1. open hyper-v vm manager, click New -> Virtual Machine -> Next
  2. Note the Option Store the virtual machine in a different location, it is greyed out by default, and the path box below shows your default store path. Mine is some custom path that I used a long time ago, which doesn't exist anymore, and which is the CAUSE of this prblem.
  3. Create that path by mkdir -p in powershell (no need to be admin).

Voila, problem solved, multipass launch now works flawlessly!

HOW IS THIS A POTENTIAL IMPROVEMENT FOR MULTIPASS?

The New-VM cmdlet offers an argument -Path which we can use to specify store lcation. multipass didn't use that argument. I've reproduced the error using New-VM and confirmed it can be resolved by specifying custom -Path location that actually exists.

So

It's embarassing that this problem has cost me a whole day.

Please consider reopening this issue as a bug.

@ricab

xinstein avatar Nov 22 '23 04:11 xinstein

Hi @xinstein, thanks for sharing your findings. I am sorry you had to spend all that time. I thought this was totally outside of Multipass, but you've shown otherwise, so reopening.

So this happens when the user set a "default store path" that can't be accessed, correct? How exactly did you set that? Would you be able to list exact steps to reproduce?

ricab avatar Nov 22 '23 11:11 ricab

I've looked into this a little further. I managed to reproduce by setting the default "Virtual Machines" folder to a missing directory in Hyper-V. And I confirm that it can be fixed with a -Path parameter to New-VM.

I guess we could use our own directory for the remaining VM files that Hyper-V creates. We don't control the structure and it is a little ugly when specifying -Path for a single VM (<specified-vm-dir>/<vm-name>/Virtual Machines/...). I suppose we could work with it, if it works for Hyper-V, but is it worth it?

Another consideration is that we'd stop using users' location preference, but we already do so for "Virtual Hard Disks", which is what eats up space and what people would most likely want to change. They can do so with MULTIPASS_STORAGE today, which would apply for this as well.

All that said, I don't think this is exactly a fault on Multipass's part. It is reasonable to require Hyper-V configurations to work, as a precondition. We can't check or override everything that could have been incorrectly setup, although we could add to our initial backend checks for obvious misses. In any case, I regard this as a feature request with low priority, (especially now that @xinstein documented how to correct it).

ricab avatar Nov 22 '23 16:11 ricab

. We can't check or override everything that could have been incorrectly setup, although we could add to our initial backend checks for obvious misses.

Fair point.

Also, I found the more decent workaround: All the default store locations can be configured via Hyper-V Manager GUI -> Hyper-V Settings.

At least this could be added as an instruction in prerequisites

xinstein avatar Nov 23 '23 15:11 xinstein