Firewall randomly messing with Multipass networking on macOS #2387
Description
Update: If you are using an unmanaged Mac and run across this issue, the following commands may fix this issue:
/usr/libexec/ApplicationFirewall/socketfilterfw --add /usr/libexec/bootpd
/usr/libexec/ApplicationFirewall/socketfilterfw --unblock /usr/libexec/bootpd
Original post
Multipass crashes unexpectedly, and all instances (including primary) will not restart. I am using multipass 1.8.1+mac,
multipassd 1.8.1+mac. (multipass --version), on macOS Monterey 12.1, M1 Max, 32 GB RAM. I installed multipass for macOS directly from Canonical's website.
start failed: The following errors occurred:
dbarn: timed out waiting for response
This has happened twice. The first time I uninstalled multipass, reinstalled, and re-built my instances thinking it was a fluke. Multipass performed fine for roughly a week, then crashed again and I lost some work. I am not able to determine what the cause is, or how to reproduce it. System restarts do not help. I'm hoping someone can spot the issue in the logs.
Logs here:
[2022-01-04T13:30:56.044] [warning] [qemu-system-aarch64]
[2022-01-04T13:30:56.044] [debug] [dbarn] QMP: {"QMP": {"version": {"qemu": {"micro": 0, "minor": 1, "major": 6}, "package": ""}, "capabilities": ["oob"]}}
[2022-01-04T13:30:56.062] [debug] [dbarn] QMP: {"return": {}}
[2022-01-04T13:31:08.663] [debug] [dbarn] QMP: {"timestamp": {"seconds": 1641321068, "microseconds": 663550}, "event": "NIC_RX_FILTER_CHANGED", "data": {"path": "/machine/unattached/device[7]/virtio-backend"}}
[2022-01-04T13:36:37.352] [debug] [dbarn] process working dir ''
[2022-01-04T13:36:37.353] [info] [dbarn] process program 'qemu-system-aarch64'
[2022-01-04T13:36:37.353] [info] [dbarn] 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, -nic, vmnet-macos,mode=shared,model=virtio-net-pci,mac=52:54:00:11:ff:d3, -cpu, cortex-a72, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/dbarn/ubuntu-20.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/dbarn/cloud-init-config.iso'
[2022-01-04T13:36:37.353] [warning] [Qt] QProcess: Destroyed while process ("qemu-system-aarch64") is still running.
[2022-01-04T13:36:37.370] [error] [dbarn] process error occurred Crashed program: qemu-system-aarch64; error: Process crashed
[2022-01-04T13:36:37.371] [info] [dbarn] process state changed to NotRunning
[2022-01-04T13:36:37.371] [error] [dbarn] error: program: qemu-system-aarch64; error: Process crashed
[2022-01-04T13:36:37.372] [warning] [Qt] QObject::connect(multipass::Process, Unknown): invalid nullptr parameter
[2022-01-04T13:36:37.372] [warning] [Qt] QObject::connect(multipass::Process, Unknown): invalid nullptr parameter
[2022-01-04T13:36:37.372] [warning] [Qt] QObject::connect(multipass::Process, Unknown): invalid nullptr parameter
[2022-01-04T13:36:37.372] [warning] [Qt] QObject::connect(multipass::Process, Unknown): invalid nullptr parameter
[2022-01-04T13:36:37.372] [warning] [Qt] QObject::connect(multipass::Process, Unknown): invalid nullptr parameter
[2022-01-04T13:36:37.372] [warning] [Qt] QObject::connect(multipass::Process, Unknown): invalid nullptr parameter
[2022-01-04T13:36:38.572] [debug] [update] Latest Multipass release available is version 1.8.0
[2022-01-04T13:36:40.666] [info] [VMImageHost] Did not find any supported products in "appliance"
[2022-01-04T13:36:40.671] [info] [rpc] gRPC listening on unix:/var/run/multipass_socket, SSL:on
[2022-01-04T13:36:40.673] [debug] [qemu-img] [1300] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/tractorgeeks/ubuntu-20.04-server-cloudimg-arm64.img
[2022-01-04T13:36:40.677] [debug] [qemu-img] [1301] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-20.04-server-cloudimg-arm64.img
[2022-01-04T13:36:40.681] [debug] [qemu-img] [1302] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/dbarn/ubuntu-20.04-server-cloudimg-arm64.img
[2022-01-04T13:36:40.686] [info] [daemon] Starting Multipass 1.8.1+mac
[2022-01-04T13:36:40.686] [info] [daemon] Daemon arguments: /Library/Application Support/com.canonical.multipass/bin/multipassd --verbosity debug
[2022-01-04T13:43:16.997] [debug] [dbarn] process working dir ''
[2022-01-04T13:43:16.998] [info] [dbarn] process program 'qemu-system-aarch64'
[2022-01-04T13:43:16.998] [info] [dbarn] 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, -nic, vmnet-macos,mode=shared,model=virtio-net-pci,mac=52:54:00:11:ff:d3, -cpu, cortex-a72, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/dbarn/ubuntu-20.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/dbarn/cloud-init-config.iso'
[2022-01-04T13:43:17.004] [debug] [qemu-system-aarch64] [1384] started: qemu-system-aarch64 -machine virt,highmem=off -nographic -dump-vmstate /private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T/multipassd.pRWjeY
[2022-01-04T13:43:17.061] [info] [dbarn] process state changed to Starting
[2022-01-04T13:43:17.063] [info] [dbarn] process state changed to Running
[2022-01-04T13:43:17.063] [debug] [qemu-system-aarch64] [1385] 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 -nic vmnet-macos,mode=shared,model=virtio-net-pci,mac=52:54:00:11:ff:d3 -cpu cortex-a72 -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/dbarn/ubuntu-20.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/dbarn/cloud-init-config.iso
[2022-01-04T13:43:17.063] [info] [dbarn] process started
[2022-01-04T13:43:17.063] [debug] [dbarn] Waiting for SSH to be up
[2022-01-04T13:43:17.347] [warning] [dbarn] qemu-system-aarch64: -nic vmnet-macos,mode=shared,model=virtio-net-pci,mac=52:54:00:11:ff:d3: info: Started vmnet interface with configuration:
qemu-system-aarch64: -nic vmnet-macos,mode=shared,model=virtio-net-pci,mac=52:54:00:11:ff:d3: info: MTU: 1500
qemu-system-aarch64: -nic vmnet-macos,mode=shared,model=virtio-net-pci,mac=52:54:00:11:ff:d3: info: Max packet size: 1514
qemu-system-aarch64: -nic vmnet-macos,mode=shared,model=virtio-net-pci,mac=52:54:00:11:ff:d3: info: MAC: de:e5:9b:47:58:c4
qemu-system-aarch64: -nic vmnet-macos,mode=shared,model=virtio-net-pci,mac=52:54:00:11:ff:d3: info: DHCP IPv4 start: 192.168.64.1
qemu-system-aarch64: -nic vmnet-macos,mode=shared,model=virtio-net-pci,mac=52:54:00:11:ff:d3: info: DHCP IPv4 end: 192.168.64.254
qemu-system-aarch64: -nic vmnet-macos,mode=shared,model=virtio-net-pci,mac=52:54:00:11:ff:d3: info: IPv4 subnet mask: 255.255.255.0
qemu-system-aarch64: -nic vmnet-macos,mode=shared,model=virtio-net-pci,mac=52:54:00:11:ff:d3: info: UUID: 9736AE0D-0FAE-4223-847E-517E35533FEA
[2022-01-04T13:43:17.348] [warning] [qemu-system-aarch64]
[2022-01-04T13:43:17.351] [debug] [dbarn] QMP: {"QMP": {"version": {"qemu": {"micro": 0, "minor": 1, "major": 6}, "package": ""}, "capabilities": ["oob"]}}
[2022-01-04T13:43:17.399] [debug] [dbarn] QMP: {"return": {}}
[2022-01-04T13:43:29.746] [debug] [dbarn] QMP: {"timestamp": {"seconds": 1641321809, "microseconds": 746100}, "event": "NIC_RX_FILTER_CHANGED", "data": {"path": "/machine/unattached/device[7]/virtio-backend"}}