/system.slice/cron.service is not a snap cgroup

caino · May 26, 2022, 3:38pm

Hello, I’ve a dotnet application running on Ubuntu Server 22.04 LTS (GNU/Linux 5.15.0-33-generic x86_64) that uses chromedriver and a cronjob to launch it.

All works fine when I’m logged in with SSH. The cronjob starts, the application do what it’s meant to do. When I logout the cronjob always fails.

I found it in /var/log/mail:

/system.slice/cron.service is not a snap cgroup

And this in /var/log/syslog:

May 26 16:49:04 vmi811203 kernel: [ 3504.260610] audit: type=1400 audit(1653576544.714:1687): apparmor="DENIED" operation="capable" profile="/snap/snapd/15904/usr/lib/snapd/snap-confine" pid=2193 comm="snap-confine" capability=12  capname="net_admin"
May 26 16:49:04 vmi811203 kernel: [ 3504.260619] audit: type=1400 audit(1653576544.714:1688): apparmor="DENIED" operation="capable" profile="/snap/snapd/15904/usr/lib/snapd/snap-confine" pid=2193 comm="snap-confine" capability=38  capname="perfmon"

Snap Version:

snap    2.55.5
snapd   2.55.5
series  16
ubuntu  22.04
kernel  5.15.0-33-generic

SNAPD_DEBUG=1 snap run chromium.chromedriver

2022/05/26 17:33:59.065793 tool_linux.go:204: DEBUG: restarting into "/snap/snapd/current/usr/bin/snap"
2022/05/26 17:33:59.092335 cmd_run.go:1035: DEBUG: executing snap-confine from /snap/snapd/15904/usr/lib/snapd/snap-confine
2022/05/26 17:33:59.093857 cmd_run.go:438: DEBUG: SELinux not enabled
2022/05/26 17:33:59.094320 tracking.go:46: DEBUG: creating transient scope snap.chromium.chromedriver
2022/05/26 17:33:59.095243 tracking.go:186: DEBUG: using session bus
2022/05/26 17:33:59.098074 tracking.go:319: DEBUG: create transient scope job: /org/freedesktop/systemd1/job/45
2022/05/26 17:33:59.098735 tracking.go:419: DEBUG: job result is "done"
2022/05/26 17:33:59.098753 tracking.go:426: DEBUG: transient scope snap.chromium.chromedriver.d5a94fd7-5592-4f60-9e27-18479e15408d.scope created
2022/05/26 17:33:59.099095 tracking.go:146: DEBUG: waited 3.770213ms for tracking
DEBUG: umask reset, old umask was   02
DEBUG: security tag: snap.chromium.chromedriver
DEBUG: executable:   /usr/lib/snapd/snap-exec
DEBUG: confinement:  non-classic
DEBUG: base snap:    core20
DEBUG: ruid: 1000, euid: 0, suid: 0
DEBUG: rgid: 1000, egid: 1000, sgid: 1000
DEBUG: apparmor label on snap-confine is: /snap/snapd/15904/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 5
DEBUG: opened snap-update-ns executable as file descriptor 5
DEBUG: opened snap-discard-ns executable as file descriptor 6
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/chromium.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 chromium, uid 0)
DEBUG: sanity timeout reset and disabled
DEBUG: initializing mount namespace: chromium
DEBUG: setting up device cgroup
DEBUG: libudev has current tags support
DEBUG: device /sys/devices/pci0000:00/0000:00:02.0/drm/card0 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_chromium_chromedriver
DEBUG: set_effective_identity uid:0 (change: no), gid:1000 (change: yes)
DEBUG: found existing device map
DEBUG: get next key for map 8
DEBUG: get next key for map 8
DEBUG: get next key for map 8
DEBUG: get next key for map 8
DEBUG: get next key for map 8
DEBUG: get next key for map 8
DEBUG: get next key for map 8
DEBUG: get next key for map 8
DEBUG: get next key for map 8
DEBUG: get next key for map 8
DEBUG: get next key for map 8
DEBUG: get next key for map 8
DEBUG: get next key for map 8
DEBUG: get next key for map 8
DEBUG: get next key for map 8
DEBUG: get next key for map 8
DEBUG: get next key for map 8
DEBUG: get next key for map 8
DEBUG: get next key for map 8
DEBUG: get next key for map 8
DEBUG: get next key for map 8
DEBUG: found 20 existing entries in devices map
DEBUG: delete key for c 140:-1
DEBUG: delete elem in map 8
DEBUG: delete key for c 143:-1
DEBUG: delete elem in map 8
DEBUG: delete key for c 10:239
DEBUG: delete elem in map 8
DEBUG: delete key for c 142:-1
DEBUG: delete elem in map 8
DEBUG: delete key for c 5:0
DEBUG: delete elem in map 8
DEBUG: delete key for c 1:5
DEBUG: delete elem in map 8
DEBUG: delete key for c 10:242
DEBUG: delete elem in map 8
DEBUG: delete key for c 138:-1
DEBUG: delete elem in map 8
DEBUG: delete key for c 136:-1
DEBUG: delete elem in map 8
DEBUG: delete key for c 5:1
DEBUG: delete elem in map 8
DEBUG: delete key for c 5:2
DEBUG: delete elem in map 8
DEBUG: delete key for c 1:3
DEBUG: delete elem in map 8
DEBUG: delete key for c 137:-1
DEBUG: delete elem in map 8
DEBUG: delete key for c 1:7
DEBUG: delete elem in map 8
DEBUG: delete key for c 226:0
DEBUG: delete elem in map 8
DEBUG: delete key for c 1:9
DEBUG: delete elem in map 8
DEBUG: delete key for c 141:-1
DEBUG: delete elem in map 8
DEBUG: delete key for c 1:8
DEBUG: delete elem in map 8
DEBUG: delete key for c 10:200
DEBUG: delete elem in map 8
DEBUG: delete key for c 139:-1
DEBUG: delete elem in map 8
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/dri/card0
DEBUG: v2 allow c 226:0
DEBUG: device /sys/devices/pci0000:00/0000:00:02.0/drm/card0/card0-Virtual-1 has matching current tag
DEBUG: cannot get major/minor numbers for syspath /sys/devices/pci0000:00/0000:00:02.0/drm/card0/card0-Virtual-1
DEBUG: device /sys/devices/virtual/mem/full has matching current tag
DEBUG: inspecting type of device: /dev/full
DEBUG: v2 allow c 1:7
DEBUG: device /sys/devices/virtual/misc/rfkill has matching current tag
DEBUG: inspecting type of device: /dev/rfkill
DEBUG: v2 allow c 10:242
DEBUG: device /sys/module/rfkill has matching current tag
DEBUG: cannot get major/minor numbers for syspath /sys/module/rfkill
DEBUG: process in cgroup /user.slice/user-1000.slice/user@1000.service/app.slice/snap.chromium.chromedriver.d5a94fd7-5592-4f60-9e27-18479e15408d.scope
DEBUG: cgroup /sys/fs/cgroup//user.slice/user-1000.slice/user@1000.service/app.slice/snap.chromium.chromedriver.d5a94fd7-5592-4f60-9e27-18479e15408d.scope opened at 10
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: attach type 0x6 program 9 to cgroup 10
DEBUG: set_effective_identity uid:0 (change: no), gid:1000 (change: yes)
DEBUG: associated snap application process 3586 with device cgroup snap.chromium.chromedriver
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: forked support process 3605
DEBUG: changing apparmor hat to mount-namespace-capture-helper
DEBUG: helper process waiting for command
DEBUG: sanity timeout initialized and set for 30 seconds
DEBUG: block device of snap core20, revision 1494 is 7:3
DEBUG: sanity timeout initialized and set for 30 seconds
DEBUG: joining preserved mount namespace for inspection
DEBUG: block device of the root filesystem is 7:3
DEBUG: sanity timeout reset and disabled
DEBUG: preserved mount is not stale, reusing
DEBUG: joined preserved mount namespace chromium
DEBUG: joining preserved per-user mount namespace
DEBUG: unsharing the mount namespace (per-user)
DEBUG: sc_setup_user_mounts: chromium
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: calling snapd tool snap-update-ns
DEBUG: waiting for snapd tool snap-update-ns to terminate
DEBUG: requesting changing of apparmor profile on next exec to snap-update-ns.chromium
change.go:503: DEBUG: desired mount entries
change.go:505: DEBUG: - /run/user/1000/doc/by-app/snap.chromium /run/user/1000/doc none bind,rw,x-snapd.ignore-missing 0 0
change.go:503: DEBUG: desired mount entries (sorted)
change.go:505: DEBUG: - /run/user/1000/doc/by-app/snap.chromium /run/user/1000/doc none bind,rw,x-snapd.ignore-missing 0 0
change.go:578: DEBUG: desiredIDs: map[/run/user/1000/doc:true]
change.go:579: DEBUG: reuse: map[]
change.go:636: DEBUG: processing mount entries
change.go:680: DEBUG: entry that requires "/run/user/1000": /run/user/1000/doc/by-app/snap.chromium /run/user/1000/doc none bind,rw,x-snapd.ignore-missing 0 0
change.go:698: DEBUG: all mimics:
change.go:700: DEBUG: - /run/user/1000
change.go:623: DEBUG: adding entry: /run/user/1000/doc/by-app/snap.chromium /run/user/1000/doc none bind,rw,x-snapd.ignore-missing 0 0
change.go:503: DEBUG: mount entries ordered as they will be applied
change.go:505: DEBUG: - /run/user/1000/doc/by-app/snap.chromium /run/user/1000/doc none bind,rw,x-snapd.ignore-missing 0 0
DEBUG: snap-update-ns finished successfully
DEBUG: set_effective_identity uid:0 (change: no), gid:1000 (change: yes)
DEBUG: NOT preserving per-user mount namespace
DEBUG: releasing lock 7
DEBUG: sending command 0 to helper process (pid: 3605)
DEBUG: DEBUG: sanity timeout reset and disabled
DEBUG: helper process received command 0
DEBUG: helper process exiting
waiting for response from helper
DEBUG: waiting for the helper process to exit
DEBUG: helper process exited normally
DEBUG: resetting PATH to values in sync with core snap
DEBUG: set_effective_identity uid:1000 (change: yes), gid:1000 (change: yes)
DEBUG: creating user data directory: /home/moneymaker/snap/chromium/1993
DEBUG: requesting changing of apparmor profile on next exec to snap.chromium.chromedriver
DEBUG: ruid: 1000, euid: 1000, suid: 0
DEBUG: setting capabilities bounding set
DEBUG: regaining SYS_ADMIN
DEBUG: loading bpf program for security tag snap.chromium.chromedriver
DEBUG: read 6544 bytes from /var/lib/snapd/seccomp/bpf//snap.chromium.chromedriver.bin
DEBUG: read 152 bytes from /var/lib/snapd/seccomp/bpf/global.bin
DEBUG: clearing SYS_ADMIN
DEBUG: execv(/usr/lib/snapd/snap-exec, /usr/lib/snapd/snap-exec...)
DEBUG:  argv[1] = chromium.chromedriver
DEBUG: umask restored to   02
DEBUG: working directory restored to /home/moneymaker
Starting ChromeDriver 101.0.4951.64 (d1daa9897e1bc1d507d6be8f2346e377e5505905-refs/branch-heads/4951@{#1208}) on port 9515
Only local connections are allowed.
Please see https://chromedriver.chromium.org/security-considerations for suggestions on keeping ChromeDriver safe.
[1653579239,204][SEVERE]: bind() failed: Cannot assign requested address (99)
ChromeDriver was started successfully.
^C

Any suggestions? Thank you

Captive9199 · July 18, 2022, 12:30am

This is not an answer. So far, given the input that I have read from package mantainers, it seems that these snap packages for desktop apps expect you to have a functioning desktop and/or desktop session. This is troublesome in the case of chromedriver/geckodriver/…, which depend on these snap packages.

A similar issue, if not the same, is being tracked at https://bugs.launchpad.net/ubuntu/+source/snapd/+bug/1951491

EDIT: Details about the solution for my use-case

My use-case, is running: cron > geckodriver from a python 3.10 venv > headless Ubuntu 22.04

Since I was already using crontab with bash (“SHELL=/bin/bash” within my crontab), all I had to do was add the following line (after the SHELL variable definition and before any of my crontabs that make use of geckodriver):

# using explicit path + User ID (mine is 1000), because of cron limitation in variable resolution, due to incomplete environment
DBUS_SESSION_BUS_ADDRESS="unix:path=/run/user/1000/bus"

Captive9199 · July 27, 2022, 10:41pm

I discovered later that my proposed solution does not work at all. It was merely a coincidence that I was connected via SSH at the time.

Note: I was not able to edit my previous answer, so I had to reply to it

Captive9199 · July 27, 2022, 11:40pm

I explored this issue a bit further, because I had important monitoring that was waiting for this fixed. I manage to find a workaround that implies not using the default snap for firefox.

The root cause seems to be software development/design that intents to not allow this type of usage. Somewhere in the last few years, the snap firefox package started being distributed with a confinement level of ‘strict’. In this confinement level, there is no way to run the software like you want it to. The firefox snap handles just like proprietary software, in this regard.

What you can do is one of:

Use a non-strict-confined snap. For example: snap install firefox --devmode
Use a browser/driver not distributed via snaps: firefox from official Mozilla PPA, Chrome from DEB package
Maybe using “dbus-run-session” or “dbus-launch” during a cronjob. However, dbus-launch was not designed for this purpose. Troubleshooting dbus when running your scripts via cron is actual torture, considering that, for example, you have to logout of the server, because your SSH session affects DBUS and that you have to print process lists and environments to files

caino · July 28, 2022, 9:12am

I finally solved the issue letting the user to be always logged in using command:

loginctl enable-linger USER

it’s a workaround but it works!

Captive9199 · July 28, 2022, 11:24am

Ah, that is interesting. It is very hard to find documentation on it. I have confirmed that it persists a socket in /run/user/1000/bus (the value of DBUS_SESSION_BUS_ADDRESS during a login).

I found additional documentation in man org.freedesktop.login1.5 on my system:

   SetUserLinger() enables or disables user lingering. If enabled, the runtime directory of a user is kept around and they may continue to run processes while logged
  out. If disabled, the runtime directory goes away as soon as they log out.  SetUserLinger() expects three arguments: the UID, a boolean whether to enable/disable
  and a boolean controlling the polkit[1] authorization interactivity (see below). Note that the user linger state is persistently stored on disk.