Cron-Jobs werden nicht mehr gestartet

Kürzlich wurde auf einem unserer AIX Systeme kein Cron-Job mehr gestartet. Es gab keinen Eintrag im Error Report und auch per Syslog konnte kein Hinweis auf das Problem gefunden werden. Im Log des cron-Daemon fanden sich allerdings jede Menge Meldungen:

# cat /var/adm/cron/log
...
! c queue max run limit reached Sat Feb 23 08:49:00 2019
! rescheduling a cron job Sat Feb 23 08:49:00 2019
...

Unter AIX ist die Anzahl der aktiven Cron-Jobs standardmäßig auf maximal 100 gesetzt. Offensichtlich war diese Anzahl auf unserem System erreicht worden. Neue Einträge werden dann per Default 60 Sekunden später ausgeführt. Beides kann über die Datei /var/adm/cron/queuedefs konfiguriert werden. Der Wert 100 ist allerdings schon recht hoch und ein Erreichen des Wertes deutet auf ein Problem hin.

Die PID des cron-Daemon lässt sich schnell herausfinden:

$ ps -ef|grep cron
    root  6684924        1   0   Sep 26      -  8:03 /usr/sbin/cron
$

Die aktuell aktiven Cron-Jobs laufen als Sohn-Prozesse des cron. Mit der Option „-T“ des ps-Kommandos lassen wir uns diese auflisten:

$ ps -T 6684924
      PID    TTY  TIME CMD
  6684924      -  8:03 cron
  3276876      -  0:00    |\--perl
  9961588      -  0:00    |    \--mount
 12714002      -  0:07    |        \--nfsmnthelp
  3604516      -  0:00    |\--perl
 20185130      -  0:00    |    \--mount
 10158264      -  0:35    |        \--nfsmnthelp
  4587542      -  0:00    |\--perl
...

Es fällt sofort auf, das sich die Zeilen immer wieder wiederholen, d.h. ein Perl-Programm wurde per cron immer wieder gestartet, dieses hat versucht ein Filesystem per NFS zu mounten, was aber nicht funktioniert hat (keine Antwort vom NFS-Server) und das Perl-Skript hängt. Da das Skript immer wieder neu gestartet wurde, gab es dann ab irgendeinem Zeitpunkt 100 aktive Cron-Jobs und von diesem Moment an wurden dann keine weiteren Cron-Jobs mehr gestartet. Wir zählen kurz die aktiven Perl-Prozesse:

$ ps -T 6684924 |grep perl |wc -l
     100
$

Es sind genau 100 Perl-Prozesse, die von cron gestartet wurden. Wir beenden einige der hängenden Perl-Prozesse:

# kill 3276876 3604516  4587542
#

Ein Blick ans Ende der Logdatei von cron zeigt das Jobs beendet wurden, und nach kurzer Zeit taucht dann auch schon der erste neu gestartete Cron-Job auf:

# tail –f /var/adm/cron/log
…
Cron Job with pid: 3276876 Failed
Cron Job with pid: 3604516  Failed
Cron Job with pid: 4587542Failed
mqm       : CMD ( /appdata/mqm/admin/bin/checks/checkXmitMonitoring.sh >>/appdata/mqm/tracks/logs/scheduler/checkXmitMonitoring.fatal 2>&1 ) : PID ( 28442840 ) : Mon Feb 25 10:34:00 2019
…

Wir beenden auch die übrigen hängenden Prozesse und restarten den cron-Daemon sicherheitshalber, indem wir ihn einfach beenden:

# kill 6684924
#

Der cron-Daemon wird Dank eines /etc/inittab-Eintrags automatisch neu gestartet:

# lsitab cron
cron:23456789:respawn:/usr/sbin/cron
#

Nachdem cron wieder arbeitet, sollte das Perl-Skript untersucht werden, welches letztlich zum Hängen von cron geführt hat. Bei regelmäßig per cron gestarteten Skripten empfiehlt sich eine Überprüfung, ob der Job eventuell noch oder schon läuft.

%d Bloggern gefällt das: