Bug 1474899 - GDM user logins failing because of systemd1 service failing
GDM user logins failing because of systemd1 service failing
Status: NEW
Product: Fedora
Classification: Fedora
Component: sssd (Show other bugs)
26
x86_64 Linux
unspecified Severity high
: ---
: ---
Assigned To: Jakub Hrozek
Fedora Extras Quality Assurance
:
: 1473806 (view as bug list)
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2017-07-25 11:17 EDT by Brian Sipos
Modified: 2017-12-08 18:38 EST (History)
22 users (show)

See Also:
Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed:
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
boot and login log (337.76 KB, text/plain)
2017-07-26 08:53 EDT, Brian Sipos
no flags Details
Copy of /etc/pam.d/systemd-user from failing host (248 bytes, text/plain)
2017-07-26 12:48 EDT, Brian Sipos
no flags Details
journalctl log from succesful fedora 24 use (3.23 KB, text/plain)
2017-07-27 09:17 EDT, Brian Sipos
no flags Details
differences from base fedora-24 to upgraded 24-to-26 file (1.27 KB, patch)
2017-07-27 13:47 EDT, Brian Sipos
no flags Details | Diff

  None (edit)
Description Brian Sipos 2017-07-25 11:17:52 EDT
Description of problem:
I recently upgraded a host from Fedora 24 to Fedora 26. The upgrade appeared to have completed with no issue. When attempting a terminal (VT) login, I see normal successful behavior. When I attempt a graphical (GDM) login with the same account the login iteslf succeeds, the screen flashes black, and the GDM prompt appears again. In troubleshooting this problem it appears to boil down to an issue launching the D-Bus service "org.freedesktop.systemd1.

The problem also appears if I attempt to run "systemctl --user" mode after a shell login, for example:

$ eval `dbus-launch --sh-syntax`
$ systemctl --user
Failed to list units: Process org.freedesktop.systemd1 exited with status 1


Version-Release number of selected component (if applicable):
kernel-4.11.10-300.fc26.x86_64
dbus-1.11.14-1.fc26.x86_64
systemd-233-6.fc26.x86_64


How reproducible:
Consistently; I thought it might be a single host problem but I see the same thing on a second host which also was stock Fedora 24 upgraded to Fedora 26.

Steps to Reproduce:
1. Have a working Fedora 24 host enrolled in an IPA domain.
2. Upgrade to Fedora 26 with default options (all packages upgraded and successful).
3. Attempt graphical logins with GDM under Fedora 26.

Actual results:
User is unable to consistently login to GDM.

Expected results:
Valid user should be able to login properly.

Additional info:
Comment 1 Zbigniew Jędrzejewski-Szmek 2017-07-25 18:19:45 EDT
This error usually means that the systemd process is non-functional. In this case systemd@<uid>.service for your <uid>. Please attach the full logs from the boot, including a failed login attempt (journalctl -b).
Comment 2 Brian Sipos 2017-07-26 08:53 EDT
Created attachment 1304785 [details]
boot and login log

This is the result of "journalctl -b" on one of the failing hosts.
Comment 3 Brian Sipos 2017-07-26 09:25:06 EDT
After trying out logins some more on these hosts, it appears that after some time after boot (which seems to be inconsistent) I am able to get a graphical login on the host. Even after I do, the use of "systemctl --user" fails as described above. If I then log-out and attempt another login it will then fail when starting a gnome session (for the original reason above).
So there is some amount of non-repeatability that I'm seeing.
Comment 4 Zbigniew Jędrzejewski-Szmek 2017-07-26 10:57:00 EDT
Jul 26 08:48:18 dev-travel-t440.ipa.rkf-engineering.com systemd[1]: Created slice User Slice of bsipos.
Jul 26 08:48:18 dev-travel-t440.ipa.rkf-engineering.com systemd[1]: Starting User Manager for UID 1364400003...
Jul 26 08:48:18 dev-travel-t440.ipa.rkf-engineering.com systemd-logind[1025]: New session 2 of user bsipos.
Jul 26 08:48:18 dev-travel-t440.ipa.rkf-engineering.com systemd[1]: Started Session 2 of user bsipos.
Jul 26 08:48:18 dev-travel-t440.ipa.rkf-engineering.com systemd[1705]: pam_sss(systemd-user:account): Access denied for user bsipos: 6 (Permission denied)
                                                                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 26 08:48:18 dev-travel-t440.ipa.rkf-engineering.com audit[1705]: USER_ACCT pid=1705 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='op=PAM:accounting grantors=? acct="bsipos" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
Jul 26 08:48:18 dev-travel-t440.ipa.rkf-engineering.com systemd[1705]: user@1364400003.service: Failed at step PAM spawning /usr/lib/systemd/systemd: Operation not permitted
Jul 26 08:48:18 dev-travel-t440.ipa.rkf-engineering.com systemd[1]: Failed to start User Manager for UID 1364400003.
Jul 26 08:48:18 dev-travel-t440.ipa.rkf-engineering.com audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=user@1364400003 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
Jul 26 08:48:18 dev-travel-t440.ipa.rkf-engineering.com systemd[1]: user@1364400003.service: Unit entered failed state.
Jul 26 08:48:18 dev-travel-t440.ipa.rkf-engineering.com systemd[1]: user@1364400003.service: Failed with result 'protocol'.
Jul 26 08:48:18 dev-travel-t440.ipa.rkf-engineering.com gdm-password][1692]: pam_systemd(gdm-password:session): Failed to create session: Start job for unit user@1364400003.service failed with 'failed'
Jul 26 08:48:18 dev-travel-t440.ipa.rkf-engineering.com gdm-password][1692]: pam_unix(gdm-password:session): session opened for user bsipos by (uid=0)
Jul 26 08:48:19 dev-travel-t440.ipa.rkf-engineering.com audit[1692]: USER_START pid=1692 uid=0 auid=1364400003 ses=2 subj=system_u:system_r:xdm_t:s0-s0:c0.c1023 msg='op=PAM:session_open grantors=pam_selinux,pam_loginuid,pam_selinux,pam_keyinit,pam_namespace,pam_keyinit,pam_limits,pam_unix,pam_sss,pam_gnome_keyring acct="bsipos" exe="/usr/libexec/gdm-session-worker" hostname=dev-travel-t440.ipa.rkf-engineering.com addr=? terminal=/dev/tty2 res=success'
Jul 26 08:48:19 dev-travel-t440.ipa.rkf-engineering.com audit[1692]: USER_LOGIN pid=1692 uid=0 auid=1364400003 ses=2 subj=system_u:system_r:xdm_t:s0-s0:c0.c1023 msg='uid=1364400003 exe="/usr/libexec/gdm-session-worker" hostname=? addr=? terminal=? res=success'

It seems like pam_sss is denying the creation of the pam session. It'll reassing,
since this seems to be sssd specific.

Can you also paste your /etc/pam.d/systemd-user file?
Comment 5 Lukas Slebodnik 2017-07-26 11:43:55 EDT
It would be also good to provide sssd log files
https://docs.pagure.org/SSSD.sssd/users/troubleshooting.html#troubleshooting-authentication-password-change-and-access-control

BTW is user "bsipos" in local files /etc/passwd  or from freeIPA?
Comment 6 Brian Sipos 2017-07-26 12:47:54 EDT
This user is an IPA user, I do have a local account on a different host I can attach a log for. The thing about the GDM login is that it has the same failing behavior for the local user as the IPA user.

I am able to successufully get a non-graphical shell login from one of the VTs on the same host and I am able to enable SSH and get a remote shell login, which both work consistently. It's just the GDM login which has trouble.

Related to SSSd, I've also tried un-enrolling and re-enrolling the host with IPA. This has had no effect on the login trouble, seeing same behavior after as before the re-enrollment.
Comment 7 Brian Sipos 2017-07-26 12:48 EDT
Created attachment 1304918 [details]
Copy of /etc/pam.d/systemd-user from failing host
Comment 8 Brian Sipos 2017-07-26 13:42:11 EDT
Since it was mentioned above that the root cause seemed to be the "systemd-user" PAM service being disallowed, I checked my IPA HBAC configuration and found that my normal allow-user-login policy did not include the "systemd-user" service. I added that service to the allowed list in my IPA policy and now GDM logins (and "systemctl --user" from SSH logins) appear to work correctly.

We are mostly still on Fedora 24 here, and have just begun to migrate up to Fedora 26. I don't know when (either in FC25 or 26) that the behavior in either SSSD, PAM, or systemd may have changed but there may be a benefit in listing this issue on the upgrade bugs page <https://fedoraproject.org/wiki/Common_F26_bugs>. Only a suggestion, since this issue appears to be solved for me but this may help others figure out the same problem.
Comment 9 Lukas Slebodnik 2017-07-27 09:03:44 EDT
Brian,
I can see /etc/pam.d/systemd-user also on fedora24 and fedora25
with the same content as you attached in Comment 7.

SSSD is the same on f24+.

Are you sure that it works for you on f24? Maybe HBAC rules were configured differently for different hosts.

If it works on f24/f25 and does not work after upgrade to f26 then something had to change in systemd.
Comment 10 Brian Sipos 2017-07-27 09:17 EDT
Created attachment 1305363 [details]
journalctl log from succesful fedora 24 use

I've logged and attached a sequence from SSH login an "systemctl --user status" run. From what I can tell, it appears that systemd is using PAM differently between the two Fedora versions; in F24 it is using "pam_unix(systemd-user:session)" while in F26 it's using also "pam_sss(systemd-user:account)" to authorize access. F24 systemd never seems to use the PAM account validation.
Comment 11 Zbigniew Jędrzejewski-Szmek 2017-07-27 09:46:03 EDT
I don't think systemd pam code or config changed.
Is /etc/pam.d/systemd-user and /etc/pam.d/system-auth identical between F24 and F26? (It is here...)
Comment 12 Zbigniew Jędrzejewski-Szmek 2017-07-27 09:54:14 EDT
We added pam_loginuid in an update in F24 for #1328947. I believe that was the last significant change to the system pam stack.
Comment 13 Lukas Slebodnik 2017-07-27 10:27:15 EDT
Then /etc/pam.d/system-auth had to change after upgrade from f24 -> f26
Which might be related to BZ1449106. And some package called "authconfig --updateall" in rpm scriptlet. Because authconfig does not do it itself.

I was not able to see fixed version of authconfig for f24 in koji.
You might try to upgrade from f24 -> f25 and execute "authconfig --updateall" on your own. Then it might fail as well.


Or you can copy /etc/pam.d/system-auth from f26 to f24. And IMHO it will fail as well
Comment 14 Zbigniew Jędrzejewski-Szmek 2017-07-27 10:37:37 EDT
Is *your* /etc/pam.d/system-auth different between f24 and f26? Please paste the diff.
Comment 15 Brian Sipos 2017-07-27 13:47 EDT
Created attachment 1305617 [details]
differences from base fedora-24 to upgraded 24-to-26 file

I've attached a difference (from my other host running Fedora-24 enrolled on IPA domain) in the /etc/pam.d/system-auth file on my newly upgraded Fedora 26 host. This is after both an upgrade and an IPA unenroll-and-re-enroll to attempt to deal with my original problem.

As an interesting observation, I noticed that a freshly installed-and-enrolled Fedora 26 host has a fully identical /etc/pam.d/system-auth file from my installed-and-enrolled Fedora 24 host.
Comment 16 Pavel Březina 2017-07-28 05:07:03 EDT
This difference is in auth and password phases of pam authentication so it does not affect session and account phase which validates the account. But to be sure, does it work if you use system-auth file from f24 on f26?
Comment 17 Brian Sipos 2017-07-31 09:16:08 EDT
(In reply to Pavel Březina from comment #16)
> This difference is in auth and password phases of pam authentication so it
> does not affect session and account phase which validates the account. But
> to be sure, does it work if you use system-auth file from f24 on f26?

To clarify my original issue, the problem was never the PAM configuration on the Fedora log-in-able host. My problem was that in F24, systemd never requested the PAM service:method of "systemd-user:account" so I never needed to enable IPA HBAC rule for "systemd-user" to allow normal GDM logins.
In F26 (and maybe in F25, but I've not tested) there is now a use of PAM "systemd-user:account" so there needed to be a new IPA HBAC condition to allow this new use. I just didn't realize, until digging through logs and asking for your advice, that this PAM service was used/needed.

So to answer your question, the PAM configurations 'work' in both cases in that they are sending out proper requests to proper handlers.
Comment 18 Ian Collier 2017-08-03 15:54:33 EDT
We have had the same issue.  In our case, the systemd-user is failing in F24 but that isn't
preventing login, whereas the failure in F26 does prevent login.  It's my opinion that the
behaviour of gdm has changed.  (I reported bug 1473806 but ultimately it's the same as
the bug here.)
Comment 19 Petr Vobornik 2017-08-14 04:56:52 EDT
*** Bug 1473806 has been marked as a duplicate of this bug. ***
Comment 20 Jakub Hrozek 2017-09-06 15:37:05 EDT
Ray, are you aware of any GDM changes in Fedora-26 that could cause this behaviour?
Comment 22 MS 2017-11-06 20:59:31 EST
Having the same issue. I did notice that after rebooting F26 and I first log in as an IPA user in a non-GDM session then I can log in an IPA GDM session.
Comment 23 MS 2017-12-08 18:21:25 EST
Upgraded to F27 but still have the same issue logging in to a GDM session after machine reboot. What is the fix?
Comment 24 Ian Collier 2017-12-08 18:38:21 EST
If you are using HBAC on the IPA server the fix is to add systemd-user to the list of allowed services in your HBAC rules.

Note You need to log in before you can comment on or make changes to this bug.