Re: Manual start of user@<uid>.service failed with permission denied

Mantas Mikulėnas <grawity@xxxxxxxxx> · Fri, 8 Dec 2023 22:53:29 +0200

On Fri, Dec 8, 2023 at 6:53 PM Christopher Wong <Christopher.Wong@xxxxxxxx> wrote:

Hi Mantas,

I have from your suggestion done the following:

Putting the below in user@.service

[Service]
...
Environment=XDG_RUNTIME_DIR=/run/user/%i
Environment=SYSTEMD_LOG_LEVEL=debug

Putting the below in user-runtime-dir@.service

[Service]
...
Environment=SYSTEMD_LOG_LEVEL=debug

Then I have disabled the global set-log-level debug (if this is also required, please let me know).

Unlike set-environment that's not global, it only affects pid1.

What I can see from the logs is that
user-runtime-dir@1001.service seems to be started and mount /run/user/1001, but addition creation of directory under this mount is getting permission denied.

Dec 08 17:33:29 host systemd[1]: Created slice User Slice of UID 1001.
Dec 08 17:33:29 host systemd[1]: Starting User Runtime Directory /run/user/1001...
Dec 08 17:33:29 host systemd-user-runtime-dir[36278]: Bus n/a: changing state UNSET -> OPENING
Dec 08 17:33:29 host systemd-user-runtime-dir[36278]: sd-bus: starting bus by connecting to /run/dbus/system_bus_socket...
Dec 08 17:33:29 host systemd-user-runtime-dir[36278]: Bus n/a: changing state OPENING -> AUTHENTICATING
Dec 08 17:33:29 host systemd-user-runtime-dir[36278]: Bus n/a: changing state AUTHENTICATING -> HELLO
Dec 08 17:33:29 host systemd-user-runtime-dir[36278]: Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus
 member=Hello cookie=1 reply_cookie=0 signature=n/a error-name=n/a error-message=n/a
Dec 08 17:33:29 host systemd-user-runtime-dir[36278]: Got message type=method_return sender=org.freedesktop.DBus destination=:1.2536 path=n/a interface=n/a member=n/a  cookie=1 reply_cookie=1
 signature=s error-name=n/a error-message=n/a
Dec 08 17:33:29 host systemd-user-runtime-dir[36278]: Bus n/a: changing state HELLO -> RUNNING
Dec 08 17:33:29 host systemd-user-runtime-dir[36278]: Sent message type=method_call sender=n/a destination=org.freedesktop.login1 path=/org/freedesktop/login1 interface=org.freedesktop.DBus.Properties
 member=Get cookie=2 reply_cookie=0 signature=ss error-name=n/a error-message=n/a
Dec 08 17:33:29 host systemd-user-runtime-dir[36278]: Got message type=method_return sender=:1.323 destination=:1.2536 path=n/a interface=n/a member=n/a  cookie=15 reply_cookie=2
 signature=v error-name=n/a error-message=n/a
Dec 08 17:33:29 host systemd-user-runtime-dir[36278]: Sent message type=method_call sender=n/a destination=org.freedesktop.login1 path=/org/freedesktop/login1 interface=org.freedesktop.DBus.Properties
 member=Get cookie=3 reply_cookie=0 signature=ss error-name=n/a error-message=n/a
Dec 08 17:33:29 host systemd-user-runtime-dir[36278]: Got message type=method_return sender=:1.323 destination=:1.2536 path=n/a interface=n/a member=n/a  cookie=16 reply_cookie=3
 signature=v error-name=n/a error-message=n/a
Dec 08 17:33:29 host systemd-user-runtime-dir[36278]: Bus n/a: changing state RUNNING -> CLOSED
Dec 08 17:33:29 host systemd-user-runtime-dir[36278]: Will mount /run/user/1001 owned by 1001:118
Dec 08 17:33:29 host systemd-user-runtime-dir[36278]: Mounting tmpfs (tmpfs) on /run/user/1001 (MS_NOSUID|MS_NODEV "mode=0700,uid=1001,gid=118,size=99426304,nr_inodes=24274")...
Dec 08 17:33:29 host systemd[1]: Finished User Runtime Directory /run/user/1001.
Dec 08 17:33:29 host systemd[1]: Starting User Manager for UID 1001...
Dec 08 17:33:29 host systemd[36280]: systemd 254.7-2-g9edc143 running in user mode for user 1001/ida. (-PAM -AUDIT -SELINUX -APPARMOR +IMA -SMACK +SECCOMP +GCRYPT +GNUTLS +OPENSSL
 -ACL +BLKID +CURL -ELFUTILS -FIDO2 -IDN2 -IDN -IPTC +KMOD -LIBCRYPTSETUP +LIBFDISK -PCRE2 -PWQUALITY -P11KIT -QRENCODE -TPM2 +BZIP2 -LZ4 +XZ +ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON -UTMP -SYSVINIT default-hierarchy=unified)
Dec 08 17:33:29 host systemd[36280]: Failed to create '/run/user/1001/systemd/inaccessible', ignoring: Permission denied
Dec 08 17:33:29 host systemd[36280]: Failed to create '/run/user/1001/systemd/inaccessible/reg', ignoring: Permission denied
Dec 08 17:33:29 host systemd[36280]: Failed to create '/run/user/1001/systemd/inaccessible/dir', ignoring: Permission denied
Dec 08 17:33:29 host systemd[36280]: Failed to create '/run/user/1001/systemd/inaccessible/fifo', ignoring: Permission denied
Dec 08 17:33:29 host systemd[36280]: Failed to create '/run/user/1001/systemd/inaccessible/sock', ignoring: Permission denied
Dec 08 17:33:29 host systemd[36280]: Failed to create '/run/user/1001/systemd/inaccessible/chr', ignoring: Permission denied
Dec 08 17:33:29 host systemd[36280]: Failed to create '/run/user/1001/systemd/inaccessible/blk', ignoring: Permission denied

What's the ownership of /run/user/1001 and /run/user/1001/systemd after all of this?

Are you rebooting between tests or just manually starting it?

My current guess is that due to the earlier `systemctl set-environment`, some *other* thing that's running as root inherited the /run/user/1001 path and created root-owned directories there? That's the issue with setting global environment, it needs to be unset afterwards...

-- 
Mantas Mikulėnas