Gigantische Apache Errorlogs

Wer kennt das nicht: Hin und wieder wachsen die Errorlogs von Apache binnen kürzester Zeit zu gigantischen Größen an. Wer (zweifelhaftes) Glück hat bemerkt das nicht weil das System hohen I/O Load davon bekommt, sondern erst wenn die Festplatte voll ist. Da steht schnell die Frage im Raum: „Tut das Not? Das muss doch nicht sein!“

Muss es auch nicht.

Unter CentOS 5 haben wir dazu den Apache angewiesen seine Errorlogs einfach an das Tool multilog aus den daemontools zu übergeben, das hat sich dann darum gekümmert die Logs zu rotieren wenn sie zu groß wurden, sie zu komprimieren (um genau zu sein: es kann ein externes Programm auf die Logfiles loslassen, z.B. einen Kompressor) und alte Logfiles beizeiten wegzuräumen:

ErrorLog "|/command/multilog s9999999 c40 n10 '!/bin/gzip' -*PHP*Deprecated* -*PHP*Notice* -*EACCELERATOR*hit* /var/log/httpd/errors"

Obendrein konnten wir so gleich noch ein paar PHP-Meldungen direkt verwerfen, so dass sie gar nicht erst geloggt wurden. In der Prozessliste sah das dann so aus:


7951 ? S 0:00 | \_ supervise httpd
12563 ? Ss 0:10 | | \_ /usr/sbin/httpd -D FOREGROUND
12565 ? S 0:00 | | \_ /command/multilog s9999999 c40 n10 '!/bin/gzip' -*PHP*Deprecated* -*PHP*Notice* -*EACCELERATOR*hit* /var/log/httpd/errors


Unter CentOS 6 hat das leider nicht mehr funktioniert. Offenbar beendete multilog dem Apache nicht schnell genug wenn er sich neugestartet hat und dann blockierte die neu gestartete multilog-Instanz weil sie die Dateien nicht locken konnte, da die alte Instanz noch Locks darauf hielt.

Deswegen waren lange Zeit unsere mit CentOS 5 laufenden Uberspace-Hosts etwas besser vor ausrastenden Applikationen die wie bekloppt das Errorlog vollspammen geschützt als die neueren mit CentOS 6 laufenden Hosts. Das war zwar manchmal auch amüsant (Spitzenreiter war bisher ein 300 GB großes Logfile, das in unter 6 Stunden geschrieben worden war), aber vor allem war es nervig und ärgerlich. Deshalb haben wir hier schon länger nach einer neuen Lösung gesucht.

Nun liefert das Apache-Projekt selbst eine ansatzweise Lösung mit: das Tool rotatelogs. Das kann aber leider nicht alles was multilog kann, z.B. kann es keine alten Logfiles wegräumen und nicht selbst den Input filtern. Aber es kann wie multilog ein externes Programm aufrufen und auf die Logfiles loslassen. Das funktioniert aber etwas umständlich, wie die Manpage zum Parameter „-p“ verrät:

If given, rotatelogs will execute the specified program every time a new log file is opened. The filename of the newly opened file is passed as the first argument to the program. If executing after a rotation, the old log file is passed as the second argument. rotatelogs does not wait for the specified program to terminate before continuing to operate, and will not log any error code returned on termination. The spawned program uses the same stdin, stdout, and stderr as rotatelogs itself, and also inherits the environment.

Ich hab daher ein Skript gebastelt, das den Großteil der Schwächen von rotatelogs gegenüber multilogs ausgleicht. Es sorgt für eine Kompression der Logfiles, es räumt alte Logfiles weg und aus der Testphase sind noch ein paar (eher unelegante) Debugging-Funktionen übrig: logjanitor.

Es ist dafür gedacht zusammen mit rotatelogs so genutzt zu werden:

ErrorLog "|| /usr/sbin/rotatelogs -f -p /usr/local/sbin/logjanitor -L /var/log/httpd/error_log /var/log/httpd/error_log.%Y-%m-%d-%H_%M_%S 86400 8M"

Bei dieser Konfiguration landen Logfiles im Ordner /var/log/httpd/ und bekommen einen detaillierten Zeitstempel in den Namen. Sie werden nach 86400 Sekunden (24 Stunden) rotiert, oder wenn Apache neustartet, oder wenn sie größer werden als 8 MB. Bei all diesen Gelegenheiten wird logjanitor ausgeführt und erhält ggf. noch Parameter von rotatelogs dazu, wie im obrigen Zitat beschrieben. Wenn logjanitor einen zweiten Parameter erhält, nimmt es an dass es sich um einen Dateinamen handelt komprimiert diese Datei. Außerdem sucht es in /var/log/httpd/ nach unkomprimierten Dateien mit dem passenden Namensschema und komprimiert diese ebenfalls. Schließlich löscht es alte Logs die älter als 7 Tage sind.

Mit dem Schalter -v lässt sich logjanitor gesprächiger machen. Das ist aber nur zum Testen gedacht. Da die Position der Parameter 1 und 2 relevant ist, sollte -v (oder -h) frühestens als dritter Parameter übergeben werden. (Ja, das kann alles noch schöner gemacht werden.) In diesem Fall schreibt logjanitor nach /var/log/logjanitor/“ ein Log (Achtung: hier gibt es keine automatische Rotation).

Nachdem heute auf einem unserer Hosts mal wieder die Festplatte mit PHP-Warnings vollgelaufen war, hab ich die Testphase kurzerhand für beendet erklärt und das jetzt auf allen Uberspace-Hosts ausgerollt. Falls noch Fehler auftreten, müssen die jetzt eben sofort gefixt werden.

Da wir sicher nicht die einzigen mit diesem Problem sind, dachte ich ich veröffentliche das direkt, manchmal gibt’s dann ja direkt noch interessanten Input. Das ganze ist zwar etwas mit der heißen Nadel gestrickt und noch nicht so elegant wie ich es gerne hätte, aber die nächste Version kommt bestimmt.