search

canonical / multipass

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

Multipass won't start if systemd-resolved is disabled #2167

Open prosperoking opened 3 years ago

prosperoking commented 3 years ago

Describe the bug Mulipassd does not start unless I install snapcraft --classic

To Reproduce How, and what happened?

  1. Multipass service does not start

Expected behavior What did you expect to happen? After installation multipass service fails to start

Logs No logs are created

Additional info

Additional context Service starts if I install snapcraft --classic

townsend2010 commented 3 years ago

Hi @prosperoking,

Sorry you are having an issue. That is very strange. You say no logs are created, but did you see https://multipass.run/docs/accessing-logs on how to get logs? Logs would be very helpful to us in helping you diagnose the issue.

Thanks!

prosperoking commented 3 years ago

Thanks @townsend2010,

I did run journalctl --unit snap.multipass* but I recieved no matches found: snap.multipass*

prosperoking commented 3 years ago

I have uninstalled and reinstalled still the issue persists

prosperoking commented 3 years ago

The closest log I can get is from systemctl status

Failed to start Service for snap application multipass.multipassd.
Jul 06 10:37:23 xxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Start request repeated too quickly.
Jul 06 10:37:23 xxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Failed with result 'exit-code'.
Jul 06 10:37:23 xxxx-pop-pc systemd[1]: Failed to start Service for snap application multipass.multipassd.
Jul 06 10:37:24 xxxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Start request repeated too quickly.
Jul 06 10:37:24 xxxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Failed with result 'exit-code'.
Jul 06 10:37:24 xxx-pop-pc systemd[1]: Failed to start Service for snap application multipass.multipassd.
Jul 06 10:37:27 xxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Start request repeated too quickly.
Jul 06 10:37:27 xxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Failed with result 'exit-code'.
Jul 06 10:37:27 xxx-pop-pc systemd[1]: Failed to start Service for snap application multipass.multipassd.
townsend2010 commented 3 years ago

Ok, thanks. The fact that installing snapcraft --classic makes it work is very strange since Multipass is a strictly confined snap. With multipass installed and without snapcraft installed, could you paste the output of snap connections multipass?

Also, could you paste the output of journalctl -f while you try to start the multipass snap? I'd like to se if some other service is complaining or such.

Thanks!

prosperoking commented 3 years ago

Okay, will do that now

prosperoking commented 3 years ago

snap connection mulitpass


Interface          Plug                         Slot                Notes
firewall-control   multipass:firewall-control   :firewall-control   -
home               multipass:all-home           :home               -
home               multipass:home               :home               -
kvm                multipass:kvm                :kvm                -
libvirt            multipass:libvirt            -                   -
lxd                multipass:lxd                -                   -
multipass-support  multipass:multipass-support  :multipass-support  -
network            multipass:network            :network            -
network-bind       multipass:network-bind       :network-bind       -
network-control    multipass:network-control    :network-control    -
removable-media    multipass:removable-media    -                   -
unity7             multipass:unity7             :unity7             -
wayland            multipass:wayland            :wayland            -
x11                multipass:x11                :x11                -

> journalctl -f

Jul 06 13:40:57 xxxx-pop-pc kernel: pcieport 0000:00:1d.4: AER: Corrected error received: 0000:08:00.0 Jul 06 13:40:57 xxxx-pop-pc kernel: alx 0000:08:00.0: PCIe Bus Error: severity=Corrected, type=Data Link Layer, (Receiver ID) Jul 06 13:40:57 xxxx-pop-pc kernel: alx 0000:08:00.0: device [1969:e0b1] error status/mask=00000080/00002000 Jul 06 13:40:57 xxxx-pop-pc kernel: alx 0000:08:00.0: [ 7] BadDLLP
Jul 06 13:40:57 xxxx-pop-pc kernel: pcieport 0000:00:1d.4: AER: Corrected error received: 0000:08:00.0 Jul 06 13:40:57 xxxx-pop-pc kernel: alx 0000:08:00.0: PCIe Bus Error: severity=Corrected, type=Data Link Layer, (Receiver ID) Jul 06 13:40:57 xxxx-pop-pc kernel: alx 0000:08:00.0: device [1969:e0b1] error status/mask=00000080/00002000 Jul 06 13:40:57 xxxx-pop-pc kernel: alx 0000:08:00.0: [ 7] BadDLLP
Jul 06 13:40:57 xxxx-pop-pc kernel: pcieport 0000:00:1d.4: AER: Corrected error received: 0000:08:00.0 Jul 06 13:40:57 xxxx-pop-pc kernel: alx 0000:08:00.0: PCIe Bus Error: severity=Corrected, type=Data Link Layer, (Receiver ID) Jul 06 13:40:57 xxxx-pop-pc kernel: alx 0000:08:00.0: device [1969:e0b1] error status/mask=00000080/00002000 Jul 06 13:40:57 xxxx-pop-pc kernel: alx 0000:08:00.0: [ 7] BadDLLP
Jul 06 13:40:57 xxxx-pop-pc kernel: pcieport 0000:00:1d.4: AER: Corrected error received: 0000:08:00.0 Jul 06 13:40:57 xxxx-pop-pc kernel: alx 0000:08:00.0: PCIe Bus Error: severity=Corrected, type=Data Link Layer, (Receiver ID) Jul 06 13:40:57 xxxx-pop-pc kernel: alx 0000:08:00.0: device [1969:e0b1] error status/mask=00000080/00002000 Jul 06 13:40:57 xxxx-pop-pc kernel: alx 0000:08:00.0: [ 7] BadDLLP
Jul 06 13:40:57 xxxx-pop-pc kernel: pcieport 0000:00:1d.4: AER: Corrected error received: 0000:08:00.0 Jul 06 13:40:57 xxxx-pop-pc kernel: alx 0000:08:00.0: PCIe Bus Error: severity=Corrected, type=Data Link Layer, (Receiver ID) Jul 06 13:40:57 xxxx-pop-pc kernel: alx 0000:08:00.0: device [1969:e0b1] error status/mask=00000080/00002000 Jul 06 13:40:57 xxxx-pop-pc kernel: alx 0000:08:00.0: [ 7] BadDLLP

prosperoking commented 3 years ago

I ran journalctl -f before the snap connection mulitpass command

townsend2010 commented 3 years ago

Ok, thanks. The snap connections look fine.

As for journalctl -f, what I need is in one terminal, have journalctl -f running and then in another terminal window, run snap restart multipass and then capture the journalctl output of what happens during the snap restart. Thanks!

prosperoking commented 3 years ago

Here is the result


Jul 06 13:49:16 xxxxx-pop-pc sudo[60790]: xxxxx : TTY=pts/5 ; PWD=/home/xxxxx/tools ; USER=root ; COMMAND=/usr/bin/snap restart nultipass
Jul 06 13:49:34 xxxxx-pop-pc sudo[60818]: xxxxx : TTY=pts/5 ; PWD=/home/xxxxx/tools ; USER=root ; COMMAND=/usr/bin/snap restart multipass
Jul 06 13:49:35 xxxxx-pop-pc systemd[1]: Started Service for snap application multipass.multipassd.
Jul 06 13:49:35 xxxxx-pop-pc audit[60837]: AVC apparmor="DENIED" operation="open" profile="/snap/core/11316/usr/lib/snapd/snap-confine" name="/etc/pop-os/os-release" pid=60837 comm="snap-confine" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc audit[60837]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=60837 comm="snap-exec" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc kernel: audit: type=1400 audit(1625575775.143:2650): apparmor="DENIED" operation="open" profile="/snap/core/11316/usr/lib/snapd/snap-confine" name="/etc/pop-os/os-release" pid=60837 comm="snap-confine" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc kernel: audit: type=1400 audit(1625575775.147:2651): apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=60837 comm="snap-exec" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc audit[60862]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=60862 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc kernel: audit: type=1400 audit(1625575775.315:2652): apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=60862 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc audit[60869]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=60869 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc kernel: audit: type=1400 audit(1625575775.371:2653): apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=60869 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc audit[60874]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=60874 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc kernel: audit: type=1400 audit(1625575775.375:2654): apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=60874 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc audit[60837]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGL.so.1.7.0" pid=60837 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc audit[60837]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGL.so.1.7.0" pid=60837 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc kernel: audit: type=1400 audit(1625575775.475:2655): apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGL.so.1.7.0" pid=60837 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc kernel: audit: type=1400 audit(1625575775.475:2656): apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGL.so.1.7.0" pid=60837 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc audit[60837]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGLX.so.0.0.0" pid=60837 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc audit[60837]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGLX.so.0.0.0" pid=60837 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc audit[60837]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGLdispatch.so.0.0.0" pid=60837 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc audit[60837]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGLdispatch.so.0.0.0" pid=60837 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc kernel: audit: type=1400 audit(1625575775.483:2657): apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGLX.so.0.0.0" pid=60837 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc kernel: audit: type=1400 audit(1625575775.483:2658): apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGLX.so.0.0.0" pid=60837 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc kernel: audit: type=1400 audit(1625575775.483:2659): apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGLdispatch.so.0.0.0" pid=60837 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc audit[60884]: AVC apparmor="STATUS" operation="profile_load" profile="snap.multipass.multipassd" name="multipass.dnsmasq" pid=60884 comm="apparmor_parser"
Jul 06 13:49:35 xxxxx-pop-pc multipassd[60837]: [60885] started: - --keep-in-foreground --strict-order --bind-interfaces --pid-file --domain=multipass --local=/multipass/ --except-interface=lo --interface=mpqemubr0 --listen-address=10.109.67.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.109.67.2,10.109.67.254,infinite --conf-file=/var/snap/multipass/common/data/multipassd/network/dnsmasq-J60837.conf
Jul 06 13:49:35 xxxxx-pop-pc audit[60887]: AVC apparmor="STATUS" operation="profile_remove" profile="snap.multipass.multipassd" name="multipass.dnsmasq" pid=60887 comm="apparmor_parser"
Jul 06 13:49:35 xxxxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Main process exited, code=exited, status=1/FAILURE
Jul 06 13:49:35 xxxxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Failed with result 'exit-code'.
Jul 06 13:49:35 xxxxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Scheduled restart job, restart counter is at 1.
Jul 06 13:49:35 xxxxx-pop-pc snapd[1063]: response.go:370: cannot stream response; problem writing: write unix /run/snapd.socket->@: write: broken pipe
Jul 06 13:49:35 xxxxx-pop-pc systemd[1]: Stopped Service for snap application multipass.multipassd.
Jul 06 13:49:35 xxxxx-pop-pc systemd[1]: Started Service for snap application multipass.multipassd.
Jul 06 13:49:35 xxxxx-pop-pc audit[60888]: AVC apparmor="DENIED" operation="open" profile="/snap/core/11316/usr/lib/snapd/snap-confine" name="/etc/pop-os/os-release" pid=60888 comm="snap-confine" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc audit[60888]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=60888 comm="snap-exec" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc audit[60910]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=60910 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc audit[60916]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=60916 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc audit[60921]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=60921 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc audit[60888]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGL.so.1.7.0" pid=60888 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc audit[60888]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGL.so.1.7.0" pid=60888 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc audit[60888]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGLX.so.0.0.0" pid=60888 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc audit[60888]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGLX.so.0.0.0" pid=60888 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc audit[60888]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGLdispatch.so.0.0.0" pid=60888 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:35 xxxxx-pop-pc audit[60888]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGLdispatch.so.0.0.0" pid=60888 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:36 xxxxx-pop-pc audit[60931]: AVC apparmor="STATUS" operation="profile_load" profile="snap.multipass.multipassd" name="multipass.dnsmasq" pid=60931 comm="apparmor_parser"
Jul 06 13:49:36 xxxxx-pop-pc multipassd[60888]: [60932] started: - --keep-in-foreground --strict-order --bind-interfaces --pid-file --domain=multipass --local=/multipass/ --except-interface=lo --interface=mpqemubr0 --listen-address=10.109.67.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.109.67.2,10.109.67.254,infinite --conf-file=/var/snap/multipass/common/data/multipassd/network/dnsmasq-J60888.conf
Jul 06 13:49:36 xxxxx-pop-pc audit[60934]: AVC apparmor="STATUS" operation="profile_remove" profile="snap.multipass.multipassd" name="multipass.dnsmasq" pid=60934 comm="apparmor_parser"
Jul 06 13:49:36 xxxxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Main process exited, code=exited, status=1/FAILURE
Jul 06 13:49:36 xxxxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Failed with result 'exit-code'.
Jul 06 13:49:36 xxxxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Scheduled restart job, restart counter is at 2.
Jul 06 13:49:36 xxxxx-pop-pc systemd[1]: Stopped Service for snap application multipass.multipassd.
Jul 06 13:49:36 xxxxx-pop-pc systemd[1]: Started Service for snap application multipass.multipassd.
Jul 06 13:49:36 xxxxx-pop-pc audit[60936]: AVC apparmor="DENIED" operation="open" profile="/snap/core/11316/usr/lib/snapd/snap-confine" name="/etc/pop-os/os-release" pid=60936 comm="snap-confine" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:36 xxxxx-pop-pc audit[60936]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=60936 comm="snap-exec" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:36 xxxxx-pop-pc audit[60959]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=60959 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:36 xxxxx-pop-pc audit[60964]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=60964 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:36 xxxxx-pop-pc audit[60969]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=60969 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:36 xxxxx-pop-pc audit[60936]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGL.so.1.7.0" pid=60936 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:36 xxxxx-pop-pc audit[60936]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGL.so.1.7.0" pid=60936 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:36 xxxxx-pop-pc audit[60936]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGLX.so.0.0.0" pid=60936 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:36 xxxxx-pop-pc audit[60936]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGLX.so.0.0.0" pid=60936 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:36 xxxxx-pop-pc audit[60936]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGLdispatch.so.0.0.0" pid=60936 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:36 xxxxx-pop-pc audit[60936]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGLdispatch.so.0.0.0" pid=60936 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:36 xxxxx-pop-pc audit[60979]: AVC apparmor="STATUS" operation="profile_load" profile="snap.multipass.multipassd" name="multipass.dnsmasq" pid=60979 comm="apparmor_parser"
Jul 06 13:49:36 xxxxx-pop-pc multipassd[60936]: [60980] started: - --keep-in-foreground --strict-order --bind-interfaces --pid-file --domain=multipass --local=/multipass/ --except-interface=lo --interface=mpqemubr0 --listen-address=10.109.67.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.109.67.2,10.109.67.254,infinite --conf-file=/var/snap/multipass/common/data/multipassd/network/dnsmasq-J60936.conf
Jul 06 13:49:36 xxxxx-pop-pc audit[60982]: AVC apparmor="STATUS" operation="profile_remove" profile="snap.multipass.multipassd" name="multipass.dnsmasq" pid=60982 comm="apparmor_parser"
Jul 06 13:49:36 xxxxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Main process exited, code=exited, status=1/FAILURE
Jul 06 13:49:36 xxxxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Failed with result 'exit-code'.
Jul 06 13:49:36 xxxxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Scheduled restart job, restart counter is at 3.
Jul 06 13:49:36 xxxxx-pop-pc systemd[1]: Stopped Service for snap application multipass.multipassd.
Jul 06 13:49:36 xxxxx-pop-pc systemd[1]: Started Service for snap application multipass.multipassd.
Jul 06 13:49:36 xxxxx-pop-pc audit[60984]: AVC apparmor="DENIED" operation="open" profile="/snap/core/11316/usr/lib/snapd/snap-confine" name="/etc/pop-os/os-release" pid=60984 comm="snap-confine" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:36 xxxxx-pop-pc audit[60984]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=60984 comm="snap-exec" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:36 xxxxx-pop-pc audit[61008]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=61008 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:36 xxxxx-pop-pc audit[61013]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=61013 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:36 xxxxx-pop-pc audit[61018]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=61018 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:36 xxxxx-pop-pc audit[60984]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGL.so.1.7.0" pid=60984 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:36 xxxxx-pop-pc audit[60984]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGL.so.1.7.0" pid=60984 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:36 xxxxx-pop-pc audit[60984]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGLX.so.0.0.0" pid=60984 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:36 xxxxx-pop-pc audit[60984]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGLX.so.0.0.0" pid=60984 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:36 xxxxx-pop-pc audit[60984]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGLdispatch.so.0.0.0" pid=60984 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:36 xxxxx-pop-pc audit[60984]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGLdispatch.so.0.0.0" pid=60984 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:37 xxxxx-pop-pc audit[61028]: AVC apparmor="STATUS" operation="profile_load" profile="snap.multipass.multipassd" name="multipass.dnsmasq" pid=61028 comm="apparmor_parser"
Jul 06 13:49:37 xxxxx-pop-pc multipassd[60984]: [61029] started: - --keep-in-foreground --strict-order --bind-interfaces --pid-file --domain=multipass --local=/multipass/ --except-interface=lo --interface=mpqemubr0 --listen-address=10.109.67.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.109.67.2,10.109.67.254,infinite --conf-file=/var/snap/multipass/common/data/multipassd/network/dnsmasq-J60984.conf
Jul 06 13:49:37 xxxxx-pop-pc audit[61031]: AVC apparmor="STATUS" operation="profile_remove" profile="snap.multipass.multipassd" name="multipass.dnsmasq" pid=61031 comm="apparmor_parser"
Jul 06 13:49:37 xxxxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Main process exited, code=exited, status=1/FAILURE
Jul 06 13:49:37 xxxxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Failed with result 'exit-code'.
Jul 06 13:49:37 xxxxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Scheduled restart job, restart counter is at 4.
Jul 06 13:49:37 xxxxx-pop-pc systemd[1]: Stopped Service for snap application multipass.multipassd.
Jul 06 13:49:37 xxxxx-pop-pc systemd[1]: Started Service for snap application multipass.multipassd.
Jul 06 13:49:37 xxxxx-pop-pc audit[61032]: AVC apparmor="DENIED" operation="open" profile="/snap/core/11316/usr/lib/snapd/snap-confine" name="/etc/pop-os/os-release" pid=61032 comm="snap-confine" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:37 xxxxx-pop-pc audit[61032]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=61032 comm="snap-exec" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:37 xxxxx-pop-pc audit[61055]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=61055 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:37 xxxxx-pop-pc audit[61060]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=61060 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:37 xxxxx-pop-pc audit[61065]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=61065 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:37 xxxxx-pop-pc audit[61032]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGL.so.1.7.0" pid=61032 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:37 xxxxx-pop-pc audit[61032]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGL.so.1.7.0" pid=61032 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:37 xxxxx-pop-pc audit[61032]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGLX.so.0.0.0" pid=61032 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:37 xxxxx-pop-pc audit[61032]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGLX.so.0.0.0" pid=61032 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:37 xxxxx-pop-pc audit[61032]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGLdispatch.so.0.0.0" pid=61032 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:37 xxxxx-pop-pc audit[61032]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGLdispatch.so.0.0.0" pid=61032 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 13:49:37 xxxxx-pop-pc audit[61075]: AVC apparmor="STATUS" operation="profile_load" profile="snap.multipass.multipassd" name="multipass.dnsmasq" pid=61075 comm="apparmor_parser"
Jul 06 13:49:37 xxxxx-pop-pc multipassd[61032]: [61076] started: - --keep-in-foreground --strict-order --bind-interfaces --pid-file --domain=multipass --local=/multipass/ --except-interface=lo --interface=mpqemubr0 --listen-address=10.109.67.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.109.67.2,10.109.67.254,infinite --conf-file=/var/snap/multipass/common/data/multipassd/network/dnsmasq-J61032.conf
Jul 06 13:49:37 xxxxx-pop-pc audit[61078]: AVC apparmor="STATUS" operation="profile_remove" profile="snap.multipass.multipassd" name="multipass.dnsmasq" pid=61078 comm="apparmor_parser"
Jul 06 13:49:37 xxxxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Main process exited, code=exited, status=1/FAILURE
Jul 06 13:49:37 xxxxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Failed with result 'exit-code'.
Jul 06 13:49:37 xxxxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Scheduled restart job, restart counter is at 5.
Jul 06 13:49:37 xxxxx-pop-pc systemd[1]: Stopped Service for snap application multipass.multipassd.
Jul 06 13:49:37 xxxxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Start request repeated too quickly.
Jul 06 13:49:37 xxxxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Failed with result 'exit-code'.
Jul 06 13:49:37 xxxxx-pop-pc systemd[1]: Failed to start Service for snap application multipass.multipassd.
townsend2010 commented 3 years ago

Hey @prosperoking,

Thanks! This is what I need. I'll analyze this and either determine what may be going wrong or ask for more info :smiley:

prosperoking commented 3 years ago

Okay, thank a lot

townsend2010 commented 3 years ago

I'm going to try this in a virtual machine. You said you are running Pop OS version 21.01, but all I can find is 20.04 LTS and 21.04. Did you mean 20.04? If not, do you know where I can find the version you have?

Thanks!

townsend2010 commented 3 years ago

I tried Pop_OS! 20.04 LTS in a virtual machine and Multipass works as expected. Please confirm the version of Pop_OS! you are using and we'll go from there.

prosperoking commented 3 years ago

I am running pop os 21.04

prosperoking commented 3 years ago

It was released quite recently

townsend2010 commented 3 years ago

Ok, thanks, I will try that version.

prosperoking commented 3 years ago

I saw apparmor denied in the log. Could that be the issue?

townsend2010 commented 3 years ago

There are a number of apparmor denials, some I'm familiar with and cause no harm and others I'm not familiar with and not sure if it causes issues or not.

While I'm trying Pop OS 21.04 in a virtual machine, could you please do the same journalctl -f/snap restart multipass stuff but with snapcraft installed? I'm curious as to what, if any, different log messages are printed out.

townsend2010 commented 3 years ago

Ok, this works for me as well with Pop OS 21.04 in a virtual machine. It's not clear from the logs you've posted what is causing multipassd to exit either. Let's see what your logs say when you snapcraft installed, which is still puzzling me why that makes Multipass work.

prosperoking commented 3 years ago

Tried it again now and it did not start

prosperoking commented 3 years ago

Here is the log

Jul 06 16:05:25 xxxx-pop-pc audit[81629]: AVC apparmor="DENIED" operation="open" profile="/snap/core/11316/usr/lib/snapd/snap-confine" name="/etc/pop-os/os-release" pid=81629 comm="snap-confine" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:25 xxxx-pop-pc kernel: kauditd_printk_skb: 55 callbacks suppressed
Jul 06 16:05:25 xxxx-pop-pc kernel: audit: type=1400 audit(1625583925.940:3955): apparmor="DENIED" operation="open" profile="/snap/core/11316/usr/lib/snapd/snap-confine" name="/etc/pop-os/os-release" pid=81629 comm="snap-confine" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:25 xxxx-pop-pc audit[81629]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=81629 comm="snap-exec" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:25 xxxx-pop-pc kernel: audit: type=1400 audit(1625583925.944:3956): apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=81629 comm="snap-exec" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:25 xxxx-pop-pc audit[81652]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=81652 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:25 xxxx-pop-pc kernel: audit: type=1400 audit(1625583925.948:3957): apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=81652 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:25 xxxx-pop-pc sudo[81611]: pam_unix(sudo:session): session closed for user root
Jul 06 16:05:25 xxxx-pop-pc audit[81657]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=81657 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:25 xxxx-pop-pc audit[81663]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=81663 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:25 xxxx-pop-pc kernel: audit: type=1400 audit(1625583925.968:3958): apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=81657 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:25 xxxx-pop-pc kernel: audit: type=1400 audit(1625583925.968:3959): apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=81663 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:25 xxxx-pop-pc audit[81629]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGL.so.1.7.0" pid=81629 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:25 xxxx-pop-pc audit[81629]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGL.so.1.7.0" pid=81629 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:25 xxxx-pop-pc audit[81629]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGLX.so.0.0.0" pid=81629 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:25 xxxx-pop-pc audit[81629]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGLX.so.0.0.0" pid=81629 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:25 xxxx-pop-pc audit[81629]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGLdispatch.so.0.0.0" pid=81629 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:25 xxxx-pop-pc audit[81629]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGLdispatch.so.0.0.0" pid=81629 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:25 xxxx-pop-pc kernel: audit: type=1400 audit(1625583925.972:3960): apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGL.so.1.7.0" pid=81629 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:25 xxxx-pop-pc kernel: audit: type=1400 audit(1625583925.972:3961): apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGL.so.1.7.0" pid=81629 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:25 xxxx-pop-pc kernel: audit: type=1400 audit(1625583925.972:3962): apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGLX.so.0.0.0" pid=81629 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:25 xxxx-pop-pc kernel: audit: type=1400 audit(1625583925.972:3963): apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGLX.so.0.0.0" pid=81629 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:25 xxxx-pop-pc kernel: audit: type=1400 audit(1625583925.972:3964): apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGLdispatch.so.0.0.0" pid=81629 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:25 xxxx-pop-pc multipassd[81629]: Using AppArmor support
Jul 06 16:05:25 xxxx-pop-pc kernel: pcieport 0000:00:1d.4: AER: Corrected error received: 0000:08:00.0
Jul 06 16:05:25 xxxx-pop-pc kernel: alx 0000:08:00.0: PCIe Bus Error: severity=Corrected, type=Data Link Layer, (Receiver ID)
Jul 06 16:05:25 xxxx-pop-pc kernel: alx 0000:08:00.0:   device [1969:e0b1] error status/mask=00000080/00002000
Jul 06 16:05:25 xxxx-pop-pc kernel: alx 0000:08:00.0:    [ 7] BadDLLP               
Jul 06 16:05:25 xxxx-pop-pc kernel: pcieport 0000:00:1d.4: AER: Corrected error received: 0000:08:00.0
Jul 06 16:05:25 xxxx-pop-pc kernel: alx 0000:08:00.0: PCIe Bus Error: severity=Corrected, type=Data Link Layer, (Transmitter ID)
Jul 06 16:05:25 xxxx-pop-pc kernel: alx 0000:08:00.0:   device [1969:e0b1] error status/mask=00001000/00002000
Jul 06 16:05:25 xxxx-pop-pc kernel: alx 0000:08:00.0:    [12] Timeout               
Jul 06 16:05:26 xxxx-pop-pc audit[81676]: AVC apparmor="STATUS" operation="profile_load" profile="snap.multipass.multipassd" name="multipass.dnsmasq" pid=81676 comm="apparmor_parser"
Jul 06 16:05:26 xxxx-pop-pc multipassd[81629]: Starting dnsmasq
Jul 06 16:05:26 xxxx-pop-pc multipassd[81677]: Applying AppArmor policy: multipass.dnsmasq
Jul 06 16:05:26 xxxx-pop-pc multipassd[81629]: [81677] started: - --keep-in-foreground --strict-order --bind-interfaces --pid-file --domain=multipass --local=/multipass/ --except-interface=lo --interface=mpqemubr0 --listen-address=10.109.67.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.109.67.2,10.109.67.254,infinite --conf-file=/var/snap/multipass/common/data/multipassd/network/dnsmasq-J81629.conf
Jul 06 16:05:26 xxxx-pop-pc dnsmasq[81677]: directory /etc/resolv.conf for resolv-file is missing, cannot poll
Jul 06 16:05:26 xxxx-pop-pc dnsmasq[81677]: FAILED to start up
Jul 06 16:05:26 xxxx-pop-pc multipassd[81629]: 
                                                       dnsmasq: directory /etc/resolv.conf for resolv-file is missing, cannot poll
Jul 06 16:05:26 xxxx-pop-pc multipassd[81629]: dnsmasq died: Process returned exit code: 5
Jul 06 16:05:26 xxxx-pop-pc audit[81679]: AVC apparmor="STATUS" operation="profile_remove" profile="snap.multipass.multipassd" name="multipass.dnsmasq" pid=81679 comm="apparmor_parser"
Jul 06 16:05:26 xxxx-pop-pc multipassd[81629]: Caught an unhandled exception: dnsmasq died: Process returned exit code: 5
Jul 06 16:05:26 xxxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Main process exited, code=exited, status=1/FAILURE
Jul 06 16:05:26 xxxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Failed with result 'exit-code'.
Jul 06 16:05:26 xxxx-pop-pc systemd[1]: snap.multipass.multipassd.service: Scheduled restart job, restart counter is at 1.
Jul 06 16:05:26 xxxx-pop-pc systemd[1]: Stopped Service for snap application multipass.multipassd.
Jul 06 16:05:26 xxxx-pop-pc systemd[1]: Started Service for snap application multipass.multipassd.
Jul 06 16:05:26 xxxx-pop-pc audit[81680]: AVC apparmor="DENIED" operation="open" profile="/snap/core/11316/usr/lib/snapd/snap-confine" name="/etc/pop-os/os-release" pid=81680 comm="snap-confine" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:26 xxxx-pop-pc audit[81680]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=81680 comm="snap-exec" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:26 xxxx-pop-pc audit[81704]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=81704 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:26 xxxx-pop-pc audit[81709]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=81709 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:26 xxxx-pop-pc audit[81714]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/etc/pop-os/os-release" pid=81714 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:26 xxxx-pop-pc audit[81680]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGL.so.1.7.0" pid=81680 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:26 xxxx-pop-pc audit[81680]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGL.so.1.7.0" pid=81680 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:26 xxxx-pop-pc audit[81680]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGLX.so.0.0.0" pid=81680 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:26 xxxx-pop-pc audit[81680]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGLX.so.0.0.0" pid=81680 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:26 xxxx-pop-pc audit[81680]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libGLdispatch.so.0.0.0" pid=81680 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:26 xxxx-pop-pc audit[81680]: AVC apparmor="DENIED" operation="open" profile="snap.multipass.multipassd" name="/var/lib/snapd/hostfs/usr/lib/i386-linux-gnu/libGLdispatch.so.0.0.0" pid=81680 comm="multipassd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul 06 16:05:26 xxxx-pop-pc multipassd[81680]: Using AppArmor support
Jul 06 16:05:26 xxxx-pop-pc kernel: pcieport 0000:00:1d.4: AER: Corrected error received: 0000:08:00.0
Jul 06 16:05:26 xxxx-pop-pc kernel: alx 0000:08:00.0: PCIe Bus Error: severity=Corrected, type=Data Link Layer, (Receiver ID)
Jul 06 16:05:26 xxxx-pop-pc kernel: alx 0000:08:00.0:   device [1969:e0b1] error status/mask=00000080/00002000
Jul 06 16:05:26 xxxx-pop-pc kernel: alx 0000:08:00.0:    [ 7] BadDLLP               
Jul 06 16:05:26 xxxx-pop-pc audit[81724]: AVC apparmor="STATUS" operation="profile_load" profile="snap.multipass.multipassd" name="multipass.dnsmasq" pid=81724 comm="apparmor_parser"
Jul 06 16:05:26 xxxx-pop-pc multipassd[81680]: Starting dnsmasq
Jul 06 16:05:26 xxxx-pop-pc multipassd[81725]: Applying AppArmor policy: multipass.dnsmasq
Jul 06 16:05:26 xxxx-pop-pc multipassd[81680]: [81725] started: - --keep-in-foreground --strict-order --bind-interfaces --pid-file --domain=multipass --local=/multipass/ --except-interface=lo --interface=mpqemubr0 --listen-address=10.109.67.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.109.67.2,10.109.67.254,infinite --conf-file=/var/snap/multipass/common/data/multipassd/network/dnsmasq-J81680.conf
Jul 06 16:05:26 xxxx-pop-pc dnsmasq[81725]: directory /etc/resolv.conf for resolv-file is missing, cannot poll
Jul 06 16:05:26 xxxx-pop-pc multipassd[81680]: 
                                                       dnsmasq: directory /etc/resolv.conf for resolv-file is missing, cannot poll
Jul 06 16:05:26 xxxx-pop-pc dnsmasq[81725]: FAILED to start up
Jul 06 16:05:26 xxxx-pop-pc multipassd[81680]: dnsmasq died: Process returned exit code: 5
Jul 06 16:05:26 xxxx-pop-pc kernel: pcieport 0000:00:1d.4: AER: Corrected error received: 0000:08:00.0
Jul 06 16:05:26 xxxx-pop-pc kernel: alx 0000:08:00.0: PCIe Bus Error: severity=Corrected, type=Data Link Layer, (Receiver ID)
Jul 06 16:05:26 xxxx-pop-pc kernel: alx 0000:08:00.0:   device [1969:e0b1] error status/mask=00000080/00002000
Jul 06 16:05:26 xxxx-pop-pc kernel: alx 0000:08:00.0:    [ 7] BadDLLP               
Jul 06 16:05:26 xxxx-pop-pc kernel: pcieport 0000:00:1d.4: AER: Corrected error received: 0000:08:00.0
Jul 06 16:05:26 xxxx-pop-pc kernel: alx 0000:08:00.0: PCIe Bus Error: severity=Corrected, type=Data Link Layer, (Transmitter ID)
Jul 06 16:05:26 xxxx-pop-pc kernel: alx 0000:08:00.0:   device [1969:e0b1] error status/mask=00001000/00002000
Jul 06 16:05:26 xxxx-pop-pc kernel: alx 0000:08:00.0:    [12] Timeout               
Jul 06 16:05:26 xxxx-pop-pc audit[81727]: AVC apparmor="STATUS" operation="profile_remove" profile="snap.multipass.multipassd" name="multipass.dnsmasq" pid=81727 comm="apparmor_parser"
townsend2010 commented 3 years ago

Ahh, that last log has some info that sheds light on this. It looks like dnsmasq is unexpectedly dying and multipassd is not expecting that and exits. So now to figure out why dnsmasq is dying for you...

prosperoking commented 3 years ago

I have dnsmasq installed on my host machine. Can that be the problem?

townsend2010 commented 3 years ago

I'm not sure yet if that may be the problem. However, what the dnsmasq error is saying is that there is a symbolic link in the core18 snap found under /snap/core18/current/etc/resolv.conf that points to /run/systemd/resolve/stub-resolv.conf on the host and some directory in that path does not exist. Can you confirm if /run/systemd/resolve/stub-resolv.conf is not present? If not, do you have systemd-reolved disabled or not running?

prosperoking commented 3 years ago

Yes, it's disabled

townsend2010 commented 3 years ago

Ok, then that is the problem. Is there a reason it is disabled?

prosperoking commented 3 years ago 
> multipass info --all
info failed: cannot connect to the multipass socket
Please ensure multipassd is running and '/var/snap/multipass/common/multipass_socket' is accessible

any reason for this?

townsend2010 commented 3 years ago

Yes, because the client needs to connect to multipassd to get info for any instances, but multipassd cannot run due to the error in dnsmasq because the systemd-resolved unit is disabled on your system.

prosperoking commented 3 years ago

Okay. Thanks

prosperoking commented 3 years ago

I truly appreciate your help

townsend2010 commented 3 years ago

Although I think this case is an outlier, we should be able to do better than this if systemd-resolved is disabled. I'm going to reopen and we'll see what we can do to make it better in the future.