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

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). 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

Dec 08 17:33:29 host systemd[36280]: Failed to create parent directory of /run/user/1001/systemd/propagate/.os-release-stage/os-release, ignoring: Permission denied

Dec 08 17:33:29 host systemd[36280]: Failed to copy os-release for propagation, ignoring: Permission denied

Dec 08 17:33:29 host systemd[36280]: Failed at setting rlimit 1073741816 for resource RLIMIT_NOFILE. Will attempt setting value 524288 instead.

Dec 08 17:33:29 host systemd[36280]: Found cgroup2 on /sys/fs/cgroup/, full unified hierarchy

Dec 08 17:33:29 host systemd[36280]: Unified cgroup hierarchy is located at /sys/fs/cgroup/user.slice/user-1001.slice/user@1001.service.

Dec 08 17:33:29 host systemd[36280]: bpf-firewall: Got EBADF when using BPF_F_ALLOW_MULTI, which indicates it is supported. Yay!

Dec 08 17:33:29 host systemd[36280]: Not enough privileges, BPF device control is not supported.

Dec 08 17:33:29 host systemd[36280]: Controller 'cpu' supported: yes

Dec 08 17:33:29 host systemd[36280]: Controller 'cpuacct' supported: no

Dec 08 17:33:29 host systemd[36280]: Controller 'cpuset' supported: no

Dec 08 17:33:29 host systemd[36280]: Controller 'io' supported: no

Dec 08 17:33:29 host systemd[36280]: Controller 'blkio' supported: no

Dec 08 17:33:29 host systemd[36280]: Controller 'memory' supported: yes

Dec 08 17:33:29 host systemd[36280]: Controller 'devices' supported: no

Dec 08 17:33:29 host systemd[36280]: Controller 'pids' supported: yes

Dec 08 17:33:29 host systemd[36280]: Controller 'bpf-firewall' supported: yes

Dec 08 17:33:29 host systemd[36280]: Controller 'bpf-devices' supported: no

Dec 08 17:33:29 host systemd[36280]: Controller 'bpf-foreign' supported: yes

Dec 08 17:33:29 host systemd[36280]: Controller 'bpf-socket-bind' supported: no

Dec 08 17:33:29 host systemd[36280]: Controller 'bpf-restrict-network-interfaces' supported: no

Dec 08 17:33:29 host systemd[36280]: Set up TFD_TIMER_CANCEL_ON_SET timerfd.

Dec 08 17:33:29 host systemd[36280]: Failed to establish memory pressure event source, ignoring: Operation not supported

Dec 08 17:33:29 host systemd[36280]: Failed to allocate manager object: Permission denied

Dec 08 17:33:29 host systemd[1]: user@1001.service: Main process exited, code=exited, status=1/FAILURE

Dec 08 17:33:29 host systemd[1]: user@1001.service: Failed with result 'exit-code'.

Dec 08 17:33:29 host systemd[1]: Failed to start User Manager for UID 1001.

Dec 08 17:33:29 host systemd[1]: Stopping User Runtime Directory /run/user/1001...

Dec 08 17:33:29 host systemd-user-runtime-dir[36283]: Will remove /run/user/1001

Dec 08 17:33:29 host systemd[1]: user-runtime-dir@1001.service: Deactivated successfully.

Dec 08 17:33:29 host systemd[1]: Stopped User Runtime Directory /run/user/1001.

Dec 08 17:33:29 host systemd[1]: Removed slice User Slice of UID 1001.

Best regards,

Christopher Wong

From: Mantas Mikulėnas <grawity@xxxxxxxxx>
Date: Friday, 8 December 2023 at 12:11
To: Christopher Wong <Christopher.Wong@xxxxxxxx>
Cc: Luca Boccassi <luca.boccassi@xxxxxxxxx>, Systemd <systemd-devel@xxxxxxxxxxxxxxxxxxxxx>
Subject: Re: [systemd-devel] Manual start of user@<uid>.service failed with permission denied

On Fri, Dec 8, 2023, 12:22 Christopher Wong <Christopher.Wong@xxxxxxxx> wrote:

Hi Luca,

Sorry, for late reply, below is a log with debug. This time I run with a user with higher UID, but the result is the same.

root@host:~# systemd-analyze set-log-level debug

root@host:~# systemctl set-environment XDG_RUNTIME_DIR="/run/user/1001"

I'd avoid doing that globally. If you really want to have a PAM-less system, then edit the unit to set this through its Environment= instead.

root@host:~# systemctl start user@1001.service

Job for user@1001.service failed because the control process exited with error code.

See "systemctl status user@1001.service" and "journalctl -xeu user@1001.service" for details.

root@host:~# journalctl -xeu user@1001.service

Dec 08 09:35:53 host systemd[1]: /usr/lib/systemd/system/user@.service:19: Support for option PAMName= has been disabled at compile time and it is ignored

Dec 08 09:35:53 host systemd[1]: user@1001.service: Trying to enqueue job user@1001.service/start/replace

Dec 08 09:35:53 host systemd[1]: user@1001.service: Installed new job user@1001.service/start as 6724

Dec 08 09:35:53 host systemd[1]: user@1001.service: Enqueued job user@1001.service/start as 6724

Dec 08 09:35:53 host systemd[1]: user@1001.service: starting held back, waiting for: user-runtime-dir@1001.service

Dec 08 09:35:54 host systemd[1]: user@1001.service: Will spawn child (service_enter_start): /usr/lib/systemd/systemd

Dec 08 09:35:54 host systemd[1]: user@1001.service: Failed to set 'memory.zswap.max' attribute on '/user.slice/user-1001.slice/user@1001.service' to 'max': No such file or directory

Dec 08 09:35:54 host systemd[1]: user@1001.service: Passing 0 fds to service

Dec 08 09:35:54 host systemd[1]: user@1001.service: About to execute: /usr/lib/systemd/systemd --user

Dec 08 09:35:54 host systemd[1]: user@1001.service: Forked /usr/lib/systemd/systemd as 6899

Dec 08 09:35:54 host (systemd)[6899]: Found cgroup2 on /sys/fs/cgroup/, full unified hierarchy

Dec 08 09:35:54 host systemd[1]: user@1001.service: Changed dead -> start

Dec 08 09:35:54 host systemd[1]: Starting User Manager for UID 1001...

Dec 08 09:35:54 host (systemd)[6899]: Bind-mounting / on /run/systemd/mount-rootfs (MS_BIND|MS_REC "")...

Dec 08 09:35:54 host systemd[1]: user@1001.service: User lookup succeeded: uid=1001 gid=118

Dec 08 09:35:54 host (systemd)[6899]: Applying namespace mount on /run/systemd/mount-rootfs/run/credentials

Dec 08 09:35:54 host (systemd)[6899]: Bind-mounting /run/systemd/inaccessible/dir on /run/systemd/mount-rootfs/run/credentials (MS_BIND|MS_REC "")...

Dec 08 09:35:54 host (systemd)[6899]: Successfully mounted /run/systemd/inaccessible/dir to /run/systemd/mount-rootfs/run/credentials

Dec 08 09:35:54 host (systemd)[6899]: Applying namespace mount on /run/systemd/mount-rootfs/run/systemd/incoming

Dec 08 09:35:54 host (systemd)[6899]: Followed source symlinks /run/systemd/propagate/user@1001.service → /run/systemd/propagate/user@1001.service.

Dec 08 09:35:54 host (systemd)[6899]: Bind-mounting /run/systemd/propagate/user@1001.service on /run/systemd/mount-rootfs/run/systemd/incoming (MS_BIND "")...

Dec 08 09:35:54 host (systemd)[6899]: Successfully mounted /run/systemd/propagate/user@1001.service to /run/systemd/mount-rootfs/run/systemd/incoming

Dec 08 09:35:54 host (systemd)[6899]: Applying namespace mount on /run/systemd/mount-rootfs/sys

Dec 08 09:35:54 host (systemd)[6899]: Failed to umount /run/systemd/mount-rootfs/sys, ignoring: Device or resource busy

Dec 08 09:35:54 host (systemd)[6899]: Failed to umount /run/systemd/mount-rootfs/sys, ignoring: Device or resource busy

Dec 08 09:35:54 host (systemd)[6899]: Failed to umount /run/systemd/mount-rootfs/sys, ignoring: Device or resource busy

Dec 08 09:35:54 host (systemd)[6899]: Failed to umount /run/systemd/mount-rootfs/sys, ignoring: Device or resource busy

Dec 08 09:35:54 host (systemd)[6899]: Failed to umount /run/systemd/mount-rootfs/sys, ignoring: Device or resource busy

Dec 08 09:35:54 host (systemd)[6899]: Failed to umount /run/systemd/mount-rootfs/sys, ignoring: Device or resource busy

Dec 08 09:35:54 host (systemd)[6899]: Failed to umount /run/systemd/mount-rootfs/sys, ignoring: Device or resource busy

Dec 08 09:35:54 host (systemd)[6899]: Failed to umount /run/systemd/mount-rootfs/sys, ignoring: Device or resource busy

Dec 08 09:35:54 host (systemd)[6899]: Mounting sysfs (sysfs) on /run/systemd/mount-rootfs/sys (MS_NOSUID|MS_NODEV|MS_NOEXEC "")...

Dec 08 09:35:54 host (systemd)[6899]: user@1001.service: Executing: /usr/lib/systemd/systemd --user

Dec 08 09:35:54 host systemd[6899]: Failed to copy os-release for propagation, ignoring: Permission denied

Dec 08 09:35:54 host systemd[6899]: Failed to allocate manager object: Permission denied

Try setting SYSTEMD_LOG_LEVEL=debug for the user@ service unit to see what happens here. (This is a separate instance so it doesn't inherit the debug level that pid1 has...)

Also, I might've missed this, but does anything *create* /run/user/1001 here? Normally user-user-runtime-dir@1001.service would be the one to do so, and I see "waiting for: user-runtime-dir@1001.service" in the logs, but I don't see anything else – did that service actually succeed? is the path owned by UID 1001?

Dec 08 09:35:54 host systemd[1]: user@1001.service: Got notification message from PID 6899 (ERRNO=13)

Dec 08 09:35:54 host systemd[1]: user@1001.service: Got notification message from PID 6899 (EXIT_STATUS=1)

Dec 08 09:35:54 host systemd[1]: user@1001.service: Child 6899 belongs to user@1001.service.

Dec 08 09:35:54 host systemd[1]: user@1001.service: Main process exited, code=exited, status=1/FAILURE

Dec 08 09:35:54 host systemd[1]: user@1001.service: Failed with result 'exit-code'.

Dec 08 09:35:54 host systemd[1]: user@1001.service: Service will not restart (restart setting)

Dec 08 09:35:54 host systemd[1]: user@1001.service: Changed start -> failed

Dec 08 09:35:54 host systemd[1]: user@1001.service: Job 6724 user@1001.service/start finished, result=failed

Dec 08 09:35:54 host systemd[1]: Failed to start User Manager for UID 1001.

Dec 08 09:35:54 host systemd[1]: user@1001.service: Unit entered failed state.

Dec 08 09:35:54 host systemd[1]: user@1001.service: Consumed 63ms CPU time.

Dec 08 09:35:54 host systemd[1]: user@1001.service: Releasing resources...

Best regards,

Christopher Wong

From: Luca Boccassi <luca.boccassi@xxxxxxxxx>
Date: Wednesday, 6 December 2023 at 17:46
To: Christopher Wong <Christopher.Wong@xxxxxxxx>
Cc: systemd-devel@xxxxxxxxxxxxxxxxxxxxx <systemd-devel@xxxxxxxxxxxxxxxxxxxxx>
Subject: Re: [systemd-devel] Manual start of user@<uid>.service failed with permission denied

On Wed, 6 Dec 2023 at 16:00, Christopher Wong <Christopher.Wong@xxxxxxxx> wrote:
> Hi,
>
> I’m trying to do the following:
>
> root@host:~# systemctl set-environment XDG_RUNTIME_DIR="/run/user/503"

Why are you setting this?
Anyway, enable debug level log and attach the output, otherwise it's hard to say