[systemd-devel] Manual start of user@<uid>.service failed with permission denied

Fri Dec 8 11:11:08 UTC 2023

On Fri, Dec 8, 2023, 12:22 Christopher Wong <Christopher.Wong at axis.com>
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 at host:~# systemd-analyze set-log-level debug
>
> root at 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 at host:~# systemctl start user at 1001.service
>
> Job for user at 1001.service failed because the control process exited with
> error code.
>
> See "systemctl status user at 1001.service" and "journalctl -xeu
> user at 1001.service" for details.
>
> root at host:~# journalctl -xeu user at 1001.service
>
> Dec 08 09:35:53 host systemd[1]: /usr/lib/systemd/system/user at .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 at 1001.service: Trying to enqueue job
> user at 1001.service/start/replace
>
> Dec 08 09:35:53 host systemd[1]: user at 1001.service: Installed new job
> user at 1001.service/start as 6724
>
> Dec 08 09:35:53 host systemd[1]: user at 1001.service: Enqueued job
> user at 1001.service/start as 6724
>
> Dec 08 09:35:53 host systemd[1]: user at 1001.service: starting held back,
> waiting for: user-runtime-dir at 1001.service
>
> Dec 08 09:35:54 host systemd[1]: user at 1001.service: Will spawn child
> (service_enter_start): /usr/lib/systemd/systemd
>
> Dec 08 09:35:54 host systemd[1]: user at 1001.service: Failed to set
> 'memory.zswap.max' attribute on
> '/user.slice/user-1001.slice/user at 1001.service' to 'max': No such file or
> directory
>
> Dec 08 09:35:54 host systemd[1]: user at 1001.service: Passing 0 fds to
> service
>
> Dec 08 09:35:54 host systemd[1]: user at 1001.service: About to execute:
> /usr/lib/systemd/systemd --user
>
> Dec 08 09:35:54 host systemd[1]: user at 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 at 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 at 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 at 1001.service →
> /run/systemd/propagate/user at 1001.service.
>
> Dec 08 09:35:54 host (systemd)[6899]: Bind-mounting
> /run/systemd/propagate/user at 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 at 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 at 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 at 1001.service would be the one to do
so, and I see "waiting for: user-runtime-dir at 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 at 1001.service: Got notification
> message from PID 6899 (ERRNO=13)
>
> Dec 08 09:35:54 host systemd[1]: user at 1001.service: Got notification
> message from PID 6899 (EXIT_STATUS=1)
>
> Dec 08 09:35:54 host systemd[1]: user at 1001.service: Child 6899 belongs to
> user at 1001.service.
>
> Dec 08 09:35:54 host systemd[1]: user at 1001.service: Main process exited,
> code=exited, status=1/FAILURE
>
> Dec 08 09:35:54 host systemd[1]: user at 1001.service: Failed with result
> 'exit-code'.
>
> Dec 08 09:35:54 host systemd[1]: user at 1001.service: Service will not
> restart (restart setting)
>
> Dec 08 09:35:54 host systemd[1]: user at 1001.service: Changed start ->
> failed
>
> Dec 08 09:35:54 host systemd[1]: user at 1001.service: Job 6724
> user at 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 at 1001.service: Unit entered failed
> state.
>
> Dec 08 09:35:54 host systemd[1]: user at 1001.service: Consumed 63ms CPU
> time.
>
> Dec 08 09:35:54 host systemd[1]: user at 1001.service: Releasing resources...
>
>
>
> Best regards,
>
> Christopher Wong
>
>
>
>
>
>
>
> *From: *Luca Boccassi <luca.boccassi at gmail.com>
> *Date: *Wednesday, 6 December 2023 at 17:46
> *To: *Christopher Wong <Christopher.Wong at axis.com>
> *Cc: *systemd-devel at lists.freedesktop.org <
> systemd-devel at lists.freedesktop.org>
> *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 at axis.com>
> wrote:
> > Hi,
> >
> > I’m trying to do the following:
> >
> > root at 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
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/systemd-devel/attachments/20231208/4bb02b97/attachment-0001.htm>