Trying to run as user instance, but $XDG_RUNTIME_DIR is not set #232

smcv · 2015-06-16T17:14:29Z

I'm working on a semi-embedded distribution which starts a PAM session for a designated user during boot, then instructs that session to start a target that includes Xorg and a GUI. This mostly works fine, but there seems to be a race condition in which the systemd --user run by user@.service doesn't always pick up its $XDG_RUNTIME_DIR correctly:

Jun 16 17:02:25 xxx systemd[1]: Starting User Manager for UID 1000...
Jun 16 17:02:25 xxx systemd[539]: Trying to run as user instance, but $XDG_RUNTIME_DIR is not set.

It seems to fail about 1/3 of the time on my virtual machine setup. I've found one possible reason for the race, which does look like a genuine bug, for which I'll send a pull request; but unfortunately, that commit doesn't actually fix it.

The text was updated successfully, but these errors were encountered:

Previously, I think this was a race condition during a user's first login. Some component calls CreateSession (most likely by a PAM service other than 'systemd-user' running pam_systemd), with the following results: - logind: * create the user's XDG_RUNTIME_DIR * tell pid 1 to create user-UID.slice * tell pid 1 to start user@UID.service Then these two processes race: - logind: * save information including XDG_RUNTIME_DIR to /run/systemd/users/UID - (subprocesses of) pid 1: * start a 'systemd-user' PAM session, which reads XDG_RUNTIME_DIR and puts it in the environment * run systemd --user, which requires XDG_RUNTIME_DIR in the environment If logind wins the race, everything is fine, but if the subprocesses of pid 1 win the race, systemd --user exits unsuccessfully. This is an attempt to fix <systemd#232>, but unfortunately does not actually do so. It seems to be a genuine bug anyway, though.

There seems to be some race condition in which logind does not always communicate the XDG_RUNTIME_DIR to the process that is about to exec systemd --user (<systemd#232>). systemd --user fails if there is no XDG_RUNTIME_DIR; try falling back to /run/user/UID instead of giving up.

poettering · 2015-06-17T10:27:25Z

The first patch indeed should fix a bug. Can you send a PR for it please?

poettering · 2015-06-17T10:28:53Z

But the second patch looks like a hack indeed... This really shouldn't be necessary.

Have you tried adding an ExecStartPre=/bin/cat /run/systemd/users/1000 to your user@.service, so that that file is logged right before the user instance is started?

smcv · 2015-06-17T10:35:48Z

But the second patch looks like a hack indeed... This really shouldn't be necessary.

I know, I deliberately didn't submit a PR for it (but we needed a workaround right now, so we can start X reliably again, and it does work).

I'm continuing to look into the root cause; the ExecStartPre is a good idea, I'll try that.

smcv · 2015-06-17T12:51:32Z

The first patch indeed should fix a bug.

Should, but doesn't, because I call:

        user_save(u);

but user_save() has:

        if (!u->started)
                return 0;

and u->started hasn't been set TRUE yet.

I'll try to work out the least problematic way to fix this...

smcv · 2015-06-17T13:00:57Z

We're doing a "transaction" in which we start the user's user-session. It looks as though we want to only write out /run/systemd/users/ after the transaction has been started successfully; but one of the things we do in the transaction is to StartUnit for user@.service, which can fail with ENOMEM or a D-Bus error, and we need the XDG_RUNTIME_DIR before we can rely on that to work.

We can either:

create the file earlier/more often (make the early-return not trigger in this particular case); or
have a separate way to communicate the XDG_RUNTIME_DIR to system --user

smcv · 2015-06-17T13:03:35Z

One way to do it would be to turn my workaround into the real "API" used by pam-systemd: if /run/user/UID exists and is owned by UID, use it; and don't bother with /run/systemd/users/UID at all. This is unsuitable if you are more likely to change the location of users' runtime directories than to change how /run/systemd/users/UID works, though.

smcv · 2015-06-17T13:23:35Z

The other way to do it would be to write out the state-file in this one particular case even if u->starting is not yet true, because it is about to be true. We shouldn't actually set u->starting to true any earlier, because that has an effect on how much we roll back when the user is finalized (we shouldn't emit UserRemoved if there was no UserNew).

poettering · 2015-06-17T15:55:15Z

I think we should probably create a call user_get_runtime_dir(uid_t uid, char **ret) in src/basic/login-util.[ch], and then use that in the PAM module and in logind, and then stop reading the /run file from the PAM module. That we make sure both sides use the same logic to come up with the dir, but they will no longer need synchronization.

smcv · 2015-06-17T16:15:25Z

Do you mean a stateless call that doesn't look at the filesystem, and just returns the equivalent of printf ("/run/user/" UID_FMT, uid)? I'd assumed that if it was that simple, you'd already have done it...

I have a patch for the current way of doing it (as described in my most recent comment here) that needs some testing, but is hopefully ready. But I could go for the other approach if desired.

smcv · 2015-06-17T16:17:58Z

One situation where the state-file business could matter is if the way we construct XDG_RUNTIME_DIR changes, and an upgrade results in briefly running a new PAM module against XDG_RUNTIME_DIRs created by an old logind, or an old PAM module (in a long-running daemon) against XDG_RUNTIME_DIRs created by a newly restarted logind. I'd assumed that this sort of concern was why we didn't just do (API calls that end up with) the simple printf.

poettering · 2015-06-17T16:18:03Z

Do you mean a stateless call that doesn't look at the filesystem, and just returns the equivalent of printf ("/run/user/" UID_FMT, uid)?

Yes!

I'd assumed that if it was that simple, you'd already have done it...

Well, we didn't have src/basic/login-util.c and hence no nice place to have function to share between the module and logind ;-).

poettering · 2015-06-17T16:21:07Z

One situation where the state-file business could matter is if the way we construct XDG_RUNTIME_DIR changes, and an upgrade results in briefly running a new PAM module against XDG_RUNTIME_DIRs created by an old logind, or an old PAM module (in a long-running daemon) against XDG_RUNTIME_DIRs created by a newly restarted logind. I'd assumed that this sort of concern was why we didn't just do (API calls that end up with) the simple printf.

Yupp, that was something I thought, but back when I hacked this up I didn't realize the race you ran into. I think just accepting that upgrades are fucked is nicer in this case then adding more synchronization between the components...

Previously, this had a race condition during a user's first login. Some component calls CreateSession (most likely by a PAM service other than 'systemd-user' running pam_systemd), with the following results: - logind: * create the user's XDG_RUNTIME_DIR * tell pid 1 to create user-UID.slice * tell pid 1 to start user@UID.service Then these two processes race: - logind: * save information including XDG_RUNTIME_DIR to /run/systemd/users/UID - the subprocess of pid 1 responsible for user@service: * start a 'systemd-user' PAM session, which reads XDG_RUNTIME_DIR and puts it in the environment * run systemd --user, which requires XDG_RUNTIME_DIR in the environment If logind wins the race, which usually happens, everything is fine; but if the subprocesses of pid 1 win the race, which can happen under load, then systemd --user exits unsuccessfully. To avoid this race, we have to write out /run/systemd/users/UID even though the service has not "officially" started yet; previously this did an early-return without saving anything. Record its state as OPENING in this case. Bug: systemd#232 Reviewed-by: Philip Withnall <philip.withnall@collabora.co.uk>

smcv · 2015-06-17T16:25:24Z

I have a patch for the current way of doing it (as described in my most recent comment here) that needs some testing, but is hopefully ready

That patch is smcv@7116130, and seems to work (a test that failed 2/6 times on a 219 derivative without this patch has worked 10/10 times with it).

smcv · 2015-06-17T16:29:10Z

Well, we didn't have src/basic/login-util.c and hence no nice place

I'll do a patch for master that adds the function you suggested, and a 219 backport (since that's what I actually need, and it doesn't have src/basic) that just does the equivalent asprintf like smcv@15b4044 did. It is going to take a little while to get that through continuous integration machinery though.

poettering · 2015-06-17T16:32:41Z

I like you patch smcv@7116130 actually better than my idea. If you post a PR for it, I'll merge it.

smcv · 2015-06-17T16:50:14Z

#265 is the requested PR. Thank you for not forcing me to do another two rounds of testing :-)

poettering · 2015-06-17T20:47:40Z

Closing, as #265 has been merged. Thanks!

Previously, this had a race condition during a user's first login. Some component calls CreateSession (most likely by a PAM service other than 'systemd-user' running pam_systemd), with the following results: - logind: * create the user's XDG_RUNTIME_DIR * tell pid 1 to create user-UID.slice * tell pid 1 to start user@UID.service Then these two processes race: - logind: * save information including XDG_RUNTIME_DIR to /run/systemd/users/UID - the subprocess of pid 1 responsible for user@service: * start a 'systemd-user' PAM session, which reads XDG_RUNTIME_DIR and puts it in the environment * run systemd --user, which requires XDG_RUNTIME_DIR in the environment If logind wins the race, which usually happens, everything is fine; but if the subprocesses of pid 1 win the race, which can happen under load, then systemd --user exits unsuccessfully. To avoid this race, we have to write out /run/systemd/users/UID even though the service has not "officially" started yet; previously this did an early-return without saving anything. Record its state as OPENING in this case. Bug: systemd/systemd#232 Reviewed-by: Philip Withnall <philip.withnall@collabora.co.uk> (cherry picked from commit 7116130)

Previously, this had a race condition during a user's first login. Some component calls CreateSession (most likely by a PAM service other than 'systemd-user' running pam_systemd), with the following results: - logind: * create the user's XDG_RUNTIME_DIR * tell pid 1 to create user-UID.slice * tell pid 1 to start user@UID.service Then these two processes race: - logind: * save information including XDG_RUNTIME_DIR to /run/systemd/users/UID - the subprocess of pid 1 responsible for user@service: * start a 'systemd-user' PAM session, which reads XDG_RUNTIME_DIR and puts it in the environment * run systemd --user, which requires XDG_RUNTIME_DIR in the environment If logind wins the race, which usually happens, everything is fine; but if the subprocesses of pid 1 win the race, which can happen under load, then systemd --user exits unsuccessfully. To avoid this race, we have to write out /run/systemd/users/UID even though the service has not "officially" started yet; previously this did an early-return without saving anything. Record its state as OPENING in this case. Bug: systemd/systemd#232 Reviewed-by: Philip Withnall <philip.withnall@collabora.co.uk> (cherry picked from commit 7116130) [fbui: fixes bsc#996269]

Previously, this had a race condition during a user's first login. Some component calls CreateSession (most likely by a PAM service other than 'systemd-user' running pam_systemd), with the following results: - logind: * create the user's XDG_RUNTIME_DIR * tell pid 1 to create user-UID.slice * tell pid 1 to start user@UID.service Then these two processes race: - logind: * save information including XDG_RUNTIME_DIR to /run/systemd/users/UID - the subprocess of pid 1 responsible for user@service: * start a 'systemd-user' PAM session, which reads XDG_RUNTIME_DIR and puts it in the environment * run systemd --user, which requires XDG_RUNTIME_DIR in the environment If logind wins the race, which usually happens, everything is fine; but if the subprocesses of pid 1 win the race, which can happen under load, then systemd --user exits unsuccessfully. To avoid this race, we have to write out /run/systemd/users/UID even though the service has not "officially" started yet; previously this did an early-return without saving anything. Record its state as OPENING in this case. Bug: systemd/systemd#232 Reviewed-by: Philip Withnall <philip.withnall@collabora.co.uk>

gclawes · 2018-10-29T21:54:38Z

I'm seeing this issue on systemd 239 (sys-apps/systemd-239-r2 on gentoo)

It looks like /run/user/UID is being created, but /run/systemd/users/UID is not

enterprise ~ # ls -lah /run/user
total 0
drwxr-xr-x  2 root root  40 Oct 29 17:49 .
drwxr-xr-x 24 root root 740 Oct 29 17:45 ..
enterprise ~ # ls -lah /run/systemd/user
ls: cannot access '/run/systemd/user': No such file or directory

Oct 29 17:49:41 enterprise.lan systemd[1]: Created slice User Slice of UID 1000.
-- Subject: Unit user-1000.slice has finished start-up
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit user-1000.slice has finished starting up.
--
-- The start-up result is RESULT.
Oct 29 17:49:41 enterprise.lan systemd[1]: Created slice system-user\x2druntime\x2ddir.slice.
-- Subject: Unit system-user\x2druntime\x2ddir.slice has finished start-up
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit system-user\x2druntime\x2ddir.slice has finished starting up.
--
-- The start-up result is RESULT.
Oct 29 17:49:41 enterprise.lan systemd[1]: Started /run/user/1000 mount wrapper.
-- Subject: Unit user-runtime-dir@1000.service has finished start-up
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit user-runtime-dir@1000.service has finished starting up.
--
-- The start-up result is RESULT.
Oct 29 17:49:41 enterprise.lan systemd[1]: Starting User Manager for UID 1000...
-- Subject: Unit user@1000.service has begun start-up
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit user@1000.service has begun starting up.
Oct 29 17:49:41 enterprise.lan systemd[17543]: pam_unix(systemd-user:session): session opened for user gclawes by (uid=0)
Oct 29 17:49:41 enterprise.lan systemd[17543]: Trying to run as user instance, but $XDG_RUNTIME_DIR is not set.
Oct 29 17:49:41 enterprise.lan systemd[1]: user@1000.service: Failed with result 'protocol'.
Oct 29 17:49:41 enterprise.lan systemd[1]: Failed to start User Manager for UID 1000.
-- Subject: Unit user@1000.service has failed
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit user@1000.service has failed.
--
-- The result is RESULT.
Oct 29 17:49:41 enterprise.lan systemd[1]: user-runtime-dir@1000.service: Unit not needed anymore. Stopping.
Oct 29 17:49:41 enterprise.lan systemd[1]: Stopping /run/user/1000 mount wrapper...
-- Subject: Unit user-runtime-dir@1000.service has begun shutting down
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit user-runtime-dir@1000.service has begun shutting down.
Oct 29 17:49:41 enterprise.lan systemd[1]: Stopped /run/user/1000 mount wrapper.
-- Subject: Unit user-runtime-dir@1000.service has finished shutting down
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit user-runtime-dir@1000.service has finished shutting down.

gclawes · 2018-10-29T22:18:37Z

With ExecStartPre=/bin/cat /run/systemd/users/%i added to user@.service:

-- Unit user@1000.service has begun starting up.
Oct 29 18:16:48 enterprise.lan systemd[1]: Started /run/user/1000 mount wrapper.
Oct 29 18:16:48 enterprise.lan systemd[12809]: pam_unix(systemd-user:session): session opened for user gclawes by (uid=0)
Oct 29 18:16:48 enterprise.lan cat[12809]: /bin/cat: /run/systemd/users/1000: No such file or directory
Oct 29 18:16:48 enterprise.lan systemd[12810]: pam_unix(systemd-user:session): session closed for user gclawes
Oct 29 18:16:48 enterprise.lan systemd[1]: user@1000.service: Control process exited, code=exited status=1
Oct 29 18:16:48 enterprise.lan systemd[1]: user@1000.service: Failed with result 'exit-code'.
Oct 29 18:16:48 enterprise.lan systemd[1]: Failed to start User Manager for UID 1000.
-- Subject: Unit user@1000.service has failed

gclawes · 2018-10-29T22:19:10Z

@poettering should a new issue be opened for this?

smcv · 2018-10-30T12:14:05Z

should a new issue be opened for this?

Yes please. If in doubt, open a new issue, and in particular if you have the same symptom in a version a lot later than the one where it's meant to have been fixed, always open a new issue.

If you open too many issues, it's easy for developers to close the duplicates, but if you reuse an existing issue number when the same symptom is seen for a different reason, it can become very hard to disentangle.

gclawes · 2018-10-30T12:33:59Z

Opened: #10574

smcv mentioned this issue Jun 17, 2015

Stop talking about the "XDG" version of basename() #246

Merged

poettering added the login label Jun 17, 2015

smcv mentioned this issue Jun 17, 2015

logind: save /run/systemd/users/UID before starting user@.service #265

Merged

poettering closed this as completed Jun 17, 2015

gclawes mentioned this issue Oct 30, 2018

user@.service: Trying to run as user instance, but $XDG_RUNTIME_DIR is not set. #10574

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Trying to run as user instance, but $XDG_RUNTIME_DIR is not set #232

Trying to run as user instance, but $XDG_RUNTIME_DIR is not set #232

smcv commented Jun 16, 2015

poettering commented Jun 17, 2015

poettering commented Jun 17, 2015

smcv commented Jun 17, 2015

smcv commented Jun 17, 2015

smcv commented Jun 17, 2015

smcv commented Jun 17, 2015

smcv commented Jun 17, 2015

poettering commented Jun 17, 2015

smcv commented Jun 17, 2015

smcv commented Jun 17, 2015

poettering commented Jun 17, 2015

poettering commented Jun 17, 2015

smcv commented Jun 17, 2015

smcv commented Jun 17, 2015

poettering commented Jun 17, 2015

smcv commented Jun 17, 2015

poettering commented Jun 17, 2015

gclawes commented Oct 29, 2018

gclawes commented Oct 29, 2018

gclawes commented Oct 29, 2018

smcv commented Oct 30, 2018

gclawes commented Oct 30, 2018

Trying to run as user instance, but $XDG_RUNTIME_DIR is not set #232

Trying to run as user instance, but $XDG_RUNTIME_DIR is not set #232

Comments

smcv commented Jun 16, 2015

poettering commented Jun 17, 2015

poettering commented Jun 17, 2015

smcv commented Jun 17, 2015

smcv commented Jun 17, 2015

smcv commented Jun 17, 2015

smcv commented Jun 17, 2015

smcv commented Jun 17, 2015

poettering commented Jun 17, 2015

smcv commented Jun 17, 2015

smcv commented Jun 17, 2015

poettering commented Jun 17, 2015

poettering commented Jun 17, 2015

smcv commented Jun 17, 2015

smcv commented Jun 17, 2015

poettering commented Jun 17, 2015

smcv commented Jun 17, 2015

poettering commented Jun 17, 2015

gclawes commented Oct 29, 2018

gclawes commented Oct 29, 2018

gclawes commented Oct 29, 2018

smcv commented Oct 30, 2018

gclawes commented Oct 30, 2018