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.