Essbase.log mit PERL und SQLite analysieren

PERL* ist für mich in den letzten Jahren eine Allzweckwaffe zur skriptgesteuerten Bewirtschaftung von Essbase geworden, nach einem Tipp von Philip habe ich mir das PERL-Tool EssbaseRightLog des Kollegen Sebastien Roux sofort angesehen.

* Inzwischen weiß ich die Vorzüge von Groovy zu schätzen und freue mich darauf, schon bald den einen oder anderen Beitrag darüber zu schreiben. Aber zurück zu EssbaseRightLog

Bevor wir weiter einsteigen: Was mag der Grund dafür sein, dass jemand eine Lösung für die Logdatei-Analyse entwickelt?

Wie viele Essbase-Anwender wissen, ist die Analyse der Essbase-Protokoll-Dateien schwierig, der Excel-Import gelingt problemlos, aber dann sieht man, dass logisch zusammengehörende Einträge auf 2 Zeilen verteilt sind, anschließend folgt eine Leerzeile.

Auszug aus einer Essbase-Logdatei:
[Tue Oct 14 08:43:59 2014]Local/ESSBASE0///6945/Info(1051187)
Logging in user [TestUser@Native Directory] from [::ffff:xxx.xxx.xxx.xxx]

[Tue Oct 14 08:43:59 2014]Local/ESSBASE0///5403/Info(1042059)
Connected from from [::ffff:xxx.xxx.xxx.xxx]

[Tue Oct 14 08:43:59 2014]Local/ESSBASE0///5403/Info(1051001)
Received client request: Get Client Settings (from user [TestUser@Native Directory])

[Tue Oct 14 08:43:59 2014]Local/ESSBASE0///6431/Info(1042059)
Connected from from [::ffff:xxx.xxx.xxx.xxx]

[Tue Oct 14 08:43:59 2014]Local/ESSBASE0///6431/Info(1051001)
Received client request: MaxL: Execute (from user [TestUser@Native Directory])

Wir sehen in diesem Auszug, dass sich Benutzer „TestUser“ an Essbase angemeldet und in der Folge einen unbekannten Befehl ausgeführt hat.

Wird diese Datei sortiert oder gefiltert, enthält

• ein Drittel der Datensätze Leerzeilen,
• ein weiteres Drittel die Zeitstempel-Zeilen mit Info/Warning/Error-Hinweisen
• und das letzte Drittel die ausgeführten Aktionen.

Bei Logdateien mit Zig-Tausenden Zeilen geht der Zusammenhang zwischen Aktionen und Zeitspempel schnell verloren. Fallen Zusammenhänge nicht per Zufall beim rauf- und runterscrollen auf, ist die Protokoll-Datei für Fragen wie

• Welche Fehlermeldungen (Kategorie: Error) sind gestern aufgetreten?
• Wann hat sich ein Anwender angemeldet und welche Skripte hat er gestartet?
• Wie oft gibt es Anmeldeversuche mit falschem Paßwort?
• Was ist die durchschnittliche Laufzeit eines Kalkulations-Skriptes?
• Wieviele Anwender haben sich dieses Jahr an Essbase angemeldet?

nahezu unbrauchbar.

Ok, eine Möglichkeit zur Analyse dieser Dateien wäre wirklich hilfreich. Zwar gibt es schon lange die Möglichkeit, im EAS Logdateien grafisch darzustellen oder auch spez. Outlines, um Logdateien mittels Essbase-Datenbank zu analysieren, aber auch diese Tools haben ihre Grenzen.

Deshalb möchte ich nun zeigen, wie uns EssbaseRightLog bei dieser Aufgabe helfen kann:
Essbase-Server-Logdateien und Essbase-Applikations-Logdateien werden so aufbereitet, dass ein Protokoll-Eintrag vollständig in einer Zeile enthalten ist und so die Analyse erleichtert.

Zusätzlich können Spaltentrenner individuell gesetzt werden, die Ausgabe erfolgt wahlweise in eine Textdatei, eine Excel-Datei oder in eine spezielle Datenbank (dazu später mehr).

Praktischerweise kann ein Filter gesetzt werden, sodass z.B. nur Einträge der Kategorie „Warnung“ oder „Fehler“ gefunden werden. Selbst die Filterung einer einzelnen Essbase-Meldung /Fehler-Referenz-Nummer (error-code) ist so möglich.

Da auch andere EPM-Produkte Einträge im Essbase-Log erzeugen, bietet sich das Ganze auch z.B. für die Analyse von Hyperion Planning an.

Die Anwendung
EssbaseRightLog ist als .zip-Datei auf http://code.google.com/p/essbaserightlog/downloads/list oder als Link in unserem Download-Bereich zu finden.
Die Lösung besteht zum jetzigen Zeiptunkt aus einer PERL-Datei „EssbaseRightLog_2.7.0.pl“, dem obligatorischen GNU-Lizenz-Hinweis und einer Readme.txt. Letztere enthält hauptsächlich Hinweise zu den einzelnen Versionen und Entwicklungsschritten.

Nach Entpacken der 3 Dateien in ein beliebiges Verzeichnis (ich habe mich für E:\PERL64\EssbaseRightLog entschieden), kopiere ich zusätzlich die zu analysierenden Logdateien in das gleiche Verzeichnis, in diesem Beitrag sind das die Dateien Essbase.log und Sample.log.

Aber wie starte ich denn jetzt den Analyse-Prozess? Ich kürze an dieser Stelle ab und führe das PERL-Skript einfach in der Kommandozeile aus.

$ EssbaseRightLog.pl
Can’t locate Spreadsheet/WriteExcel.pm in @INC (@INC contains: /usr/opt/perl5/lib/5.8.8/aix-thread-multi /usr/opt/perl5/lib/5.8.8 /usr/opt/perl5/lib/site_perl/5.8.8/aix-thread-multi /usr/opt/perl5/lib/site_perl/5.8.8 /usr/opt/perl5/lib/site_perl .) at EssbaseRightLog.pl line 12.
BEGIN failed–compilation aborted at EssbaseRightLog.pl line 12.

Exkurs:
Es gibt einen Abbruch, das Skript wurde nicht ausgeführt. Hierzu muss man wissen, das es eine Meldung zur PERL-Installation ist, sie weist darauf hin, dass ein benötigtes PERL-Modul namens WriteExcel.pm nicht installiert ist. Von den möglichen Alternativen „PERL-Modul installieren“ oder „Modul-Aufruf auskommentieren“, wähle ich Letzteres.
Ende Exkurs

Zeile 12 use Spreadsheet::WriteExcel; auskommentiert, dann auf ein Neues:

$ EssbaseRightLog.pl
Can’t locate DBI.pm in @INC (@INC contains: /usr/opt/perl5/lib/5.8.8/aix-thread-multi /usr/opt/perl5/lib/5.8.8 /usr/opt/perl5/lib/site_perl/5.8.8/aix-thread-multi /usr/opt/perl5/lib/site_perl/5.8.8 /usr/opt/perl5/lib/site_perl .) at EssbaseRightLog.pl line 14.
BEGIN failed–compilation aborted at EssbaseRightLog.pl line 14.

Na, hoffentlich geht das nicht noch lange so, wieder ein Abbruch, dieses Mal verursacht vom ebenfalls fehlenden PERL-Modul DBI.pm. Einmal probiere ich es noch, also wird auch Zeile 14 „use DBI;“ auskommentiert und erneut gestartet:

$ EssbaseRightLog.pl
USAGE: EssbaseRightLog -i <logfile(s)>
[-o , -c, -d , -t, -s , -f , -x , -q, -h]

-i specify Essbase log(s), args: <logfile1[;logfile2;…]>
-o specify output file, arg:
-c specify message categories
-d specify date format, arg: <ISO|EUR|US>
-t specify headers on top
-s specify separator, arg: <*>
-f specify filter (case sensitive), arg:
-x specify Excel output, arg:
-q specify query output
-h display usage
$

Das sieht doch schon anders aus, offensichtlich muss der Skript-Aufruf mit korrekten Parametern ergänzt werden.
Der Skriptaufruf, -i für das zu analysierende Logfile, -o für die Ausgabedatei müssten eigentlich mindestens notwendig sein. Also gebe ich ein:

Aufruf:
EssbaseRightLog.pl -i Essbase.log -o EssLog_Analyse.txt

Es funktioniert!
Ausgabedatei EssLog_Analyse.txt wird erzeugt, die vorher 3-zeiligen Protokolleinträge sind nun in einer Zeile enthalten (der Zeilenumbruch auf dieser Seite wird wegen besserer Lesbakeit automatisch hinzugefügt):
Tue|10|14|08:43:59|2014|Local|ESSBASE0|||6945|Info|1051187|Logging in user [TestUser@Native Directory] from [::ffff:xxx.xxx.xxx.xxx]
Tue|10|14|08:43:59|2014|Local|ESSBASE0|||5403|Info|1042059|Connected from [::ffff:xxx.xxx.xxx.xxx]
Tue|10|14|08:43:59|2014|Local|ESSBASE0|||5403|Info|1051001|Received client request: Get Client Settings (from user [TestUser@Native Directory])
Tue|10|14|08:43:59|2014|Local|ESSBASE0|||6431|Info|1042059|Connected from [::ffff:xxx.xxx.xxx.xxx]
Tue|10|14|08:43:59|2014|Local|ESSBASE0|||6431|Info|1051001|Received client request: MaxL: Execute (from user [TestUser@Native Directory])

Nun ist es Zeit, sich die weiteren, (optionalen) Parameter anzusehen:

Parameter -d für das Datumsformat
Mit folgendem Aufruf wird das Datum im europäischen Format angezeigt:
EssbaseRightLog.pl -i Essbase.log -o EssLog_Analyse.txt -d EUR

14/10/2014|08:43:59|Local|ESSBASE0|||6945|Info|1051187|Logging in user [TestUser@Native Directory] from [::ffff:140.101.175.112]
14/10/2014|08:43:59|Local|ESSBASE0|||5403|Info|1042059|Connected from [::ffff:xxx.xxx.xxx.xxx]
14/10/2014|08:43:59|Local|ESSBASE0|||5403|Info|1051001|Received client request: Get Client Settings (from user [TestUser@Native Directory])

Parameter -c für die Category
Mit folgendem Aufruf wird die Kategorie in Spalte 10 ergänzt:
EssbaseRightLog.pl -i Essbase.log -o EssLog_Analyse.txt -d EUR -c

14/10/2014|08:43:59|Local|ESSBASE0|||6945|Info|1051187|Agent|Logging in user [TestUser@Native Directory] from [::ffff:140.101.175.112]
14/10/2014|08:43:59|Local|ESSBASE0|||5403|Info|1042059|Network?TCP|Connected from [::ffff:xxx.xxx.xxx.xxx]
14/10/2014|08:43:59|Local|ESSBASE0|||5403|Info|1051001|Agent|Received client request: Get Client Settings (from user [TestUser@Native Directory])

Wenn man dann noch nach Category filtern könnte. Ja bitte, ….

Parameter -f für den Filter über eine beliebige Spalte (case-sensitiv)
….mit folgendem Aufruf werden nur noch Einträge der Kategorie „Agent“ ausgegeben:
EssbaseRightLog.pl -i Essbase.log -o EssLog_Analyse.txt -d EUR -c -f „Agent“

14/10/2014|08:43:59|Local|ESSBASE0|||6945|Info|1051187|Agent|Logging in user [TestUser@Native Directory] from [::ffff:xxx.xxx.xxx.xxx]
14/10/2014|08:43:59|Local|ESSBASE0|||5403|Info|1051001|Agent|Received client request: Get Client Settings (from user [TestUser@Native Directory])
14/10/2014|08:43:59|Local|ESSBASE0|||6431|Info|1051001|Agent|Received client request: MaxL: Execute (from user [TestUser@Native Directory])

Für mich die stärkste Funktion. Filtern nach einzelnen Fehler-Code, Suche nach bestimmten Worten, Anzeige aller Fehlermeldungen oder aller Warnungen, und, und, und

Parameter -f für den Filter über eine bestimmte Fehlermeldung (Oracle Essbase Error Message Code)
Mit folgendem Aufruf werden nur Einträge mit Fehler-Code „1051032“ ausgegeben:
EssbaseRightLog.pl -i Essbase.log -o EssLog_Analyse.txt -d EUR -c -f 1051032

28/07/2014|16:32:34|Local|ESSBASE0|||140102787966720|Warning|1401027|Other|Error 1051032 processing request [Get Database Info] – disconnecting
28/07/2014|16:32:46|Local|ESSBASE0|||140102789019392|Warning|1401027|Other|Error 1051032 processing request [Get Database Info] – disconnecting
28/07/2014|16:33:05|Local|ESSBASE0|||140102791124736|Warning|1401027|Other|Error 1051032 processing request [Get Database Info] – disconnecting
31/07/2014|09:46:35|Local|ESSBASE0|||139724001085184|Warning|1397240|Other|Error 1051032 processing request [Get Database Info] – disconnecting
Applikations-Log
Neben dem Essbase-Serverlog sind viele weitere Informationen in den einzelnen Applikations-Logdateien enthalten. Eine beliebte Analyse sehen wir hier:

Parameter -f für den Filter über einen beliebigen Text
Mit folgendem Aufruf werden nur Einträge mit Text „Total Calc Elapsed Time“ ausgegeben:
EssbaseRightLog.pl -i Sample.log -o SampleLog_Analyse.txt -d EUR -c -f „Total Calc Elapsed Time“ (case-sensitiv)

20/10/2014|13:38:52|Local|Sample|Basic|TestUser@Native Directory|11826|Info|1012550|Calculator|Total Calc Elapsed Time : [243.15] seconds

Parameter -t für eine Zeile mit Titeln (Überschriften)
Mit folgendem Aufruf wird eine Titelzeile (Spaltenüberschriften) eingefügt:
EssbaseRightLog.pl -i Sample.log -o SampleLog_Analyse.txt -d EUR -t

date|time|server|application|database|user|msglevel|msgcode|description
20/10/2014|13:36:09|Local|Sample|||1|Info|1002035|Starting Essbase Server – Application [Sample]
20/10/2014|13:36:10|Local|Sample|||1|Info|1200480|Loaded and initialized JVM module
20/10/2014|13:36:11|Local|Sample|||1|Info|1019008|Reading Application Definition For [Sample]
20/10/2014|13:36:11|Local|Sample|||1|Info|1019009|Reading Database Definition For [Basic]
20/10/2014|13:36:12|Local|Sample|||1|Info|1019012|Reading Outline For Database [Basic]

Parameter -s für einen individuellen Spalten-Trenner (Beispiel Komma und Semikolon)
Mit folgendem Aufruf werden die einzelnen Spalten mit Komma getrennt:
EssbaseRightLog.pl -i Sample.log -o SampleLog_Analyse.txt -d EUR -s , (Komma ohne weitere Angaben)
Mit folgendem Aufruf werden die einzelnen Spalten mit Semikolon getrennt:
EssbaseRightLog.pl -i Sample.log -o SampleLog_Analyse.txt -d EUR -s „;“ (Semikolon muss maskiert werden)

20/10/2014;13:36:09;Local;Sample;;;1;Info;1002035;Starting Essbase Server – Application [Sample]
20/10/2014;13:36:10;Local;Sample;;;1;Info;1200480;Loaded and initialized JVM module
20/10/2014;13:36:11;Local;Sample;;;1;Info;1019010;Writing Application Definition For [Sample]
20/10/2014;13:36:11;Local;Sample;;;1;Info;1019011;Writing Database Definition For [Basic]
20/10/2014;13:36:12;Local;Sample;;;1;Info;1019012;Reading Outline For Database [Basic]

Parameter -x für die Ausgaben in eine Excel-Datei
Alternativ zur Ausgabe in eine Textdatei lassen sich direkt Excel-Dateien im .xls-Format erzeugen. Voraussetzung ist ein installiertes Perl-Modul writeExcel
Mit folgendem Aufruf wird das Ergebnis in eine Excel-Datei ausgegeben:
EssbaseRightLog.pl -i Sample.log -x SampleLog_Analyse.xls -c -t -d EUR

Die Anzahl Spalten-Titel stimmt nicht mit der Anzahl Spalten der Logdatei-Inhalte überein, aber sonst sieht es gut aus, der Auto-Filter ist bereits in Datei „SampleLog_Analyse.xls“ enthalten.

Hierzu ein Hinweis:
In unserem Downloadbereich haben wir auf den Orginal-Code verlinkt. Unserer Erfahrung nach gibt es in dem Tool kleinere Schwächen im Zusammenhang mit der Excel-Ausgabe und ganz besonders bei Verwendung von SQLite (s. nächster Absatz). Von Sebastien Roux, dem Autor des Original-Codes, haben wir kein Feedback erhalten und deshalb die nötigen Korrekturen selbst in der Perl-Datei vorgenommen. Wir bieten auf Nachfrage diese „optimierte“ Version kostenlos zum Download an.

Bei Erreichen der Zeilengrenze von 65326 Zeilen in Excel wird eine weitere Arbeitsmappe angelegt, solange, bis alle Zeilen verarbeitet sind. Im Test wurde ein Essbase-Log mit etwa 3 Mio. Zeilen problemlos als Excel-Datei erzeugt.

Für die Analyse großer Log-Dateien empfiehlt sich dennoch eine weitere Option, die der folgende Absatz beschreibt.

Essbase-Log-Analyse mit SQLite

So, wir haben fast alles durch, bleibt noch Parameter „-q“. Denn wie heißt es so schön? Das Beste kommt zum Schluss!
Der sog. Query-Parameter ist kein gewöhnlicher Parameter, er erlaubt ungeahnte Analysen auf dem Datenbestand. Aber der Reihe nach!

Parameter -q für die Ausgabe in eine SQLite-Datenbank
Hier kommt der Dienst SQLite ins Spiel: Das ist eine SQL-Datenbank, die eine Funktionalität bietet, wie man sie von einer SQL-DB erwartet. Bevor ich sie benutzen kann, installiere ich die Software auf meinem Rechner. Halt! Installieren ist nicht der richtige Ausdruck, SQLite erfordert keine Installation, keine Konfiguration, keinen Server,…., es funktioniert einfach, nachdem die erforderlichen Dateien auf den eigenen Rechner kopiert wurden. Die ganze Datenbank besteht einschließlich aller Tabellen aus einer einzigen Datei.

Hierzu ein Hinweis:
In unserem Downloadbereich haben wir auf den Orginal-Code verlinkt. Unserer Erfahrung nach gibt es in dem Tool kleinere Schwächen im Zusammenhang mit SQLite. Von Sebastien Roux, dem Autor des Original-Codes, haben wir kein Feedback erhalten und deshalb die nötigen Korrekturen selbst in der Perl-Datei vorgenommen. Wir bieten auf Nachfrage diese „optimierte“ Version kostenlos zum Download an.

Jetzt führe ich das Skript mit dem Query-Parameter aus:
Aufruf:
EssbaseRightLog.pl -i Sample.log -q > EssbaseQuery_Analyse.txt

Der Aufruf erzeugt 3 Dateien in unserem Verzeichnis:

• querycfg.xml (enthält 15 vordefinierte SQL-Abfragen, weitere können für individuelle Analysen einfach ergänzt werden)
• EssbaseQuery_Analyse.txt (enthält das als Bericht aufbereitete Ergebnis der 15 vordefinierten SQL-Abfragen)
• rightlog.db (enthält die Essbase-Log-Daten in Form einer SQLite-Datei)

Den Rest erledigt das PERL-Skript, es importiert die Daten in eine SQLite-Datei, führt die in querycfg.xml definierten Abfragen aus und erzeugt daraus einen Bericht zur Nutzung von Essbase.

Die Daten stehen für die Abfrage bereit, jetzt fehlt nur noch ein grafisches Frontend, mit dem darauf zugegriffen und individuelle Abfragen ausgeführt werden können. Da Mozilla Firefox ebenfalls SQLite verwendet, bietet sich das Firefox-Plugin SQLite Manager an. Damit lassen sich nun beliebige Abfragen auf dem Datenbestand ausführen.

Das Plugin wird in einem neuen Browserfenster geöffnet:

Wir möchten mit der von EssbaseRightLog erzeugten SQLite-Datenbank arbeiten und verbinden uns damit:

Mit „SQL-ausführen“ wird die Standard-Abfrage ausgeführt. Nun sind beliebige SQL-Abfragen auf dem Datenbestand möglich.

Hätten Sie gedacht, das so etwas mit unsere Essbase-Logdateien möglich ist? Und das ist noch nicht alles, richtig „rund“ wird es, wenn solch ein Prozess automatisiert läuft und Ergebnisse per E-Mail an Administratoren versendet.
Sprechen Sie uns hierzu gerne an.

nach oben