Protokollierung

Übersicht

Die Protokollierung wird gerne vernachlässigt, dabei ist eine saubere Buchführung im System in vielen Situationen hilfreich.

Was ist, wenn z.B. ein Dienst versagt, dessen Fehlerausschrift aber eher nichts besagt? Ein lapidarer Ausspruch des Clients wie: »Server antwortet nicht«, lässt die Suche nach dem Fehler überall und nirgends ansetzen. Aber... mit großer Sicherheit finden Sie in einer der Protokolldateien detaillierte Hinweise auf eine mögliche Ursache.

Oder vermuten Sie einen Hacker in Ihrem System? Dann haben Sie hoffentlich alle Anmelde-Vorgänge automatisch notieren lassen? Hacker sind vielleicht keine symphatischen, aber ganz sicher keine dummen Zeitgenossen und haben sie einmal Zugang zum System gefunden, so werden sie alles ihnen Mögliche tun, um ihre Spuren zu verwischen... Und auch dem können Sie durch eine geschickte Protokollierung vorbeugen.

Der Alptraum eines jeden Administrators... Ihre Maschine reagiert nicht mehr! Was den Zustand verursacht hat, steht vielleicht irgendwo geschrieben und Sie sind nach dem Neustart in der Lage, dem Übel nachzugehen...

Dieser Abschnitt erklärt Ihnen die Möglichkeiten, welche Ereignisse Sie in welcher Art und Weise protokollieren können.

Der Syslog-Dämon

Der Syslog-Dämon »syslogd« bietet eine Methode, um Fehler- und/oder Protokollausgaben von Programmen abzufangen und diese nach konkreten Regeln zu verwalten. Daneben existiert der Klog-Dämon »klogd«, der die Syslog-Funktionalität auf die speziellen Belange des Linux-Kernels erweitert. Letzterer ist Dreh- und Angelpunkt eines späteren Abschnitts.

Um die Meldungen beim Systemstart nicht zu versäumen, wird der klogd als erster Dämonen-Prozess überhaupt gestartet, noch bevor der Kernel seine Überprüfung und Initialisierung der Hardware beginnt. Der syslogd wird erst hochgefahren, wenn der Kernel seine »Hausaufgaben« erledigt hat.

Was der Syslogd kann

Letztlich liegt es im Ermessen der Programmierer eines Programmes, inwiefern dieses Mitteilungen über außergewöhnliche Ereignisse erzeugt. Bei Anwendungen, die normalerweise mit der Standardausgabe verbunden arbeiten, ist es durchaus Brauch, auch Fehler auf das Terminal des Benutzers zu senden. Was aber ist mit Prozessen, die keinerlei Ausgaben erzeugen? Dass z.B. ein Dämon seine Probleme jedem Anwender offenbart, kann nicht die Lösung sein. Oder nützt Hans aus Hinterfindmichnicht die Meldung über einen Papierstau des Druckers seines Internet Services Providers etwas, wo er sich doch nur zum Abholen seiner Mails angemeldet hat?

Viele Programme unter Unix greifen deshalb auf den Systemruf syslog() zurück. Dieser Systemruf schreibt nun die Protokollnachricht in das Device »/dev/log« und der syslogd liest aus diesem. »Programme« umfasst hier sowohl Prozesse, als auch Hardwaretreiber oder den Benutzer, der mit Hilfe des Kommandos logger selbst Meldungen einbringen kann. Und wird der syslogd mit der Option -r gestartet, nimmt er auch Meldungen anderer syslogd (über UDP-Port 514) aus dem Netzwerk entgegen.

Abbildung 1: Quellen und Ziele von Protokolldaten

Wohin mit den Meldungen? Das liegt an der jeweiligen Konfiguration. Prinzipiell sind folgende Ziele möglich:

• Die Meldung wird in eine bestimmte Datei geschrieben
• Die Meldung wird auf das Terminal ausgewählter (oder aller) Benutzer geschrieben, insofern sie am System angemeldet sind
• Die Meldung wird zur Behandlung an den syslogd eines anderen Rechners weiter geleitet

Vor allem wenn der lokale syslogd auch Meldungen aus dem Netz entgegen nimmt und diese in lokale Dateien verstreut, nehmen die Daten rasch überhand. Auch heute ist es ein beliebter Angriffspunkt von Hackern, durch Provokation von Fehlermeldungen, die Platten eines Rechners »vollzumüllen« und somit das System in die Knie zu zwingen. Aus diesem Grund enthält jede Protokollnachricht neben dem eigentlichen Text noch eine Herkunft (Typ der Nachricht) und eine Priorität (Dringlichkeit der Nachricht).

Eine Protokollnachricht kann von folgenden Quellen stammen:

Als Dringlichkeit sind möglich:

Die Namensgebung für Herkunft und Priorität in den Tabellen entspricht dabei den möglichen Angaben in der nachfolgend beschriebenen Konfigurationsdatei »/etc/syslog.conf«.

Sicherlich ist mit einer »debug«-Meldung von einem »user« anders zu verfahren als mit einem »alert« vom »kernel«. Letztere ist sichere Kandidatin, um unverzüglich auf der Konsole ausgegeben zu werden. Vielleicht kann der Systemverwalter den drohenden Absturz noch abwenden? Außerdem ist es einen Versuch wert, eine solche kritische Situation auf einem anderen Rechner protokollieren zu lassen, um im Falle des lokalen Crashs noch einen Hinweis auf die Fehlerursache vorzufinden. Mit welcher Meldung letztlich wie verfahren wird, wird in der Datei /etc/syslog.conf festgelegt.

Das Format der Protokolldaten

Der syslogd ergänzt, bevor er die Meldung protokolliert, zu jeder Nachricht weitere Informationen: Zum einen ist dies die Zeit des Eintreffens der Meldung, der Rechnername, von dem die Meldung kam und zum anderen deren Verursacher, also »kernel« bzw. der Name des protokollierenden Programmes. Typische Einträge in den Protokolldateien sehen also wie folgt aus:

Die Zeile »-- MARK --« ist eine interne Meldung vom syslogd selbst, eine Art Zeitstempel, der die Aktivität des Protokollanten bezeugen soll (in der Voreinstellung wird aller 20 Minuten ein Eintrag vorgenommen).

Die Optionen des Syslogd

Der syslogd kommt mit verschiedenen Kommandozeilenoptionen klar. In den meisten Fällen begibt sich das Programm sofort nach Aufruf in den Hintergrund, einzig die Option -d verhindert dies. In Folge dessen wird der Protokollant allerlei Debugmeldungen auf dem Terminal produzieren.

Sollen Meldungen aus dem Netzwerk entgegen genommen werden, ist das Programm mit der Option -r zu starten. Der syslogd verarbeitet jetzt alle Pakete, die am UDP-Port 514 eintreffen.

Die lokalen Meldungen erhält das Programm aus dem Socket »/dev/log«, mit -p socket kann ein alternativer Socket und mit -a socket bis zu 19 zusätzlich zu überwachende Sockets angegeben werden.

Als letzte wichtige Option soll -m Zeit genannt werden, die die Zeit zwischen den Zeitstempeln auf das angegebene Intervall (in Minuten) festlegt. Ein Wert "0" schaltet die Generierung des Zeitstempels ab.

Die Datei /etc/syslog.conf

Dem syslogd muss man genau sagen, was er protokollieren soll. Alles, was nicht explizit in seiner Konfigurationsdatei - der /etc/syslog.conf - benannt wurde, schickt er unbeachtet ins Nirwana.

Eine Zeile der Datei »/etc/syslog.conf«, die nicht mit einem Doppelkreuz beginnt (Kommentar), besteht aus zwei, durch Leerzeichen oder Tabulatoren voneinander getrennten Teilen.
Der zweite, rechts stehende Teil beschreibt das Ziel der Nachricht. Hier kann eine Datei stehen (Protokolldatei, Device-Datei, Pipe) oder der Name eines Rechners, falls die Protokollierung von einem entfernten syslogd erledigt werden soll.
Der erste Teil besteht aus Paaren von Herkunft.Priorität (durch den Punkt getrennt), mehrere solcher Paare können, jeweils durch ein Semikolon getrennt, angegeben werden (es dürfen keine Leerzeichen enthalten sein!).

Jede Priorität ist einem bestimmten Level zugeordnet, wobei die Ordnung gemäß der Anordnung in obiger Tabelle gilt, d.h. die Priorität »debug« besitzt das niedrigste Level und »panic« das höchste. Die Angabe einer Priorität schließt alle Prioritäten höherer Level ein.

Beispiel: Der folgende Eintrag protokolliert alle Meldungen des Mailsystems »mail« mit der Priorität »warn« und höher (also »err«, »crit«, »alert», »emerg«) und des Newssystems »news« mit den Prioritäten »err«, »crit«, »alert« und »emerg« in einer Datei »/var/log/info.log«:

Die Protokollierung in Dateien im Verzeichnis »/var« anzusiedeln, ist der gebräuchliche Weg (Vergleiche Bemerkungen zum Filesystem Hierarchie Standard).

Nun ist es doch nicht immer ideal, mit einer Priorität gleich den ganzen »Schwanz« der übergeordneten Level nach sich zu ziehen. Deswegen existieren vier Modifzierer, mit denen die Angaben ausgeweitet, eingeschränkt, ausgeschlossen oder gar negiert werden können:

• Der Stern »*« darf dabei sowohl für die Herkunft als auch für die Dringlichkeit eingesetzt werden und bewirkt die »Ausweitung« auf alle Quellen bzw. alle Prioritäten
• Um Meldungen einer bestimmten, einzelnen Dringlichkeit zu behandeln, ist der Prioritätsangabe ein Gleichheitszeichen "=" voran zu stellen
• Um Meldungen einer konkreten Herkunft oder Priorität von der Protokollierung auszuschließen, kann das Schlüsselwort none eingesetzt werden
• Und um die Auswahl bestimmter Prioritäten zu negieren oder eine einzelne Herkunft auszuschließen, kann dem Eintrag ein Ausrufezeichen "!" voran gestellt werden

Beispiel: Alle kritischen Meldungen werden in einer einzelnen Datei gesammelt, wobei Nachrichten vom Kernel ausgeschlossen werden sollen (erste Zeile). Des Weiteren wünschen wir alle Prioritäten »alert« und höher dem Systemadministrator und Benutzer »tux« auf dessen Konsolen mitzuteilen (zweite Zeile). In der dritten Zeile sammeln wir alle Nachrichten geringerer Priorität (»warn« und kleiner) in einer extra Datei.

Beispiel: Um alle Meldungen des Mailsystems zu unterdrücken sind zahlreiche Syntaxvarianten möglich:

Beispiel: Es sollen nur die Meldungen des Newssystems protokolliert werden, die mindestens die Priorität »info«, aber höchstens die Priorität »warn« besitzen:

Etwas Schreibarbeit erspart man sich, indem man mehrere Quellen, die mit identischen Prioritäten zu protokollieren sind, per Komma getrennt an die Stelle der Herkunft einsetzt. Im folgenden Beispiel werden die Meldungen der Sicherheitsdienste gleichwertig behandelt und an den syslogd des Rechners »erde« geleitet:

Zwei weitere Varianten zur Angabe des Ziels der Protokollnachricht vervollständigen die Möglichkeiten. Zum einen kann ein einzelner Stern »*« dort stehen (es steht für das Kommando wall), dann erhalten alle aktuell angemeldeten Benutzer die Meldung auf dem Terminal angezeigt. Und zum zweiten darf eine Fifo-Datei als Ziel angegeben werden (ihr ist das Pipe-Zeichen »|« voran zu stellen). Aus einer solchen können beliebige Programme dann lesen. Eine typische Anwendung ist das Programm »xconsole«, das aus der Fifo-Datei »/dev/xconsole« seine Eingaben bezieht. Alle Zielangaben sollen nochmals zusammengefasst dargestellt werden:

Bekanntlich werden modifzierte Dateien im Normalfall nicht sofort auf die Festplatte zurückgeschrieben. Im Sinne der Protokollierung kritischer Situationen entpuppt sich das Vorgehen für unzureichend, da im Falle eines Systemausfalls wichtige Informationen womöglich verloren gehen. Aus diesem Grund kann dem Ziel, insofern es sich um eine Dateiangabe handelt, ein Minus vorangestellt werden, was die sofortige Synchronisation der Datei veranlasst.
Das Beispiel einer vollständigen Datei /etc/syslogd soll den Abschnitt beenden:

Tipp: Vergessen Sie nicht, die Protokolldateien hin und wieder zu sichern und das Original zu leeren, sonst werden sich binnen kürzester Zeit die Megabytes in ihrem /var-Verzeichnis ansammeln. Nach dem Bearbeiten der /etc/syslog.conf ist der syslogd zum Einlesen der neuen Konfiguration zu bewegen:

Der klog-Dämon

In den üblichen Konfigurationen von Linux wird als eine der ersten Aktionen der klogd gestartet (meist unmittelbar im Anschluss an das Mounten des /proc-Dateisystems). Dieser Dämon ist es nun, der die zahlreichen Meldungen, die während des Bootvorganges über den Bildschirm rauschen, veranlasst. Der klogd tut auf den ersten Blick nichts anderes, als wir es vom syslogd her kennen, abgesehen davon, dass er nur die vom Kernel ausgehenden Nachrichten verarbeitet.

In Abhängigkeit ihrer Verfügbarkeit bezieht der klogd seine Informationen aus einer von zwei möglichen Quellen. Sobald der Dämon startet, sucht er das gemountete /proc-Dateisystem. Wird er fündig, ist die dortige Datei /proc/kmsg Quelle der Nachrichten. Existiert das /proc-Dateisystem nicht, erhält der Kernel-Log-Dämon alle Nachrichten über einen Systemruf »sys_syslog()«.

Der wesentliche Unterschied zum syslogd ist die Fähigkeit der weiteren Verarbeitung der Kernelmeldungen. Der Dämon extrahiert zunächst eine enthaltene Priorität (es werden dieselben Level wie beim »syslogd« unterschieden), anhand derer über die weitere Verfahrensweise entschieden wird. Genau das tut der syslogd ebenso... doch der klogd vermag nun aus der Meldung ebenso den Namen der verursachenden Funktion heraus zu lesen. Die Ursache kann somit wesentlich exakter eingegrenzt werden, als es die vielsagenden Ausschriften - wie »Modul xyz verursachte eine allgemeine Schutzverletzung« - vermögen.

Um diese Zuordnung zwischen Adresse und Funktionsname vornehmen zu können, schaut der klogd in einer internen Tabelle nach, die er zu Beginn anhand der Informationen der Datei /boot/System.map (oder, falls sie nicht existiert aus /System.map bzw. /usr/src/linux/System.map) generiert.

In der Voreinstellung des Kernel-Log-Dämons werden alle Meldungen der Priorität »info« und höher auf der Konsole ausgegeben. Auf die Dauer ist es sicherlich sehr ermüdend, Nachrichten vom Mounten eines Dateisystems und vom Laden eines Modules ständig vom Terminal löschen zu müssen. Aus diesem Grund wird der klogd (eigentlich immer) mit der Option -c Levelnummer angewiesen, nur wirklich problematische Situationen den Konsolen zuzuführen. In vielen Distributionen lautet der Aufruf klogd -c 1, so dass der Nutzer nur noch den »letzten« Aufschrei vor dem Systemabsturz miterleben darf.

Neben der Ausgabe auf der Konsole werden alle Nachrichten nach Aufbereitung durch den klogd an den syslogd weiter gereicht, der dann gemäß seiner Regeln diese verarbeitet (in den Protokolldateien erkennt man die Kernelmeldungen anhand der Herkunft "kernel").

Folgende wichtige Optionen steuern den klogd:

Zum Abschluss noch ein praktisches Beispiel der Verwendung des klogd in einem SuSE-System. Wer ein solches vor sich hat, findet eine Datei »/var/log/boot.msg« vor, die genau die während des Bootvorgangs erzeugten Kernelmeldungen enthält. Zu einem späteren Zeitpunkt allerdings erkennt man anhand der Ausgaben des Kommandos ps, dass der klogd mit der Option -c 1 aktiv ist. Wie wurde das realisiert?

Indem als eine der ersten Maßnahmen der klogd im so genannten One-Shot-Mode gestartet wurde, er die bis dahin aufgehäuften Nachrichten verarbeitet, in die Datei schreibt und sich anschließend beendet (der Aufruf dazu lautet "/usr/sbin/klogd -s -o -n -f /var/log/boot.msg"). Später, nachdem die Initialisierung abgeschlossen ist, wird der Dämon erneut als Hintergrundprozess gestartet "klog -c 1".

Logger

Mit dem Kommando logger steht eine Nutzerschnittstelle zum syslogd bereit. Seine Anwendung macht in erster Linie innerhalb von Shellskripten Sinn, wenn diese Fehlermeldungen oder außergewöhnliche Situationen für notierenswert erachten. Es steht jedoch auch dem »normalen« Benutzer zu, mit dem Kommando eine Protokollierung seiner Nachrichten dem syslogd aufzuerlegen.

Die Kommandozeilenoptionen setzen in erster Linie die Parameter der Nachricht:

Wird auf der Kommandozeile keine Nachricht eingegeben, erwartet logger diese von der Standardeingabe (Eingabeende mit [Ctrl]-[D]), sonst wird alles bis zum Zeilenende als Inhalt der Meldung betrachtet.

Einige Beispiele sollen das Thema beenden. Bitte beachten Sie beim Nachvollziehen der Beispiele, dass die tatsächliche Protokollierung von der konkreten Konfiguration des syslogd abhängt.

Logrotate

Die detaillierte Aufzeichnung der Vorgänge im System wirft allerdings auch eine neues Problem auf: »Wohin mit all den Daten?«.

Wenn Sie den unmittelbar nach einer frischen Installation aufgezeichneten Speicherbedarf des Verzeichnisses /var/log mit dem Stand einige Wochen später vergleichen, so werden Sie ein Wachstum von einigen Kilobyte bis zu mehreren hundert Megabyte verzeichnen. Selbst wenn letztere Werte wohl eher auf einem frequentierten Server gemessen werden, so führen auch die kleineren Datenmengen auf ihren privaten Rechner irgendwann zu einer Sättigung der Speicherkapazität der Partition.

Ein Volllaufen einer Partition kann drastische Folgen für die Stabilität Ihres Systems haben. Mitunter ist sogar ein Einfrieren dessen denkbar, was einen Neustart und manuellen Eingriff des Administrators erfordert. Im privaten Kämmerlein hakt man das kleine Ärgernis mit einem Schulterzucken ab, aber einen Ausfall des Webservers wird der Chef wohl wenig erbaulich registrieren...

Besser agieren als reagieren und einer solchen Situation zuvor kommen!

Ein Ausweg aus dem Übel ist die regelmäße Archivierung der Protokolldateien und damit eine Beschränkung ihres Wachstums. Neben der Realisierung der Aufgaben durch per Cronjob gestartete Shellskripte hat das Programm logrotate eine weite Verbreitung erlangt.

Was kann Logrotate?

Wie der Name schon andeutet, »rotiert« das Programm die Protokolldateien. Typisch ist der Aufruf von logrotate über einen Cronjob; die Frequenz hängt vom Datenaufkommen ab und sollte zwischen einmal im Monat und täglich gewählt werden. Darüber hinaus vermag logrotate eine Protokolldatei erst zu bearbeiten, wenn sie eine bestimmte Dateigröße überschritten hat.

logrotate kann die Logdateien komprimieren. Es kann archivierte Dateien löschen oder sie per Mail an einen Administrator versenden. Wird logrotate mehrfach am Tag gestartet, so modifiziert sie eine Logdatei nur, wenn die Option -f angegeben wurde oder die betreffende Datei die maximal zulässige Größe erreicht hat.

Treten bei der Arbeit von logrotate Fehler auf, ist das Kommando in der Lage, eine Nachricht darüber zu versenden.

Wird das Kommando mit der Option -d gerufen, so werden alle Aktionen »simuliert«, die Protokolldateien und die Statusdatei (/var/lib/logrotate.status) aber nicht verändert. Durch -s Datei lässt sich logrotate zur Verwendung einer alternativen Statusdatei überreden.

Die Arbeitsweise von Logrotate lässt sich am einfachsten anhand des Beispiels der Datei /var/log/messages erläutern. Angenommen, die Konfiguration sieht vier Rotationsstufen vor. Auch soll vorerst auf eine Komprimierung verzichtet werden. Nach Ablauf einer bestimmten Zeit - bzw. bei Erreichen einer konkreten Dateigröße - verschiebt logrotate die Datei /var/log/messages nach /var/log/messages.1 und erzeugt eine leere /var/log/messages. Sind die Voraussetzungen für eine weitere Rotation erfüllt, wird aus /var/log/messages.1 /var/log/messages.2, aus /var/log/messages wird /var/log/messages.1 und eine neue leere Datei entsteht. Das Ganze setzt sich fort, bis /var/log/messages.4 verschoben werden soll. Da die Rotation allerdings auf 4 Durchläufe beschränkt wurde, wird diese Datei durch /var/log/messages.3 überschrieben, ohne ihren Inhalt weiterhin zu archivieren.

Zumindest bei der auf Dateigröße basierenden Konfiguration ist somit ein maximaler Speicherverbrauch durch die von logrotate erfassten Protokolldateien garantiert.

Konfiguration von Logrotate

Das Verhalten von logrotate wird üblicherweise durch mehrere Dateien beschrieben. Dabei ist /etc/logrotate.conf der ursprüngliche Anlaufpunkt für Konfigurationen. Diese Datei selbst bindet jedoch die Dateien des Verzeichnisses /etc/logrotate.d/ ein, die zumeist auf einzelne RPM-Pakete zugeschnittene Konfigurationen beinhalten (alternativ werden alle dem Kommando als Argumente übergebenen Dateien als Konfigurationsdateien eingelesen).

Jede Option, die außerhalb der Definition zu einer Protokolldatei steht, ist eine globale Option und gilt für alle Dateien, insofern sie dort nicht wieder überschrieben wird. Eine spätere Bezugnahme auf eine Option überschreibt frühere Zuweisungen. D.h. die Reihenfolge des Einlesens mehrerer Konfigurationsdateien ist durchaus entscheidend für das Ergebnis.

Betrachten wir zunächst eine typische Datei /etc/logrotate.conf:

Für die Datei /var/log/wtmp (»lastlog«) wurden die globalen Werte überschrieben, sodass sie einmal im Monat rotiert wird. Sie wird nur einmal rotiert (es existiert also jeweils nur die Sicherungsdatei des letzten Monats). Und eine leere Datei wird mit den Rechten 644 (ohne Angabe gibt umask diese vor), dem Eigentümer root und der besitzenden Gruppe utmp angelegt.

In den Dateien unter /etc/logrotate.d werden oft die globalen Vorgaben überschrieben:

Das Senden des Signals SIGHUP an den Syslog-Dämon bewirkt, dass dieser all seine offenen Dateideskriptoren schließt, seine Konfigurationsdatei neu einliest und anschließend mit seiner Arbeit fort fährt. Ohne diese Maßnahme wäre der Deskriptor ungültig (da logrotate dem Syslog seine Datei entrissen hat) und das Ergebnis vermutlich fatal. Zwischen den Schlüsselwörtern prerotate...endscript und postrotate...endscript können beliebige Kommandos gestartet werden, die im ersten Fall unmittelbar vor dem Rotieren und in letzterem Fall direkt anschließend ausgeführt werden. Denkbar wären hier Skripte, die die Logdateien scannen und verdächtige Zeilen an den Administrator senden.

Die Angabe von Dateinamen darf Wildcards enthalten! Nachfolgende Konfiguration ist durchaus legitim und meint »alle Dateien des Verzeichnisses«:

Die Optionen für logrotate sind (mit vorangestelltem »no« wird die Bedeutung negiert):