====== Logging in Skripten ======

  * Urspruenglicher Autor: Dirk Deimeke
  * Urspruengliches Datum: 22.07.2011

Wenn Shell-Skripte eine gewisse Groesse bekommen, mehrere systemkritische Operationen ausfuehren oder sogar interaktiv von Benutzern gesteuert werden, ist es sinnvoll, ein eigenes Logfile anlegen zu lassen. Selbstverstaendlich kann man aus einem Shell-Skript heraus mit dem Programm logger Meldungen direkt an den Syslog-Daemon schicken. Oft ist es aber sinnvoller, ein eigenstaendiges Log zur Auswertung zu besitzen.

[[http://www.gossiplabs.org/log4bash.html|log4bash]] bietet genau diese Moeglichkeit. Wenn die bash nicht verwendet wird, lohnt sich ein Blick auf das allgemeinere [[http://freshmeat.net/projects/log4sh|log4sh]].

Die Einfachste Anwendung ist das folgende Kurzskript ''myfirstlog.bash'':

<code bash>#!/bin/bash
source /home/dirk/scripts/log4bash.sh
log4bash 0 Meldung</code>

Durch das Einbinden kann man die Funktion log4bash direkt im Skript aufrufen. Der Aufruf des Skripts erzeugt eine Logdatei, die zum Skriptnamen passt, an die das Datum angehaengt ist und die auf ''.log'' endet. In unserem Beispiel heisst sie also ''myfirst-log.bash.jjjjmmdd.log'', ''wobei jjjjmmdd'' fuer das heutige Datum steht. In dem neu erstellten Log findet sich folgende Meldung: ''2010-11-01 19:09:49.748490329 CET|DEBUG|0|main|meldung''

Die Logeintraege bestehen aus fuenf Elementen:

  * Datum, Uhrzeit und Zeitzone: Nach dem Muster YYYY-MM-DD HH:MM:ss.N Z wird das Datum angegeben.

  * Loglevel: Das Loglevel wird ueber folgende Zahlenwerte angegeben:
<code>0 = DEBUG
1 = INFO
2 = WARN
3 = ERROR
4 = CRITICAL
5 = FATAL</code>

  * Zeilennummer: Ohne Angabe wird die Zeilennummer (wie im Beispiel) auf 0 gesetzt. Diese kann fuer weitere (eigene) Auswertungszwecke beliebig vergeben werden – zum Beispiel in der gleichen Notation wie HTTP-Statuscodes.

  * Funktionsname: Ohne die ebenfalls beliebige Angabe wird als Funktionsname main gesetzt.

  * Meldung: Abschliessend wird die uebergebene Meldung ausgefuehrt.

Entsprechend diesen Elementen kann man log4bash mit mehreren Parametern aufrufen. Der folgende Aufruf wuerde eine Logmeldung der Stufe ''INFO'' mit der Zeilennummer ''20'', dem Funktionsnamen ''Funktion'' und der Meldung ''Meldung'', die aus mehreren Woertern besteht, erstellen.

<code>log4bash 1 "Meldung aus mehreren Woertern" 20 Funktion</code>

Im Log wird dies entsprechend hinterlegt:

<code>2010-11-01 19:29:50.627352792 CET|INFO|20|Funktion|Meldung aus mehreren Woertern</code>

Damit laesst sich ein gut durchsuchbares Basis-Logging realisieren. Das Verhalten von log4bash laesst sich mit den folgenden Variablen beeinflussen.

  * ''L4B_DELIM'': Definiert das Trennzeichen (Default: ''|'')

  * ''L4B_DATE'': Datumskommando (Default: ''date'')

  * ''L4B_DATEFORMAT'': Datumsformat-Spezifikation (Default: ''+%Y-%m-%d %H:%M:%S.%N %Z'')

  * ''L4B_VERBOSE'': Gibt an, ob die Logmeldung auch auf dem Bildschirm ausgegeben werden soll (Default: ''false'')

  * ''L4B_LABEL'': Feld (Array) mit den Logleveln

  * ''L4B_LOGFILE'': Namensgebung der Logdatei (Default: ''&lt;SKRIPT_NAME&gt;.&lt;DATUM&gt;.log'')

  * ''L4B_DEBUGLVL'': Schwellenwert, der angibt, ab wann Meldungen ins Log geschrieben werden (Default: 0 = Alles wird geloggt.)

Das fuehrt zu folgendem Beispiel:

<code bash>#!/bin/bash
source /home/dirk/scripts/log4bash.sh
declare -a L4B_LABEL=(DEBUG INFO WARN ERROR CRITICAL FATAL ENDOFWORLD)
L4B_DEBUGLVL=1
L4B_DELIM=" "
L4B_DATE="date"
L4B_DATEFORMAT="+%Y%m%d-%H%M%S.%N"
L4B_VERBOSE=true
L4B_LOGFILE="skript.log"
log4bash 1 "1. Meldung" 15 Hauptprogramm
L4B_VERBOSE=false
log4bash 0 "2. Meldung" 25 Hauptprogramm
log4bash 1 "3. Meldung" 25 Hauptprogramm</code>

Nach dem Ausfuehren des Skriptes findet sich in der angegebenen Log-Datei ''skript.log'' folgender Inhalt:

<code>20101101-135700.980323531 INFO 15 Hauptprogramm 1. Meldung
20101101-135701.026624750 INFO 25 Hauptprogramm 3. Meldung</code>

Bereits waehrend der Ausfuehrung wurde die erste Meldung auch auf dem Bildschirm ausgegeben. Meldung 3 hingegen findet sich nur im Log wieder, da die Variable ''L4B_VERBOSE'' vor der Verarbeitung auf ''false'' gesetzt wurde. Meldung 2 wurde weder auf dem Bildschirm ausgegeben noch in die Log-Datei geschrieben. Dies ist darauf zurueckzufuehren, dass der zweiten Meldung der Loglevel ''0'' zugewiesen wurde. ueber die Zuweisung der Variable ''L4B_DEBUGLVL'' auf den Wert 1 wurde log4bash angewiesen, nur Logeintraege zu protokollieren, die mindestens dem Loglevel 1 entsprechen.

[[adminstoriesartikel|Zurück zur Uebersicht]]