systemd-logind (war pve-ha-lrm crash)

jms1000

Well-Known Member
Oct 25, 2016
150
4
58
60
Germany, Schkeuditz
www.sv-forensik.de
Hallo,

ab und an bekomme ich die nachfolgende Meldung. in folge läuft zwar alles weiter, der proxmo-server braucht jedoch Ewigkeiten bis ich eine Konsole oder ein Login auf der Shell (ssh) bekomme. Abhilfe bekomme ich nur durch einen Reboot. nervig. hat jemand Vorschläge woher das kommt und wie ich Abhilfe bekomme? das ganze tritt auf unterschiedlichen Servern (Hardware) und zu unterschiedlichen Zeiten auf ... es läuft ein aktuelles 5.x proxmox auf den proxmoxen ...

Sep 7 15:28:00 prx4 systemd[1]: Starting Proxmox VE replication runner...
Sep 7 15:28:02 prx4 systemd[1]: Started Proxmox VE replication runner.
Sep 7 15:28:10 prx4 pmxcfs[2303]: [status] notice: received log
Sep 7 15:29:00 prx4 systemd[1]: Starting Proxmox VE replication runner...
Sep 7 15:29:02 prx4 systemd[1]: Started Proxmox VE replication runner.
Sep 7 15:29:58 prx4 kernel: [426054.926294] INFO: task pve-ha-lrm:20187 blocked for more than 120 seconds.
Sep 7 15:29:58 prx4 kernel: [426054.926328] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Sep 7 15:29:58 prx4 kernel: [426054.926345] Call Trace:
Sep 7 15:29:58 prx4 kernel: [426054.926351] schedule+0x36/0x80
Sep 7 15:29:58 prx4 kernel: [426054.926353] ? ktime_get+0x41/0xb0
Sep 7 15:29:58 prx4 kernel: [426054.926356] __lock_page+0x10d/0x150
Sep 7 15:29:58 prx4 kernel: [426054.926357] pagecache_get_page+0x19f/0x2a0
Sep 7 15:29:58 prx4 kernel: [426054.926359] shmem_unused_huge_scan+0x20/0x30
Sep 7 15:29:58 prx4 kernel: [426054.926361] shrink_slab.part.40+0x1f5/0x420
Sep 7 15:29:58 prx4 kernel: [426054.926365] do_try_to_free_pages+0xf5/0x330
Sep 7 15:29:58 prx4 kernel: [426054.926367] __alloc_pages_slowpath+0x40f/0xba0
Sep 7 15:29:58 prx4 kernel: [426054.926370] alloc_pages_current+0x95/0x140
Sep 7 15:29:58 prx4 kernel: [426054.926373] alloc_set_pte+0x592/0x600
Sep 7 15:29:58 prx4 kernel: [426054.926376] ? common_mmap+0x48/0x50
Sep 7 15:29:58 prx4 kernel: [426054.926379] do_page_fault+0x22/0x30
Sep 7 15:29:58 prx4 kernel: [426054.926382] RAX: 0000000000000000 RBX: 0000560c5c040040 RCX: 0000000000000000
Sep 7 15:29:58 prx4 kernel: [426054.926383] R13: 0000000000000010 R14: 0000000000000000 R15: 0000000000000010

Nachtrag: Im Syslog findet sich dann auch noch so etwas:

Sep 8 10:38:16 prx4 systemd[1]: systemd-logind.service: Watchdog timeout (limit 3min)!
Sep 8 10:38:16 prx4 systemd[1]: systemd-logind.service: Killing process 1851 (systemd-logind) with signal SIGABRT.
Sep 8 10:39:46 prx4 systemd[1]: systemd-logind.service: State 'stop-sigabrt' timed out. Terminating.
Sep 8 10:41:16 prx4 systemd[1]: systemd-logind.service: State 'stop-sigterm' timed out. Killing.
Sep 8 10:41:16 prx4 systemd[1]: systemd-logind.service: Killing process 1851 (systemd-logind) with signal SIGKILL.
Sep 8 10:42:46 prx4 systemd[1]: systemd-logind.service: Processes still around after SIGKILL. Ignoring.
 
Ich habe mal noch etwas weiter gesucht. Scheint nicht der pve-ha-lrm zu sein, der kann wohl nur nicht mehr, weil der systemd-logind.service klemmt. bevor der anfängt zu spucken, passiert immer so was (nach einem ssh-logout):

Sep 8 10:28:16 prx4 sshd[4135]: pam_unix(sshd:session): session closed for user root
Sep 8 10:28:16 prx4 systemd-logind[1974]: Removed session 1298.
Sep 8 10:28:16 prx4 systemd[1]: Stopping User Manager for UID 0...
Sep 8 10:28:16 prx4 systemd[11897]: Stopped target Default.
Sep 8 10:28:16 prx4 systemd[11897]: Stopped target Basic System.
Sep 8 10:28:16 prx4 systemd: pam_unix(systemd-user:session): session closed for user root
Sep 8 10:28:16 prx4 systemd[11897]: Stopped target Sockets.
Sep 8 10:28:16 prx4 systemd[11897]: Closed GnuPG cryptographic agent and passphrase cache.
Sep 8 10:28:16 prx4 systemd[11897]: Closed GnuPG cryptographic agent (ssh-agent emulation).
Sep 8 10:28:16 prx4 systemd[11897]: Closed GnuPG cryptographic agent (access for web browsers).
Sep 8 10:28:16 prx4 systemd[11897]: Closed GnuPG cryptographic agent and passphrase cache (restricted).
Sep 8 10:28:16 prx4 systemd[11897]: Reached target Shutdown.
Sep 8 10:28:16 prx4 systemd[11897]: Starting Exit the Session...
Sep 8 10:28:16 prx4 systemd[11897]: Stopped target Paths.
Sep 8 10:28:16 prx4 systemd[11897]: Stopped target Timers.
Sep 8 10:28:16 prx4 systemd[11897]: Received SIGRTMIN+24 from PID 11044 (kill).
Sep 8 10:28:16 prx4 systemd[1]: Stopped User Manager for UID 0.
Sep 8 10:28:16 prx4 systemd[1]: Removed slice User Slice of root.
Sep 8 10:29:00 prx4 systemd[1]: Starting Proxmox VE replication runner...
Sep 8 10:29:00 prx4 systemd[1]: Started Proxmox VE replication runner.
Sep 8 10:30:00 prx4 systemd[1]: Starting Proxmox VE replication runner...
Sep 8 10:30:00 prx4 systemd[1]: Started Proxmox VE replication runner.
Sep 8 10:30:20 prx4 liblogging-stdlog: -- MARK --
Sep 8 10:31:00 prx4 systemd[1]: Starting Proxmox VE replication runner...
Sep 8 10:31:00 prx4 systemd[1]: systemd-logind.service: Watchdog timeout (limit 3min)!
Sep 8 10:31:00 prx4 systemd[1]: systemd-logind.service: Killing process 1974 (systemd-logind) with signal SIGABRT.
Sep 8 10:31:00 prx4 systemd[1]: Started Proxmox VE replication runner.
Sep 8 10:32:00 prx4 systemd[1]: Starting Proxmox VE replication runner...
Sep 8 10:32:00 prx4 systemd[1]: Started Proxmox VE replication runner.
Sep 8 10:32:30 prx4 systemd[1]: systemd-logind.service: State 'stop-sigabrt' timed out. Terminating.
Sep 8 10:33:00 prx4 systemd[1]: Starting Proxmox VE replication runner...
Sep 8 10:33:00 prx4 systemd[1]: Started Proxmox VE replication runner.
Sep 8 10:34:00 prx4 systemd[1]: Starting Proxmox VE replication runner...
Sep 8 10:34:00 prx4 systemd[1]: Started Proxmox VE replication runner.
Sep 8 10:34:00 prx4 systemd[1]: systemd-logind.service: State 'stop-sigterm' timed out. Killing.
Sep 8 10:34:00 prx4 systemd[1]: systemd-logind.service: Killing process 1974 (systemd-logind) with signal SIGKILL.


Hat jemand Vorschläge zu Lösung oder zu Ursache? System ist vom Proxmos-ISO installiert, dann aktualsiert und ohne extras ...

MfG. Jörg
 
UPS! Nachdem sich der systemd-logind.servie eingestellt hat, läuft zwar scheinbar alles weiter (außer das ein Login auf dem Proxmox-Server sehr lange dauert), aber dem ist wohl doch nicht so.

Ich wollte jetzt mal einen LXC (HA) von einem Proxmox-Server auf dem anderen migrieren und bekomme so etwas im Logfile:

Sep 11 12:53:19 prx1 pvestatd[9315]: Use of uninitialized value in concatenation (.) or string at /usr/share/perl5/PVE/Tools.pm line 932.
Sep 11 12:53:19 prx1 pvestatd[9315]: Use of uninitialized value in concatenation (.) or string at /usr/share/perl5/PVE/Tools.pm line 932.
Sep 11 12:53:19 prx1 pvestatd[9315]: Use of uninitialized value in concatenation (.) or string at /usr/share/perl5/PVE/Tools.pm line 932.
Sep 11 12:53:19 prx1 pvestatd[2453]: Argument "" isn't numeric in int at /usr/share/perl5/PVE/Tools.pm line 945, <GEN36504190> line 1.
Sep 11 12:53:19 prx1 pvestatd[2453]: Argument "" isn't numeric in int at /usr/share/perl5/PVE/Tools.pm line 946, <GEN36504190> line 2.
Sep 11 12:53:19 prx1 pvestatd[2453]: Argument "" isn't numeric in int at /usr/share/perl5/PVE/Tools.pm line 947, <GEN36504190> line 3.
Sep 11 12:53:19 prx1 pve-ha-lrm[7405]: Task 'UPID:prx1:00001CEF:01F1220B:59B66AC0:vzshutdown:20116:root@pam:' still active, waiting
Sep 11 12:54:04 prx1 pve-ha-lrm[7405]: Task 'UPID:prx1:00001CEF:01F1220B:59B66AC0:vzshutdown:20116:root@pam:' still active, waiting

und dort hängt das Ding jetzt fest und bringt immer die gleichen Meldungen ...
 
Tja schade, das Problem taucht nun doch wieder auf: ich habe ewig lange Antwortzeiten beim anmelden auf einem Proxmox-Server. Im Syslog kann man dann lesen das der systemd-logind.service einen weg hat:

Sep 14 15:33:37 prx4 systemd[1]: systemd-logind.service: Unit entered failed state.
Sep 14 15:33:37 prx4 systemd[1]: systemd-logind.service: Failed with result 'exit-code'.
Sep 14 15:33:37 prx4 systemd[1]: systemd-logind.service: Service has no hold-off time, scheduling restart.
Sep 14 15:33:37 prx4 systemd-logind[24460]: Failed to register name: File exists
Sep 14 15:33:37 prx4 systemd-logind[24460]: Failed to fully start up daemon: File exists
Sep 14 15:33:37 prx4 systemd[1]: systemd-logind.service: Main process exited, code=exited, status=1/FAILURE
Sep 14 15:35:08 prx4 systemd[1]: systemd-logind.service: State 'stop-sigterm' timed out. Killing.
Sep 14 15:35:08 prx4 systemd[1]: systemd-logind.service: Killing process 2131 (systemd-logind) with signal SIGKILL.
Sep 14 15:36:38 prx4 systemd[1]: systemd-logind.service: Processes still around after SIGKILL. Ignoring.


und die Abfrage des Status ergibt das hier:

systemctl status systemd-logind.service
● systemd-logind.service - Login Service
Loaded: loaded (/lib/systemd/system/systemd-logind.service; static; vendor preset: enabled)
Active: deactivating (stop-sigkill) (Result: exit-code) since Thu 2017-09-14 14:56:00 CEST; 33min 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
Process: 18705 ExecStart=/lib/systemd/systemd-logind (code=exited, status=1/FAILURE)
Main PID: 18705 (code=exited, status=1/FAILURE)
Status: "Shutting down..."
Tasks: 1 (limit: 4915)
CGroup: /system.slice/systemd-logind.service
└─2131 /lib/systemd/systemd-logind

Sep 14 15:27:36 prx4 systemd[1]: Starting Login Service...
Sep 14 15:27:36 prx4 systemd[1]: systemd-logind.service: Main process exited, code=exited, status=1/FAILURE
Sep 14 15:29:06 prx4 systemd[1]: systemd-logind.service: State 'stop-sigterm' timed out. Killing.
Sep 14 15:29:06 prx4 systemd[1]: systemd-logind.service: Killing process 2131 (systemd-logind) with signal SIGK


Hat jemand Vorschläge zur Lösungsfindung?

MfG. Jörg

PS: System ist auf dem aktuellen 5.x Stand ...
 
Wie ich feststellen musste, klemmen bei Ausfall des systemd-logind.service nicht nur die ssh Connects, es klappt auch keine Migration vom/zum Proxmox-Server. Ich vermute hier auch den hohen Timeout.

Nachdem ich keine andere Lösung gefunden habe, habe ich das Ding einfach deaktiviert (systemctl mask systemd-logind.service) und den Server neu gestartet. Nun scheint alles wieder zu laufen.

Hat jemand gegenteilige Meinungen warum man Ding nicht abschalten sollte?

MfG. Jörg