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.

11 Antworten zu “Gigantische Apache Errorlogs”

  1. Marc sagt:

    Schon mal überlegt Logstash (http://logstash.net/) einzusetzen?

    Da steckt natürlich ein bissl mehr Aufwand drin, aber wenn viele Logs anfallen kann sich das schon lohnen. Wenn man als Backend das empfohlene Elastic Search verwendet, kann man die Logs auch vielfältig auswerten.

  2. Christopher Hirschmann sagt:

    Hm, interessant. Aber nicht wirklich was für unseren Use-Case. Wir wollen die Logs ja gerade nicht ewig archivieren sondern eher schnell loswerden (Datensparsamkeit) und wir brauchen auch eher keinen Suchindex.

    Wenn wir Logs zentral einsammeln wollen verwenden wir syslog-ng.

  3. Martin sagt:

    Warum loggt ihr das denn dann überhaupt, Notices und co sind ja auch nicht gerade so interessant.

    ansonsten: http://cronolog.org/

  4. Christopher Hirschmann sagt:

    Das ist nicht unsere Entscheidung. Wir brauchen ein ErrorLog um Usern die sich mit Problemen an uns wenden sagen zu können, woran es liegt. Und leider schreibt enorm viele Software abartig viel Zeug ins Log.

    cronolog scheint nun quasi das gleiche zu machen wie multilog und rotatelogs, wobei multilog bei uns aber aus den geschilderten Gründen leider nicht mehr passt und rotatelogs schon mit dem Apache installiert wurde… insofern hab ich da einer Lösung die schon vorinstalliert ist den Vorzug gegeben.

  5. Marcus sagt:

    Ich benutze logrotate von redhat, gibts das nicht bei centOS?

    dort kann man auch logfiles oder ordner nach Zeit oder Größe rotieren und komprimieren lassen.

  6. Jonas Pasche sagt:

    Doch, sicher. Aber was nützt dir ein z.B. täglicher logrotate-Job, wenn das Logfile zwischen zwei logrotate-Durchläufen extrem angewachsen ist, möglicherweise binnen Minuten? Auch kann logrotate nicht via Pipe angesprochen werden; es erfordert insofern nach dem Rotieren einen Apache-Reload, damit jener weiter loggt (schlecht), oder es macht mehr I/O durch Umkopieren der Logs und provoziert Lücken in den Daten (bei copytruncate).

  7. Marcus sagt:

    binnen minuten ist natürlich schlecht. Ich bin jetzt noch davon ausgegangen das zumindest ein hourly aufruf reichen würde.

    Einen apache reload musste ich aber nach logrotate ncoh nie machen.

    mehr I/O ist allerdings sehr gut möglich.

  8. Jonas Pasche sagt:

    Die Apache-Doku sagt ganz deutlich: „It will consequently be necessary to periodically rotate the log files by moving or deleting the existing logs. This cannot be done while the server is running, because Apache will continue writing to the old log file as long as it holds the file open. Instead, the server must be restarted after the log files are moved or deleted so that it will open new log files.“

  9. Marcus sagt:

    kurios. War mir nich klar, seh den reload nach dem logrotate jetzt aber auch in den logs

  10. bodsch sagt:

    Zum ersten … ein logrotate kann auch angestoßen werden, wenn eine Datei eine bestimmte Größe erreicht hat (man logrotate.conf grep nach size).
    cronolog hat den extremen Nachteil, dass es bei ordentlichen Zugriffen auf den Webserver, eine verdammt hohe I/O nach sich zieht.
    cronolog kennt auch kein vernüftiges Filecaching.
    Dann lieber das ganze über syslog-ng …
    Von daher … lokale Logfiles sind böse, die sollten dann eher auf eine zentrale Node ausgelagert werden.
    Dort hat man dann auch beim Rotieren keine Probleme mehr. :)

  11. Jonas Pasche sagt:

    Ich schätze einfach mal, du hast meinen Kommentar vom 08. Januar 2014 um 14:51 Uhr überlesen. :-)


Impressum