Yet another snapd.apparmor problem

BearGiles · January 22, 2025, 1:42am

Yet another problem with

ap-confine has elevated permissions and is not confined but should be. Refusing to continue to avoid permission escalation attacks
Please make sure that the snapd.apparmor service is enabled and started.

I’ve already done all of the regular stuff - verifying that apparmor and snapd.apparmor are enabled and running. They are, but both immediately exited without any type of error message.

There’s a weird twist though - I can start snaps, and I’m seeing plenty of apparmor messages in my logs. I can even get those messages to go away if I edit the file in /etc/apparmor.d, run aa-complain, and then run the snap as root instead of an unprivileged user.

So something is running even though the services say they’ve exited. I can launch some snaps (but probably ones marked ‘classic’). But I can’t run all - I get the ‘privilege escalation’ message.

Information requested in other reponses:

Two different systems, one is 24.04, one is 24.10.

Eris - 24.04

bgiles@eris:~$ snap version
snap    2.67
snapd   2.67
series  16
ubuntu  24.04
kernel  6.8.0-51-generic

bgiles@eris:~$ sudo aa-status | grep snap-confine
   /snap/core/17200/usr/lib/snapd/snap-confine
   /snap/core/17200/usr/lib/snapd/snap-confine//mount-namespace-capture-helper
   /snap/snapd/21759/usr/lib/snapd/snap-confine
   /snap/snapd/21759/usr/lib/snapd/snap-confine//mount-namespace-capture-helper
   /snap/snapd/23258/usr/lib/snapd/snap-confine
   /snap/snapd/23258/usr/lib/snapd/snap-confine//mount-namespace-capture-helper
   /snap/snapd/23545/usr/lib/snapd/snap-confine
   /snap/snapd/23545/usr/lib/snapd/snap-confine//mount-namespace-capture-helper
   /usr/lib/snapd/snap-confine
   /usr/lib/snapd/snap-confine//mount-namespace-capture-helper
   /usr/bin/snap//null-/snap/snapd/23545/usr/bin/snap//null-/snap/snapd/23545/usr/lib/snapd/snap-confine
   /usr/bin/snap//null-/snap/snapd/23545/usr/lib/snapd/snap-confine

bgiles@eris:~$ snap debug confinement
strict

bgiles@eris:~$ snap debug sandbox-features
apparmor:             kernel:caps kernel:dbus kernel:domain kernel:domain:attach_conditions kernel:file kernel:io_uring kernel:ipc kernel:mount kernel:namespaces kernel:network kernel:network_v8 kernel:policy kernel:policy:permstable32:allow kernel:policy:permstable32:audit kernel:policy:permstable32:complain kernel:policy:permstable32:cond kernel:policy:permstable32:deny kernel:policy:permstable32:hide kernel:policy:permstable32:kill kernel:policy:permstable32:label kernel:policy:permstable32:prompt kernel:policy:permstable32:quiet kernel:policy:permstable32:subtree kernel:policy:permstable32:tag kernel:policy:permstable32:xindex kernel:policy:unconfined_restrictions kernel:policy:versions kernel:ptrace kernel:query kernel:query:label kernel:rlimit kernel:signal parser:allow-all parser:cap-audit-read parser:cap-bpf parser:include-if-exists parser:io-uring parser:mqueue parser:prompt parser:qipcrtr-socket parser:snapd-internal parser:unconfined parser:unsafe parser:userns parser:xdp policy:default support-level:full
confinement-options:  classic devmode strict
dbus:                 mediated-bus-access
kmod:                 mediated-modprobe
mount:                layouts mount-namespace per-snap-persistency per-snap-profiles per-snap-updates per-snap-user-profiles stale-base-invalidation
seccomp:              bpf-actlog bpf-argument-filtering kernel:allow kernel:errno kernel:kill_process kernel:kill_thread kernel:log kernel:trace kernel:trap kernel:user_notif
udev:                 device-cgroup-v2 device-filtering tagging

bgiles@eris:~$ SNAPD_DEBUG=1 SNAP_CONFINE_DEBUG=1 snap run hello-world
2025/01/21 18:41:16.454214 logger.go:99: DEBUG: restarting into "/snap/snapd/current/usr/bin/snap"
2025/01/21 18:41:16.464447 logger.go:99: DEBUG: -- snap startup {"stage":"start", "time":"1737510076.464445"}
2025/01/21 18:41:16.464971 logger.go:99: DEBUG: checking internal apparmor_parser candidate at /snap/snapd/23545/usr/lib/snapd/apparmor_parser
2025/01/21 18:41:16.471095 logger.go:99: DEBUG: executing snap-confine from /snap/snapd/23545/usr/lib/snapd/snap-confine
2025/01/21 18:41:16.473664 logger.go:99: DEBUG: SELinux not enabled
2025/01/21 18:41:16.475897 logger.go:99: DEBUG: creating transient scope snap.hello-world.hello-world
2025/01/21 18:41:16.476770 logger.go:99: DEBUG: using session bus
2025/01/21 18:41:16.478504 logger.go:99: DEBUG: create transient scope job: /org/freedesktop/systemd1/job/20890
2025/01/21 18:41:16.492575 logger.go:99: DEBUG: job result is "done"
2025/01/21 18:41:16.492593 logger.go:99: DEBUG: transient scope snap.hello-world.hello-world-9132572d-10dd-4f64-bdc5-056f567db907.scope created
2025/01/21 18:41:16.492842 logger.go:99: DEBUG: waited 16.026628ms for tracking
2025/01/21 18:41:16.492860 logger.go:99: DEBUG: -- snap startup {"stage":"snap to snap-confine", "time":"1737510076.492855"}
DEBUG: -- snap startup {"stage":"snap-confine enter", "time":"1737510076.495247"}
DEBUG: SNAP_MOUNT_DIR (probed): /snap
DEBUG: umask reset, old umask was   02
DEBUG: security tag: snap.hello-world.hello-world
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: /usr/bin/snap
DEBUG: apparmor mode is: complain
snap-confine has elevated permissions and is not confined but should be. Refusing to continue to avoid permission escalation attacks
Please make sure that the snapd.apparmor service is enabled and started.

Chaos - 24.10

bgiles@chaos:/etc/apparmor$ snap version
snap    2.66.1+24.10
snapd   2.66.1+24.10
series  16
ubuntu  24.10
kernel  6.11.0-13-generic

bgiles@chaos:/etc/apparmor$ sudo aa-status | grep snap-confine
   /snap/core/17200/usr/lib/snapd/snap-confine
   /snap/core/17200/usr/lib/snapd/snap-confine//mount-namespace-capture-helper
   /snap/snapd/23258/usr/lib/snapd/snap-confine
   /snap/snapd/23258/usr/lib/snapd/snap-confine//mount-namespace-capture-helper
   /snap/snapd/23545/usr/lib/snapd/snap-confine
   /snap/snapd/23545/usr/lib/snapd/snap-confine//mount-namespace-capture-helper
   /usr/lib/snapd/snap-confine
   /usr/lib/snapd/snap-confine//mount-namespace-capture-helper

bgiles@chaos:/etc/apparmor$ snap debug confinement
strict

bgiles@chaos:/etc/apparmor$ snap debug sandbox-features
apparmor:             kernel:caps kernel:dbus kernel:domain kernel:domain:attach_conditions kernel:file kernel:io_uring kernel:ipc kernel:mount kernel:namespaces kernel:network kernel:network_v8 kernel:policy kernel:policy:notify kernel:policy:notify:user:file kernel:policy:permstable32:allow kernel:policy:permstable32:audit kernel:policy:permstable32:complain kernel:policy:permstable32:cond kernel:policy:permstable32:deny kernel:policy:permstable32:hide kernel:policy:permstable32:kill kernel:policy:permstable32:label kernel:policy:permstable32:prompt kernel:policy:permstable32:quiet kernel:policy:permstable32:subtree kernel:policy:permstable32:tag kernel:policy:permstable32:xindex kernel:policy:unconfined_restrictions kernel:policy:versions kernel:ptrace kernel:query kernel:query:label kernel:rlimit kernel:signal parser:allow-all parser:cap-audit-read parser:cap-bpf parser:include-if-exists parser:io-uring parser:mqueue parser:prompt parser:qipcrtr-socket parser:unconfined parser:unsafe parser:userns parser:xdp policy:default support-level:full
confinement-options:  classic devmode strict
dbus:                 mediated-bus-access
kmod:                 mediated-modprobe
mount:                layouts mount-namespace per-snap-persistency per-snap-profiles per-snap-updates per-snap-user-profiles stale-base-invalidation
seccomp:              bpf-actlog bpf-argument-filtering kernel:allow kernel:errno kernel:kill_process kernel:kill_thread kernel:log kernel:trace kernel:trap kernel:user_notif
udev:                 device-cgroup-v2 device-filtering tagging

bgiles@chaos:/etc/apparmor$ SNAPD_DEBUG=1 SNAP_CONFINE_DEBUG=1 snap run hello-world
2025/01/21 18:42:08.561895 logger.go:99: DEBUG: snap (at "/snap/snapd/current") is older ("2.66.1") than distribution package ("2.66.1+24.10")
2025/01/21 18:42:08.568895 logger.go:99: DEBUG: -- snap startup {"stage":"start", "time":"1737510128.568877"}
2025/01/21 18:42:08.570352 logger.go:99: DEBUG: checking distro apparmor_parser at /usr/sbin/apparmor_parser
2025/01/21 18:42:08.570398 logger.go:99: DEBUG: apparmor 4.0 ABI detected but ignored
2025/01/21 18:42:08.587176 logger.go:99: DEBUG: executing snap-confine from /usr/lib/snapd/snap-confine
2025/01/21 18:42:08.591292 logger.go:99: DEBUG: SELinux not enabled
2025/01/21 18:42:08.591875 logger.go:99: DEBUG: creating transient scope snap.hello-world.hello-world
2025/01/21 18:42:08.594145 logger.go:99: DEBUG: using session bus
2025/01/21 18:42:08.602839 logger.go:99: DEBUG: create transient scope job: /org/freedesktop/systemd1/job/17156
2025/01/21 18:42:08.629614 logger.go:99: DEBUG: job result is "done"
2025/01/21 18:42:08.629707 logger.go:99: DEBUG: transient scope snap.hello-world.hello-world-6d6bff2c-2df1-4151-b3aa-9a14fe912d9d.scope created
2025/01/21 18:42:08.630396 logger.go:99: DEBUG: waited 35.930265ms for tracking
2025/01/21 18:42:08.630442 logger.go:99: DEBUG: -- snap startup {"stage":"snap to snap-confine", "time":"1737510128.630435"}
DEBUG: -- snap startup {"stage":"snap-confine enter", "time":"1737510128.634765"}
DEBUG: SNAP_MOUNT_DIR (probed): /snap
DEBUG: umask reset, old umask was   02
DEBUG: security tag: snap.hello-world.hello-world
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: /usr/bin/snap
DEBUG: apparmor mode is: complain
snap-confine has elevated permissions and is not confined but should be. Refusing to continue to avoid permission escalation attacks
Please make sure that the snapd.apparmor service is enabled and started.

mborzecki1 · January 22, 2025, 7:09am

This isn’t right though. The transition to /usr/lib/snapd/snap-confine (or /snap/snapd/23545/usr/lib/snapd/snap-confine from the first log) is supposed to happen automatically on exec and is handled by apparmor kernel parts.

zyga · January 22, 2025, 9:23am

Can you tell us more about those systems? Are they bare metal, virtual machines, containers? Are you using something like zfs or btrfs? I have dozens of boxes running 24.04 and 24.10 and I have never experienced this failure

zyga · January 22, 2025, 10:02am

Can you please check if any files in /etc/apparmor.d reference /usr/bin/snap (a simple grep should do). I wonder if something is providing a confinement profile for path-attached /usr/bin/snap so by the time we run snap-confine, profile transition does NOT occur.

Could you please pastebin the output of dpkg --get-selections?

BearGiles · January 22, 2025, 11:17pm

Eris (Ubuntu 24.04)

Nothing (I had manually removed sssd)

Chaos (Ubuntu 24.10)

bgiles@chaos:~$ find /etc/apparmor.d -type l
/etc/apparmor.d/force-complain/usr.sbin.sssd

Both are pretty much stock Ubuntu systems configured for java and devops development. Chaos is an old Dell Optiplex and Eris is a homebuilt AMD Ryzen (AM4 socket).

It looks like I’ll have to link the files above - I don’t see a way to upload anything but an image here.

I was planning to create some new virtual machines soon - one under virtualbox 7 and one under proxmox - and I’ll check whether snapd.apparmor is still running.

Also… it occurred to me last night that I’ve seen problems for a while. E.g., I remember needing to add something to /etc/apparmor.d for cups to start working again, and I’ve seen warnings from ‘brave’ for a long time.

I nuked a bunch of old log files last night… but I can check other systems to see when I first started seeing these apparmor errors.

BearGiles · January 22, 2025, 11:42pm

Here are the requested files.

I’ll make the repo private in a few days - I’m just a little paranoid about revealing so much.

https://github.com/beargiles/snapd.apparmor

P.S., something changed over the past few days so ‘intellij-idea-*’ no longer loads - same error. However brave, cups, etc., are still running. (For now.)

That might be due to trying to clean up the list of snaps - deleting unused or rarely used apps, etc. I’ve looked at the long list of command line options and didn’t find anything equivalent to a ‘apt-get install --reinstall pkgname’ - it looks like the only option is fully removing a snap and then reinstalling it and that can have secondary effects beyond just (possibly) losing configuration details.

BearGiles · January 23, 2025, 1:54am

I’ve updated that repo with information on a third system. This is also Ubuntu 24.04.1, but I haven’t updated it in the last month since it’s a laptop I typically only use during meetups. It shows the same behavior discussed above.

I’ve captured all(?) of the previously requested information, plus some ‘journalctl -xeu’ results.

BearGiles · January 23, 2025, 8:23pm

Sigh. Virtualbox 7.1 (from Oraclee PPA, not official Debian/Ubuntu package).

Minimal 24.10 desktop install - I choose ‘essentials’ instead of ‘full’. However I did also download media drivers, etc.

Same problem. Apparmor and snap.apparmor start but immediately exit (“successfully”). However I still see apparmor messages in syslog, and some of them are denials related to snap-confine.

This problem occurs with both the ISO install and a subsequent apt-get update/upgrade and rebeoot cycle. (I’ve also installed guest additions but that didn’t change anything here.)

I had hoped that this problem is due to a third-party snap - I saw a similar problem that was tracked down to this - but this is default minimal system.

I’ll still be installing 24.10 on a proxmox instance. This isn’t bare metal but it removes a lot of the shims used by virtualbox (e.g., custom network and display drivers). I don’t expect a different result - I mostly use various distros’ ‘server’ versions but will sometimes use a remote desktop for improved security, etc.

Snaps:

bgiles@u2410base:~/.ssh$ snap list
Name                       Version          Rev    Tracking         Publisher   Notes
bare                       1.0              5      latest/stable    canonical✓  base
core22                     20241119         1722   latest/stable    canonical✓  base
desktop-security-center    0+git.9d68ad0    43     1/stable/…       canonical✓  -
firefox                    134.0.2-1        5647   latest/stable/…  mozilla✓    -
firmware-updater           0+git.7983059    147    1/stable/…       canonical✓  -
gnome-42-2204              0+git.38ea591    202    latest/stable/…  canonical✓  -
gtk-common-themes          0.1-81-g442e511  1535   latest/stable/…  canonical✓  -
prompting-client           0+git.e2e32ad    80     1/stable/…       canonical✓  -
snap-store                 0+git.7a3a49a6   1248   2/stable/…       canonical✓  -
snapd                      2.67             23545  latest/stable    canonical✓  snapd
snapd-desktop-integration  0.9              253    latest/stable/…  canonical✓  -

dpkg --get-selections has over 1600 entries. (Sigh - I remember when slackware fit on 6 floppies.) I could toss it on my github pages but I don’t know if there’s any value in that since this is the default setup.

bgiles@u2410base:~/.ssh$ grep -i apparmor /var/log/syslog | grep -i denied
2025-01-23T19:03:46.227235+00:00 u2410base kernel: audit: type=1400 audit(1737659026.226:168): apparmor="DENIED" operation="open" class="file" profile="snap-update-ns.firefox" name="/usr/local/share/" pid=2106 comm="6" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
2025-01-23T19:03:54.127075+00:00 u2410base kernel: audit: type=1400 audit(1737659034.126:169): apparmor="DENIED" operation="capable" class="cap" profile="/usr/lib/snapd/snap-confine" pid=2342 comm="snap-confine" capability=12  capname="net_admin"
2025-01-23T19:03:54.127151+00:00 u2410base kernel: audit: type=1400 audit(1737659034.126:170): apparmor="DENIED" operation="capable" class="cap" profile="/usr/lib/snapd/snap-confine" pid=2342 comm="snap-confine" capability=38  capname="perfmon"
2025-01-23T19:03:54.261102+00:00 u2410base kernel: audit: type=1400 audit(1737659034.260:171): apparmor="DENIED" operation="open" class="file" profile="snap-update-ns.prompting-client" name="/proc/2369/maps" pid=2369 comm="5" requested_mask="r" denied_mask="r" fsuid=120 ouid=0
2025-01-23T19:04:01.272079+00:00 u2410base kernel: audit: type=1400 audit(1737659041.271:172): apparmor="DENIED" operation="capable" class="cap" profile="/usr/lib/snapd/snap-confine" pid=2419 comm="snap-confine" capability=12  capname="net_admin"
2025-01-23T19:04:01.272094+00:00 u2410base kernel: audit: type=1400 audit(1737659041.271:173): apparmor="DENIED" operation="capable" class="cap" profile="/usr/lib/snapd/snap-confine" pid=2419 comm="snap-confine" capability=38  capname="perfmon"
2025-01-23T19:04:01.419083+00:00 u2410base kernel: audit: type=1400 audit(1737659041.418:174): apparmor="DENIED" operation="open" class="file" profile="snap-update-ns.snapd-desktop-integration" name="/proc/2445/maps" pid=2445 comm="5" requested_mask="r" denied_mask="r" fsuid=120 ouid=0
2025-01-23T19:04:06.284770+00:00 u2410base kernel: audit: type=1400 audit(1737659046.283:175): apparmor="DENIED" operation="open" class="file" profile="snap-update-ns.snapd-desktop-integration" name="/proc/2626/maps" pid=2626 comm="5" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T19:04:06.284780+00:00 u2410base kernel: audit: type=1400 audit(1737659046.284:176): apparmor="DENIED" operation="open" class="file" profile="snap-update-ns.prompting-client" name="/proc/2625/maps" pid=2625 comm="5" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T19:04:07.648318+00:00 u2410base kernel: audit: type=1400 audit(1737659047.647:177): apparmor="DENIED" operation="open" class="file" profile="snap.prompting-client.daemon" name="/sys/fs/cgroup/user.slice/user-1000.slice/user@1000.service/app.slice/cpu.max" pid=2499 comm="prompting-clien" requested_mask="r" denied_mask="r" fsuid=1000 ouid=1000
2025-01-23T19:04:07.648331+00:00 u2410base kernel: audit: type=1400 audit(1737659047.647:178): apparmor="DENIED" operation="open" class="file" profile="snap.prompting-client.daemon" name="/sys/fs/cgroup/user.slice/user-1000.slice/user@1000.service/cpu.max" pid=2499 comm="prompting-clien" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T19:04:07.648332+00:00 u2410base kernel: audit: type=1400 audit(1737659047.647:179): apparmor="DENIED" operation="open" class="file" profile="snap.prompting-client.daemon" name="/sys/fs/cgroup/user.slice/user-1000.slice/cpu.max" pid=2499 comm="prompting-clien" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T19:04:07.648333+00:00 u2410base kernel: audit: type=1400 audit(1737659047.647:180): apparmor="DENIED" operation="open" class="file" profile="snap.prompting-client.daemon" name="/sys/fs/cgroup/user.slice/cpu.max" pid=2499 comm="prompting-clien" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T19:04:10.859525+00:00 u2410base kernel: audit: type=1400 audit(1737659050.857:181): apparmor="DENIED" operation="open" class="file" profile="snap-update-ns.snapd-desktop-integration" name="/proc/3579/maps" pid=3579 comm="5" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T12:07:31.329631-07:00 u2410base kernel: audit: type=1400 audit(1737659251.328:167): apparmor="DENIED" operation="capable" class="cap" profile="/usr/sbin/cupsd" pid=1389 comm="cupsd" capability=12  capname="net_admin"
2025-01-23T12:07:31.926651-07:00 u2410base kernel: audit: type=1400 audit(1737659251.925:168): apparmor="DENIED" operation="capable" class="cap" profile="/usr/lib/snapd/snap-confine" pid=1443 comm="snap-confine" capability=12  capname="net_admin"
2025-01-23T12:07:31.926833-07:00 u2410base kernel: audit: type=1400 audit(1737659251.925:169): apparmor="DENIED" operation="capable" class="cap" profile="/usr/lib/snapd/snap-confine" pid=1443 comm="snap-confine" capability=38  capname="perfmon"
2025-01-23T12:07:31.930975-07:00 u2410base kernel: audit: type=1400 audit(1737659251.929:170): apparmor="DENIED" operation="capable" class="cap" profile="/usr/lib/snapd/snap-confine" pid=1445 comm="snap-confine" capability=12  capname="net_admin"
2025-01-23T12:07:31.932835-07:00 u2410base kernel: audit: type=1400 audit(1737659251.929:171): apparmor="DENIED" operation="capable" class="cap" profile="/usr/lib/snapd/snap-confine" pid=1445 comm="snap-confine" capability=38  capname="perfmon"
2025-01-23T12:07:32.252659-07:00 u2410base kernel: audit: type=1400 audit(1737659252.251:172): apparmor="DENIED" operation="open" class="file" profile="snap-update-ns.prompting-client" name="/proc/1537/maps" pid=1537 comm="5" requested_mask="r" denied_mask="r" fsuid=120 ouid=0
2025-01-23T12:07:32.267639-07:00 u2410base kernel: audit: type=1400 audit(1737659252.266:173): apparmor="DENIED" operation="open" class="file" profile="snap-update-ns.snapd-desktop-integration" name="/proc/1544/maps" pid=1544 comm="5" requested_mask="r" denied_mask="r" fsuid=120 ouid=0
2025-01-23T12:14:36.593732-07:00 u2410base kernel: audit: type=1400 audit(1737659676.592:174): apparmor="DENIED" operation="open" class="file" profile="snap-update-ns.snapd-desktop-integration" name="/proc/2245/maps" pid=2245 comm="5" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T12:14:36.602756-07:00 u2410base kernel: audit: type=1400 audit(1737659676.601:175): apparmor="DENIED" operation="open" class="file" profile="snap-update-ns.prompting-client" name="/proc/2250/maps" pid=2250 comm="5" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T12:14:37.768721-07:00 u2410base kernel: audit: type=1400 audit(1737659677.767:176): apparmor="DENIED" operation="open" class="file" profile="snap.prompting-client.daemon" name="/sys/fs/cgroup/user.slice/user-1000.slice/user@1000.service/app.slice/cpu.max" pid=2108 comm="prompting-clien" requested_mask="r" denied_mask="r" fsuid=1000 ouid=1000
2025-01-23T12:14:37.768729-07:00 u2410base kernel: audit: type=1400 audit(1737659677.767:177): apparmor="DENIED" operation="open" class="file" profile="snap.prompting-client.daemon" name="/sys/fs/cgroup/user.slice/user-1000.slice/user@1000.service/cpu.max" pid=2108 comm="prompting-clien" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T12:14:37.768730-07:00 u2410base kernel: audit: type=1400 audit(1737659677.767:178): apparmor="DENIED" operation="open" class="file" profile="snap.prompting-client.daemon" name="/sys/fs/cgroup/user.slice/user-1000.slice/cpu.max" pid=2108 comm="prompting-clien" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T12:14:37.768730-07:00 u2410base kernel: audit: type=1400 audit(1737659677.767:179): apparmor="DENIED" operation="open" class="file" profile="snap.prompting-client.daemon" name="/sys/fs/cgroup/user.slice/cpu.max" pid=2108 comm="prompting-clien" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T12:14:40.128264-07:00 u2410base kernel: audit: type=1400 audit(1737659680.126:180): apparmor="DENIED" operation="open" class="file" profile="snap-update-ns.snapd-desktop-integration" name="/proc/3065/maps" pid=3065 comm="5" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T12:16:10.687856-07:00 u2410base kernel: audit: type=1400 audit(1737659770.685:172): apparmor="DENIED" operation="capable" class="cap" profile="/usr/lib/snapd/snap-confine" pid=2055 comm="snap-confine" capability=12  capname="net_admin"
2025-01-23T12:16:10.687857-07:00 u2410base kernel: audit: type=1400 audit(1737659770.685:173): apparmor="DENIED" operation="capable" class="cap" profile="/usr/lib/snapd/snap-confine" pid=2055 comm="snap-confine" capability=38  capname="perfmon"
2025-01-23T12:16:10.701785-07:00 u2410base kernel: audit: type=1400 audit(1737659770.700:174): apparmor="DENIED" operation="open" class="file" profile="snap-update-ns.snapd-desktop-integration" name="/proc/2197/maps" pid=2197 comm="5" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T12:16:10.701791-07:00 u2410base kernel: audit: type=1400 audit(1737659770.700:175): apparmor="DENIED" operation="open" class="file" profile="snap-update-ns.prompting-client" name="/proc/2198/maps" pid=2198 comm="5" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T12:16:11.226745-07:00 u2410base kernel: audit: type=1400 audit(1737659771.225:176): apparmor="DENIED" operation="open" class="file" profile="snap.prompting-client.daemon" name="/sys/fs/cgroup/user.slice/user-1000.slice/user@1000.service/app.slice/cpu.max" pid=2054 comm="prompting-clien" requested_mask="r" denied_mask="r" fsuid=1000 ouid=1000
2025-01-23T12:16:11.226757-07:00 u2410base kernel: audit: type=1400 audit(1737659771.225:177): apparmor="DENIED" operation="open" class="file" profile="snap.prompting-client.daemon" name="/sys/fs/cgroup/user.slice/user-1000.slice/user@1000.service/cpu.max" pid=2054 comm="prompting-clien" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T12:16:11.226757-07:00 u2410base kernel: audit: type=1400 audit(1737659771.225:178): apparmor="DENIED" operation="open" class="file" profile="snap.prompting-client.daemon" name="/sys/fs/cgroup/user.slice/user-1000.slice/cpu.max" pid=2054 comm="prompting-clien" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T12:16:11.226758-07:00 u2410base kernel: audit: type=1400 audit(1737659771.225:179): apparmor="DENIED" operation="open" class="file" profile="snap.prompting-client.daemon" name="/sys/fs/cgroup/user.slice/cpu.max" pid=2054 comm="prompting-clien" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T12:16:13.732377-07:00 u2410base kernel: audit: type=1400 audit(1737659773.730:180): apparmor="DENIED" operation="open" class="file" profile="snap-update-ns.snapd-desktop-integration" name="/proc/2892/maps" pid=2892 comm="5" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T12:24:57.853966-07:00 u2410base kernel: audit: type=1400 audit(1737660297.851:172): apparmor="DENIED" operation="open" class="file" profile="snap-update-ns.snapd-desktop-integration" name="/proc/2165/maps" pid=2165 comm="5" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T12:24:57.857675-07:00 u2410base kernel: audit: type=1400 audit(1737660297.856:173): apparmor="DENIED" operation="open" class="file" profile="snap-update-ns.prompting-client" name="/proc/2171/maps" pid=2171 comm="5" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T12:24:58.386667-07:00 u2410base kernel: audit: type=1400 audit(1737660298.385:174): apparmor="DENIED" operation="open" class="file" profile="snap.prompting-client.daemon" name="/sys/fs/cgroup/user.slice/user-1000.slice/user@1000.service/app.slice/cpu.max" pid=2040 comm="prompting-clien" requested_mask="r" denied_mask="r" fsuid=1000 ouid=1000
2025-01-23T12:24:58.386709-07:00 u2410base kernel: audit: type=1400 audit(1737660298.385:175): apparmor="DENIED" operation="open" class="file" profile="snap.prompting-client.daemon" name="/sys/fs/cgroup/user.slice/user-1000.slice/user@1000.service/cpu.max" pid=2040 comm="prompting-clien" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T12:24:58.386744-07:00 u2410base kernel: audit: type=1400 audit(1737660298.385:176): apparmor="DENIED" operation="open" class="file" profile="snap.prompting-client.daemon" name="/sys/fs/cgroup/user.slice/user-1000.slice/cpu.max" pid=2040 comm="prompting-clien" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T12:24:58.386761-07:00 u2410base kernel: audit: type=1400 audit(1737660298.385:177): apparmor="DENIED" operation="open" class="file" profile="snap.prompting-client.daemon" name="/sys/fs/cgroup/user.slice/cpu.max" pid=2040 comm="prompting-clien" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T12:25:00.881654-07:00 u2410base kernel: audit: type=1400 audit(1737660300.880:178): apparmor="DENIED" operation="capable" class="cap" profile="/usr/lib/snapd/snap-confine" pid=2812 comm="snap-confine" capability=12  capname="net_admin"
2025-01-23T12:25:00.884650-07:00 u2410base kernel: audit: type=1400 audit(1737660300.883:179): apparmor="DENIED" operation="capable" class="cap" profile="/usr/lib/snapd/snap-confine" pid=2812 comm="snap-confine" capability=38  capname="perfmon"
2025-01-23T12:25:00.893652-07:00 u2410base kernel: audit: type=1400 audit(1737660300.892:180): apparmor="DENIED" operation="open" class="file" profile="snap-update-ns.snapd-desktop-integration" name="/proc/2829/maps" pid=2829 comm="5" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
2025-01-23T12:25:21.311707-07:00 u2410base kernel: audit: type=1400 audit(1737660321.310:181): apparmor="DENIED" operation="connect" class="file" profile="/usr/bin/wsdd" name="/run/uuidd/request" pid=3149 comm="python3" requested_mask="w" denied_mask="w" fsuid=1000 ouid=0
2025-01-23T12:25:21.311720-07:00 u2410base kernel: audit: type=1400 audit(1737660321.310:182): apparmor="DENIED" operation="mknod" class="file" profile="/usr/bin/wsdd" name="/var/lib/libuuid/clock.txt" pid=3149 comm="python3" requested_mask="c" denied_mask="c" fsuid=1000 ouid=1000
2025-01-23T12:25:22.319745-07:00 u2410base kernel: audit: type=1400 audit(1737660322.318:183): apparmor="DENIED" operation="connect" class="file" profile="/usr/bin/wsdd" name="/run/uuidd/request" pid=3149 comm="python3" requested_mask="w" denied_mask="w" fsuid=1000 ouid=0
2025-01-23T12:25:26.981878-07:00 u2410base kernel: audit: type=1400 audit(1737660326.980:184): apparmor="DENIED" operation="connect" class="file" profile="/usr/bin/wsdd" name="/run/uuidd/request" pid=3149 comm="python3" requested_mask="w" denied_mask="w" fsuid=1000 ouid=0
2025-01-23T12:32:38.904877-07:00 u2410base kernel: audit: type=1400 audit(1737660758.902:403): apparmor="DENIED" operation="capable" class="cap" profile="/snap/snapd/23545/usr/lib/snapd/snap-confine" pid=20751 comm="snap-confine" capability=12  capname="net_admin"
2025-01-23T12:32:38.924729-07:00 u2410base kernel: audit: type=1400 audit(1737660758.922:404): apparmor="DENIED" operation="capable" class="cap" profile="/snap/snapd/23545/usr/lib/snapd/snap-confine" pid=20751 comm="snap-confine" capability=4  capname="fsetid"
2025-01-23T12:32:56.224888-07:00 u2410base kernel: audit: type=1400 audit(1737660776.222:405): apparmor="DENIED" operation="capable" class="cap" profile="/snap/snapd/23545/usr/lib/snapd/snap-confine" pid=20944 comm="snap-confine" capability=12  capname="net_admin"
2025-01-23T12:32:56.241493-07:00 u2410base kernel: audit: type=1400 audit(1737660776.238:406): apparmor="DENIED" operation="capable" class="cap" profile="/snap/snapd/23545/usr/lib/snapd/snap-confine" pid=20944 comm="snap-confine" capability=4  capname="fsetid"
2025-01-23T12:39:25.265868-07:00 u2410base kernel: audit: type=1400 audit(1737661165.264:169): apparmor="DENIED" operation="capable" class="cap" profile="/snap/snapd/23545/usr/lib/snapd/snap-confine" pid=1885 comm="snap-confine" capability=12  capname="net_admin"
2025-01-23T12:39:25.265912-07:00 u2410base kernel: audit: type=1400 audit(1737661165.264:170): apparmor="DENIED" operation="capable" class="cap" profile="/snap/snapd/23545/usr/lib/snapd/snap-confine" pid=1885 comm="snap-confine" capability=38  capname="perfmon"
2025-01-23T12:39:25.269379-07:00 u2410base kernel: audit: type=1400 audit(1737661165.266:171): apparmor="DENIED" operation="capable" class="cap" profile="/snap/snapd/23545/usr/lib/snapd/snap-confine" pid=1885 comm="snap-confine" capability=4  capname="fsetid"
2025-01-23T12:39:25.279392-07:00 u2410base kernel: audit: type=1400 audit(1737661165.278:172): apparmor="DENIED" operation="capable" class="cap" profile="/snap/snapd/23545/usr/lib/snapd/snap-confine" pid=1883 comm="snap-confine" capability=12  capname="net_admin"
2025-01-23T12:39:25.280313-07:00 u2410base kernel: audit: type=1400 audit(1737661165.279:173): apparmor="DENIED" operation="capable" class="cap" profile="/snap/snapd/23545/usr/lib/snapd/snap-confine" pid=1883 comm="snap-confine" capability=38  capname="perfmon"
2025-01-23T12:53:45.898358-07:00 u2410base kernel: audit: type=1400 audit(1737662025.894:174): apparmor="DENIED" operation="connect" class="file" profile="/usr/bin/wsdd" name="/run/uuidd/request" pid=6449 comm="python3" requested_mask="w" denied_mask="w" fsuid=1000 ouid=0
2025-01-23T12:53:45.898359-07:00 u2410base kernel: audit: type=1400 audit(1737662025.894:175): apparmor="DENIED" operation="mknod" class="file" profile="/usr/bin/wsdd" name="/var/lib/libuuid/clock.txt" pid=6449 comm="python3" requested_mask="c" denied_mask="c" fsuid=1000 ouid=1000
2025-01-23T12:53:46.898381-07:00 u2410base kernel: audit: type=1400 audit(1737662026.896:176): apparmor="DENIED" operation="connect" class="file" profile="/usr/bin/wsdd" name="/run/uuidd/request" pid=6449 comm="python3" requested_mask="w" denied_mask="w" fsuid=1000 ouid=0
2025-01-23T12:53:48.620322-07:00 u2410base kernel: audit: type=1400 audit(1737662028.618:177): apparmor="DENIED" operation="connect" class="file" profile="/usr/bin/wsdd" name="/run/uuidd/request" pid=6449 comm="python3" requested_mask="w" denied_mask="w" fsuid=1000 ouid=0
2025-01-23T12:55:25.845228-07:00 u2410base kernel: audit: type=1400 audit(1737662125.843:169): apparmor="DENIED" operation="capable" class="cap" profile="/snap/snapd/23545/usr/lib/snapd/snap-confine" pid=1888 comm="snap-confine" capability=12  capname="net_admin"
2025-01-23T12:55:25.846206-07:00 u2410base kernel: audit: type=1400 audit(1737662125.845:170): apparmor="DENIED" operation="capable" class="cap" profile="/snap/snapd/23545/usr/lib/snapd/snap-confine" pid=1888 comm="snap-confine" capability=38  capname="perfmon"
2025-01-23T12:55:25.849210-07:00 u2410base kernel: audit: type=1400 audit(1737662125.847:171): apparmor="DENIED" operation="capable" class="cap" profile="/snap/snapd/23545/usr/lib/snapd/snap-confine" pid=1887 comm="snap-confine" capability=12  capname="net_admin"
2025-01-23T12:55:25.849217-07:00 u2410base kernel: audit: type=1400 audit(1737662125.847:172): apparmor="DENIED" operation="capable" class="cap" profile="/snap/snapd/23545/usr/lib/snapd/snap-confine" pid=1887 comm="snap-confine" capability=38  capname="perfmon"
2025-01-23T12:55:25.856237-07:00 u2410base kernel: audit: type=1400 audit(1737662125.854:173): apparmor="DENIED" operation="capable" class="cap" profile="/snap/snapd/23545/usr/lib/snapd/snap-confine" pid=1888 comm="snap-confine" capability=4  capname="fsetid"

BearGiles · January 23, 2025, 11:55pm

This is getting ridiculous. HP workstation (Z440 - older but functional). Proxmox 8.0.3 on this cluster - latest release is 8.3.

I installed the default version of both 24.04 (not 24.04.1) and 24.10 desktops. No extra drivers, etc., just the basics you get when you accept all of the defaults.

BOTH systems still show these errors.

It’s impossible that this has gone unnoticed since the 24.04 release. But I also can’t think of anything more generic than this setup - I could probably throw a spare disk in one of my Dell Optiplex micros and do a bare install but I can’t see that making a difference. Proxmox is heavily used, and while professionals may prefer the server versions of the distros I know that many homelabbers still use the desktop versions for everything. Any fundamental problems would have been found a long time ago.

(For completeness I’ll also run desktop environments in remote VMs - but I’m actually using them as remote desktops that I connect to via RDP. It’s for security - one VM only used for banking, etc. However I prefer server versions and avoiding 4k installed packages.)

mborzecki1 · January 24, 2025, 8:52am

sorry, which errors? The ones with denials are expected. Your original problem however was that you were unable to run any snaps. As I myself and @zyga pointed out there was an issue with AppArmor profile transition. Can you run snap applications at this point or not? Judging by the denials, I’m guessing that the answer is yes.

BearGiles · January 24, 2025, 5:54pm

I can run some, not all, and more importantly some have stopped working and now produce the same error message about excessive permissions. Specifically intellij-idea-java, but I’ve already removed a number of less frequently used snaps while investigating this.

This had been working under 24.04, stopped, and after trying a few things I bumped to 24.10 in hope that would repair any missing files. No difference.

I was going to add that both cups and brave continue to work even after multiple reboots - but I now see the same error even though brave is currently running and has several tabs open.

That made me wonder if there’s a difference between the launcher and the command line - but the launcher just quietly fails. I’ll check syslog in a moment - at the moment it looks like some ad in chrome is trying very, very hard to call home and I’m currently using it to edit this page.

BearGiles · January 24, 2025, 6:12pm

This is getting weird - I just used ‘flameshot’ (see above) but now get ‘unable to capture the screen’ errors. This suggests (to me) that there may be something mucking with systemd given the error message I saw in syslog. I’m going to try a reboot and launching the intellij immediately after the system is back up just to see if that makes a difference.

Back to the main point - it’s the same error message I see when I tried running the app at the command line.

bgiles@eris2:~$ tail -18 /var/log/syslog
2025-01-24T17:55:48.127048+00:00 eris2 google-chrome.desktop[40408]: [40452:40467:0124/105548.126682:ERROR:ssl_client_socket_impl.cc(876)] handshake failed; returned -1, SSL error code 1, net_error -202
2025-01-24T17:55:48.129672+00:00 eris2 google-chrome.desktop[40408]: [40452:40467:0124/105548.129266:ERROR:ssl_client_socket_impl.cc(876)] handshake failed; returned -1, SSL error code 1, net_error -202
2025-01-24T17:55:58.322698+00:00 eris2 1password.desktop[573802]: #033[38;5;196mERROR#033[0m #033[38;5;196m2025-01-24T17:55:58.315+00:00#033[0m runtime-worker(ThreadId(2)) [1P:native-messaging/op-native-core-integration/src/connection_handler.rs:82] #033[38;5;196mmessage from b5x was None: EndConnection#033[0m
2025-01-24T17:55:58.327405+00:00 eris2 1password.desktop[573802]: #033[38;5;196mERROR#033[0m #033[38;5;196m2025-01-24T17:55:58.320+00:00#033[0m runtime-worker(ThreadId(2)) [1P:native-messaging/op-native-core-integration/src/connection_handler.rs:47] #033[38;5;196mDropping connection with b5x due to error handling incoming message: EndConnection#033[0m
2025-01-24T17:55:58.686726+00:00 eris2 systemd[6433]: app-gnome-google\x2dchrome-40402.scope: Consumed 2d 19h 21min 5.186s CPU time, 42.5G memory peak, 469.4M memory swap peak.
2025-01-24T17:56:47.815024+00:00 eris2 gnome-shell[9763]: libinput error: event9  - HID 0c45:7403: client bug: event processing lagging behind by 24ms, your system is too slow
2025-01-24T17:56:47.844376+00:00 eris2 dbus-daemon[6484]: apparmor="ALLOWED" operation="dbus_method_call"  bus="session" path="/org/freedesktop/systemd1" interface="org.freedesktop.systemd1.Manager" member="StartTransientUnit" mask="send" name="org.freedesktop.systemd1" pid=2060835 label="/usr/bin/snap" peer_pid=6433 peer_label="unconfined"
2025-01-24T17:56:47.855266+00:00 eris2 systemd[6433]: Started snap.intellij-idea-ultimate.intellij-idea-ultimate-4de4865c-7432-4a52-a2a6-599f83892903.scope.
2025-01-24T17:56:47.855401+00:00 eris2 dbus-daemon[6484]: apparmor="ALLOWED" operation="dbus_signal"  bus="session" path="/org/freedesktop/systemd1" interface="org.freedesktop.systemd1.Manager" member="JobRemoved" name=":1.4" mask="receive" pid=2060835 label="/usr/bin/snap" peer_pid=6433 peer_label="unconfined"
2025-01-24T17:56:47.858253+00:00 eris2 intellij-idea-ultimate_intellij-idea-ultimate.desktop[2060835]: snap-confine has elevated permissions and is not confined but should be. Refusing to continue to avoid permission escalation attacks
2025-01-24T17:56:47.858359+00:00 eris2 intellij-idea-ultimate_intellij-idea-ultimate.desktop[2060835]: Please make sure that the snapd.apparmor service is enabled and started.
2025-01-24T17:57:34.478092+00:00 eris2 systemd[6433]: Started app-gnome-org.flameshot.Flameshot-2061138.scope - Application launched by gnome-shell.
2025-01-24T17:57:35.125387+00:00 eris2 xdg-desktop-por[10425]: Failed to associate portal window with parent window 
2025-01-24T17:57:35.131513+00:00 eris2 xdg-desktop-por[10219]: Failed to show access dialog: GDBus.Error:org.freedesktop.DBus.Error.AccessDenied: GDBus.Error:org.freedesktop.DBus.Error.AccessDenied: Only the focused app is allowed to show a system access dialog
2025-01-24T17:57:35.167136+00:00 eris2 org.flameshot.Flameshot.desktop[2061138]: flameshot: error: Unable to capture screen
2025-01-24T17:57:35.178093+00:00 eris2 org.flameshot.Flameshot.desktop[2061138]: flameshot: error: Unable to capture screen
2025-01-24T17:57:35.279155+00:00 eris2 org.flameshot.Flameshot.desktop[2061138]: flameshot: info: Screenshot aborted.
2025-01-24T17:57:42.682283+00:00 eris2 systemd[6433]: Started app-gnome-org.flameshot.Flameshot-2061187.scope - Application launched by gnome-shell.

BearGiles · January 26, 2025, 7:14pm

I have a few more data points that strongly suggest this is caused by a routine update - think of the earlier problem tied to a GIS(?) snap overwriting a file.

I successfully installed and ran intellij on the new VMs. I don’t understand why apparmor is reporting those errors but I don’t care as long as I can run my critical apps.
I had mentioned that intellij abruptly stopped working on ‘chaos’ (24.10). A few days ago the same thing happened on ‘eris’ (24.08). I don’t think I did anything on the system - I tend to bounce between the two desktops - but there may have been routine software updates, etc.

Put all of this together and you see a situation where these snaps work and then they don’t. There must be a critical change in the software, probably in either snapd or apparmor, but posssibly systemd, etc. I don’t know why all vulnerable don’t stop working at the same time, esp. if there are system reboots during this period.

I might not be able to provide much additional information since intellij is so critical for me that I need to shift to a manually installed tarball. A few other snaps will also need to go back to their official PPA version since they simply can’t not work on the occasional times I need them. That means I could set up a cron job to take deep snapshots of snapd and apparmor but I probably won’t notice if any of the remaining apps stop working since I use them so rarely.

mborzecki1 · January 27, 2025, 7:46am

There’s still something off with your system. For instance, I don’t understand why you see this log:

2025-01-24T17:56:47.844376+00:00 eris2 dbus-daemon[6484]: 
apparmor="ALLOWED" operation="dbus_method_call" 
bus="session" path="/org/freedesktop/systemd1" interface="org.freedesktop.systemd1.Manager" 
member="StartTransientUnit" mask="send" 
name="org.freedesktop.systemd1" pid=2060835 label="/usr/bin/snap" 
peer_pid=6433 peer_label="unconfined"

There is no profile for /usr/bin/snap, so why is audit logging anything here?

Please attach the full outputs of the following commands:

find /etc/apparmor.d/ -ls | grep snap
find /var/lib/snapd/apparmor/ -ls
sudo aa-status | grep snap