Non-classic snaps fail to load due to cgroup/AppArmor issue

snapd
1

Hi, I’m running Snapd on a Debian installation. I’m unable to start non-classic snaps (tested with notepadqq and postman), due to what seems to be an error related to how AppArmor is handling its permissions.

$ notepadqq
/user.slice/user-1000.slice/session-c102.scope is not a snap cgroup

A similar problem is described here, though following the proposed solution did not help me: https://unix.stackexchange.com/questions/684002/snap-on-kubuntu-21-10

Based on the syslog output I tried to create to set up a new AppArmor profile for the used snap-confine instance, but that didn’t work either:

$ cat snap.core.12603.usr.lib.snapd.snap-confine 
# Last Modified: Wed Feb  9 09:37:16 2022
#include <tunables/global>

/snap/core/12603/usr/lib/snapd/snap-confine flags=(complain) {
  include "/var/lib/snapd/apparmor/snap-confine/cap-bpf"
  #include <abstractions/base>
  #include <abstractions/dovecot-common>
  #include <abstractions/lightdm>

  capability net_admin,
  capability perfmon,
  capability sys_ptrace,

  ptrace read peer=unconfined,

  /snap/core/12603/usr/lib/snapd/snap-confine mr,
  owner /proc/*/attr/current r,
  owner /proc/*/cgroup r,
  owner /proc/*/mountinfo r,
  owner /proc/*/mounts r,
  owner /{,var/}run/** mrwk,

}

Could someone please help out?

Some useful (debugging) information:

$ cat /etc/debian_version 
11.2
$ uname -srm
Linux 5.10.0-11-amd64 x86_64

Running Snap in debug mode:

$ SNAPD_DEBUG=1 snap run notepadqq
2022/02/15 11:33:36.369427 tool_linux.go:204: DEBUG: restarting into "/snap/core/current/usr/bin/snap"
2022/02/15 11:33:36.396306 cmd_run.go:433: DEBUG: SELinux not enabled
2022/02/15 11:33:36.396855 tracking.go:46: DEBUG: creating transient scope snap.notepadqq.notepadqq
2022/02/15 11:33:36.397499 tracking.go:186: DEBUG: using session bus
2022/02/15 11:33:36.401245 tracking.go:294: DEBUG: StartTransientUnit failed with "org.freedesktop.DBus.Error.Spawn.ChildExited": [Process org.freedesktop.systemd1 exited with status 1]
2022/02/15 11:33:36.401686 cmd_run.go:1196: DEBUG: snapd cannot track the started application
2022/02/15 11:33:36.401704 cmd_run.go:1197: DEBUG: snap refreshes will not be postponed by this process
DEBUG: umask reset, old umask was  022
DEBUG: security tag: snap.notepadqq.notepadqq
DEBUG: executable:   /usr/lib/snapd/snap-exec
DEBUG: confinement:  non-classic
DEBUG: base snap:    core
DEBUG: ruid: 1000, euid: 0, suid: 0
DEBUG: rgid: 1000, egid: 1000, sgid: 1000
DEBUG: apparmor label on snap-confine is: /snap/core/12603/usr/lib/snapd/snap-confine
DEBUG: apparmor mode is: enforce
DEBUG: creating lock directory /run/snapd/lock (if missing)
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: opening lock directory /run/snapd/lock
DEBUG: set_effective_identity uid:0 (change: no), gid:1000 (change: yes)
DEBUG: opening lock file: /run/snapd/lock/.lock
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: set_effective_identity uid:0 (change: no), gid:1000 (change: yes)
DEBUG: sanity timeout initialized and set for 30 seconds
DEBUG: acquiring exclusive lock (scope (global), uid 0)
DEBUG: sanity timeout reset and disabled
DEBUG: ensuring that snap mount directory is shared
DEBUG: unsharing snap namespace directory
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: set_effective_identity uid:0 (change: no), gid:1000 (change: yes)
DEBUG: releasing lock 6
DEBUG: opened snap-update-ns executable as file descriptor 6
DEBUG: opened snap-discard-ns executable as file descriptor 7
DEBUG: creating lock directory /run/snapd/lock (if missing)
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: opening lock directory /run/snapd/lock
DEBUG: set_effective_identity uid:0 (change: no), gid:1000 (change: yes)
DEBUG: opening lock file: /run/snapd/lock/notepadqq.lock
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: set_effective_identity uid:0 (change: no), gid:1000 (change: yes)
DEBUG: sanity timeout initialized and set for 30 seconds
DEBUG: acquiring exclusive lock (scope notepadqq, uid 0)
DEBUG: sanity timeout reset and disabled
DEBUG: initializing mount namespace: notepadqq
DEBUG: setting up device cgroup
DEBUG: libudev has current tags support
DEBUG: device /sys/devices/pci0000:00/0000:00:07.1/ata1/host1/target1:0:0/1:0:0:0/block/sr0 has matching current tag
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: get bpf object at path /sys/fs/bpf/snap/snap_notepadqq_notepadqq
DEBUG: set_effective_identity uid:0 (change: no), gid:1000 (change: yes)
DEBUG: found existing device map
DEBUG: get next key for map 9
DEBUG: get next key for map 9
DEBUG: get next key for map 9
DEBUG: get next key for map 9
DEBUG: get next key for map 9
DEBUG: get next key for map 9
DEBUG: get next key for map 9
DEBUG: get next key for map 9
DEBUG: get next key for map 9
DEBUG: get next key for map 9
DEBUG: get next key for map 9
DEBUG: get next key for map 9
DEBUG: get next key for map 9
DEBUG: get next key for map 9
DEBUG: get next key for map 9
DEBUG: get next key for map 9
DEBUG: get next key for map 9
DEBUG: get next key for map 9
DEBUG: get next key for map 9
DEBUG: get next key for map 9
DEBUG: get next key for map 9
DEBUG: get next key for map 9
DEBUG: get next key for map 9
DEBUG: found 22 existing entries in devices map
DEBUG: delete key for c 5:1
DEBUG: delete elem in map 9
DEBUG: delete key for c 1:8
DEBUG: delete elem in map 9
DEBUG: delete key for c 10:200
DEBUG: delete elem in map 9
DEBUG: delete key for c 226:128
DEBUG: delete elem in map 9
DEBUG: delete key for c 140:-1
DEBUG: delete elem in map 9
DEBUG: delete key for c 137:-1
DEBUG: delete elem in map 9
DEBUG: delete key for c 5:2
DEBUG: delete elem in map 9
DEBUG: delete key for c 21:1
DEBUG: delete elem in map 9
DEBUG: delete key for c 142:-1
DEBUG: delete elem in map 9
DEBUG: delete key for c 1:9
DEBUG: delete elem in map 9
DEBUG: delete key for c 226:0
DEBUG: delete elem in map 9
DEBUG: delete key for c 5:0
DEBUG: delete elem in map 9
DEBUG: delete key for c 139:-1
DEBUG: delete elem in map 9
DEBUG: delete key for c 1:7
DEBUG: delete elem in map 9
DEBUG: delete key for c 1:5
DEBUG: delete elem in map 9
DEBUG: delete key for c 138:-1
DEBUG: delete elem in map 9
DEBUG: delete key for c 136:-1
DEBUG: delete elem in map 9
DEBUG: delete key for c 141:-1
DEBUG: delete elem in map 9
DEBUG: delete key for c 10:239
DEBUG: delete elem in map 9
DEBUG: delete key for b 11:0
DEBUG: delete elem in map 9
DEBUG: delete key for c 1:3
DEBUG: delete elem in map 9
DEBUG: delete key for c 143:-1
DEBUG: delete elem in map 9
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: load program of type 0xf, 33 instructions
DEBUG: set_effective_identity uid:0 (change: no), gid:1000 (change: yes)
DEBUG: v2 allow c 1:3
DEBUG: v2 allow c 1:5
DEBUG: v2 allow c 1:7
DEBUG: v2 allow c 1:8
DEBUG: v2 allow c 1:9
DEBUG: v2 allow c 5:0
DEBUG: v2 allow c 5:1
DEBUG: v2 allow c 5:2
DEBUG: v2 allow c 136:4294967295
DEBUG: v2 allow c 137:4294967295
DEBUG: v2 allow c 138:4294967295
DEBUG: v2 allow c 139:4294967295
DEBUG: v2 allow c 140:4294967295
DEBUG: v2 allow c 141:4294967295
DEBUG: v2 allow c 142:4294967295
DEBUG: v2 allow c 143:4294967295
DEBUG: v2 allow c 10:239
DEBUG: v2 allow c 10:200
DEBUG: inspecting type of device: /dev/sr0
DEBUG: v2 allow b 11:0
DEBUG: device /sys/devices/pci0000:00/0000:00:07.1/ata1/host1/target1:0:0/1:0:0:0/scsi_generic/sg1 has matching current tag
DEBUG: inspecting type of device: /dev/sg1
DEBUG: v2 allow c 21:1
DEBUG: device /sys/devices/pci0000:00/0000:00:0f.0/drm/card0 has matching current tag
DEBUG: inspecting type of device: /dev/dri/card0
DEBUG: v2 allow c 226:0
DEBUG: device /sys/devices/pci0000:00/0000:00:0f.0/drm/card0/card0-Virtual-1 has matching current tag
DEBUG: cannot get major/minor numbers for syspath /sys/devices/pci0000:00/0000:00:0f.0/drm/card0/card0-Virtual-1
DEBUG: device /sys/devices/pci0000:00/0000:00:0f.0/drm/card0/card0-Virtual-2 has matching current tag
DEBUG: cannot get major/minor numbers for syspath /sys/devices/pci0000:00/0000:00:0f.0/drm/card0/card0-Virtual-2
DEBUG: device /sys/devices/pci0000:00/0000:00:0f.0/drm/card0/card0-Virtual-3 has matching current tag
DEBUG: cannot get major/minor numbers for syspath /sys/devices/pci0000:00/0000:00:0f.0/drm/card0/card0-Virtual-3
DEBUG: device /sys/devices/pci0000:00/0000:00:0f.0/drm/card0/card0-Virtual-4 has matching current tag
DEBUG: cannot get major/minor numbers for syspath /sys/devices/pci0000:00/0000:00:0f.0/drm/card0/card0-Virtual-4
DEBUG: device /sys/devices/pci0000:00/0000:00:0f.0/drm/card0/card0-Virtual-5 has matching current tag
DEBUG: cannot get major/minor numbers for syspath /sys/devices/pci0000:00/0000:00:0f.0/drm/card0/card0-Virtual-5
DEBUG: device /sys/devices/pci0000:00/0000:00:0f.0/drm/card0/card0-Virtual-6 has matching current tag
DEBUG: cannot get major/minor numbers for syspath /sys/devices/pci0000:00/0000:00:0f.0/drm/card0/card0-Virtual-6
DEBUG: device /sys/devices/pci0000:00/0000:00:0f.0/drm/card0/card0-Virtual-7 has matching current tag
DEBUG: cannot get major/minor numbers for syspath /sys/devices/pci0000:00/0000:00:0f.0/drm/card0/card0-Virtual-7
DEBUG: device /sys/devices/pci0000:00/0000:00:0f.0/drm/card0/card0-Virtual-8 has matching current tag
DEBUG: cannot get major/minor numbers for syspath /sys/devices/pci0000:00/0000:00:0f.0/drm/card0/card0-Virtual-8
DEBUG: device /sys/devices/pci0000:00/0000:00:0f.0/drm/renderD128 has matching current tag
DEBUG: inspecting type of device: /dev/dri/renderD128
DEBUG: v2 allow c 226:128
DEBUG: process in cgroup /user.slice/user-1000.slice/session-c102.scope
/user.slice/user-1000.slice/session-c102.scope is not a snap cgroup

Syslog output while running the command above (before and after adding the AppArmor profile):

$ tail -f /var/log/syslog
Feb 15 11:31:41 Exsell dbus-daemon[4074855]: [session uid=1000 pid=4074851] Activating service name='org.freedesktop.systemd1' requested by ':1.35' (uid=1000 pid=4077638 comm="snap run notepadqq ")
Feb 15 11:31:41 Exsell dbus-daemon[4074855]: [session uid=1000 pid=4074851] Activated service 'org.freedesktop.systemd1' failed: Process org.freedesktop.systemd1 exited with status 1
Feb 15 11:31:41 Exsell kernel: [601262.069590] audit: type=1400 audit(1644921101.053:1027): apparmor="DENIED" operation="capable" profile="/snap/core/12603/usr/lib/snapd/snap-confine" pid=4077638 comm="snap-confine" capability=12  capname="net_admin"
2

Anyone that can steer me in the right direction with this issue?

3

this appears to be the root of the problem. IDK why systemd does not start or create a cgroup when request to do so.

4

Thanks for your reply. The issues arose for the first time when I upgraded Debian 10 to 11, though that can also be caused by me using the classic versions of the applications before the upgrade. Is there a way to force apps to run in classic mode?

As mentioned in my original post, the failure of the ‘org.freedesktop.systemd1’ process goes hand in hand with the ‘DENIED’ error from AppArmor. Anything else I can do to tackle that error except for setting up a new AppArmor profile like I already tried?

I already reinstalled snapd after a purge of all files and settings, to no avail.

Edit: I noticed an AppArmor kernel feature issue in the snapd status output, could this be related?

$ systemctl status snapd.service 
● snapd.service - Snap Daemon
     Loaded: loaded (/lib/systemd/system/snapd.service; enabled; vendor preset: enabled)
     Active: active (running) since Fri 2022-02-25 13:47:11 CET; 4min 47s ago
TriggeredBy: ● snapd.socket
   Main PID: 2003714 (snapd)
      Tasks: 32 (limit: 106266)
     Memory: 30.1M
        CPU: 1.023s
     CGroup: /system.slice/snapd.service
             └─2003714 /usr/lib/snapd/snapd

Feb 25 13:47:10 BM01-N0113-EXSELL-DEV systemd[1]: Starting Snap Daemon...
Feb 25 13:47:10 BM01-N0113-EXSELL-DEV snapd[2003714]: AppArmor status: apparmor is enabled but some kernel features are missing: dbus, network
Feb 25 13:47:10 BM01-N0113-EXSELL-DEV snapd[2003714]: AppArmor status: apparmor is enabled but some kernel features are missing: dbus, network
Feb 25 13:47:10 BM01-N0113-EXSELL-DEV snapd[2003714]: daemon.go:246: started snapd/2.54.3.2 (series 16; classic; devmode) debian/11 (amd64) linux/5.10.0-11-amd64.
Feb 25 13:47:10 BM01-N0113-EXSELL-DEV snapd[2003714]: daemon.go:339: adjusting startup timeout by 1m35s (pessimistic estimate of 30s plus 5s per snap)
Feb 25 13:47:11 BM01-N0113-EXSELL-DEV systemd[1]: Started Snap Daemon.
5

The problem appears to be related to systemd not creating a transient scope for the application, which is required for snap-confine to be able to set up device filtering without breaking your session. The logs clearly indicate that a request failed and system --user (most likely) exited with exit code 1. Maybe it’s related to upgrade from 10 to 11, but I don’t exactly how the user session is set up in Debian. FWIW our CI runs tests on Debian 10 and 11 vanilla images and things appear to be working correctly, so my guess is there’s something missing or misconfigured in your session.

6

the ubuntu bug tracking this is: https://bugs.launchpad.net/ubuntu/+source/snapd/+bug/1951491 It’s affecting xubuntu session for people connection with a solution that sets up a session, such as nomachine virtual desktop.