Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
yangletec opened this issue Feb 22, 2024 · 21 comments
Open
Labels

Comments

@yangletec
Copy link

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

  • OS: [macOS 14.3.1 (23D60)]
  • multipass 1.13.1+mac、multipassd 1.13.1+mac
  • multipass info --all
  • multipass get local.driver: qemu

Additional context
Add any other context about the problem here.

@yangletec yangletec added bug needs triage Issue needs to be triaged labels Feb 22, 2024
@ricab
Copy link
Collaborator

ricab commented Feb 22, 2024

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
Copy link
Author

yangletec commented Feb 23, 2024

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
Copy link
Collaborator

ricab commented Feb 23, 2024

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
Copy link

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
Copy link
Collaborator

ricab commented Feb 23, 2024

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
Copy link

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 #2387 (comment) 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
Copy link
Collaborator

ricab commented Feb 23, 2024

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

@yangletec
Copy link
Author

[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
Copy link
Collaborator

ricab commented Feb 26, 2024

@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
Copy link
Author

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
Copy link

u1925 commented Mar 1, 2024

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
Copy link
Collaborator

ricab commented Mar 1, 2024

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
Copy link

u1925 commented Mar 1, 2024

@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
Copy link
Collaborator

ricab commented Mar 1, 2024

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
Copy link
Collaborator

ricab commented Mar 1, 2024

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

@u1925
Copy link

u1925 commented Mar 2, 2024

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
Copy link
Collaborator

ricab commented Mar 4, 2024

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

@townsend2010 townsend2010 removed the needs triage Issue needs to be triaged label Mar 18, 2024
@townsend2010
Copy link
Collaborator

@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
Copy link

balboah commented May 14, 2024

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
Copy link

balboah commented May 14, 2024

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
Copy link

balboah commented May 16, 2024

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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

6 participants