canonical / multipass

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

Mac M1 machine cannot start the container. timed out waiting for response #3411

Open yangletec opened 8 months ago

yangletec commented 8 months ago

Describe the bug After installing Multipass on Mac M1, when launching a container with 'multipass launch,' the console remains in the 'Starting' state. After a while, a 'timed out waiting for response' error occurs. The issue is persistent.

To Reproduce How, and what happened? multipass launch lts

Expected behavior

Logs

Additional info

Additional context Add any other context about the problem here.

ricab commented 8 months ago

Hi @yangletec, does this happen only with one instance or with any instance? Does multipass launch work?

We'd need logs to investigate, but this is often a networking problem (the instance doesn't get an IP, which is necessary to complete the start transition). Could you please try to follow our troubleshooting docs and let us know if that it helps?

yangletec commented 8 months ago

All instances fail to start. I have reinstalled and uninstalled multiple times in the past month. I can create instances, but none of them can be started. I have provided some logs here.

multipass start -vv test
[2024-02-23T09:13:04.551] [info] [test] process program 'qemu-system-aarch64'
[2024-02-23T09:13:04.551] [info] [test] process arguments '-machine, virt,gic-version=3, -accel, hvf, -drive, file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on, -cpu, host, -nic, vmnet-shared,model=virtio-net-pci,mac=52:54:00:5c:f9:fa, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/test/ubuntu-22.04-server-cloudimg-arm64.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/test/cloud-init-config.iso'
[2024-02-23T09:13:06.087] [info] [test] process state changed to Starting
[2024-02-23T09:13:06.090] [info] [test] process state changed to Running
[2024-02-23T09:13:06.090] [info] [test] process started
Starting test ...

Screenshot2024_02_23_091513 Now it has turned into an unknown status.

primary                 Unknown           --               Ubuntu 22.04 LTS
adapting-ladybug        Stopped           --               Ubuntu 22.04 LTS
completed-leopardess    Stopped           --               Ubuntu 22.04 LTS
engrossed-lemming       Stopped           --               Ubuntu 22.04 LTS
healing-filly           Unknown           --               Ubuntu 22.04 LTS
liked-koi               Stopped           --               Ubuntu 22.04 LTS
set-mastodon            Stopped           --               Ubuntu 22.04 LTS
test                    Unknown           --               Ubuntu 22.04 LTS
ricab commented 8 months ago

Hi @yangletec, Do you have the firewall on?

I couldn't find the logs (apart from the few messages you pasted). Did you perhaps forget to attach them?

pixerl0n commented 8 months ago

I've the similar issue. I've uninstalled multipass and installed it from scratch. The same behavior if the firewall is turned on or turned off.

fx@Air-xp ~ % multipass launch -vvv 22.04
[2024-02-23T13:36:32.611] [debug] [qemu-system-aarch64] [3130] started: qemu-system-aarch64 --version
[2024-02-23T13:36:32.640] [debug] [qemu-img] [3131] started: qemu-img info /var/root/Library/Caches/multipassd/qemu/vault/images/jammy-20240221/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-23T13:36:32.658] [debug] [qemu-img] [3132] started: qemu-img resize /var/root/Library/Application Support/multipassd/qemu/vault/instances/suitable-reindeer/ubuntu-22.04-server-cloudimg-arm64.img 5368709120
[2024-02-23T13:36:32.675] [debug] [qemu-img] [3133] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/suitable-reindeer/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-23T13:36:32.681] [debug] [qemu-img] [3134] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/suitable-reindeer/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-23T13:36:32.687] [debug] [suitable-reindeer] process working dir ''
[2024-02-23T13:36:32.687] [info] [suitable-reindeer] process program 'qemu-system-aarch64'
[2024-02-23T13:36:32.687] [info] [suitable-reindeer] process arguments '-machine, virt,gic-version=3, -accel, hvf, -drive, file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on, -cpu, host, -nic, vmnet-shared,model=virtio-net-pci,mac=52:54:00:01:3c:8c, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/suitable-reindeer/ubuntu-22.04-server-cloudimg-arm64.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/suitable-reindeer/cloud-init-config.iso'
[2024-02-23T13:36:32.688] [debug] [qemu-system-aarch64] [3135] started: qemu-system-aarch64 -machine virt,gic-version=3 -nographic -dump-vmstate /private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T/multipassd.QfuRdw
[2024-02-23T13:36:32.720] [info] [suitable-reindeer] process state changed to Starting
[2024-02-23T13:36:32.721] [info] [suitable-reindeer] process state changed to Running
[2024-02-23T13:36:32.721] [debug] [qemu-system-aarch64] [3136] started: qemu-system-aarch64 -machine virt,gic-version=3 -accel hvf -drive file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on -cpu host -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:01:3c:8c -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/suitable-reindeer/ubuntu-22.04-server-cloudimg-arm64.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/suitable-reindeer/cloud-init-config.iso
[2024-02-23T13:36:32.721] [info] [suitable-reindeer] process started
launch failed: The following errors occurred:
suitable-reindeer: timed out waiting for response
fx@Air-xp ~ % 
ricab commented 8 months ago

Hi @pixerl0n, have you gone through the troubleshooting I linked above?

These symptoms can have different causes, so your issues may well differ, but logs would be helpful to diagnose, preferably with trace verbosity. You can configure the daemon to log with trace verbosity like this:

  1. stop the multipass daemon with sudo launchctl unload /Library/LaunchDaemons/com.canonical.multipassd.plist
  2. edit /Library/LaunchDaemons/com.canonical.multipassd.plist and change verbosity from "debug" to "trace"
  3. after saving the file, restart the multipass daemon: sudo launchctl load /Library/LaunchDaemons/com.canonical.multipassd.plist
pixerl0n commented 8 months ago

Hi @pixerl0n, have you gone through the troubleshooting I linked above?

These symptoms can have different causes, so your issues may well differ, but logs would be helpful to diagnose, preferably with trace verbosity. You can configure the daemon to log with trace verbosity like this:

  1. stop the multipass daemon with sudo launchctl unload /Library/LaunchDaemons/com.canonical.multipassd.plist
  2. edit /Library/LaunchDaemons/com.canonical.multipassd.plist and change verbosity from "debug" to "trace"
  3. after saving the file, restart the multipass daemon: sudo launchctl load /Library/LaunchDaemons/com.canonical.multipassd.plist

Thank you. I figured out that the issue must be related to the Cisco secure client and the macOS firewall. I uninstalled the Cisco Secure Client and it still didn't work. I used this advice https://github.com/canonical/multipass/issues/2387#issue-1093663351 and it worked then without any issue. After installing the Cisco Secure Client I cannot start any VM. I will do after the weekend some more research and will keep you up to date there.

ricab commented 8 months ago

OK, so yours was the firewall issue @pixerl0n. Glad you got it working.

yangletec commented 8 months ago

[2024-02-26T09:28:58.579] [debug] [qemu-system-aarch64] [97600] started: qemu-system-aarch64 --version [2024-02-26T09:28:58.599] [debug] [qemu-img] [97601] started: qemu-img info /var/root/Library/Caches/multipassd/qemu/vault/images/jammy-20240223/ubuntu-22.04-server-cloudimg-arm64.img [2024-02-26T09:28:58.617] [debug] [qemu-img] [97602] started: qemu-img resize /var/root/Library/Application Support/multipassd/qemu/vault/instances/impartial-tern/ubuntu-22.04-server-cloudimg-arm64.img 5368709120 [2024-02-26T09:28:58.634] [debug] [qemu-img] [97603] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/impartial-tern/ubuntu-22.04-server-cloudimg-arm64.img [2024-02-26T09:28:58.644] [debug] [qemu-img] [97604] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/impartial-tern/ubuntu-22.04-server-cloudimg-arm64.img [2024-02-26T09:28:58.652] [debug] [impartial-tern] process working dir '' [2024-02-26T09:28:58.652] [info] [impartial-tern] process program 'qemu-system-aarch64' [2024-02-26T09:28:58.653] [info] [impartial-tern] process arguments '-machine, virt,gic-version=3, -accel, hvf, -drive, file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on, -cpu, host, -nic, vmnet-shared,model=virtio-net-pci,mac=52:54:00:1b:8b:a9, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/impartial-tern/ubuntu-22.04-server-cloudimg-arm64.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/impartial-tern/cloud-init-config.iso' [2024-02-26T09:28:58.655] [debug] [qemu-system-aarch64] [97605] started: qemu-system-aarch64 -machine virt,gic-version=3 -nographic -dump-vmstate /private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T/multipassd.xVEVlh [2024-02-26T09:28:58.697] [info] [impartial-tern] process state changed to Starting [2024-02-26T09:28:58.699] [info] [impartial-tern] process state changed to Running [2024-02-26T09:28:58.699] [debug] [qemu-system-aarch64] [97606] started: qemu-system-aarch64 -machine virt,gic-version=3 -accel hvf -drive file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on -cpu host -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:1b:8b:a9 -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/impartial-tern/ubuntu-22.04-server-cloudimg-arm64.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/impartial-tern/cloud-init-config.iso [2024-02-26T09:28:58.699] [info] [impartial-tern] process started Starting impartial-tern /

ricab commented 8 months ago

@yangletec did you get those with -vvvv on the command line? There are messages in the log that are not included in that. Those messages are important to determine which part of the start transition is failing. Also, the logs could have earlier clues as to why this started happening. In case you missed it, here are the instructions on how to get logs. And have you tried turning the firewall off?

yangletec commented 8 months ago

I have tried to disable the firewall, but the issue persists. Below is the log printed by the command 'multipass launch -n test2 -vvvv'. I hope this log can help you troubleshoot the problem.

multipass launch -n test2 -vvvv
[2024-02-27T09:51:09.940] [debug] [qemu-system-aarch64] [57878] started: qemu-system-aarch64 --version
[2024-02-27T09:51:10.352] [debug] [qemu-img] [57879] started: qemu-img info /var/root/Library/Caches/multipassd/qemu/vault/images/jammy-20240223/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-27T09:51:10.379] [debug] [qemu-img] [57880] started: qemu-img resize /var/root/Library/Application Support/multipassd/qemu/vault/instances/test2/ubuntu-22.04-server-cloudimg-arm64.img 5368709120
[2024-02-27T09:51:10.409] [debug] [qemu-img] [57881] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/test2/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-27T09:51:10.429] [debug] [qemu-img] [57882] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/test2/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-27T09:51:10.441] [debug] [test2] process working dir ''
[2024-02-27T09:51:10.441] [info] [test2] process program 'qemu-system-aarch64'
[2024-02-27T09:51:10.441] [info] [test2] process arguments '-machine, virt,gic-version=3, -accel, hvf, -drive, file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on, -cpu, host, -nic, vmnet-shared,model=virtio-net-pci,mac=52:54:00:f4:94:4a, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/test2/ubuntu-22.04-server-cloudimg-arm64.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/test2/cloud-init-config.iso'
[2024-02-27T09:51:10.444] [debug] [qemu-system-aarch64] [57883] started: qemu-system-aarch64 -machine virt,gic-version=3 -nographic -dump-vmstate /private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T/multipassd.qXmyGu
[2024-02-27T09:51:10.500] [info] [test2] process state changed to Starting
[2024-02-27T09:51:10.502] [info] [test2] process state changed to Running
[2024-02-27T09:51:10.502] [debug] [qemu-system-aarch64] [57884] started: qemu-system-aarch64 -machine virt,gic-version=3 -accel hvf -drive file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on -cpu host -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:f4:94:4a -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/test2/ubuntu-22.04-server-cloudimg-arm64.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/test2/cloud-init-config.iso
[2024-02-27T09:51:10.502] [info] [test2] process started
Starting test2 |
u1925 commented 8 months ago

Hello, I'm facing a similar issue (my intention is not to hijack this thread, just to add to it).

Last week an instance just stopped responding. (I'm running a web container and a database on the instance and I couldn't reach it.)

Hadn't done anything to the instance or the M2 Mac it's running on. Stopping the instance, multipass stop --all, didn't work. Ended up restarting the Mac but couldn't start the instance after reboot. Upgraded multipass from 1.13.0 to 1.13.1 hoping it would make a difference, but it didn't. The instance was in Suspended state. Tried deleting the suspended snapshot as described in other threads, that didn't make a difference either. Ran the qemu-img check command on it and that displays zero errors. At least after unloading/loading the multipass service I get the instance into Stopped state.

Launched a new instance and that one can be stopped and restarted, in bridged mode (the non-working instance is in bridged mode), no probs.

Looking at the output in the log, for the new instance that is working:

[2024-02-29T13:42:29.902] [debug] [test1] process working dir ''
[2024-02-29T13:42:29.903] [info] [test1] process program 'qemu-system-aarch64'
[2024-02-29T13:42:29.903] [info] [test1] process arguments '-machine, virt,gic-version=3, -accel, hvf, -drive, file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on, -cpu, host, -nic, vmnet-shared,model=virtio-net-pci,mac=52:54:00:a4:00:4c, -nic, vmnet-bridged,ifname=en1,model=virtio-net-pci,mac=52:54:00:4b:ab:cd, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/test1/ubuntu-22.04-server-cloudimg-arm64.img,if=none,format=qcow2,discard=unmap,id=hda, -device, scsi-hd,drive=hda,bus=scsi0.0, -smp, 2, -m, 4096M, -qmp, stdio, -chardev, null,id=char0, -serial, chardev:char0, -nographic, -cdrom, /var/root/Library/Application Support/multipassd/qemu/vault/instances/test1/cloud-init-config.iso'
[2024-02-29T13:42:29.910] [debug] [qemu-system-aarch64] [5281] started: qemu-system-aarch64 -machine virt,gic-version=3 -nographic -dump-vmstate /private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T/multipassd.LGszXF
[2024-02-29T13:42:29.971] [info] [test1] process state changed to Starting
[2024-02-29T13:42:29.972] [info] [test1] process state changed to Running
[2024-02-29T13:42:29.972] [debug] [qemu-system-aarch64] [5282] started: qemu-system-aarch64 -machine virt,gic-version=3 -accel hvf -drive file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on -cpu host -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:a4:00:4c -nic vmnet-bridged,ifname=en1,model=virtio-net-pci,mac=52:54:00:4b:ab:cd -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/test1/ubuntu-22.04-server-cloudimg-arm64.img,if=none,format=qcow2,discard=unmap,id=hda -device scsi-hd,drive=hda,bus=scsi0.0 -smp 2 -m 4096M -qmp stdio -chardev null,id=char0 -serial chardev:char0 -nographic -cdrom /var/root/Library/Application Support/multipassd/qemu/vault/instances/test1/cloud-init-config.iso
[2024-02-29T13:42:29.973] [info] [test1] process started
[2024-02-29T13:42:29.973] [debug] [test1] Waiting for SSH to be up
[2024-02-29T13:42:30.099] [debug] [test1] QMP: {"QMP": {"version": {"qemu": {"micro": 1, "minor": 2, "major": 8}, "package": ""}, "capabilities": ["oob"]}}

[2024-02-29T13:42:30.125] [debug] [test1] QMP: {"return": {}}

[2024-02-29T13:42:42.426] [debug] [test1] QMP: {"timestamp": {"seconds": 1709210562, "microseconds": 426660}, "event": "NIC_RX_FILTER_CHANGED", "data": {"path": "/machine/unattached/device[8]/virtio-backend"}}

[2024-02-29T13:42:42.427] [debug] [test1] QMP: {"timestamp": {"seconds": 1709210562, "microseconds": 427070}, "event": "NIC_RX_FILTER_CHANGED", "data": {"path": "/machine/unattached/device[7]/virtio-backend"}}

[2024-02-29T13:43:24.965] [debug] [test1] QMP: {"timestamp": {"seconds": 1709210604, "microseconds": 965457}, "event": "RTC_CHANGE", "data": {"offset": 1, "qom-path": "/machine/unattached/device[5]"}}

And for the failing instance:

[2024-02-29T13:43:39.027] [debug] [microk8s-vm] process working dir ''
[2024-02-29T13:43:39.028] [info] [microk8s-vm] process program 'qemu-system-aarch64'
[2024-02-29T13:43:39.028] [info] [microk8s-vm] process arguments '-machine, virt,gic-version=3, -accel, hvf, -drive, file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on, -cpu, host, -nic, vmnet-shared,model=virtio-net-pci,mac=52:54:00:51:39:11, -nic, vmnet-bridged,ifname=en1,model=virtio-net-pci,mac=52:54:00:86:ce:b0, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/microk8s-vm/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, 8192M, -qmp, stdio, -chardev, null,id=char0, -serial, chardev:char0, -nographic, -cdrom, /var/root/Library/Application Support/multipassd/qemu/vault/instances/microk8s-vm/cloud-init-config.iso'
[2024-02-29T13:43:39.036] [debug] [qemu-system-aarch64] [5287] started: qemu-system-aarch64 -machine virt,gic-version=3 -nographic -dump-vmstate /private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T/multipassd.nVvfMt
[2024-02-29T13:43:39.099] [info] [microk8s-vm] process state changed to Starting
[2024-02-29T13:43:39.101] [info] [microk8s-vm] process state changed to Running
[2024-02-29T13:43:39.101] [debug] [qemu-system-aarch64] [5288] started: qemu-system-aarch64 -machine virt,gic-version=3 -accel hvf -drive file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on -cpu host -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:51:39:11 -nic vmnet-bridged,ifname=en1,model=virtio-net-pci,mac=52:54:00:86:ce:b0 -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/microk8s-vm/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 8192M -qmp stdio -chardev null,id=char0 -serial chardev:char0 -nographic -cdrom /var/root/Library/Application Support/multipassd/qemu/vault/instances/microk8s-vm/cloud-init-config.iso
[2024-02-29T13:43:39.101] [info] [microk8s-vm] process started
[2024-02-29T13:43:39.101] [debug] [microk8s-vm] Waiting for SSH to be up
[2024-02-29T13:43:39.247] [debug] [microk8s-vm] QMP: {"QMP": {"version": {"qemu": {"micro": 1, "minor": 2, "major": 8}, "package": ""}, "capabilities": ["oob"]}}

[2024-02-29T13:43:39.276] [debug] [microk8s-vm] QMP: {"return": {}}

So, looks to me like it's not reaching the part where it should say NIC_RX_FILTER_CHANGED etc. But why? Looked at the page describing common networking problems, firewall is disabled, restarted the Mac multiple times. No luck.

Usually I wouldn't be concerned, but there's data in the DB that I haven't made a backup of in a couple of weeks that I would really want to salvage.

If I change the log level to trace I get a lot of output saying verifying certificate, with some complaints, not sure if they are related though:

[2024-03-01T09:49:06.266] [trace] [microk8s-vm] ssh connection failed: 'Timeout connecting to 192.168.64.4'
[2024-03-01T09:49:06.703] [trace] [client cert store] Verifying cert:
-----BEGIN CERTIFICATE-----
MIIBizCCATECBBh+fDcwCgYIKoZIzj0EAwIwUDELMAkGA1UEBhMCVVMxEjAQBgNV
BAoMCUNhbm9uaWNhbDEtMCsGA1UEAwwkYjNmOTcwNDQtM2QyZC00MWMwLWE5ODQt
ZDIwNzJjZTE1MzdjMB4XDTIzMTIyMTE3MjY1N1oXDTI0MTIyMDE3MjY1N1owUDEL
MAkGA1UEBhMCVVMxEjAQBgNVBAoMCUNhbm9uaWNhbDEtMCsGA1UEAwwkYjNmOTcw
NDQtM2QyZC00MWMwLWE5ODQtZDIwNzJjZTE1MzdjMFkwEwYHKoZIzj0CAQYIKoZI
zj0DAQcDQgAEyCGR9+LPePYFZBw/wWYBXTEy3j/j+5NtdMznTr7IY43Lyw6ZkLXw
7S4tnQ9/AJhgNoDpCo9X8fLVl8fsgCWNeDAKBggqhkjOPQQDAgNIADBFAiAxhs1a
7Sx6pmRihJNGCzI0yG88JMGgkksCPDYTm0JT/gIhAPMl21LkdNwnwT7s37/8yw5h
n9us4OFoXdbvXgermE5Q
-----END CERTIFICATE-----
ricab commented 8 months ago

Hi @u1925, sorry you're missing that data. The absence of that NIC_RX_FILTER_CHANGED indicates that the instance is not being able to complete the boot, at least not up to the point where it can connect. Mulitpass thinks it has an IP (as per the first trace msg), but I believe that's from an earlier lease (which may have conflicted and prevented the instance from acquiring an IP when it started failing).

Could you please try the following command to run the instance manually, after making sure that it is not being run by Multipass (i.e. no analogous qemu-system-aarch64 process for this instance running - kill it if necessary)? sudo /Library/Application\ Support/com.canonical.multipass/bin/qemu-system-aarch64 -machine virt,gic-version=3 -accel hvf -drive file=/Library/Application\ Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on -cpu host -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:51:39:11 -nic vmnet-bridged,ifname=en1,model=virtio-net-pci,mac=52:54:00:86:ce:b0 -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application\ Support/multipassd/qemu/vault/instances/microk8s-vm/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 8192M -qmp stdio -cdrom /var/root/Library/Application\ Support/multipassd/qemu/vault/instances/microk8s-vm/cloud-init-config.iso.

You should see a window popping up. What does it say? And if you select VGA/serial/parallel in menu->view?

u1925 commented 8 months ago

@ricab Thanks for such a quick reply.

When doing a ps -ax | grep qemu I could see that although the instance appeared to be Stopped when doing multipass list, there was a PID available, which I killed.

I ran the command you suggested, wasn't able to catch all output, it just went by quickly. But took a screenshot after it stopped printing to the console.

initial-terminal-window

Other screenshot is from View -> parallel0, I only had that and serial0 to select from.

after-view-parallel0

ricab commented 8 months ago

Hi @u1925, I think that indicates that QEMU can't mount the filesystem, as that's the next thing that happens in a normally functioning instance. Here's a very similar case.

To be sure, can you confirm that the QEMU screen remains in that state after 2 or 3 minutes? Sometimes a service takes a long time to start and that blocks the boot procedure until systemd decides to time out that service and move on.

The last option would be to try to mount the image to recover data. Here are some instructions that you can try.

ricab commented 8 months ago

Also, I don't suppose you took a snapshot of the instance while it was working?

u1925 commented 8 months ago

Hi @ricab Yes, the QEMU screen remains in that state for hours on, nothing more happens. I didn't take any snapshots unfortunately. I suppose I will try mounting it in a new instance next, and if that doesn't help me in the end, I'll begin trying to recreate the lost data somehow. Thanks for your help so far!

ricab commented 8 months ago

OK, thanks for letting me know @u1925. Sorry again for your situation, I hope you can recover somehow.

townsend2010 commented 8 months ago

@yangletec,

Did you disable the firewall and reboot? I have seen cases where just disabling the firewall and trying to start an instance does not work until a reboot.

balboah commented 6 months ago

Same started happening for me as well, possibly after an update of multipass (1.13.1 now). Tried the firewall tricks that helped previously when I had similar issues (firewall is now off), does not help this time.

Was able to multipass launch a new instance with defaults, but are unable to multipass start the previously existing ones. QEMU processes are running, but multipass says:

[2024-05-14T13:25:41.259] [info] [test-k8s-1] process state changed to Starting
[2024-05-14T13:25:41.261] [info] [test-k8s-1] process state changed to Running
[2024-05-14T13:25:41.261] [debug] [qemu-system-aarch64] [1032] started: qemu-system-aarch64 -machine virt,gic-version=3 -accel hvf -drive file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on -cpu host -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:1b:63:99 -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/test-k8s-1/ubuntu-22.04-server-cloudimg-arm64.img,if=none,format=qcow2,discard=unmap,id=hda -device scsi-hd,drive=hda,bus=scsi0.0 -smp 2 -m 4096M -qmp stdio -chardev null,id=char0 -serial chardev:char0 -nographic -cdrom /var/root/Library/Application Support/multipassd/qemu/vault/instances/test-k8s-1/cloud-init-config.iso
[2024-05-14T13:25:41.261] [info] [test-k8s-1] process started
start failed: The following errors occurred:
test-k8s-1: timed out waiting for response
balboah commented 6 months ago

After toggling the firewall back to on I could no longer launch new instances either, once more I got it working after /usr/libexec/ApplicationFirewall/socketfilterfw --unblock /usr/libexec/bootpd. Seems a bit flaky.

Not sure what happened to the old instances tho, deleted those.

update Actually no, suddenly all multipass commands stops working. Can't list, launch or anything else. I'll be debugging some more in a few days.

balboah commented 6 months ago

Seems that for me it was a combination of issues. Mac firewall was one, but also the mac host ip changed from 192.168.64.1 to 192.168.65.1 which broke some firewall rules on the instances themselves, thus couldn't access them but still launch new ones.

iRON5 commented 1 month ago

Hi @yangletec, does this happen only with one instance or with any instance? Does multipass launch work?

We'd need logs to investigate, but this is often a networking problem (the instance doesn't get an IP, which is necessary to complete the start transition). Could you please try to follow our troubleshooting docs and let us know if that it helps?

In my case the issue was caused by VPN. Just turned it off and everything started working well. Thanks!

fat-man-forever commented 3 weeks ago

by reinstall multipass I fixed the problem

  1. brew install multipass
  2. delete the instances
  3. launch a new instance multipass launch 22.04 --name <myname> --cpus 4 --memory 4G --disk 50G -vvvv

it works

libert-xyz commented 2 weeks ago

Same issue. Same OS Same multipass version.

Enabled this https://github.com/canonical/multipass/issues/3411#issuecomment-1961300306 and turn firewall off

Logs

multipass launch -vvvv 24.04

[2024-10-29T15:15:48.801] [debug] [qemu-system-aarch64] [87444] started: qemu-system-aarch64 --version
[2024-10-29T15:15:48.839] [debug] [qemu-img] [87445] started: qemu-img info /var/root/Library/Caches/multipassd/qemu/vault/images/noble-20241004/ubuntu-24.04-server-cloudimg-arm64.img
[2024-10-29T15:15:48.865] [debug] [qemu-img] [87446] started: qemu-img resize /var/root/Library/Application Support/multipassd/qemu/vault/instances/momentous-puffin/ubuntu-24.04-server-cloudimg-arm64.img 5368709120
[2024-10-29T15:15:48.890] [debug] [qemu-img] [87447] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/momentous-puffin/ubuntu-24.04-server-cloudimg-arm64.img
[2024-10-29T15:15:48.900] [debug] [qemu-img] [87448] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/momentous-puffin/ubuntu-24.04-server-cloudimg-arm64.img
[2024-10-29T15:15:48.907] [debug] [momentous-puffin] process working dir ''
[2024-10-29T15:15:48.907] [info] [momentous-puffin] process program 'qemu-system-aarch64'
[2024-10-29T15:15:48.907] [info] [momentous-puffin] process arguments '-machine, virt,gic-version=3, -accel, hvf, -drive, file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on, -cpu, host, -nic, vmnet-shared,model=virtio-net-pci,mac=52:54:00:ac:0a:cb, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/momentous-puffin/ubuntu-24.04-server-cloudimg-arm64.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/momentous-puffin/cloud-init-config.iso'
[2024-10-29T15:15:48.910] [debug] [qemu-system-aarch64] [87449] started: qemu-system-aarch64 -machine virt,gic-version=3 -nographic -dump-vmstate /private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T/multipassd.WBFurh
[2024-10-29T15:15:48.946] [info] [momentous-puffin] process state changed to Starting
[2024-10-29T15:15:48.948] [info] [momentous-puffin] process state changed to Running
[2024-10-29T15:15:48.948] [debug] [qemu-system-aarch64] [87450] started: qemu-system-aarch64 -machine virt,gic-version=3 -accel hvf -drive file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on -cpu host -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:ac:0a:cb -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/momentous-puffin/ubuntu-24.04-server-cloudimg-arm64.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/momentous-puffin/cloud-init-config.iso
[2024-10-29T15:15:48.948] [info] [momentous-puffin] process started
launch failed: The following errors occurred:
momentous-puffin: timed out waiting for response
ricab commented 2 weeks ago

@libert-xyz, could you please try https://github.com/canonical/multipass/releases/tag/v1.14.1 ?

libert-xyz commented 2 weeks ago

@ricab yes, that solved the problem!

> multipass --version
multipass   1.14.1+mac
multipassd  1.14.1+mac
> multipass list
Name                    State             IPv4             Image
in-anchovy              Running           192.168.64.16    Ubuntu 24.04 LTS

Thanks for the help