canonical / multipass

Multipass orchestrates virtual Ubuntu instances
https://multipass.run
GNU General Public License v3.0
7.73k stars 642 forks source link

Multipass instances do not boot on macOS #3674

Open pkarjala opened 1 week ago

pkarjala commented 1 week ago

Describe the bug

When starting a new multipass instance, it will hang and the status becomes "Unknown".

To Reproduce

From either the GUI or the CLI, launch a new Ubuntu 24.04 LTS image with default settings.

  1. multipass launch 24.04

Expected behavior

The instance should launch and be available for use.

Logs

When launching from GUI:

[2024-09-12T11:10:03.774] [debug] [blueprint provider] Loading "anbox-cloud-appliance" v1
[2024-09-12T11:10:03.775] [debug] [blueprint provider] Loading "charm-dev" v1
[2024-09-12T11:10:03.776] [debug] [blueprint provider] Loading "docker" v1
[2024-09-12T11:10:03.776] [debug] [blueprint provider] Loading "jellyfin" v1
[2024-09-12T11:10:03.776] [debug] [blueprint provider] Loading "minikube" v1
[2024-09-12T11:10:03.777] [debug] [blueprint provider] Loading "ros-noetic" v1
[2024-09-12T11:10:03.777] [debug] [blueprint provider] Loading "ros2-humble" v1
[2024-09-12T11:10:03.784] [debug] [qemu-system-x86_64] [12137] started: qemu-system-x86_64 --version
[2024-09-12T11:10:03.844] [debug] [qemu-img] [12138] started: qemu-img info /var/root/Library/Caches/multipassd/qemu/vault/images/noble-20240821/ubuntu-24.04-server-cloudimg-amd64.img
[2024-09-12T11:10:03.882] [debug] [qemu-img] [12139] started: qemu-img resize /var/root/Library/Application Support/multipassd/qemu/vault/instances/rich-labrador/ubuntu-24.04-server-cloudimg-amd64.img 5368709120
[2024-09-12T11:10:03.926] [debug] [qemu-img] [12140] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/rich-labrador/ubuntu-24.04-server-cloudimg-amd64.img
[2024-09-12T11:10:03.942] [debug] [qemu-img] [12141] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/rich-labrador/ubuntu-24.04-server-cloudimg-amd64.img
[2024-09-12T11:10:03.973] [debug] [rich-labrador] process working dir ''
[2024-09-12T11:10:03.973] [info] [rich-labrador] process program 'qemu-system-x86_64'
[2024-09-12T11:10:03.974] [info] [rich-labrador] process arguments '-accel, hvf, -drive, file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-x86_64-code.fd,if=pflash,format=raw,readonly=on, -cpu, host, -nic, vmnet-shared,model=virtio-net-pci,mac=52:54:00:dc:0d:a7, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/rich-labrador/ubuntu-24.04-server-cloudimg-amd64.img,if=none,format=qcow2,discard=unmap,id=hda, -device, scsi-hd,drive=hda,bus=scsi0.0, -smp, 1, -m, 1024M, -qmp, stdio, -chardev, null,id=char0, -serial, chardev:char0, -nographic, -cdrom, /var/root/Library/Application Support/multipassd/qemu/vault/instances/rich-labrador/cloud-init-config.iso'
[2024-09-12T11:10:03.979] [debug] [qemu-system-x86_64] [12142] started: qemu-system-x86_64 -nographic -dump-vmstate /private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T/multipassd.lMYTrt
[2024-09-12T11:10:04.081] [info] [rich-labrador] process state changed to Starting
[2024-09-12T11:10:04.087] [info] [rich-labrador] process state changed to Running
[2024-09-12T11:10:04.087] [debug] [qemu-system-x86_64] [12143] started: qemu-system-x86_64 -accel hvf -drive file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-x86_64-code.fd,if=pflash,format=raw,readonly=on -cpu host -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:dc:0d:a7 -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/rich-labrador/ubuntu-24.04-server-cloudimg-amd64.img,if=none,format=qcow2,discard=unmap,id=hda -device scsi-hd,drive=hda,bus=scsi0.0 -smp 1 -m 1024M -qmp stdio -chardev null,id=char0 -serial chardev:char0 -nographic -cdrom /var/root/Library/Application Support/multipassd/qemu/vault/instances/rich-labrador/cloud-init-config.iso
[2024-09-12T11:10:04.087] [info] [rich-labrador] process started
[2024-09-12T11:10:04.089] [debug] [rich-labrador] Waiting for SSH to be up
[2024-09-12T11:10:04.237] [debug] [rich-labrador] QMP: {"QMP": {"version": {"qemu": {"micro": 1, "minor": 2, "major": 8}, "package": ""}, "capabilities": ["oob"]}}

[2024-09-12T11:10:04.242] [warning] [rich-labrador] Could not open option rom 'kvmvapic.bin': No such file or directory

[2024-09-12T11:10:04.242] [warning] [qemu-system-x86_64]
[2024-09-12T11:10:04.279] [debug] [rich-labrador] QMP: {"return": {}}

[2024-09-12T11:10:04.922] [debug] [rich-labrador] QMP: {"timestamp": {"seconds": 1726175404, "microseconds": 922404}, "event": "RTC_CHANGE", "data": {"offset": 0, "qom-path": "/machine/unattached/device[3]/rtc"}}

[2024-09-12T11:10:05.924] [debug] [rich-labrador] QMP: {"timestamp": {"seconds": 1726175405, "microseconds": 133553}, "event": "RTC_CHANGE", "data": {"offset": -1, "qom-path": "/machine/unattached/device[3]/rtc"}}

[2024-09-12T11:10:29.541] [debug] [rich-labrador] QMP: {"timestamp": {"seconds": 1726175429, "microseconds": 541772}, "event": "NIC_RX_FILTER_CHANGED", "data": {"path": "/machine/unattached/device[21]/virtio-backend"}}

[2024-09-12T11:16:33.800] [debug] [daemon] Returning setting local.driver=qemu

When launching from CLI:

% multipass launch 24.04
launch failed: The following errors occurred:
delectable-ling: timed out waiting for response

Logs:

[2024-09-12T11:32:09.682] [debug] [blueprint provider] Loading "anbox-cloud-appliance" v1
[2024-09-12T11:32:09.682] [debug] [blueprint provider] Loading "charm-dev" v1
[2024-09-12T11:32:09.683] [debug] [blueprint provider] Loading "docker" v1
[2024-09-12T11:32:09.684] [debug] [blueprint provider] Loading "jellyfin" v1
[2024-09-12T11:32:09.684] [debug] [blueprint provider] Loading "minikube" v1
[2024-09-12T11:32:09.685] [debug] [blueprint provider] Loading "ros-noetic" v1
[2024-09-12T11:32:09.685] [debug] [blueprint provider] Loading "ros2-humble" v1
[2024-09-12T11:32:45.390] [debug] [qemu-system-x86_64] [12231] started: qemu-system-x86_64 --version
[2024-09-12T11:32:45.444] [debug] [qemu-img] [12232] started: qemu-img info /var/root/Library/Caches/multipassd/qemu/vault/images/noble-20240821/ubuntu-24.04-server-cloudimg-amd64.img
[2024-09-12T11:32:45.481] [debug] [qemu-img] [12233] started: qemu-img resize /var/root/Library/Application Support/multipassd/qemu/vault/instances/delectable-ling/ubuntu-24.04-server-cloudimg-amd64.img 5368709120
[2024-09-12T11:32:45.503] [debug] [qemu-img] [12234] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/delectable-ling/ubuntu-24.04-server-cloudimg-amd64.img
[2024-09-12T11:32:45.538] [debug] [qemu-img] [12235] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/delectable-ling/ubuntu-24.04-server-cloudimg-amd64.img
[2024-09-12T11:32:45.553] [debug] [delectable-ling] process working dir ''
[2024-09-12T11:32:45.553] [info] [delectable-ling] process program 'qemu-system-x86_64'
[2024-09-12T11:32:45.553] [info] [delectable-ling] process arguments '-accel, hvf, -drive, file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-x86_64-code.fd,if=pflash,format=raw,readonly=on, -cpu, host, -nic, vmnet-shared,model=virtio-net-pci,mac=52:54:00:ee:da:48,
-device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/delectable-ling/ubuntu-24.04-server-cloudimg-amd64.img,if=none,format=qcow2,discard=unmap,id=hda, -device, scsi-hd,drive=hda,bus=scsi0.0, -smp, 1, -m, 1024M, -qmp, stdio, -chardev, null,id=char0, -serial, chardev:char0, -nographic, -cdrom, /var/root/Library/Application Support/multipassd/qemu/vault/instances/delectable-ling/cloud-init-config.iso'
[2024-09-12T11:32:45.558] [debug] [qemu-system-x86_64] [12236] started: qemu-system-x86_64 -nographic -dump-vmstate /private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T/multipassd.TMBVif
[2024-09-12T11:32:45.677] [info] [delectable-ling] process state changed to Starting
[2024-09-12T11:32:45.682] [info] [delectable-ling] process state changed to Running
[2024-09-12T11:32:45.682] [debug] [qemu-system-x86_64] [12237] started: qemu-system-x86_64 -accel hvf -drive file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-x86_64-code.fd,if=pflash,format=raw,readonly=on -cpu host -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:ee:da:48 -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/delectable-ling/ubuntu-24.04-server-cloudimg-amd64.img,if=none,format=qcow2,discard=unmap,id=hda -device scsi-hd,drive=hda,bus=scsi0.0 -smp 1 -m 1024M -qmp stdio -chardev null,id=char0 -serial chardev:char0 -nographic -cdrom /var/root/Library/Application Support/multipassd/qemu/vault/instances/delectable-ling/cloud-init-config.iso
[2024-09-12T11:32:45.682] [info] [delectable-ling] process started
[2024-09-12T11:32:45.684] [debug] [delectable-ling] Waiting for SSH to be up
[2024-09-12T11:32:45.840] [debug] [delectable-ling] QMP: {"QMP": {"version": {"qemu": {"micro": 1, "minor": 2, "major": 8}, "package": ""}, "capabilities": ["oob"]}}

[2024-09-12T11:32:45.845] [warning] [delectable-ling] Could not open option rom 'kvmvapic.bin': No such file or directory

[2024-09-12T11:32:45.845] [warning] [qemu-system-x86_64]
[2024-09-12T11:32:45.880] [debug] [delectable-ling] QMP: {"return": {}}

[2024-09-12T11:32:46.506] [debug] [delectable-ling] QMP: {"timestamp": {"seconds": 1726176766, "microseconds": 506643}, "event": "RTC_CHANGE", "data": {"offset": -1, "qom-path": "/machine/unattached/device[3]/rtc"}}

[2024-09-12T11:32:47.527] [debug] [delectable-ling] QMP: {"timestamp": {"seconds": 1726176766, "microseconds": 730314}, "event": "RTC_CHANGE", "data": {"offset": -1, "qom-path": "/machine/unattached/device[3]/rtc"}}

[2024-09-12T11:33:09.756] [debug] [delectable-ling] QMP: {"timestamp": {"seconds": 1726176789, "microseconds": 756746}, "event": "NIC_RX_FILTER_CHANGED", "data": {"path": "/machine/unattached/device[21]/virtio-backend"}}

[2024-09-12T11:37:03.491] [debug] [async task] fetch manifest periodically

Additional info

Additional context

I have rebooted the host computer, as well as uninstalled and reinstalled multipass entirely. It is installed via the .pkg method (not brew).

Initially an instance booted without issue. After that they all time out while attempting to boot. Stopping and restarting the initial working instance also resulted in a timeout and being unable to use it.

sharder996 commented 1 week ago

Hi @pkarjala, Can you verify that your firewall is not enabled and that you are not running a VPN?

pkarjala commented 1 week ago

I can confirm that I am not on a VPN, and that the macOS Firewall is disabled. Thanks!

sharder996 commented 4 days ago

One of my colleagues wrote an excellent troubleshooting guide for ssh connection issues here

From your posted logs I can see that the instance is booting up successfully, but for some reason Multipass is not able to connect to the instance. As explained in the above discussion you could try using tcpdump to check for dhcp requests and replies or check the contents of dhcp_leases.

pkarjala commented 4 days ago

Thank you, I will review and follow up!

Gab2thebo commented 4 days ago

Same issues. I have updated to macOS Sequoia today and multipass instance are not starting and are in an unknown state.

sharder996 commented 4 days ago

@Gab2thebo Yes, there is an issue with new Sequoia updating causing issues with Multipass not being able to acquire IP addresses of instances. It is being tracked with https://github.com/canonical/multipass/issues/3661