canonical / multipass

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

"Starting primary" times out on macOS 13 #2691

Closed anpep closed 2 years ago

anpep commented 2 years ago

Describe the bug I've got an Ubuntu 22.04 VM that worked perfectly before but since a few days ago it won't start on macOS

To Reproduce How, and what happened?

  1. multipass shell
  2. Starting primary shows on my terminal and eventually fails with a time out:
    start failed: The following errors occurred:
    primary: timed out waiting for response

Expected behavior My VM to start and pop a shell

Logs

[2022-08-01T17:32:29.217] [info] [daemon] Starting Multipass 1.10.1+mac
[2022-08-01T17:32:29.217] [info] [daemon] Daemon arguments: /Library/Application Support/com.canonical.multipass/bin/multipassd --verbosity debug
[2022-08-01T17:32:33.806] [debug] [primary] process working dir ''
[2022-08-01T17:32:33.806] [info] [primary] process program 'qemu-system-aarch64'
[2022-08-01T17:32:33.806] [info] [primary] process arguments '-machine, virt,highmem=off, -accel, hvf, -drive, file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on, -cpu, cortex-a72, -nic, vmnet-shared,model=virtio-net-pci,mac=52:54:00:c7:8d:46, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img,if=none,format=qcow2,discard=unmap,id=hda, -device, scsi-hd,drive=hda,bus=scsi0.0, -smp, 4, -m, 4096M, -qmp, stdio, -chardev, null,id=char0, -serial, chardev:char0, -nographic, -cdrom, /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/cloud-init-config.iso'
[2022-08-01T17:32:33.812] [debug] [qemu-system-aarch64] [10389] started: qemu-system-aarch64 -machine virt,highmem=off -nographic -dump-vmstate /private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T/multipassd.rwOrxO
[2022-08-01T17:32:33.868] [info] [primary] process state changed to Starting
[2022-08-01T17:32:33.870] [info] [primary] process state changed to Running
[2022-08-01T17:32:33.870] [debug] [qemu-system-aarch64] [10390] started: qemu-system-aarch64 -machine virt,highmem=off -accel hvf -drive file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on -cpu cortex-a72 -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:c7:8d:46 -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img,if=none,format=qcow2,discard=unmap,id=hda -device scsi-hd,drive=hda,bus=scsi0.0 -smp 4 -m 4096M -qmp stdio -chardev null,id=char0 -serial chardev:char0 -nographic -cdrom /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/cloud-init-config.iso
[2022-08-01T17:32:33.870] [info] [primary] process started
[2022-08-01T17:32:33.871] [debug] [primary] Waiting for SSH to be up
[2022-08-01T17:32:34.088] [debug] [primary] QMP: {"QMP": {"version": {"qemu": {"micro": 0, "minor": 2, "major": 6}, "package": ""}, "capabilities": ["oob"]}}

[2022-08-01T17:32:34.136] [debug] [primary] QMP: {"return": {}}

[2022-08-01T17:32:43.556] [debug] [primary] QMP: {"timestamp": {"seconds": 1659367963, "microseconds": 556752}, "event": "NIC_RX_FILTER_CHANGED", "data": {"path": "/machine/unattached/device[9]/virtio-backend"}}

[2022-08-01T17:32:56.723] [debug] [primary] QMP: {"timestamp": {"seconds": 1659367976, "microseconds": 721800}, "event": "RTC_CHANGE", "data": {"offset": 1}}

[2022-08-01T17:33:16.915] [debug] [daemon] Returning setting local.driver=qemu

Additional info

anpep commented 2 years ago

I can confirm that the problem persists even after uninstalling/reinstalling multipass.

RanKKI commented 2 years ago

same. got time out on macOS 12.5, m1 Pro chip

❯ multipass launch -vvvv --name fit -c 8 -m 4G jammy
[2022-08-02T11:04:54.159] [debug] [qemu-system-aarch64] [67456] started: qemu-system-aarch64 --version
[2022-08-02T11:04:58.479] [debug] [qemu-img] [67458] started: qemu-img info /var/root/Library/Caches/multipassd/qemu/vault/images/jammy-20220712/ubuntu-22.04-server-cloudimg-arm64.img
[2022-08-02T11:04:58.490] [debug] [qemu-img] [67459] started: qemu-img resize /var/root/Library/Application Support/multipassd/qemu/vault/instances/fit/ubuntu-22.04-server-cloudimg-arm64.img 5368709120
[2022-08-02T11:04:58.504] [debug] [qemu-img] [67460] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/fit/ubuntu-22.04-server-cloudimg-arm64.img
[2022-08-02T11:04:58.510] [debug] [fit] process working dir ''
[2022-08-02T11:04:58.510] [info] [fit] process program 'qemu-system-aarch64'
[2022-08-02T11:04:58.510] [info] [fit] process arguments '-machine, virt,highmem=off, -accel, hvf, -drive, file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on, -cpu, cortex-a72, -nic, vmnet-shared,model=virtio-net-pci,mac=52:54:00:04:2a:5a, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/fit/ubuntu-22.04-server-cloudimg-arm64.img,if=none,format=qcow2,discard=unmap,id=hda, -device, scsi-hd,drive=hda,bus=scsi0.0, -smp, 8, -m, 4096M, -qmp, stdio, -chardev, null,id=char0, -serial, chardev:char0, -nographic, -cdrom, /var/root/Library/Application Support/multipassd/qemu/vault/instances/fit/cloud-init-config.iso'
[2022-08-02T11:04:58.512] [debug] [qemu-system-aarch64] [67461] started: qemu-system-aarch64 -machine virt,highmem=off -nographic -dump-vmstate /private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T/multipassd.sQHYeQ
[2022-08-02T11:04:58.545] [info] [fit] process state changed to Starting
[2022-08-02T11:04:58.547] [info] [fit] process state changed to Running
[2022-08-02T11:04:58.547] [debug] [qemu-system-aarch64] [67462] started: qemu-system-aarch64 -machine virt,highmem=off -accel hvf -drive file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on -cpu cortex-a72 -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:04:2a:5a -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/fit/ubuntu-22.04-server-cloudimg-arm64.img,if=none,format=qcow2,discard=unmap,id=hda -device scsi-hd,drive=hda,bus=scsi0.0 -smp 8 -m 4096M -qmp stdio -chardev null,id=char0 -serial chardev:char0 -nographic -cdrom /var/root/Library/Application Support/multipassd/qemu/vault/instances/fit/cloud-init-config.iso
[2022-08-02T11:04:58.547] [info] [fit] process started
launch failed: The following errors occurred:
fit: timed out waiting for response
ricab commented 2 years ago

Hi @anpep, @RanKKI, you're probably being affected by the firewall issue. You could try to see if disabling it or putting it in debug mode would fix it for you.

Let us know if it works!

RanKKI commented 2 years ago

Hi @anpep, @RanKKI, you're probably being affected by the firewall issue. You could try to see if disabling it or putting it in debug mode would fix it for you.

Let us know if it works!

Aha, it works after turning off the firewall.

ricab commented 2 years ago

Good, thanks for letting us know :) yeah that's a painful issue right now...

I'll close this as duplicate now. Please reopen if there is something else involved.

ricab commented 2 years ago

Duplicate of https://github.com/canonical/multipass/issues/2387

anpep commented 2 years ago

Hi @anpep, @RanKKI, you're probably being affected by the firewall issue. You could try to see if disabling it or putting it in debug mode would fix it for you.

Let us know if it works!

Thanks @ricab! Unfortunately, the issue persists even after:

  1. adding the QEMU executable to the firmware exemptions in System Settings
  2. completely disabling the firewall in System Settings

The logs stay pretty much the same, though. I would say it's maybe a macOS 13.0-related issue, but I had it working last week with no problems...

ricab commented 2 years ago

Oh bummer :/ Have you tried setting the firewall to debug mode, as linked above? Do you see any relevant info under /var/log

anpep commented 2 years ago

Oh bummer :/ Have you tried setting the firewall to debug mode, as linked above? Do you see any relevant info under /var/log

I did not read that bit, it worked like a charm after that. Thank you!

ricab commented 2 years ago

Also, @anpep have a look in here, particularly the "generic networking" section. Does anything in there help?

ricab commented 2 years ago

Oh crossed messages... thanks, good to know!

anpep commented 2 years ago

Oh crossed messages... thanks, good to know!

No worries 👍 BTW, is the debug mode a permanent thing or should I run that every time my OS boots? Thank you!

ricab commented 2 years ago

I am not sure, but I suspect you would need to edit a plist file somewhere to make it permanent.