[Bug 1915502] Re: "systemd --user" fails to start for non-local users

Andy McVey 1915502 at bugs.launchpad.net
Wed Apr 7 21:17:35 UTC 2021


Dan, thanks for the comments, appreciate it.  In reply:

Using only "compat" in /etc/nsswitch.conf is legitimate and we use it
without issue on multiple Linux distributions as well as older Ubuntu
releases.  It invokes a different behaviour to using "nis", allowing
more fine grained control of who can authenticate from the NIS database
by appending +user|+netgroup to /etc/passwd.  FWIW, replacing "compat"
with "nis" and removing the + entries at the end of the passwd file
yields the same systemd behaviour.  Earlier in testing I tried using
sssd, going direct to AD, cutting out NIS entirely.  Using sssd also
failed to start the systemd user context.  I will try that again
tomorrow with the debug flags to see that shows up anything new.

getent passwd amcvey responds immediately and correctly, suggesting the
underlying calls to getpwnam() are also working correctly.  All other
NIS accounts are also resolved correctly and without delay.

I don't think using nscd will help much here, the issue is not the
response time from the NIS server(s) or the number of calls being made.
This also makes me think that the bug you referenced
(https://github.com/systemd/systemd/issues/12702) is not the root cause
here, as there are performance issues in that use case, which I'm not
seeing here at all.

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to systemd in Ubuntu.
https://bugs.launchpad.net/bugs/1915502

Title:
  "systemd --user" fails to start for non-local users

Status in systemd package in Ubuntu:
  Incomplete
Status in systemd source package in Focal:
  Incomplete

Bug description:
  systemd-logind fails to start the systemd --user process for non-local
  users on Ubuntu 20.04.  This is a reproducible problem; all our
  systems are displaying the same symptoms.

  The systems are using Kerberos (Active Directory) for authentication,
  and NIS for account meta-data and authorisation (groups)

  A base installation is performed using the server 20.04 ISO image.  No
  additional packages are selected.  Post-install, I run:

  apt-get install tcsh nis krb5-user libpam-krb5 libnss-systemd

  I set up the NIS client (supply the default domain name, check ypbind
  is running and ypcat passwd is working)

  I then set up /etc/krb5.conf for kerberos authentication to a domain
  controller, confirm that kinit works and a kerberos ticket is issued.

  I modify /etc/passwd, /etc/group and /etc/shadow, appending a "+" to
  the end of each.

  /etc/nsswitch.conf is modified to support compat mode, as well as
  systemd:

  passwd:         compat systemd
  group:          compat systemd
  shadow:         compat

  I can log in remotely via ssh using my NIS account and Kerberos
  credentials.  MY NIS meta-data looks like:

  amcvey:KRB5:<UID>:<GID>:Andy McVey:/home/amcvey:/bin/tcsh

  (where UID and GID are replaced with values unique to the
  organisation)

  On login, the following occurs:

  hostname:~> systemctl --user
  Failed to connect to bus: No such file or directory

  I put pam-systemd and systemd-logind into debug mode to get more
  information:

  Feb 12 09:51:32 myhostname sshd[1210]: Accepted publickey for amcvey from [redact] port 58849 ssh2: RSA SHA256:[redact]
  Feb 12 09:51:32 myhostname sshd[1210]: pam_unix(sshd:session): session opened for user amcvey by (uid=0)
  Feb 12 09:51:32 myhostname systemd-logind[903]: Got message type=method_call sender=:1.13 destination=org.freedesktop.login1 path=/org/freedesktop/login1 interface=org.freedesktop.login1.Manager member=CreateSession cookie=2 reply_cookie=0 signature=uusssssussbssa(sv) error-name=n/a error-message=n/a
  Feb 12 09:51:32 myhostname sshd[1210]: pam_systemd(sshd:session): pam-systemd initializing
  Feb 12 09:51:32 myhostname systemd-logind[903]: Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=GetConnectionUnixUser cookie=40 reply_cookie=0 signature=s error-name=n/a error-message=n/a
  Feb 12 09:51:32 myhostname sshd[1210]: pam_systemd(sshd:session): Asking logind to create session: uid=198083 pid=1210 service=sshd type=tty class=user desktop= seat= vtnr=0 tty= display= remote=yes remote_user= remote_host=10.105.121.110
  Feb 12 09:51:32 myhostname systemd-logind[903]: Got message type=method_return sender=org.freedesktop.DBus destination=:1.6 path=n/a interface=n/a member=n/a cookie=13 reply_cookie=40 signature=u error-name=n/a error-message=n/a
  Feb 12 09:51:32 myhostname sshd[1210]: pam_systemd(sshd:session): Session limits: memory_max=n/a tasks_max=n/a cpu_weight=n/a io_weight=n/a runtime_max_sec=n/a
  Feb 12 09:51:32 myhostname systemd-logind[903]: Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=GetConnectionUnixProcessID cookie=41 reply_cookie=0 signature=s error-name=n/a error-message=n/a
  Feb 12 09:51:32 myhostname sshd[1210]: pam_systemd(sshd:session): Failed to create session: No such process
  Feb 12 09:51:32 myhostname systemd-logind[903]: Got message type=method_return sender=org.freedesktop.DBus destination=:1.6 path=n/a interface=n/a member=n/a cookie=14 reply_cookie=41 signature=u error-name=n/a error-message=n/a
  Feb 12 09:51:32 myhostname systemd-logind[903]: Unable to connect to /run/systemd/userdb/io.systemd.Multiplexer: No such file or directory
  Feb 12 09:51:32 myhostname systemd-logind[903]: n/a: varlink: setting state idle-client
  Feb 12 09:51:32 myhostname systemd-logind[903]: /run/systemd/userdb/io.systemd.DynamicUser: Sending message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"uid":198083,"service":"io.systemd.DynamicUser"}}
  Feb 12 09:51:32 myhostname systemd-logind[903]: /run/systemd/userdb/io.systemd.DynamicUser: varlink: changing state idle-client → awaiting-reply
  Feb 12 09:51:32 myhostname systemd-logind[903]: /run/systemd/userdb/io.systemd.DynamicUser: New incoming message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
  Feb 12 09:51:32 myhostname systemd-logind[903]: /run/systemd/userdb/io.systemd.DynamicUser: varlink: changing state awaiting-reply → processing-reply
  Feb 12 09:51:32 myhostname systemd-logind[903]: Got lookup error: io.systemd.UserDatabase.NoRecordFound
  Feb 12 09:51:32 myhostname systemd-logind[903]: /run/systemd/userdb/io.systemd.DynamicUser: varlink: changing state processing-reply → idle-client
  Feb 12 09:51:32 myhostname systemd-logind[903]: Sent message type=error sender=n/a destination=:1.13 path=n/a interface=n/a member=n/a cookie=42 reply_cookie=2 signature=s error-name=org.freedesktop.DBus.Error.UnixProcessIdUnknown error-message=No such process
  Feb 12 09:51:32 myhostname systemd-logind[903]: Failed to process message type=method_call sender=:1.13 destination=org.freedesktop.login1 path=/org/freedesktop/login1 interface=org.freedesktop.login1.Manager member=CreateSession cookie=2 reply_cookie=0 signature=uusssssussbssa(sv) error-name=n/a error-message=n/a: No such process

  So it seems logind is trying to get the PID of the calling (sshd?)
  process and failing.  What's strange is that if I add my NIS entry
  directly to /etc/password it works.  systemctl --user works, and the
  following appears in the logs:

  
  Feb 12 09:59:20 myhostname sshd[1295]: Accepted publickey for amcvey from [redact] port 50775 ssh2: RSA SHA256:[redact]
  Feb 12 09:59:20 myhostname sshd[1295]: pam_unix(sshd:session): session opened for user amcvey by (uid=0)
  Feb 12 09:59:20 myhostname systemd-logind[903]: Got message type=method_call sender=:1.14 destination=org.freedesktop.login1 path=/org/freedesktop/login1 interface=org.freedesktop.login1.Manager member=CreateSession cookie=2 reply_cookie=0 signature=uusssssussbssa(sv) error-name=n/a error-message=n/a
  Feb 12 09:59:20 myhostname sshd[1295]: pam_systemd(sshd:session): pam-systemd initializing
  Feb 12 09:59:20 myhostname systemd-logind[903]: Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=GetConnectionUnixUser cookie=43 reply_cookie=0 signature=s error-name=n/a error-message=n/a
  Feb 12 09:59:20 myhostname sshd[1295]: pam_systemd(sshd:session): Asking logind to create session: uid=[redact] pid=1295 service=sshd type=tty class=user desktop= seat= vtnr=0 tty= display= remote=yes remote_user= remote_host=10.105.121.110
  Feb 12 09:59:20 myhostname systemd-logind[903]: Got message type=method_return sender=org.freedesktop.DBus destination=:1.6 path=n/a interface=n/a member=n/a cookie=15 reply_cookie=43 signature=u error-name=n/a error-message=n/a
  Feb 12 09:59:20 myhostname sshd[1295]: pam_systemd(sshd:session): Session limits: memory_max=n/a tasks_max=n/a cpu_weight=n/a io_weight=n/a runtime_max_sec=n/a
  Feb 12 09:59:20 myhostname systemd-logind[903]: Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=GetConnectionUnixProcessID cookie=44 reply_cookie=0 signature=s error-name=n/a error-message=n/a
  Feb 12 09:59:20 myhostname systemd-logind[903]: Got message type=method_return sender=org.freedesktop.DBus destination=:1.6 path=n/a interface=n/a member=n/a cookie=16 reply_cookie=44 signature=u error-name=n/a error-message=n/a
  Feb 12 09:59:20 myhostname systemd-logind[903]: Unable to connect to /run/systemd/userdb/io.systemd.Multiplexer: No such file or directory
  Feb 12 09:59:20 myhostname systemd-logind[903]: n/a: varlink: setting state idle-client
  Feb 12 09:59:20 myhostname systemd-logind[903]: /run/systemd/userdb/io.systemd.DynamicUser: Sending message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"uid":198083,"service":"io.systemd.DynamicUser"}}
  Feb 12 09:59:20 myhostname systemd-logind[903]: /run/systemd/userdb/io.systemd.DynamicUser: varlink: changing state idle-client → awaiting-reply
  Feb 12 09:59:20 myhostname systemd-logind[903]: /run/systemd/userdb/io.systemd.DynamicUser: New incoming message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
  Feb 12 09:59:20 myhostname systemd-logind[903]: /run/systemd/userdb/io.systemd.DynamicUser: varlink: changing state awaiting-reply → processing-reply
  Feb 12 09:59:20 myhostname systemd-logind[903]: Got lookup error: io.systemd.UserDatabase.NoRecordFound
  Feb 12 09:59:20 myhostname systemd-logind[903]: /run/systemd/userdb/io.systemd.DynamicUser: varlink: changing state processing-reply → idle-client
  Feb 12 09:59:20 myhostname systemd-logind[903]: Failed to do shadow lookup for UID [redact], ignoring: No such process
  Feb 12 09:59:20 myhostname systemd-logind[903]: Starting services for new user amcvey.
  Feb 12 09:59:20 myhostname systemd-logind[903]: Sent message type=method_call sender=n/a destination=org.freedesktop.systemd1 path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=StartUnit cookie=45 reply_cookie=0 signature=ss error-name=n/a error-message=n/a
  Feb 12 09:59:20 myhostname systemd-logind[903]: Got message type=method_return sender=:1.0 destination=:1.6 path=n/a interface=n/a member=n/a cookie=412 reply_cookie=45 signature=o error-name=n/a error-message=n/a
  Feb 12 09:59:20 myhostname systemd-logind[903]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/login1 interface=org.freedesktop.login1.Manager member=UserNew cookie=46 reply_cookie=0 signature=uo error-name=n/a error-message=n/a
  Feb 12 09:59:20 myhostname systemd-logind[903]: Sent message type=method_call sender=n/a destination=org.freedesktop.systemd1 path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=StartTransientUnit cookie=47 reply_cookie=0 signature=ssa(sv)a(sa(sv)) error-name=n/a error-message=n/a
  Feb 12 09:59:20 myhostname systemd-logind[903]: Got message type=method_return sender=:1.0 destination=:1.6 path=n/a interface=n/a member=n/a cookie=431 reply_cookie=47 signature=o error-name=n/a error-message=n/a
  Feb 12 09:59:20 myhostname systemd-logind[903]: New session 4 of user amcvey.

  
  root at ottub2004tst01:/etc# dpkg -l | grep systemd
  ii  dbus-user-session                    1.12.16-2ubuntu2.1                    amd64        simple interprocess messaging system (systemd --user integration)
  ii  libnss-systemd:amd64                 245.4-4ubuntu3.4                      amd64        nss module providing dynamic user and group name resolution
  ii  libpam-systemd:amd64                 245.4-4ubuntu3.4                      amd64        system and service manager - PAM module
  ii  libsystemd0:amd64                    245.4-4ubuntu3.4                      amd64        systemd utility library
  ii  networkd-dispatcher                  2.0.1-1                               all          Dispatcher service for systemd-networkd connection status changes
  ii  python3-systemd                      234-3build2                           amd64        Python 3 bindings for systemd
  ii  systemd                              245.4-4ubuntu3.4                      amd64        system and service manager
  ii  systemd-sysv                         245.4-4ubuntu3.4                      amd64        system and service manager - SysV links
  ii  systemd-timesyncd                    245.4-4ubuntu3.4                      amd64        minimalistic service to synchronize local time with NTP servers

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/systemd/+bug/1915502/+subscriptions



More information about the foundations-bugs mailing list