Splunk: Suchen verstehen mit dem Job Inspector
Jacob Brügmann & Martin Müller /
17.03.22 /
Digitale Transformation
Was ist der Job Inspector?
Viele Splunk-Nutzer fragen sich, wie ihre Suchen noch effizienter sein können. Dazu müssen zunächst die Suchen verstanden werden, wobei der Job Inspector helfen kann. Mit diesem Tool können Nutzer ihre Suchen analysieren und Potenziale für Fehlerbehebung sowie Optimierung erschließen.
Eine Vielzahl an Informationen helfen dabei, wie zum Beispiel:
- Job-Status und -Laufzeit
- Fehlermeldungen, falls vorhanden
- Anzahl durchsuchter Events
- Ausführungskosten gruppiert nach Suchbefehlen
- Job-Eigenschaften und -Parameter
- Konfiguration der saved search, falls der Job eine saved-search-Instanz ist
- Zugriff auf die search logs von Searchhead und ggf. Indexern
Der Zugriff auf den Job Inspector erfolgt für selbst ausgeführte Suchen direkt über die Benutzeroberfläche. Unter der Suchleiste befindet sich das Menü “Job” → “Inspect Job”.
Zur Analyse beliebiger Suchen ohne eigene Benutzeroberfläche, beispielsweise vom Scheduler ausgeführte Alerts, erfolgt alternativ der Einstieg über die Liste aller Jobs im Menü “Activity” → “Jobs”. Jeder für den aktuellen Nutzer freigegebene Job kann hier über das analoge Menü “Job” → “Inspect Job” analysiert werden.
Bereits auf der obersten Ebene gibt es eine wichtige Zusammenfassung, die hilft einzuschätzen, ob die Suche Potenzial zur Optimierung bietet. Zuallererst die Gesamtlaufzeit: Je mehr Zeit eine Suche benötigt, desto eher lohnt sich die Optimierung. Oft ist die Anzahl der für die Suche geladenen Events der ausschlaggebende Faktor, daher wird diese Zahl, in diesem Fall mit rund 60 Millionen Ereignissen, fett hervorgehoben.
Sollten bei der Ausführung Warnungen oder Fehler auftreten, werden diese ebenfalls am Anfang des Job Inspectors aufgeführt.
Der zweite Abschnitt schlüsselt die Ausführungskosten in Sekunden nach Suchbefehl und Unterkomponenten auf. Die Länge der Balken liefert einen schnellen Überblick, welcher Teil der Suche am meisten Zeit gekostet hat.
Hierbei werden parallel ablaufende Verarbeitungen aufsummiert: Die rund 420 Sekunden Laufzeit von “command.search” dieser nur 68 Sekunden laufenden Suche wurden verteilt auf mehrere Indexer gemessen.
Unterkomponenten werden analog zu einer Baumstruktur eingerückt dargestellt und geben ihren Anteil an der Laufzeit des übergeordneten Elements wieder. In diesem Beispiel sind die rund 58 Sekunden unter “command.search.calcfields” zum Ausführen der für die durchsuchten Sourcetypes konfigurierten, berechneten Felder ein Teil der von “command.search” verbrauchten 420 Sekunden.
Im dritten Abschnitt werden zahlreiche Eigenschaften des Jobs alphabetisch aufgelistet. Hier finden sich wichtige Eckdaten zum nachträglichen Verständnis. Dazu gehören die Startzeit des Jobs “createTime”, der durchsuchte Zeitbereich “earliestTime” & “latestTime”, die Dauer der Ausführung “runDuration” oder der Identifikator des Jobs “sid”. Zum tiefergehenden Troubleshooting sind ganz unten die search logs des Searchheads und aller Indexer verlinkt.
Wie verwende ich den Job Inspector?
Es lassen sich viele konkrete Anwendungsfälle finden, wie der Job Inspector verwendet wird. Im Folgenden haben wir einige sehr häufig auftretende Beispiele ausgesucht, anhand derer Splunk-Nutzer ihre Suchen auf Effizienz hin überprüfen und vergleichen können.
Performance-Erkenntnis #1: scanCount vs. eventCount
Je mehr Events eine Suche im Hintergrund laden und verarbeiten muss, desto mehr Ressourcen und Laufzeit verbraucht diese Suche. Ist das Verhältnis zwischen im Hintergrund geladenen Events (“scanCount”) und tatsächlich für die Suchergebnisse benötigten Events (“eventCount”) sehr groß, kann hier oft ein guter Effizienzgewinn erzielt werden. Beide Werte liefert der Job Inspector direkt in den Job-Eigenschaften.
Nehmen wir ein konkretes Beispiel: Events gruppiert nach einem Feld zählen, hier anhand der in jeder Splunk-Umgebung für Admins verfügbaren internen Splunk Logs. Inhaltlich handelt es sich hier also um Zugriffe von Nutzern auf die Splunk-Oberfläche oder -API.
index=_internal user=* | stats count by user
Der erste Versuch hatte gemäß Job Inspector eine Laufzeit von mehr als 60 Sekunden. Das Verhältnis scanCount:eventCount ist rund 61M:2M. Es werden somit im Hintergrund 30x mehr Events geladen als tatsächlich das Feld "user" enthalten und für diese Suche notwendig wären.
Die Ursache für diese niedrige Effizienz liegt in einer Grund-Eigenschaft von Splunks schema-on-the-fly-Ansatz, bei dem mit großer Flexibilität Felder erst zum Zeitpunkt der Ausführung einer Suche berechnet werden. Dabei kann das Filtern nach bestimmten Werten wie "user=Jacob" effizient umgesetzt werden, das Filtern nach “Feld user ist vorhanden” allerdings nicht.
In diesem Beispiel können wir allerdings anders filtern: Die Zugriffe von Nutzern auf Splunk sind in eigenen Sourcetypes abgelegt. Entsprechend kann die Suche hierüber effizient vorselektieren, welche Events überhaupt erst auf ein user-Feld hin überprüft werden müssen.
index=_internal sourcetype=splunk*access user=* | stats count by user
Dieser zweite Versuch benötigt nur noch 4 Sekunden zur Ausführung, und reduziert das Verhältnis von scanCount zu eventCount auf 1:1. Entsprechend wurden im Hintergrund keine Events geladen und verarbeitet, die nicht für das Suchergebnis benötigt wurden.
Übertragen auf allgemeine Fälle ergeben sich bei großen Unterschieden zwischen scanCount und eventCount immer die Fragen:
- “Kann ich meine Filterkriterien anders ausdrücken?”
- “Kann ich mein Ziel auch auf einem unterschiedlichen Weg erreichen?”
Performance-Erkenntnis #2: SmartStore
Sofern in der eigenen Splunk-Umgebung SmartStore im Einsatz ist, kann sich die Performance bei ein und derselben Suche mit der zweiten Ausführung deutlich verbessern.
Mit dem SmartStore wird neben einem Remote-Speicher auf Basis von S3 auch ein intelligenter Cache Manager eingeführt. Im Remote-Speicher liegen alle historischen Daten, im Cache lokal auf den Indexern nur die in letzter Zeit genutzten. Ist der Cache voll, sortiert der Cache Manager nach einer least-recently-used-Strategie länger nicht genutzte Daten aus. Greift nun eine Suche erstmals wieder auf bereits aussortierte Daten zu, müssen diese zunächst aus dem Remote-Speicher geladen werden. Wird die gleiche Suche direkt nochmals ausgeführt, entfällt diese zusätzliche Zeit durch den lokalen Cache.
Auf den ersten Blick scheint das Phänomen der schnelleren zweiten Ausführung für den Splunk-Nutzer nicht logisch zu sein und kann zu falschen Schlussfolgerungen führen. Werden zum Beispiel zwischen der ersten und zweiten Ausführung vermeintliche Performance-Verbesserungen angewendet, kann dieser Cache-Zeitgewinn fälschlicherweise der versuchten Verbesserung zugeschrieben werden – auch wenn es unter Umständen eine Verschlechterung war. Mit Beachtung der SmartStore-Effekte kann hier besser differenziert werden, warum eine Änderung der Ausführungszeit zustande kommt.
Im Job Inspector sollten die Komponenten “command.search.index.bucketcache.miss” sowie “command.search.rawdata.bucketcache.miss” in diesem Zusammenhang betrachtet werden. Diese geben Aufschluss über die entstandene zusätzliche Ausführungszeit aufgrund fehlender Buckets, die zum Vorfiltern anhand von Schlüsselwörtern bzw. zum Laden von Rohdaten nach dem Vorfiltern benötigt werden. Beispielsweise führen wir die folgende Suche zweimal hintereinander über einen größeren Zeitbereich aus:
index=_internal user=Martin | timechart count
Während die Suche beim ersten Mal in 400 Sekunden ausgeführt wurde, ergibt sich bei der zweiten Ausführung eine Zeit von lediglich 20 Sekunden. Durch einen Blick in die Ausführungskosten ergibt sich, dass beim ersten Versuch rund 20 Prozent der durchsuchten Buckets nicht bereits im lokalen Cache waren und entsprechend nachgeladen werden mussten:
Bei der zweiten Ausführung waren alle Buckets im Cache und konnten direkt durchsucht werden:
Gibt es in der betrachteten Suche weiteres Potenzial für Performance-Optimierungen, können diese nun in weiteren Ausführungen angewendet und getestet werden. Solange kein Nachladen unter “bucketcache.miss” stattfindet, werden Unterschiede nicht mehr von SmartStore-Cache-Effekten überlagert.
Wo finde ich weitere Informationen?
Zum Job Inspector lassen sich auf der Webseite von Splunk sowie bei YouTube weitere Informationen finden.
- Splunk-Dokumentation: https://docs.splunk.com/Documentation/Splunk/latest/Search/ViewsearchjobpropertieswiththeJobInspector
- Vortrag auf der .conf20 “Clara-fication: Job Inspector” von Clara Merriman und Martin Müller
- Splunk-Blog mit weiteren Beispielen: https://www.splunk.com/en_us/blog/tips-and-tricks/splunk-clara-fication-job-inspector.html
- Kurzanleitung von Splunk Education: https://www.youtube.com/watch?v=n3OqaB6GVXs
- Splunk-Dokumentation zu SmartStore: https://docs.splunk.com/Documentation/Splunk/latest/Indexer/AboutSmartStore
