Archiv für den Monat: September 2017

Echtzeitanalyse von Apache-Logs ohne Umweg über das Dateisystem

Ich wollte mir schon seit langer Zeit ein Tool schreiben, mit dem ich meine Apache-Logs mehr oder weniger in Echtzeit analysieren kann (z. B. um Angriffe zu erkennen). Mein erster Ansatz wäre zunächst gewesen, alle paar Minuten ein Skript laufen zu lassen, das alles, was seit dem letzten Lauf in die Log-Dateien geschrieben wurde, verarbeitet. Aber so richtig schön wäre das nicht gewesen, ginge das doch unnötigerweise über das Dateisystem. Das Rotieren der Log-Dateien hätte ebenfalls speziell behandelt werden müssen.

Dann sah ich, dass mit der CustomLog-Direktive von Apache nicht nur normale Dateien als Log-Ziel angegeben werden können, sondern es auch möglich ist, die Log-Ausgaben über eine Pipe in einen anderen Prozess zu leiten („Piped Logs“). Dazu gibt man den Pfad zur ausführbaren Datei eines Programms an, das von Apache gestartet wird und dann die Log-Ausgaben über seine Standardeingabe erhält, zum Beispiel so:

CustomLog "||/pfad/zum/programm" "<%h|%D>"

Der zweite Teil der Direktive definiert das Log-Format. Im Beispiel werden nur die IP-Adresse des Aufrufers und die zur Verarbeitung benötigte Zeit geloggt. Das ist noch ein Vorteil gegenüber der Analyse von Log-Dateien: Man kann genau auswählen, welche Daten man zur Echtzeitverarbeitung benötigt. Warum ich die Zeichen < und > am Anfang und am Ende benutze, erläutere ich weiter unten.

Nun könnte man die Log-Ausgaben direkt in diesem einen Programm verarbeiten. Jedoch wird für jeden Apache-Elternprozess eine separate Instanz dieses Programms gestartet, also laufen normalerweise viele davon parallel. Das würde es schwierig machen, die Daten zusammenzuführen.

Um eine zentrale Verarbeitung zu ermöglichen, erstelle ich ein FIFO (mkfifo) und starte ein separates Auswertungsprogramm, das stets im Hintergrund läuft. Das Programm, das von Apache gestartet wird, wird nur zum Sammeln der Daten benutzt und heißt daher von nun an „Sammelprogramm“. Alle Instanzen des Sammelprogramms schreiben ins FIFO, und das Auswertungsprogramm liest daraus und analysiert die Daten.

Ein paar Hinweise, falls das jemand nachbauen möchte:

  • Da viele Instanzen des Sammelprogramms parallel laufen werden, sollte man es möglichst speichersparend implementieren. Ich habe dafür C++ genommen statt wie üblich Python.
  • Wenn das Auswertungsprogramm nicht läuft (z. B. weil es abgestürzt ist), werden die Sammelprogramme irgendwann hängen bleiben. Das ist nicht gut, weil dann auch der jeweilige Apache-Prozess beim Loggen hängen bleibt. Zum Glück kann man die Situation erkennen, indem man das FIFO nicht-blockierend öffnet (in C/C++ mit dem Flag O_NONBLOCK). Das Öffnen schlägt dann einfach fehl statt zu blockieren.
  • Das Auswertungsprogramm sollte das FIFO zuerst zum Lesen öffnen und danach zusätzlich auch zum Schreiben. Somit verhindert man, dass es irgendwann keinen Prozess mehr gibt, der das FIFO zum Schreiben geöffnet hat (dann passieren seltsame Dinge).
  • Wenn mehrere Prozesse parallel in ein FIFO schreiben (so wie es hier der Fall ist), ist es nur unter gewissen Umständen garantiert, dass die Daten jeweils am Stück geschrieben werden. Theoretisch kann es passieren, dass das Auswertungsprogramm zuerst einen Teil der von Prozess A geschriebenen Daten liest und dann einen Teil der von Prozess B geschriebenen Daten („interleaved“). Um solche Fälle zu erkennen, verwende ich die Zeichen < und > am Anfang und am Ende jeder ins FIFO geschriebenen Zeile. Somit kann man erkennen, ob man eine unvollständige Zeile gelesen hat. Solange man nur Daten am Stück schreibt, die höchstens PIPE_BUF Bytes groß sind (Linux: 4096), sollte dies jedoch nie passieren.

Ich bin bisher sehr zufrieden mit dieser Vorgehensweise und kann sie nur weiterempfehlen.