Logging mit Monolog in Symfony2: Ein Überblick

Die offiziellen Anlaufpunkte für Monolog & Symfony2 sind:

• Der Kochbuch-Eintrag zum Schreiben von Logs mit Monolog
• Die Monolog Configuration-Reference
• Die Anpassung der Channel-Definition
• Eine Logger-Instanz samt Channel-Name in einen Dienst injecten
• Die Monolog Readme-Datei

Monolog im Überblick

Die wesentlichen Konzepte in Monolog:

• ​Klienten senden Log-Nachrichten an Logger (Interface). Verschiedene Klienten (z. B. Subsysteme einer Anwendung) können getrennte Logger-Instanzen verwenden, die daher auch channels genannt werden. Der Name eines Channel ist der erste Konstruktor-Parameter $name des Loggers.
• Für jede Log-Nachricht erzeugt der Logger einen Record. Dieser wird an alle Handler weitergereicht, die mit dem Logger verbunden sind.
• Handler verarbeiten Records auf unterschiedliche Weise (z. B. Logfiles erzeugen, Syslog, per Mail verschicken, ...)
• Jeder Handler benutzt genau einen Formatter, der den Record in ein (für das Ziel geeignetes) Ausgabeformat konvertiert. Default ist der LineFormatter.
• Sowohl Logger als auch Handler können einen Satz von Processors haben. Alle Records, die den Logger und/oder Handler passieren, werden durch die Processoren geschickt. Der Processor kann den Record verändern; typischerweise fügt er zusätzliche Daten hinzu.

Der Record hat zwei Eigenschaften context und extra :

• context soll Daten zur Nachricht aufnehmen und kommt aus PSR-3. Die Idee ist, dass die Log-Message ähnlich wie ein printf() -Formatstring Platzhalter haben kann, die dann mit Werten aus dem Context aufgefüllt werden können. Einige Handler können so eine bessere Aufbereitung finden, wenn die Nachricht (als fester String) und die Context-Daten (als ereignisbezogene Details) getrennt sind.
• extra sind nicht näher spezifizierte Zusatzinformationen, die v. a. von Processoren ergänzt werden.

Die default-Ausgabeformate ergänzen  context und  extra  als JSON hinter der Log-Message. Oft ist auch nur "[]" für leere Felder zu sehen.

Symfony2-Integration über das MonologBundle

Erzeugung und Injektion der Logger

Eigene Dienste, die mit einem PSR-3-kompatiblen Logger arbeiten sollen, können im Symfony DI-Container zunächst einfach mit dem Dienst logger konfiguriert werden. Das MonologBundle stellt von sich aus immer eine Logger-Instanz als Service mmonolog.logger bereit, die per Alias den logger stellt. Dieser Logger bildet den "app"-Channel.

Über das Attribut channel dieses Tags ist es dabei möglich, den Channel zu wählen. Wird dabei ein Channel-Name anders als das Default " app " angegeben, so

• ... wird eine weiterere Logger-Instanz erzeugt (und injiziert)
• ... diese als Service monolog.logger.[channelname] registriert
• ... und mit dem Channel-Namen versehen.

Wenn nicht - wie in den folgenden Abschnitten beschrieben - Weiteres konfiguriert wird, verarbeiten alle Handler alle Channel (d. h. sie sind als Handler in alle Logger eingefügt).

Getrennte Channels sind sinnvoll, um die Ereignisse verschiedener Subsysteme besser trennen zu können: Bereits der Channel-Name verbessert die Lesbarkeit der Logs. Auch können bei Bedarf anhand der Channels unterschiedliche Handler-Konfigurationen angewendet werden.

Erzeugung der Handler

Die Logger/Channels ergeben sich aus den monolog.logger -Tags, die in den verschiedenen Service-Definitionen "verteilt" (d. h. nicht an einer Stelle zusammen zu sehen) sind.

Im Gegensatz dazu beschreibt die Bundle-Konfiguration des Monolog-Bundle die Handler. Diese werden als Services monolog.handler.[name] angelegt, wobei name dem Abschnitt der Konfiguration entspricht, die den Handler beschreibt.

Gemeinsame Eigenschaften für alle konfigurierbaren Handler-Typen sind u. a.:

• level : Der Log-Level des Handlers, d. h. nur Log-Nachrichten ab (über) diesem Level werden vom Handler verarbeitet.
• formatter : Der Formatter, der von diesem Handler genutzt werden soll
• bubble und priority : Die Priorität kann die Handler in eine Reihenfolge bringen. Bubble steuert dann, ob Records noch an weitere Handler gereicht werden, wenn ein Handler sie verarbeitet hat.
• channels : Siehe folgender Abschnitt.

Zuordnung zwischen Handler und Channel

Normalerweise wird jeder so konfigurierte Handler allen Loggern hinzugefügt, d. h. er verarbeitet die Meldungen aller Channels.

Diese Zuordnung kann aber angepasst werden. Dabei wird je Handler die Liste der relevanten Channels festgelegt, d. h. die Logger, in denen der Handler registriert werden soll.

Erweiterte Log-Daten und Formatter

Der default-Formatter für alle Logger ist der LineFormatter, der vom NormalizerFormatter erbt.

Der NormalizerFormatter traversiert den Monolog-Record einschließlich der extra und context -Daten und wandelt dabei Objekte , DateTime -Instanzen, Resourcen etc. in String-Darstellungen um. Außerdem ist er bei Exceptions in der Lage, die previous -Eigenschaft auszuwerten und so Ketten von Exceptions korrekt zu verarbeiten. Er erzeugt in diesem Fall Stack Traces aller Exceptions hintereinander.

Der LineFormatter überschreibt diese Art der Exception-Normalisierung und gibt stattdessen immer nur die Methode aus, an der jede Exception einer Kette begann. Außerdem erlaubt er die Expansion von Platzhaltern der Form %extra.[name]%  im Format-String gegen die gleichlautende extra -Variable.

Zusammenfassung und gute Praxis

Ein konsequentes und umfassendes Logging ist Voraussetzung dafür, Probleme schnell eingrenzen und nachvollziehen zu können. Symfony2 und Monolog machen das so einfach, dass es keinen guten Grund gibt, es nicht konsequent zu nutzen.

Zum Abschluss noch ein paar Hinweise und Gedanken:

Nested Exceptions

Problematischer Code

try { ... }
catch (ApplikationsspezifischeException $e) {
    throw new Http500OderSoException();
}

Dieser Code hat ein großes Problem: Wer später noch diese Http500OderSoException fangen und hoffentlich protokollieren wird, sieht als Ursprung nur noch den catch -Block. Die gesamte ursprüngliche Exception - der Kern des Problems - ist verloren gegangen.

\Exception hat deshalb eine Eigenschaft (und Konstruktor-Argument) $previous , in dem die vorangegangene Exception $e übergeben werden sollte. Wird die neue Exception später in einem Logging-Kontext übergeben, werden die default-Formatter in Monolog die gesamte Exception-Kette protokollieren, so dass auch das ursprüngliche Problem sichtbar wird.

Eigene Channels, mindestens pro Bundle

Logger lassen sich wie beschrieben mit <tag name="monolog.logger" channel="mein_bundle"/> in einen Symfony2-Service injecten.

Dabei sollte jedes Subsystem oder auch jedes Bundle einen eigenen Logging-Channel verwenden: Das kostet praktisch nicht mehr und erfordert auch keine zusätzliche Handler-Konfiguration. Man gewinnt die bessere Lesbarkeit und kann so später immer noch abweichende Logging-Einstellungen festlegen.

Logging-Kontext statt sprintf

Bei der Übergabe von Log-Nachrichten im Klienten-Code empfehle ich, auf Konstrukte wie

$logger->info(sprintf("I've had %s for %s", $food, $meal))

zu verzichten und stattdessen den PSR-3 Log-Kontext zu verwenden:

$logger->info("I've had {food} for {meal}.", array("food" => $food, "meal" => $meal))

Mit Hilfe des PsrLogMessageProcessor , der auch pro Handler aktiviert werden kann, lassen sich immer noch lesbare Meldungen protokollieren.

Gleichzeitig ist eine "neutrale" Meldung zuzüglich Kontext-Ausgabe machbar, was bei der Weiterverarbeitung in Logfile-Monitoring-Systemen (operational intelligence) praktisch sein kann. Gleichartige Meldungen lassen sich so besser identifizieren, die Kontext-Daten aber für den Einzelfall immer noch zusätzlich darstellen. 

Log-Nachrichten als Konsolenausgabe

Mit Symfony 2.4 ist es einfach möglich, die Log-Nachrichten auch auf die Konsolenausgabe umzuleiten. Dabei kann auch der verbosity-Level der Kommandozeile direkt mit dem Log-Level in Beziehung gesetzt werden. 

Auf diese Weise bleibt die Geschäftslogik frei von Präsentationsaspekten. Trotzdem lassen sich innere Abläufe direkt als (geplante) Ausgabe von Kommandozeilen-Befehlen sichtbar machen.

Erfahren Sie mehr über unsere Leistungen als Symfony Agentur.