Multipass error while following Go Applications tutorial

Getting the following error while running the commands from the Go Applications tutorial:

$ snapcraft
Support for 'multipass' needs to be set up. Would you like to do it now? [y/N]: y
snapd is not logged in, snap install commands will use sudo
[sudo] password for wheeler: 
multipass 1.9.2 from Canonical✓ installed
Waiting for multipass...
Launching a VM.
launch failed: The following errors occurred:                                   
snapcraft-woke: timed out waiting for response
An error occurred with the instance when trying to launch with 'multipass': returned exit code 2.
Ensure that 'multipass' is setup correctly and try again.

Commands run:

git clone https://github.com/degville/woke-snap
cd woke-snap
snapcraft

Logs (sudo snap logs multipass):

2022-06-16T10:09:29-05:00 multipassd[388194]: process state changed to Running
2022-06-16T10:09:29-05:00 multipassd[388194]: [391454] started: qemu-system-x86_64 --enable-kvm -cpu host -nic tap,ifname=tap-5039d875ebb,script=no,downscript=no,model=virtio-net-pci,mac=52:54:00:65:60:76 -device virtio-scsi-pci,id=scsi0 -drive file=/var/snap/multipass/common/data/multipassd/vault/instances/snapcraft-woke/focal-server-cloudimg-amd64-disk.img,if=none,format=qcow2,discard=unmap,id=hda -device scsi-hd,drive=hda,bus=scsi0.0 -smp 2 -m 2048M -qmp stdio -chardev null,id=char0 -serial chardev:char0 -nographic -cdrom /var/snap/multipass/common/data/multipassd/vault/instances/snapcraft-woke/cloud-init-config.iso
2022-06-16T10:09:29-05:00 multipassd[388194]: process started
2022-06-16T10:09:29-05:00 multipassd[388194]: Waiting for SSH to be up
2022-06-16T10:09:29-05:00 multipassd[388194]: QMP: {"QMP": {"version": {"qemu": {"micro": 1, "minor": 2, "major": 4}, "package": "Debian 1:4.2-3ubuntu6.21"}, "capabilities": ["oob"]}}
2022-06-16T10:09:29-05:00 multipassd[388194]: QMP: {"return": {}}
2022-06-16T10:09:30-05:00 multipassd[388194]: QMP: {"timestamp": {"seconds": 1655392170, "microseconds": 979250}, "event": "RESET", "data": {"guest": true, "reason": "guest-reset"}}
2022-06-16T10:09:30-05:00 multipassd[388194]: VM restarting
2022-06-16T10:09:30-05:00 multipassd[388194]: QMP: {"timestamp": {"seconds": 1655392170, "microseconds": 981097}, "event": "RESET", "data": {"guest": true, "reason": "guest-reset"}}
2022-06-16T10:09:34-05:00 multipassd[388194]: QMP: {"timestamp": {"seconds": 1655392174, "microseconds": 470482}, "event": "NIC_RX_FILTER_CHANGED", "data": {"path": "/machine/unattached/device[23]/virtio-backend"}}

Also gave --use-lxd a try, but that is also broken:

$ snapcraft --use-lxd
Support for 'LXD' needs to be set up. Would you like to do it now? [y/N]: y
snapd is not logged in, snap install commands will use sudo
[sudo] password for wheeler: 
lxd 5.2-79c3c3b from Canonical✓ installed
Error: LXD still not running after 30s timeout (Get "http://unix.socket/1.0": dial unix /var/snap/lxd/common/lxd/unix.socket: connect: permission denied)
Timeout reached waiting for LXD to start.

Running on Fedora 36.

Any help would be appreciated.

I peeked at the multipassd service logs, and I found some interesting results:

$ journalctl -u snap.multipass.multipassd.service --no-pager -n 59
Jun 16 10:35:35 fedora systemd[1]: Started snap.multipass.multipassd.service - Service for snap application multipass.multipassd.
Jun 16 10:35:35 fedora multipassd[398571]: Using AppArmor support
Jun 16 10:35:35 fedora multipassd[398571]: Failed to enable AppArmor: AppArmor is not enabled
Jun 16 10:35:35 fedora multipassd[398571]: Starting dnsmasq
Jun 16 10:35:35 fedora multipassd[398571]: [398665] started: dnsmasq --keep-in-foreground --strict-order --bind-interfaces --pid-file --domain=multipass --local=/multipass/ --except-interface=lo --interface=mpqemubr0 --listen-address=10.197.83.1 --dhcp-no-override --dhcp-authoritative --dhcp-leasefile=/var/snap/multipass/common/data/multipassd/network/dnsmasq.leases --dhcp-hostsfile=/var/snap/multipass/common/data/multipassd/network/dnsmasq.hosts --dhcp-range 10.197.83.2,10.197.83.254,infinite --conf-file=/var/snap/multipass/common/data/multipassd/network/dnsmasq-tAVljE.conf
Jun 16 10:35:35 fedora dnsmasq[398665]: started, version 2.80 cachesize 150
Jun 16 10:35:35 fedora dnsmasq[398665]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth nettlehash DNSSEC loop-detect inotify dumpfile
Jun 16 10:35:35 fedora dnsmasq-dhcp[398665]: DHCP, IP range 10.197.83.2 -- 10.197.83.254, lease time infinite
Jun 16 10:35:35 fedora dnsmasq-dhcp[398665]: DHCP, sockets bound exclusively to interface mpqemubr0
Jun 16 10:35:35 fedora dnsmasq[398665]: using local addresses only for domain multipass
Jun 16 10:35:35 fedora dnsmasq[398665]: reading /etc/resolv.conf
Jun 16 10:35:35 fedora dnsmasq[398665]: using local addresses only for domain multipass
Jun 16 10:35:35 fedora dnsmasq[398665]: using nameserver 127.0.0.53#53
Jun 16 10:35:35 fedora dnsmasq[398665]: read /etc/hosts - 2 addresses
Jun 16 10:35:35 fedora dnsmasq-dhcp[398665]: read /var/snap/multipass/common/data/multipassd/network/dnsmasq.hosts
Jun 16 10:35:35 fedora multipassd[398571]: Cannot parse kernel version '5.18.1-602.inttf.fc36.x86_64'
Jun 16 10:35:35 fedora multipassd[398571]: Using iptables-legacy for firewall rules.
Jun 16 10:35:35 fedora multipassd[398571]: [398666] started: iptables-legacy --wait -t filter --list-rules
Jun 16 10:35:35 fedora multipassd[398571]: [398667] started: sh -c iptables-legacy --wait -t filter --delete INPUT -i mpqemubr0 -p tcp -m tcp --dport 53 -m comment --comment "generated for Multipass network mpqemubr0" -j ACCEPT
Jun 16 10:35:35 fedora multipassd[398571]: [398669] started: sh -c iptables-legacy --wait -t filter --delete INPUT -i mpqemubr0 -p udp -m udp --dport 53 -m comment --comment "generated for Multipass network mpqemubr0" -j ACCEPT
Jun 16 10:35:35 fedora multipassd[398571]: [398671] started: sh -c iptables-legacy --wait -t filter --delete INPUT -i mpqemubr0 -p udp -m udp --dport 67 -m comment --comment "generated for Multipass network mpqemubr0" -j ACCEPT
Jun 16 10:35:35 fedora multipassd[398571]: [398673] started: sh -c iptables-legacy --wait -t filter --delete FORWARD -i mpqemubr0 -o mpqemubr0 -m comment --comment "generated for Multipass network mpqemubr0" -j ACCEPT
Jun 16 10:35:35 fedora multipassd[398571]: [398675] started: sh -c iptables-legacy --wait -t filter --delete FORWARD -s 10.197.83.0/24 -i mpqemubr0 -m comment --comment "generated for Multipass network mpqemubr0" -j ACCEPT
Jun 16 10:35:35 fedora multipassd[398571]: [398677] started: sh -c iptables-legacy --wait -t filter --delete FORWARD -d 10.197.83.0/24 -o mpqemubr0 -m conntrack --ctstate RELATED,ESTABLISHED -m comment --comment "generated for Multipass network mpqemubr0" -j ACCEPT
Jun 16 10:35:35 fedora multipassd[398571]: [398679] started: sh -c iptables-legacy --wait -t filter --delete FORWARD -i mpqemubr0 -m comment --comment "generated for Multipass network mpqemubr0" -j REJECT --reject-with icmp-port-unreachable
Jun 16 10:35:35 fedora multipassd[398571]: [398681] started: sh -c iptables-legacy --wait -t filter --delete FORWARD -o mpqemubr0 -m comment --comment "generated for Multipass network mpqemubr0" -j REJECT --reject-with icmp-port-unreachable
Jun 16 10:35:35 fedora multipassd[398571]: [398683] started: sh -c iptables-legacy --wait -t filter --delete OUTPUT -o mpqemubr0 -p tcp -m tcp --sport 53 -m comment --comment "generated for Multipass network mpqemubr0" -j ACCEPT
Jun 16 10:35:35 fedora multipassd[398571]: [398685] started: sh -c iptables-legacy --wait -t filter --delete OUTPUT -o mpqemubr0 -p udp -m udp --sport 53 -m comment --comment "generated for Multipass network mpqemubr0" -j ACCEPT
Jun 16 10:35:35 fedora multipassd[398571]: [398687] started: sh -c iptables-legacy --wait -t filter --delete OUTPUT -o mpqemubr0 -p udp -m udp --sport 67 -m comment --comment "generated for Multipass network mpqemubr0" -j ACCEPT
Jun 16 10:35:35 fedora multipassd[398571]: [398689] started: iptables-legacy --wait -t nat --list-rules
Jun 16 10:35:35 fedora multipassd[398571]: [398690] started: sh -c iptables-legacy --wait -t nat --delete POSTROUTING -s 10.197.83.0/24 ! -d 10.197.83.0/24 -m comment --comment "generated for Multipass network mpqemubr0" -j MASQUERADE
Jun 16 10:35:35 fedora multipassd[398571]: [398692] started: sh -c iptables-legacy --wait -t nat --delete POSTROUTING -s 10.197.83.0/24 ! -d 10.197.83.0/24 -p udp -m comment --comment "generated for Multipass network mpqemubr0" -j MASQUERADE --to-ports 1024-65535
Jun 16 10:35:35 fedora multipassd[398571]: [398694] started: sh -c iptables-legacy --wait -t nat --delete POSTROUTING -s 10.197.83.0/24 ! -d 10.197.83.0/24 -p tcp -m comment --comment "generated for Multipass network mpqemubr0" -j MASQUERADE --to-ports 1024-65535
Jun 16 10:35:35 fedora multipassd[398571]: [398696] started: sh -c iptables-legacy --wait -t nat --delete POSTROUTING -s 10.197.83.0/24 -d 255.255.255.255/32 -m comment --comment "generated for Multipass network mpqemubr0" -j RETURN
Jun 16 10:35:35 fedora multipassd[398571]: [398698] started: sh -c iptables-legacy --wait -t nat --delete POSTROUTING -s 10.197.83.0/24 -d 224.0.0.0/24 -m comment --comment "generated for Multipass network mpqemubr0" -j RETURN
Jun 16 10:35:35 fedora multipassd[398571]: [398700] started: iptables-legacy --wait -t mangle --list-rules
Jun 16 10:35:35 fedora multipassd[398571]: [398701] started: sh -c iptables-legacy --wait -t mangle --delete POSTROUTING -o mpqemubr0 -p udp -m udp --dport 68 -m comment --comment "generated for Multipass network mpqemubr0" -j CHECKSUM --checksum-fill
Jun 16 10:35:35 fedora multipassd[398571]: [398703] started: iptables-legacy --wait -t raw --list-rules
Jun 16 10:35:35 fedora multipassd[398571]: [398704] started: iptables-legacy --wait -t filter --insert INPUT --in-interface mpqemubr0 --protocol udp --dport 67 --jump ACCEPT --match comment --comment generated for Multipass network mpqemubr0
Jun 16 10:35:35 fedora multipassd[398571]: [398705] started: iptables-legacy --wait -t filter --insert INPUT --in-interface mpqemubr0 --protocol udp --dport 53 --jump ACCEPT --match comment --comment generated for Multipass network mpqemubr0
Jun 16 10:35:35 fedora multipassd[398571]: [398706] started: iptables-legacy --wait -t filter --insert INPUT --in-interface mpqemubr0 --protocol tcp --dport 53 --jump ACCEPT --match comment --comment generated for Multipass network mpqemubr0
Jun 16 10:35:35 fedora multipassd[398571]: [398707] started: iptables-legacy --wait -t filter --insert OUTPUT --out-interface mpqemubr0 --protocol udp --sport 67 --jump ACCEPT --match comment --comment generated for Multipass network mpqemubr0
Jun 16 10:35:35 fedora multipassd[398571]: [398708] started: iptables-legacy --wait -t filter --insert OUTPUT --out-interface mpqemubr0 --protocol udp --sport 53 --jump ACCEPT --match comment --comment generated for Multipass network mpqemubr0
Jun 16 10:35:35 fedora multipassd[398571]: [398709] started: iptables-legacy --wait -t filter --insert OUTPUT --out-interface mpqemubr0 --protocol tcp --sport 53 --jump ACCEPT --match comment --comment generated for Multipass network mpqemubr0
Jun 16 10:35:35 fedora multipassd[398571]: [398710] started: iptables-legacy --wait -t mangle --insert POSTROUTING --out-interface mpqemubr0 --protocol udp --dport 68 --jump CHECKSUM --checksum-fill --match comment --comment generated for Multipass network mpqemubr0
Jun 16 10:35:35 fedora multipassd[398571]: [398711] started: iptables-legacy --wait -t nat --insert POSTROUTING --source 10.197.83.0/24 --destination 224.0.0.0/24 --jump RETURN --match comment --comment generated for Multipass network mpqemubr0
Jun 16 10:35:35 fedora multipassd[398571]: [398712] started: iptables-legacy --wait -t nat --insert POSTROUTING --source 10.197.83.0/24 --destination 255.255.255.255/32 --jump RETURN --match comment --comment generated for Multipass network mpqemubr0
Jun 16 10:35:35 fedora multipassd[398571]: [398713] started: iptables-legacy --wait -t nat --insert POSTROUTING --source 10.197.83.0/24 ! --destination 10.197.83.0/24 --protocol tcp --jump MASQUERADE --to-ports 1024-65535 --match comment --comment generated for Multipass network mpqemubr0
Jun 16 10:35:35 fedora multipassd[398571]: [398714] started: iptables-legacy --wait -t nat --insert POSTROUTING --source 10.197.83.0/24 ! --destination 10.197.83.0/24 --protocol udp --jump MASQUERADE --to-ports 1024-65535 --match comment --comment generated for Multipass network mpqemubr0
Jun 16 10:35:35 fedora multipassd[398571]: [398715] started: iptables-legacy --wait -t nat --insert POSTROUTING --source 10.197.83.0/24 ! --destination 10.197.83.0/24 --jump MASQUERADE --match comment --comment generated for Multipass network mpqemubr0
Jun 16 10:35:35 fedora multipassd[398571]: [398716] started: iptables-legacy --wait -t filter --insert FORWARD --destination 10.197.83.0/24 --out-interface mpqemubr0 --match conntrack --ctstate RELATED,ESTABLISHED --jump ACCEPT --match comment --comment generated for Multipass network mpqemubr0
Jun 16 10:35:35 fedora multipassd[398571]: [398717] started: iptables-legacy --wait -t filter --insert FORWARD --source 10.197.83.0/24 --in-interface mpqemubr0 --jump ACCEPT --match comment --comment generated for Multipass network mpqemubr0
Jun 16 10:35:35 fedora multipassd[398571]: [398718] started: iptables-legacy --wait -t filter --insert FORWARD --in-interface mpqemubr0 --out-interface mpqemubr0 --jump ACCEPT --match comment --comment generated for Multipass network mpqemubr0
Jun 16 10:35:35 fedora multipassd[398571]: [398719] started: iptables-legacy --wait -t filter --append FORWARD --in-interface mpqemubr0 --jump REJECT --reject-with icmp-port-unreachable --match comment --comment generated for Multipass network mpqemubr0
Jun 16 10:35:35 fedora multipassd[398571]: [398720] started: iptables-legacy --wait -t filter --append FORWARD --out-interface mpqemubr0 --jump REJECT --reject-with icmp-port-unreachable --match comment --comment generated for Multipass network mpqemubr0
Jun 16 10:35:42 fedora multipassd[398571]: gRPC listening on unix:/var/snap/multipass/common/multipass_socket
Jun 16 10:35:42 fedora multipassd[398571]: QIODevice::write (QFile, "/var/snap/multipass/common/cache/multipassd/vault/multipassd-image-records.json"): device not open
Jun 16 10:35:42 fedora multipassd[398571]: Starting Multipass 1.9.2
Jun 16 10:35:42 fedora multipassd[398571]: Daemon arguments: /snap/multipass/7331/bin/multipassd --verbosity debug --logger platform

2 things:

  1. It looks like there is an issue with AppArmor
    Jun 16 10:35:35 fedora multipassd[398571]: Using AppArmor support
    Jun 16 10:35:35 fedora multipassd[398571]: Failed to enable AppArmor: AppArmor is not enabled
    
  2. I am using a custom kernel with some minor patches to help with nVidia graphics card support. It looks like multipassd is having a hard time parsing the kernel version:
    Jun 16 10:35:35 fedora multipassd[398571]: Cannot parse kernel version '5.18.1-602.inttf.fc36.x86_64'
    

Maybe @mborzecki could give some directions on how to proceed here.

I think the problem is with firewalld. There’s a forum post about issues running on Fedora Multipass can't start VMs on Fedora 36 and there are other issues in the github issue tracker: https://github.com/canonical/multipass/issues/2564 https://github.com/canonical/multipass/issues/2567 so it’s probably best to get in touch with multipass team in the first place.

I was able to fix the issue by permanently allowing the multipass network adapter to be trusted by firewalld:

firewall-cmd --zone=trusted --change-interface=mpqemubr0 --permanent
sudo systemctl restart firewalld

This should be built into the installer for multipass on Fedora.

Or at the bare minimum, documented saliently.

1 Like