Grok Pattern und Graylog: Effizientes Log-Parsing ohne Bottlenecks

Geschätzte Lesezeit: 4 Minuten

Grok Pattern werden in Graylog genutzt, um aus einem für Menschen gut lesebaren „Prosa“-Log die relevanten Inhalte zu extrahieren und in dafür vorgesehenen Feldern mit dem korrekten Namen zu speichern. Dabei ist davon auszugehen, dass der „Prosa“ im Input stets dem gleichen Muster folgt, und nur einige Variablen sich von Log zu Log verändern.

Grok Pattern stehen für Reguläre ausdrücke, welche rekursiv auch wieder andere Grokpattern beinhalten können. Grok Pattern sind damit eine Abstraktionsebene, mit der komplizierte reguläre Ausdrücke einfach dargestellt werden können. Die damit gebauten Parser sind deutlich besser für Menschen lesbar, als ein einzelner regulärer Ausdruck es sein kann. Zusätzlich können mehrere Werte eingefangen und in verschiedene Felder geschrieben werden.

In diesem Artikel analysieren wir die technische Funktionsweise, verhindern von „Regexploits“ sowie Best Practices für performante Pipelines.

Grundlegendes zur Grok Syntax Erklärung und Funktionsweise

Grok Pattern haben die Form %{PATTERNNAME:feld_name}. Der PATTERNNAME wird dabei durch ein Makro mit einem regulären Ausdruck ersetzt. Der mit dem regulären Ausdruck gefangene Wert wird im Graylog in das Feld mit dem Namen feld_name gespeichert. Hier ein Beispiel mit einer Zeile aus einer Cisco ASA Firewall:

Die Lognachricht frei inspiriert nach der Dokumentation von Cisco zu den verschiedenen Logzeilen einer ASA:

%ASA-6-302013: Built outbound TCP connection 123 for eth0:10.0.0.1/50123 user@name.de to eth1:9.9.9.9/53

Die in dieser Nachricht kursiv dargestellten Werte sind Variablen, welche sich von Logzeile zu Logzeile ändern können. Diese Nachricht ist als Prosa gut für Menschen zu lesen, jedoch kann ein Computer ihr erst einmal nicht so viel abgewinnen. Der Sinn eines Grokpatterns ist jetzt, die Variablen zu erkennen und diese in die dazu gehörenden Felder abzulegen. In diesem Beispiel ist die 10.0.0.1 ist z. B. die IP, welche die Verbindung initiert hat. Diese soll in dem Feld source_ip abgelegt werden. Die anderen Variablen sollen in anderen passenden Feldern abgelegt werden.

Mit den hier gegebenen Pattern lässt sich im Großen und Ganzen die beispielhaft gezeigte Zeile Log gut parsen. Das Pattern mit den Namen „IP“ ist zusammengesetzt aus dem Pattern für eine IPv4 Adresse, und dem für eine IPv6 Adresse. Beide sind zu Gunsten der Lesbarkeit hier verkürzt dargestellt. Jede frische Installation von Graylog bringt diese drei Pattern von Haus aus mit. Beide Pattern für IPv4 und v6 sind reguläre Ausdrücke, welche beschreiben, wie eine solche IP-Adresse aussieht. Das Pattern „NU_DATA_ALL_BUT_SPACE“ akzeptiert alle Daten bis zum nächsten Lehrzeihen. Dieses Pattern ist „Greedy“, genau wie das Pattern GREEDYDATA. Beide nehmen sich erst einmal so viele Zeichen, wie sie können, und geben erst im Fall der Fälle wieder Zeichen am Ende ab. Welche Implikationen das hat, und wie die eigene Graylog Installation darunter leiden kann, erklären wir am Ende dieses Posts.

Hier ein Grok Pattern für das Beispiel von weiter oben:

%ASA-6-302013: Built %{NU_DATA_ALL_BUT_SPACE:network_direction} TCP connection %{NU_DATA_ALL_BUT_SPACE:network_connection_id} for %{NU_DATA_ALL_BUT_COLON:network_interface_in}:%{IP:source_ip}/%{NU_DATA_ALL_BUT_SPACE:source_port} %{NU_DATA_ALL_BUT_SPACE:user_name} to %{NU_DATA_ALL_BUT_COLON:network_interface_out}:%{IP:destination_ip}/%{NU_DATA_ALL_BUT_SPACE:destination_port}

Optimiertes Graylog Log Parsing mittels Pipelines

Es gibt im Graylog zwei Stellen, an denen Grok Pattern angewendet werden können, um einen Prosa-Input zu parsen: In den Extraktoren direkt am Input sowie in Pipelines.

Unsere Erfahrung sagt ganz klar: Pipelines sind den Extraktoren deutlich (!) vorzuziehen. Dies möchten wir am Beispiel des Logs der Cisco ASA von oben erklären: Im normalen Alltagsgeschäft sehen wir etwa 170 verschiedene Logzeilen mit ihren jeweiligen IDs (die ID ganz am Anfang des Logs) regelmäßig auftreten. Für jede dieser etwa 170 verschiedenen Zeilen haben wir ein Grok Pattern erstellt (und auch veröffentlicht). Wenn wir alle diese Grokpattern in einem Input als Extraktoren laufen lassen, wird jede Zeile Log gegen alle 170 verschiedenen Grok Pattern getestet. Natürlich trifft nur eines der Pattern zu, daher funktioniert es technisch. Jedoch ist der Aufwand auf CPU-Seite dafür natürlich ungemein groß, weil alle anderen auch unnötig getestet werden.

Mittels folgender Regel bekommen wir ein erstelltes Grok Pattern in einer Pipeline angewendet:

rule "Beispiel Grokpattern Anwendung"
when
    true // dies muss angepasst werden!
then
    let grokresult = grok(
        pattern:"%{NU_DATA_ALL_BUT_SPACE:feldname}", 
        // das Grok Pattern, mit dem wir arbeiten wollen
        value:to_string($message.message), 
        // das Feld, aus dem wir den Text parsen wollen
        only_named_captures:true 
        // nur Felder, die wir benannt haben, werden gespeichert
    );
    set_fields(grokresult);
end

Die Bedingung „true“ in der dritten Zeile sollte in diesem Beispiel auf jeden Fall noch angepasst werden, um nur auf Logzeilen zu treffen, die durch das durch das Grok Pattern auch geparsed werden. Hier kann z. B. mit der contains()-Funktion gearbeitet werden, um zu überprüfen, ob bestimmte Strings enthalten sind. Im Beispiel der ASA Logs oben überprüfen wir das in einem ersten Schritt extrahierte Feld der syslog_id, in diesem Beispiel 302013.

In Zeile sechs muss noch ein passendes Pattern eingesetzt werden, und dann kann es los gehen. Da Funktionen in dieser Textform für uns wesentlich leichter zu editieren, kopieren und kommentieren sind verwenden wir mit Vorliebe diesen „alten“ weg diese Rules zu erstellen und nicht den neuen graphischen Editor.

Was sind Regexploits?

Regeploits sind Reguläre ausdrücke, welche mit steigender Länge des Inputs eine exponentielle Zeit benötigen, um diese Regex zu evaluieren. Ben Caller hat dies auf seinem Blog sehr anschaulich beschrieben: Regexploit: DoS-able Regular Expressions (englisch). Kurz zusammengefasst, was das Problem hier ist: Der Algoritmus, welcher den regulären Ausdruck auswertet hat einen Pointer für jedes Element aus dem regulären Ausdruck, welcher den für dieses Element betreffenden Bereich markiert. Ein Greedy Ausdruck wie „GREEDYDATA“ oder „DATA“ wird dabei im ersten Anlauf erst einmal alles bis zum Ende der Logzeile greifen, und erst durch Backtracking dann wieder einen Teil abgeben. Meistens befinden sich dabei im Grok Pattern hinter dem (GREEDY-)DATA noch weitere Zeichen, welches den Bereich des (GREEDY-)DATA einengen und definieren. Werden jetzt mehrere solche (GREEDY-)DATA Ausdrücke in einem einzelnen Grok Pattern gebraucht gibt es eine Kaskade von Operationen, welche (potentiell) exponentiell in der Länge der Logzeile ist.

Das von uns viel genutzte Pattern wie NU_DATA_ALL_BUT_$Separator sind zwar im Kern auch Greedy. Der Separator kann dabei ein Lehrzeichen, ein Komma, Semikolon oder beliebiges anderes Zeichen sein. Wir vertrauen jedoch darauf, dass die Logs ihren Syntax behalten, und genau dieser Seperator an der Stelle auftritt, an dem wir ihn erwarten. Damit ist das Pattern zwar auf technischer Ebene Greedy, da jedoch kein Backtracking auftritt haben wir keinen Performanceverlust.

Woran merke ich, dass ich von einem Rexploit betroffen bin?

Wir haben diese Lektion vor einigen Jahren auf eine etwas ungemütliche Art kennengelernt: Immer mal wieder hörte unser Graylog auf richtig zu Arbeiten. Die Symptome waren:

• 100% CPU Load auf allen Kernen
• der Processing-Buffer war voll
• Der Output in Richtung OpenSearch war 0 Messages pro Sekunde

Um die Situation in den Griff zu bekommen, mussten wir jeweils den Graylog-Server neustarten. Dann wurden Logs wieder korrekt geparsed. Die Situation war unangenehm und unschön, geholfen bei der Fehlersuche hat uns der Thread dump und der Process-buffer dump des jeweiligen Graylog-Nodes.

Je nach Log-Menge, CPU-Power und Regulärem ausdruck können die Symptome aber auch etwas milder sein: Der Output eines Kunden mit 64 CPUs auf Graylog-Ebene war nur noch bei etwa 200 Logs pro Sekunde. Nachdem wir den Regexploit abgeschaltet haben waren es wieder deutlich über 10 000 Messages pro Sekunde.

Zusammenfassung

Solide Grok-Muster sind das Rückgrat eines funktionierenden SIEM/Log-Management-Systems. Die Balance zwischen Präzision (genaue Matches) und Flexibilität (Toleranz gegenüber Log-Variationen) verhindert Parsing-Ausfälle im laufenden Betrieb. Grokpattern wie %{IP} erlauben einem dabei eine flexible Arbeit auch in Umgebungen mit IPv4 und IPv6.

Unsere Empfehlungen

• keine Grok Pattern verwenden, welche mehr als ein (GREEDY-)DATA verwenden. Dieses soll auch nur an letzter Stelle im Pattern sein.
• Bei Engpässen auf Processing-Ebene im Graylog evaluieren, ob die verwendeten Grokpattern in irgendeiner Form Backtracking machen
• Lieber Pipelines mit Rules und darin der grok()Funktion verwenden, als Extraktoren an Inputs
• Rules müssen so spezifisch wie irgend möglich sein und nur die Logs bearbeiten, für die sie auch wirklich da sind.

Quellen

• https://www.cisco.com/c/en/us/td/docs/security/asa/syslog/asa-syslog/syslog-messages-302003-to-342008.html
• https://blog.doyensec.com/2021/03/11/regexploit.html