Unable to launch/access vm from sunbeam launch on any 2023.2 release onwards

[Matt Verran]

As per title, once installed unable to actually run a vm using sunbeam launch. (below is 2023.2 479)

$ sunbeam launch -n test ubuntu
Launching an OpenStack instance ...
Found sunbeam key in OpenStack!
⠏ Creating the OpenStack instance ... Instance creation request failed: Server:bf9a43c6-0d07-4e17-941b-f8975ab6cd98 transitioned to failure state ERROR
Error: Unable to request new instance. Please run `sunbeam configure` first.

I can assure you sunbeam configure has been run and the sunbeam launched tried again.

This occurs on at least 2023.2/edge and 2023.2/stable with my system. As such it points to a common component which I believe is Apparmor and openstack-hypervisor misconfiguration. I have briefly seen this before where switching channel helped, not in this case unfortunately (disabling via https://ubuntu.com/server/docs/apparmor didn't seem to help - possibly something else i'm missing?).

Example apparmor...

Apr 22 21:51:47 mz640 kernel: [19568.924893] audit: type=1107 audit(1713819107.842:5900): pid=2042 uid=102 auid=4294967295 ses=4294967295 subj=unconfined msg='apparmor="DENIED" operation="dbus_method_call" bus="system" path="/org/freedesktop/DBus" interface="org.freedesktop.DBus" member="ListActivatableNames" mask="send" name="org.freedesktop.DBus" pid=1762615 label="snap.openstack-hypervisor.libvirtd" peer_label="unconfined"
Apr 22 21:51:47 mz640 kernel: [19568.924893] exe="/usr/bin/dbus-daemon" sauid=102 hostname=? addr=? terminal=?'
Apr 22 21:51:47 mz640 kernel: [19568.927268] audit: type=1400 audit(1713819107.846:5901): apparmor="DENIED" operation="ptrace" class="ptrace" profile="snap.openstack-hypervisor.virtlogd" pid=1761078 comm="virtlogd" requested_mask="read" denied_mask="read" peer="snap.openstack-hypervisor.libvirtd"
Apr 22 21:51:47 mz640 kernel: [19568.927433] audit: type=1400 audit(1713819107.846:5902): apparmor="DENIED" operation="ptrace" class="ptrace" profile="snap.openstack-hypervisor.virtlogd" pid=1761078 comm="virtlogd" requested_mask="read" denied_mask="read" peer="snap.openstack-hypervisor.libvirtd"
Apr 22 21:51:47 mz640 kernel: [19568.932853] audit: type=1400 audit(1713819107.850:5903): apparmor="DENIED" operation="ptrace" class="ptrace" profile="snap.openstack-hypervisor.virtlogd" pid=1761078 comm="virtlogd" requested_mask="read" denied_mask="read" peer="snap.openstack-hypervisor.libvirtd"
Apr 22 21:51:47 mz640 kernel: [19568.932982] audit: type=1400 audit(1713819107.850:5904): apparmor="DENIED" operation="ptrace" class="ptrace" profile="snap.openstack-hypervisor.virtlogd" pid=1761078 comm="virtlogd" requested_mask="read" denied_mask="read" peer="snap.openstack-hypervisor.libvirtd"
Apr 22 21:51:47 mz640 kernel: [19568.934786] tapa7c2f8e4-17: entered promiscuous mode
Apr 22 21:51:47 mz640 kernel: [19568.967068] audit: type=1107 audit(1713819107.886:5905): pid=2042 uid=102 auid=4294967295 ses=4294967295 subj=unconfined msg='apparmor="DENIED" operation="dbus_method_call" bus="system" path="/org/freedesktop/DBus" interface="org.freedesktop.DBus" member="ListActivatableNames" mask="send" name="org.freedesktop.DBus" pid=1762615 label="snap.openstack-hypervisor.libvirtd" peer_label="unconfined"
Apr 22 21:51:47 mz640 kernel: [19568.967068] exe="/usr/bin/dbus-daemon" sauid=102 hostname=? addr=? terminal=?'
Apr 22 21:51:47 mz640 kernel: [19568.967982] audit: type=1400 audit(1713819107.886:5906): apparmor="DENIED" operation="ptrace" class="ptrace" profile="snap.openstack-hypervisor.virtlogd" pid=1761078 comm="virtlogd" requested_mask="read" denied_mask="read" peer="snap.openstack-hypervisor.libvirtd"
Apr 22 21:51:47 mz640 kernel: [19568.968179] audit: type=1400 audit(1713819107.886:5907): apparmor="DENIED" operation="ptrace" class="ptrace" profile="snap.openstack-hypervisor.virtlogd" pid=1761078 comm="virtlogd" requested_mask="read" denied_mask="read" peer="snap.openstack-hypervisor.libvirtd"
Apr 22 21:51:47 mz640 kernel: [19568.996062] tapa7c2f8e4-17 (unregistering): left promiscuous mode

[Matt Verran (mv-2112)]

For completeness, 2023.2/stable exhibiting same behaviour

[Matt Verran (mv-2112)]

kernel log entries for apparmor as it was installed. (for 2023.2/stable)

[Guillaume Boutry (gboutry)]

snap openstack did not get an update on stable since 06 dec 2023.

Can you get more logs from:

sunbeam -v launch --name ubuntu
snap logs openstack-hypervisor -n=all
kubectl logs -n openstack --all-containers nova-0

[Matt Verran (mv-2112)]

Freshly build 2023.2/stable, from around 14:00

[Chris Johnston (cjohnston)]

I'm seeing very similar behavior, also not being able to launch VMs. Similar messages are seen as well. This is one of them that I got from 2024.1/edge:

2024-04-23T18:56:13Z nova-compute[592427]: 2024-04-23 18:56:13.734 592427 DEBUG nova.compute.utils [None req-809b3de0-098e-496a-8ecd-95cdc8c60baa d424340013694bb4bbd4de65
c8d79476 ae5d4f285bb34171aa84611585a9d8a6 - - 72413730d12e40738f02d61f54b5bbc8 72413730d12e40738f02d61f54b5bbc8] [instance: aada529e-c6a8-4bd4-8aec-7eb62eb92b6b] libvirtE
rror notify_about_instance_usage /snap/openstack-hypervisor/139/usr/lib/python3/dist-packages/nova/compute/utils.py:430
2024-04-23T18:56:13Z nova-compute[592427]: 2024-04-23 18:56:13.737 592427 DEBUG nova.compute.manager [None req-809b3de0-098e-496a-8ecd-95cdc8c60baa d424340013694bb4bbd4de
65c8d79476 ae5d4f285bb34171aa84611585a9d8a6 - - 72413730d12e40738f02d61f54b5bbc8 72413730d12e40738f02d61f54b5bbc8] [instance: aada529e-c6a8-4bd4-8aec-7eb62eb92b6b] Build
of instance aada529e-c6a8-4bd4-8aec-7eb62eb92b6b was re-scheduled: error from service: GDBus.Error:org.freedesktop.DBus.Error.AccessDenied: An AppArmor policy prevents th
is sender from sending this message to this recipient; type="method_call", sender=":1.154" (uid=0 pid=592789 comm="/snap/openstack-hypervisor/139/usr/sbin/libvirtd -" lab
el="snap.openstack-hypervisor.libvirtd (enforce)") interface="org.freedesktop.DBus" member="ListActivatableNames" error name="(unset)" requested_reply="0" destination="or
g.freedesktop.DBus" (bus) _do_build_and_run_instance /snap/openstack-hypervisor/139/usr/lib/python3/dist-packages/nova/compute/manager.py:2471

[Matt Verran (mv-2112)]

Attempted to run in multipass but that hit several other errors (one issue was a match for #2030349).

It does create a VM..

ubuntu@microstack:~$ sunbeam launch ubuntu -n test
Launching an OpenStack instance ...
Access instance with `ssh -i /home/ubuntu/snap/openstack/335/sunbeam ubuntu@10.20.20.30`

We did get apparmor errors...

ubuntu@microstack:~$ Apr 24 18:58:21 microstack kernel: [ 9449.395259] audit: type=1400 audit(1713981501.419:317): apparmor="DENIED" operation="open" profile="snap.openstack-hypervisor.nova-compute" name="/sys/fs/cgroup/cgroup.controllers" pid=372811 comm="python3" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 24 18:58:25 microstack kernel: [ 9453.594641] audit: type=1107 audit(1713981505.615:318): pid=664 uid=102 auid=4294967295 ses=4294967295 subj=unconfined msg='apparmor="DENIED" operation="dbus_method_call" bus="system" path="/org/freedesktop/DBus" interface="org.freedesktop.DBus" member="ListActivatableNames" mask="send" name="org.freedesktop.DBus" pid=371651 label="snap.openstack-hypervisor.libvirtd" peer_label="unconfined"
Apr 24 18:58:25 microstack kernel: [ 9453.594641] exe="/usr/bin/dbus-daemon" sauid=102 hostname=? addr=? terminal=?'
Apr 24 18:58:25 microstack kernel: [ 9453.606854] audit: type=1400 audit(1713981505.627:319): apparmor="DENIED" operation="ptrace" profile="snap.openstack-hypervisor.virtlogd" pid=371752 comm="virtlogd" requested_mask="read" denied_mask="read" peer="snap.openstack-hypervisor.libvirtd"
Apr 24 18:58:25 microstack kernel: [ 9453.608442] audit: type=1400 audit(1713981505.631:320): apparmor="DENIED" operation="ptrace" profile="snap.openstack-hypervisor.virtlogd" pid=371752 comm="virtlogd" requested_mask="read" denied_mask="read" peer="snap.openstack-hypervisor.libvirtd"
Apr 24 18:58:25 microstack kernel: [ 9453.736633] audit: type=1400 audit(1713981505.759:321): apparmor="DENIED" operation="ptrace" profile="snap.openstack-hypervisor.virtlogd" pid=371752 comm="virtlogd" requested_mask="read" denied_mask="read" peer="snap.openstack-hypervisor.libvirtd"
Apr 24 18:58:25 microstack kernel: [ 9453.737284] audit: type=1400 audit(1713981505.759:322): apparmor="DENIED" operation="ptrace" profile="snap.openstack-hypervisor.virtlogd" pid=371752 comm="virtlogd" requested_mask="read" denied_mask="read" peer="snap.openstack-hypervisor.libvirtd"
Apr 24 18:58:25 microstack kernel: [ 9453.749108] device tap94bd3c4c-a8 entered promiscuous mode
Apr 24 18:58:26 microstack kernel: [ 9454.084902] audit: type=1400 audit(1713981506.107:323): apparmor="DENIED" operation="open" profile="snap.openstack-hypervisor.libvirtd" name="/sys/fs/cgroup/cgroup.controllers" pid=371651 comm="rpc-libvirtd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0

[Matt Verran (mv-2112)]

This suggests its something on the physical install, it is a general workstation used for all sorts so a fresh install of 22.04LTS might solve but it may be some time before i can do that. I can't think of anything specific i've done that would have caused this.

Its also worth noting a second user has reported so possibly general update cruft??

[Chris Johnston (cjohnston)]

It's actually been hit or miss for me on multipass. All of my testing has been done on fresh installs of Ubuntu, so no snap refreshes involved.

[Guillaume Boutry (gboutry)]

Can you check your snapd version ? All the apparmor profiles for snap-openstack come from snapd (through the interfaces).

I'm trying to reproduce the failure but failing to do so, so far.

I've tried with multipass but succeeded on launching a guest, and I'm currently bootstrapping a sunbeam on an ubuntu desktop.

edit: ubuntu desktop managed to launch a VM successfully

[Matt Verran (mv-2112)]

snap-store 41.3-77-g7dc86c8 1113 latest/stable/… canonical✓ -
snapd 2.62 21465 latest/stable canonical✓ snapd
snapd-desktop-integration 0.9 157 latest/stable/… canonical✓ -

All latest as far as snap refresh is telling me.

To clarify:
multipass: worked (despite other issues)
bare metal instal: can't launch VM.

The fresh install question has been answered by cjohnston so we can rule that out.

[Matt Verran (mv-2112)]

Maybe https://bugs.launchpad.net/snapd/+bug/1990875 is related?

I also suspect Andre Ruiz is also hitting this on https://bugs.launchpad.net/snap-openstack/+bug/2060573 looking at the archive.zip logs.

It's worth adding at this point that this is raised for when the bootstrap completes, I do frequently get odd timeouts where microk8s or openstack-hypervisor timeout. Brings us back to the idea there some cruft getting left behind after cleanup.

Can I confirm this is still the 'approved' way to remove?

https://ubuntu.com/tutorials/tear-down-your-openstack-lab-environment#4-uninstall-sunbeam

[Matt Verran (mv-2112)]

All 2023.2 channels still failing after fresh reinstall of 22.04.4

Latest 2024.1 does work (501 2024.1/edge) - previously this did not although I can't recall last revision tried - possibly 49x. The app armor errors are still present so appear to not be the cause. Cannot actually connect to the VM though after creating using sunbeam launch and running the given ssh command.

Would be interesting to see if @cjohnston has further updates?

Edit: corrected version having issues. 2023.1/stable works fine but lacks the features i wish to test.

[James Page (james-page)]

Hi Matt

I've been digging into what might be impacting your deployments with regards to not being able to launch VM's.

Oddly enough all three tracks of the openstack-hypervisor snap run the same libvirt/qemu build, and have the same snapcraft plugs for interfacing to the host system. Are you using the same system for all tests your're conducting?

Re 2024.1/edge - yet we've seen that issue as well and investigating before that gets proposed for candidate.

[Matt Verran (mv-2112)]

I am using the same system (HP z640) - even wiped, installed noble, found not supported so re-installed jammy (rules out it being my cruft).

re: 2024.1 agree likely different issue - feels like its somewhere in the neutron/ovs plumbing.

On 2023.2 non-stable I think i have found the answer under https://bugs.launchpad.net/snap-openstack/+bug/2065303 pending a little more testing. This also appears to have solved the plugin issue. 2023.2/stable is still broken.

Unless @cjohnston has any more information to the contrary I'd close this as user error from not understanding the manifest changes and pick up 2065303 as a documentation clarification or smarter defaults?

[Matt Verran (mv-2112)]

$ sunbeam launch -n test ubuntu
Launching an OpenStack instance ...
Access instance with `ssh -i /home/verranm/snap/openstack/335/sunbeam ubuntu@10.20.20.173`

$ ssh -i /home/mmmmm/snap/openstack/335/sunbeam ubuntu@10.20.20.173
ssh: connect to host 10.20.20.173 port 22: Connection refused

$ snap info openstack
---8<----
installed: 2023.2 (335) 153MB -

Confirmed its a case of pebkac on 2023.2/stable on my behalf where the control plane and hypervisor presumably were unable to talk to each other. I'd say this is a case where --accept-defaults doesn't result in a working setup as detailed in https://bugs.launchpad.net/snap-openstack/+bug/2065303 and hacks like me need better guidance at https://microstack.run/docs