Bug#823987: systemd: after upgrading some libs, login takes much longer until systemd-logind is restarted

Christoph Anton Mitterer calestyo at scientia.net
Wed May 18 03:35:44 BST 2016


Hey.

Another update on this... similar situation:
I was updating packages, needrestart offers me to restart dbus.service,
but ALSO systemd-logind.service.

# needrestart 
Scanning processes...                                                                                                                                                                         
Scanning candidates...                                                                                                                                                                        
Scanning linux images...                                                                                                                                                                      
Running kernel seems to be up-to-date.
Restarting services...
 systemctl daemon-reexec
 systemctl restart atd.service cron.service dbus.service epmd.service lvm2-lvmetad.service rpcbind.service smartd.service ssh.service systemd-journald.service systemd-logind.service
  systemd-udevd.service

[here it hangs for >5 mins, which is way more than the ssh/pam timeout reported before]

Job for systemd-logind.service failed because a timeout was exceeded. See "systemctl status systemd-logind.service" and "journalctl -xe" for details.
No containers need to be restarted.
User sessions running outdated binaries:
 root @ user manager service: systemd[27167]


journalctl gives:
May 18 04:23:40 kronecker systemd[1]: Reexecuting.
May 18 04:23:40 kronecker systemd[1]: systemd 229 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ -LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN)
May 18 04:23:40 kronecker systemd[1]: Detected architecture x86-64.
May 18 04:23:41 kronecker systemd[1]: Stopping Deferred execution scheduler...
May 18 04:23:41 kronecker systemd[1]: Started ACPI event daemon.
May 18 04:23:41 kronecker systemd[1]: Stopped Deferred execution scheduler.
May 18 04:23:41 kronecker systemd[1]: Started Deferred execution scheduler.
May 18 04:23:41 kronecker systemd[1]: Stopping udev Kernel Device Manager...
May 18 04:23:41 kronecker systemd[1]: Stopping Login Service...
May 18 04:23:41 kronecker systemd[1]: Stopped Flush Journal to Persistent Storage.
May 18 04:23:41 kronecker sshd[3656]: Received signal 15; terminating.
May 18 04:23:41 kronecker systemd[1]: Stopping Flush Journal to Persistent Storage...
May 18 04:23:41 kronecker systemd-journald[518]: Journal stopped
May 18 04:23:43 kronecker systemd-journald[32405]: Runtime journal (/run/log/journal/) is 14.7M, max 39.4M, 24.6M free.
May 18 04:23:43 kronecker systemd-journald[518]: Received SIGTERM from PID 1 (systemd).
May 18 04:23:43 kronecker systemd-journald[32405]: Journal started
May 18 04:23:41 kronecker cron[32365]: (CRON) INFO (pidfile fd = 3)
May 18 04:23:41 kronecker cron[32365]: (CRON) INFO (Skipping @reboot jobs -- not system startup)
May 18 04:23:43 kronecker systemd-logind[32401]: New seat seat0.
May 18 04:23:41 kronecker sshd[32363]: Server listening on [snipsnap]::2:3 port 22.
May 18 04:23:43 kronecker systemd[1]: Started User Manager for UID 0.
May 18 04:23:41 kronecker sshd[32363]: Server listening on [snipsnap] port 22.
May 18 04:23:43 kronecker systemd-logind[32401]: New session 77 of user root.
May 18 04:23:41 kronecker sshd[32363]: Server listening on [snipsnap]::1:0 port 22.
May 18 04:23:43 kronecker systemd[1]: Starting Flush Journal to Persistent Storage...
May 18 04:23:41 kronecker sshd[32363]: Server listening on 85.10.205.199 port 22.
May 18 04:23:41 kronecker sshd[32363]: Server listening on 127.0.1.1 port 22.
May 18 04:23:41 kronecker sshd[32363]: Server listening on ::1 port 22.
May 18 04:23:41 kronecker sshd[32363]: error: Bind to port 22 on ::1 failed: Address already in use.
May 18 04:23:41 kronecker sshd[32363]: Server listening on 127.0.0.1 port 22.
May 18 04:23:43 kronecker systemd[1]: Started Flush Journal to Persistent Storage.
May 18 04:23:43 kronecker systemd-udevd[32403]: invalid key/value pair in file /etc/udev/rules.d/z60_edac-utils.rules on line 11, starting at character 41 (',')
May 18 04:23:43 kronecker systemd[1]: Started udev Kernel Device Manager.
May 18 04:23:43 kronecker systemd[1]: Started RPC bind portmap service.
May 18 04:23:43 kronecker systemd[1]: Reached target RPC Port Mapper.
May 18 04:23:46 kronecker systemd[1]: Stopped A distributed, fault-tolerant Jabber/XMPP server.
May 18 04:23:46 kronecker systemd[1]: Stopping Erlang Port Mapper Daemon...
May 18 04:23:46 kronecker systemd[1]: Stopped Erlang Port Mapper Daemon.
May 18 04:23:46 kronecker systemd[1]: Started Erlang Port Mapper Daemon.
May 18 04:23:46 kronecker systemd[1]: Starting A distributed, fault-tolerant Jabber/XMPP server...
May 18 04:23:46 kronecker systemd[1]: ejabberd.service: PID file /run/ejabberd/ejabberd.pid not readable (yet?) after start: No such file or directory
May 18 04:23:48 kronecker systemd[1]: Started A distributed, fault-tolerant Jabber/XMPP server.
May 18 04:23:51 kronecker sshd[32469]: Postponed publickey for root from [snipsnap] port 34244 ssh2 [preauth]
May 18 04:23:51 kronecker sshd[32469]: Accepted publickey for root from [snipsnap] port 34244 ssh2: ED25519 SHA256:[snipsnap]
May 18 04:23:51 kronecker sshd[32469]: pam_unix(sshd:session): session opened for user root by (uid=0)
May 18 04:23:51 kronecker systemd-logind[32401]: New session 153 of user root.
May 18 04:24:16 kronecker sshd[32469]: pam_systemd(sshd:session): Failed to create session: Connection timed out


# systemctl status systemd-logind.service
● systemd-logind.service - Login Service
   Loaded: loaded (/lib/systemd/system/systemd-logind.service; static; vendor preset: enabled)
   Active: activating (start) since Wed 2016-05-18 04:28:13 CEST; 6s ago
     Docs: man:systemd-logind.service(8)
           man:logind.conf(5)
           http://www.freedesktop.org/wiki/Software/systemd/logind
           http://www.freedesktop.org/wiki/Software/systemd/multiseat
 Main PID: 32521 (systemd-logind)
   Status: "Processing requests..."
   CGroup: /system.slice/systemd-logind.service
           └─32521 /lib/systemd/systemd-logind

May 18 04:28:13 kronecker systemd[1]: Starting Login Service...
May 18 04:28:13 kronecker systemd-logind[32521]: New seat seat0.
May 18 04:28:13 kronecker systemd-logind[32521]: New session 77 of user root.
May 18 04:28:13 kronecker systemd-logind[32521]: New session 153 of user root.


It seems that eventually the services got restarted, at least another
needrestart run doesn't find any further needs.


So perhaps this is just the very same issue than before (me not a
systemd export O:-) ), but it looks different in that way, that it's
nothing with ssh/login that fails and that no such:
pam_systemd(sshd:session): Failed to create session: Connection timed out
seem to occur, but really "plain" restarting of services hangs.


HTH,
Chris.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/x-pkcs7-signature
Size: 5930 bytes
Desc: not available
URL: <http://alioth-lists.debian.net/pipermail/pkg-systemd-maintainers/attachments/20160518/3793ff72/attachment-0002.bin>


More information about the Pkg-systemd-maintainers mailing list