tl;dr: Check for cronjobs (passive like icinga-checks and active like crontabs!) and execute loginctl enable-linger [affected user]. Replace [affected user] with the user which is used for login with SSH or is executing the cronjob. Auf Cronjobs prüfen (passive Jobs wie Prüfungen von Icinga über SSH und aktive Prüfungen wie Crontabs) und für den betreffenden Benutzer, der diesen Job ausführt bzw. als Loginuser genutzt wird, loginctl enable-linger [Benutzer] ausführen.

Eigentlich hatte ich großen Respekt vor dem Upgrade von Debian Wheezy auf Jessie. Eingestiegen bin ich damals auf Squeeze; das war ein OpenVZ-Containerchen mit 1GB RAM, den ich mir offenbar regelmäßig mit anderen teilte. Seitdem bin ich nur noch mit KVM-Containern in Beziehungen, und die Kündigung damals hatte ich dem Hoster zugesandt, als Wheezy gerade das stabile Laufen gelernt hatte. Entsprechend dem setzte ich die Box bei dem neuen Provider neu auf, stieg gleichzeitig von Froxlor auf komplette eigene Administration unter nginx und mariadb um und hatte so ein Upgrade umgangen.

Mit dem Release von Jessie sah das anders aus. Ich wollte gern die Neuerungen mitnehmen und nicht im LTS verschwinden, zumindest nicht auf isogramm, meinem Server für die meisten Webseiten. Also musste das Update sein, und lief auch sauber – apt-get update, apt-get dist-upgrade und fertig. Denkste.

Die Pakete machten keine Probleme, sehr wohl aber systemd – das nun, alle paar Sekunden folgende Ausgabe ins /var/log/syslog kippte:

Aug  2 21:57:49 isogramm systemd[2334]: Starting Paths.
Aug  2 21:57:49 isogramm systemd[2334]: Reached target Paths.
Aug  2 21:57:49 isogramm systemd[2334]: Starting Timers.
Aug  2 21:57:49 isogramm systemd[2334]: Reached target Timers.
Aug  2 21:57:49 isogramm systemd[2334]: Starting Sockets.
Aug  2 21:57:49 isogramm systemd[2334]: Reached target Sockets.
Aug  2 21:57:49 isogramm systemd[2334]: Starting Basic System.
Aug  2 21:57:49 isogramm systemd[2334]: Reached target Basic System.
Aug  2 21:57:49 isogramm systemd[2334]: Starting Default.
Aug  2 21:57:49 isogramm systemd[2334]: Reached target Default.
Aug  2 21:57:49 isogramm systemd[2334]: Startup finished in 10ms.
Aug  2 21:57:49 isogramm systemd[2334]: Stopping Default.
Aug  2 21:57:49 isogramm systemd[2334]: Stopped target Default.
Aug  2 21:57:49 isogramm systemd[2334]: Stopping Basic System.
Aug  2 21:57:49 isogramm systemd[2334]: Stopped target Basic System.
Aug  2 21:57:49 isogramm systemd[2334]: Stopping Paths.
Aug  2 21:57:49 isogramm systemd[2334]: Stopped target Paths.
Aug  2 21:57:49 isogramm systemd[2334]: Stopping Timers.
Aug  2 21:57:49 isogramm systemd[2334]: Stopped target Timers.
Aug  2 21:57:49 isogramm systemd[2334]: Stopping Sockets.
Aug  2 21:57:49 isogramm systemd[2334]: Stopped target Sockets.
Aug  2 21:57:49 isogramm systemd[2334]: Starting Shutdown.
Aug  2 21:57:49 isogramm systemd[2334]: Reached target Shutdown.
Aug  2 21:57:49 isogramm systemd[2334]: Starting Exit the Session...
Aug  2 21:57:49 isogramm systemd[2334]: Received SIGRTMIN+24 from PID 2340 (kill).

Das ganze gabs dann aber nicht nur alle paar Minuten, sondern dankenswerter Weise auch gleich im Sekundentakt – mal mehr, mal weniger verzögert. Drei Mal je Minute auf jeden Fall. Die Lösungsansätze waren nicht sehr vielfältig; im Web meinten die meisten, es könne etwas mit Cronjobs zu tun haben. Hat es aber nicht; zumindest bei mir nicht; denn ein Stoppen des cron-Daemons half nicht. Also: Die Lösung muss woanders liegen.

Irgendwie wird dort immer ein systemd gestartet. Und dann wieder beendet. Es dauerte eine Weile, bis mir relativ klar war: dort muss eine Instanz für einen Nutzer (also Linux-User) geöffnet werden, und dann wieder beendet – weil der Nutzer die Maschine quasi virtuell verlässt. Der Nutzer könnte jeder erdenkliche Daemon sein. Durch ein Stoppen vom dbus wurde mir im syslog dann ausgeworfen, dass man org.freedesktop.login1 nicht starten könne – sagt mir nichts. Über etwas Recherche lies sich herausfinden, dass eben jener Loginservice mit systemd-logind  zusammenhängt – und den habe ich dann gefragt, was denn los ist:

# systemctl status systemd-logind
● systemd-logind.service - Login Service
   Loaded: loaded (/lib/systemd/system/systemd-logind.service; static)
   Active: active (running) since So 2015-08-02 21:56:05 CEST; 41min 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: 691 (systemd-logind)
   Status: "Processing requests..."
   CGroup: /system.slice/systemd-logind.service
           └─691 /lib/systemd/systemd-logind

Aug 02 21:57:49 isogramm systemd-logind[691]: New session 253 of user icinga2ssh.
Aug 02 21:57:49 isogramm systemd-logind[691]: Removed session 253.

Ah ja. Jetzt ist es doch schon klarer – es muss mit dem User icinga2ssh zusammenhängen. Dieser User wird bei mir genutzt, damit sich mein Monitoring-System (Icinga2) aus einem anderen Rechenzentrum auf den Server verbinden kann und dort Informationen zu Plattenplatz, apt und anderen abfragen kann. Und genau das passiert alle 3 Sekunden, und dann in ganz kurzen Abständen. Bingo. Das Zeitmuster von den Prüfungen passt exakt auf die Meldungen im syslog.

Damit sich nicht bei jedem Login einer neuer systemd spawnt, gibts dafür eine Option, den einfach laufen zu lassen: loginctl enable-linger icinga2ssh.

Irgendwie war mich doch so, dass mir systemd nicht allzu sympatisch ist.

One Responses

  • schweini

    Danke!

    Mit hatten die ganzen log-eintraege auch schon Sorgen gemacht. Langsam aber sichr misfaellt mir, dass Debian auf systemd umgestiegen ist, mehr und mehr.

    Antworten

Schreibe einen Kommentar

Deine E-Mail-Adresse wird nicht veröffentlicht. Erforderliche Felder sind mit * markiert