TeamSpeak-Logs mit Bash auswerten
Ich hoste seit Jahren meinen eigenen TeamSpeak-Server. Der Server hat einen öffentlichen Bereich mit so genannten Chat Corners, die für jeden öffentlich zugänglich sind. Mein Stamm-Channel dabei ist aber die Chat Corner 2. Chat Corner 1, 3 oder auch 5 unterscheiden sich in nichts von Chat Corner 2, aber die 2 hat sich als Stamm-Channel etabliert.
Irgendwann entstand für diesen Stamm-Channel eine kleine Erweiterung: die scherzhafte Klimaanlage. So wurde aus Chat Corner 2 die Chat Corner 2 - mit Klimaanlage.
Seither bekommt unsere Chat Corner immer wieder neue Gimmicks verpasst. Vielleicht eine Heizung, einen Mundschutz oder ein Sonnenschirm. Nur eine Historie, was unsere Chat Corner 2 schon alles hatte oder nicht hatte, gibt es nicht.
Da ich den TeamSpeak-Server aber selbst betreibe, kann ich mit den Logdateien rumspielen. TeamSpeak logt alles in einfache Textdateien, was meine Arbeit sehr einfach macht. Auf meinem Server mit Debian Linux kann ich deswegen mit den vielen Werkzeugen der Kommandozeile einiges an Infos aus den Logdateien holen und schön aufbereiten.
Also: Welche Namen hatte die Chat Corner 2 schon über die Jahre?
Logzeilen finden
Zunächst geht es darum, herauszufinden, wie TeamSpeak überhaupt protokolliert, dass der Channel umbenannt wurde.
Ich habe dazu eine der Logdateien zunächst erstmal mit einem Texteditor geöffnet (z. B. nano oder vi) und sie mir angeschaut.
Da ich meinen TeamSpeak-Server im Verzeichnis /var/teamspeak/
installiert habe, liegen die Logs in /var/teamspeak/logs/
.
In der Logdatei habe ich dann einige Zeilen gefunden, in denen scheinbar die Chat Corner 2 bearbeitet wurde:
2017-06-07 16:53:33.828623|INFO |VirtualServerBase|1 |channel 'Chat Corner 2 - mit Schietwetter'(id:10) edited by 'ozzyfant'(id:2)
In der Logzeile stehen einige Informationen, die vielleicht später noch interessant werden. Eine Dokumentation, wie die Logzeilen zu lesen sind, habe ich nicht. Was die einzelnen Werte bedeutet, habe ich mir aus dem Kontext erschlossen – also z. B. daraus, was in den anderen Logzeilen steht.
- Zu Beginn der Logzeile steht ein Zeitstempel:
2017-06-07 16:53:33.828623
- Als nächstes folgt eine Aussage, welches Log-Level diese Logzeile hat:
INFO
. Andere Loglevel wären z. B.ERROR
oderWARNING
. - Darauf folgt scheinbar, welche Komponente des TeamSpeak-Servers hier gerade eine Logzeile schreibt.
In unserem Fall ist das immer
VirtualServerBase
, da sich ein TeamSpeak-Server in mehrere virtuelle TeamSpeak-Server aufteilt. - Anschließend folgt die Nummer des virtuellen TeamSpeak-Servers:
1
. - Zuletzt in der Zeile steht die eigentliche Nachricht bzw. das Ereignis, das aufgetreten ist:
channel 'Chat Corner 2 - mit Schietwetter'(id:10) edited by 'ozzyfant'(id:2)
.
Genau diese Info ist interessant: Die Chat Corner 2 wurde bearbeitet. Außerdem gibt es sogar noch eine Information, wer den Channel bearbeitet hat und wann. Das Wann kann aus dem Zeitstempel am Anfang der Zeilen genommen werden.
Logzeilen filtern
Bis jetzt habe ich händisch in die Logdatei geschaut. Ab jetzt geht es darum, das ganze mit Bash auf der Kommandozeile zu tun. Der erste Schritt dabei ist, nur die interessanten Logzeilen überhaupt anzuzeigen und damit weiterzuarbeiten. Dafür gibt es in Linux das Programm grep. grep steht für global/regular expression/print1 und ist für das Suchen und Filtern von Textdateien gemacht.
Um damit zu arbeiten, müssen wir grep zwei Informationen geben:
- Wonach soll es suchen? Nach den Logzeilen, in denen das Bearbeiten des channels protokolliert wird.
- Worin soll es suchen? In allen Logdateien von TeamSpeak.
Das geben wir grep also mit auf den Weg2:
grep -h \
"'(id:10) edited by '" \
/var/teamspeak/logs/ts3server_*_1.log
Wir geben grep drei Argumente mit:
-h
- Damit sagen wir grep, dass es den Dateinamen von der Logdatei, in der es die Zeile gefunden hat, nicht ausgeben soll.
"'(id:10) edited by '"
- Such nach diesen Zeichen. Es wird nur nach Änderungen an dem Channel mit der
id:10
gesucht. Das ist Chat Corner 2. /var/teamspeak/logs/ts3server_*_1.log
- Such in diesen Dateien. Das Sternchen
*
ist ein Platzhalter, damit alle Dateien durchsucht werden.
grep gibt uns am Ende dann nur Protokollzeilen aus, in denen Chat Corner 2 bearbeitet wird. Somit haben wir keine uninteressanten Protokollzeilen mehr.
Formatieren der Logzeilen
Als nächstes wollen wir unsere gefilterten Logzeilen etwas aufhübschen, indem wir uninteressante Inhalte entfernen. Am Ende sollen nur noch drei Informationen übrig bleiben: Wann wurde der Channel umbenannt; wer hat den Channel umbenannt; wie lautet der neue Name?
Diese Informationen stehen alle in einer Zeile. Um sie zu finden, habe ich einen regulären Ausdruck (RegEx) benutzt. Mithilfe von RegEx und dem Linux-Programm sed (Stream EDitor) können wir innerhalb der Logzeile suchen und ersetzen. Das Ziel dabei ist: Wir suchen uns die interessanten Teile raus und löschen den Rest.
Wir finden wir die drei interessanten Teile?
-
Zeitstempel
Der Zeitstempel hat immer die Form von JJJJ-MM-TT HH:MM:SS. Als RegEx ausgedrückt ist das([0-9]{4}-[0-9]{2}-[0-9]{2} [0-9]{2}:[0-9]{2}:[0-9]{2})
. Zuerst Zahlen von 0-9 und davon vier. Anschließend in Bindestrich. Danach zwei Zahlen von 0-9 und noch ein Bindestrich. Zuletzt noch einmal zwei Zahlen von 0-9. Gleiches dann nocheinmal für die Uhrzeit -
Channelname
Der neue Channelname steht in einfachen Anführungszeichen vor derid:10
. Ich fange also mit den Klammern in RegEx alles ein, was zwischen den Anführungszeichen steht:channel '(.*?)'\(id:10\)
-
Autor des neuen Namens
Der Autor des neuen Namens steht am Ende der Zeile hinter einem „edited by“ und in einfachen Anführungszeichen. Ähnlich zum Channelnamen hole ich auch den Autor mit runden Klammern:edited by '(.*?)'
Mit ein bisschen Beiwerk sieht der reguläre Ausdruck am Ende so aus:
^([0-9]{4}-[0-9]{2}-[0-9]{2} [0-9]{2}:[0-9]{2}:[0-9]{2}).*channel '(.*?)'\(id:10\) edited by '(.*?)'\(id:.*$
Anmerkung
Diese regulären Ausdrücke fallen mir auch nicht einfach so aus dem Ärmel. Es ist immer einiges an Aufwand zu Probieren und zu Experimentieren, bis man einen passenden Ausdruck gefunden hat. Man kann die Ausdrücke am besten Lernen, indem man ausprobiert. Eine schöne Lernwebsite dafür gibt es hier: https://regexone.com/.
Dieser Ausdruck ist der Such-Teil aus Suchen und Ersetzen.
Mit den runden Klammern (wenn kein Backslash \
davor steht) werden jeweils die interessanten Daten aus der Zeile gesucht.
Wir ersetzen die ganze Zeile jetzt gegen einen anderen Ausdruck:
\1\t\3\t\2
Zuerst wird der erste Klammerausdruck \1
eingesetzt: der Zeitstempel.
Anschließend folgt ein Tabulator-Zeichen \t
, um die Infos voneinander zu trennen.
Darauf folgt der Autor des neuen Namens \3
, weil der Autor im Such-Ausdruck in der dritten Klammer steckte, wieder gefolgt von einem Tab \t
.
Zuletzt kommt der neue Name des Channels aus der zweiten Klammer \2
.
Wenn wir so den Filter und unsere Formatierung auf unsere Logzeilen loslassen, kommt folgendes als Ergebnis dabei raus:
2017-06-07 16:10:35 danouki Chat Corner 2 - mit okayem Wetter
2017-06-07 16:53:33 ozzyfant Chat Corner 2 - mit Schietwetter
2017-06-07 16:53:50 danouki Chat Corner 2 - mit Schietwetter
2017-06-09 19:23:35 ozzyfant Chat Corner 2 - nich mehr s Schietwetter
2017-06-09 19:24:00 ozzyfant Chat Corner 2 - ohne Schietwetter
2017-06-22 15:57:35 ozzyfant Chat Corner 2 - noch Schietwetter
2017-06-22 15:57:38 ozzyfant Chat Corner 2 - noch ohne Schietwetter
Dabei fallen mir zwei Sachen auf:
- Die Formatierung ist noch ziemlich blöd und die Spalten passen nicht aufeinander. Das liegt daran, dass die Spalten zwar mit dem Tabulator ausgerichtet sind, aber der Tabulator immer in Abständen von (in diesem Fall) acht Zeichen arbeitet. Weil der Name ozzyfant schon acht Zeichen lang ist, wird zur nächsten Spalte acht Zeichen weiter rechts gesprungen.
- Teilweise wurde der Channel zwischen diesen Zeilen gar nicht umbenannt. Für den 2017-06-07 sind zwei Einträge da, bei denen der Channel jeweils den selben Namen hat: Chat Corner 2 - mit Schietwetter.
Zunächst sollten wir aber sichergehen, dass die Einträge in der richtigen Reihenfolge sind. Im Beispiel oben ist das der Fall, aber wir sollten auf Nummer Sicher gehen.
Sortieren der Protokollzeilen
Zum Sortieren gibt es in Linux das Programm sort. In unserem Fall soll sort aber nur nach dem Zeitstempel sortieren. Wir müssen sort deswegen sagen, wie es den Zeitstempel vom Rest der Zeile unterscheiden kann:
sort -t\t -k1,1
Wir geben sort zwei Argumente mit, die aussagen, wie sortiert werden soll:
-t\t
- Wie werden Spalten voneinander getrennt? Das Trennzeichen ist der Tabulator
\t
. -k1,1
- Nach welchen Spalten soll ich sortieren? Für die Sortieren sollen die Spalten 1 bis 1 benutzt werden, also nur Spalte 1.
Mit diesen Argumenten betrachtet sort nur die erste Spalte mit den Zeitstempeln. Da die Zeitstempel schon als Jahr-Monat-Tag aufgeschrieben sind, kann sort einfach nach aufsteigender Zahlenreihenfolge sortieren.
Doppelte Einträge entfernen
Nachdem wir mit sort unsere Liste sortiert haben, müssen nun noch alle doppelten Einträge entfernt werden. Zu den doppelten Einträgen kommt es, weil wir im ersten Schritt unsere Logdateien nicht darauf gefiltert haben, ob der Channel umbenannt wurde, sondern nur, ob er geändert wurde. Eine Änderung kann aber auch etwas anderes sein, z. B. eine geänderte Channel-Beschreibung. Solche doppelten Zeilen müssen wir aus herausfiltern.
Unter Linux gibt es dafür das Programm uniq. uniq entfernt aus einer Liste alle doppelten Einträge, die direkt aufeinander folgen. Wenn Einträge zwar doppelt sind, aber nicht direkt nebeneinander stehen, dann bleiben sie bestehen. Das passt wunderbar auf unseren Fall, denn ich möchte nur doppelte Channelnamen entfernen, wenn diese aufeinander folgen.
Wir müssen uniq allerdings noch sagen, dass es sich nur mit dem Channelnamen auseinander setzen soll.
uniq hat dafür das Argument -f
, das wie folgt beschrieben ist: „avoid comparing the first N fields […]
A field is a run of blanks (usually spaces and/or TABs), then non-blank characters“.
Da uniq keine Unterscheidung zwischen Leerschritten (spaces) und Tabulatoren (TABs) macht, müssen wir drei Felder überspringen: Das Datum gefolgt vom Leerschritt: die Uhrzeit gefolgt vom Tab; den Autoren gefolgt vom Tab.
Unser uniq-Befehl sieht damit so aus:
uniq -f 3
Ausgabe verschönern
Wir haben jetzt alle Daten da, die wir brauchen. Als letztes möchte ich die Ausgabe noch etwas verschönern und dafür sorgen, dass die Spalten in der Ausgabe schön aussehen. Für die Ausrichtung der Spalten gibt es das Programm column. Diesem Programm können wir sagen, dass es die Spalten anhand des Tabulators ausrichten soll:
column -t -s $'\t'
Das Tabulatorzeichen muss ich dabei escapen durch $'\t'
, damit es wirklich als Tabulatorzeichen erkannt wird3.
Alles zusammenführen
Wie bekomme ich es jetzt aber hin, dass alle hier genannten Befehle zusammenarbeiten? In der Linux-Kommandozeile gibt es das Werkzeug der Pipe. Die Pipe nimmt die Ausgabe eines Befehls und leitet sie als Eingabe in den nächsten Befehl. Wir nehmen also jeweils das Ergebnis von einem Teilschritt und geben es an den nächsten Teilschritt weiter.
In der Kommandozeile wird das mit dem Pipe-Symbol |
gemacht.
Der fertige Befehl sieht dann wie folgt aus2:
grep "'(id:10) edited by '" \
/var/teamspeak/data/logs/ts3server_*_1.log -h \
| sed -re \
"s/^([0-9]{4}-[0-9]{2}-[0-9]{2} [0-9]{2}:[0-9]{2}:[0-9]{2}).*channel '(.*?)'\(id:10\) edited by '(.*?)'\(id:.*$/\1\t\3\t\2/" \
| sort -t\t -k1,1 \
| uniq -f 3
-
Siehe http://www.gnu.org/software/grep/manual/html_node/Usage.html, Punkt 15 (abgerufen 2020-04-15) ↩
-
Die Backslashes
\
am Ende der Zeilen in Bash zeigen an, dass der Befehl in der nächsten Zeile weiter geht. So kann ich es besser darstellen und formatieren. Der Befehl wird behandelt, als ob er ohne den Zeilenumbruch einfach weiter geht. ↩ ↩2 -
Da bin ich auch nicht drauf gekommen. Ich habe aber Hilfe bei Stack Exchange gefunden. ↩