1. Levels: Nicht alles auf info
Wenn du jemals „alles auf info“ geschrieben hast, hast du bereits fast dein eigenes Literaturgenre erschaffen: einen Log-Roman in 12 Bänden, den niemand liest. Logging-Levels sind nicht „für die Schönheit“ da und nicht, weil es die Erwachsenen so machen – sie sind notwendig, um das Rauschen zu kontrollieren und schnell das Wichtige zu finden, wenn die Anwendung sich seltsam verhält.
Der Logging-Stack ist bereits vorhanden. Jetzt ist es wichtig, ihn nicht in einen neuen println zu verwandeln, der nur etwas hübscher schreibt.
Der praktischste Gedanke hier ist: Du verteilst die Logs einmal nach Levels im Code, und dann entscheidest du per Konfiguration, wie viele Details angezeigt werden. Bei einem normalen Start (root level = INFO) siehst du die Schlüsselereignisse. Wenn etwas „nach Rauch riecht“, schaltest du DEBUG nur für das benötigte Package ein (z.B. catalog) – und erhältst Details, ohne das Log in eine Maschinengewehr-Salve aus Zeilen zu verwandeln.
2. Die „Lautstärke“-Skala der Levels
Es ist praktisch, sich Levels als „Lautstärke“ und „Dringlichkeit“ einer Nachricht vorzustellen. DEBUG – das sind Details für den Entwickler, der gerade ein Problem untersucht. INFO – der normale Lebenslauf der Anwendung. WARN – die Anwendung ist nicht abgestürzt, aber etwas läuft nicht richtig (oder wird es bald tun). ERROR – die versprochene Operation ist fehlgeschlagen, und das ist nicht mehr nur „interessant“, sondern muss untersucht werden.
Unten steht eine kurze Tabelle, die man sich als „Bedeutungs-Spickzettel“ merken sollte, nicht als Dogma:
| Level | Frage, die das Log beantwortet | Typischer Leser | Ungefähre Tonalität |
|---|---|---|---|
| DEBUG | „Wie genau haben wir das intern gemacht?“ | Entwickler während der Untersuchung | „Hier die Details, aber keine Panik“ |
| INFO | „Was macht die Anwendung gerade?“ | Entwickler, Support, Sie in einer Woche | „Normaler Lebenszyklus“ |
| WARN | „Was Seltsames ist passiert, aber wir haben überlebt?“ | Sie als zukünftiger On-Call (wenn auch nur Übungsmodus) | „Verdächtig, schau genauer hin“ |
| ERROR | „Was ist kaputt gegangen und warum wurde die Operation nicht ausgeführt?“ | derjenige, der reparieren wird | „Das ist bereits ein Problem“ |
Und wenn du es ganz kurz haben willst – hier eine Mini-Entscheidungshilfe im Diagramm (nicht perfekt, aber sie rettet deinen Verstand, wenn du unsicher bist):
flowchart TD
A["Ereignis in der Anwendung"] --> B{"Sind das interne Details (Schritte, Berechnungen, Vorbereitung)?"}
B -->|Ja| D[DEBUG]
B -->|Nein| C{"Operation nicht ausgeführt (Versprechen nicht erfüllt)?"}
C -->|Ja| E[ERROR]
C -->|Nein| F{"Liegt eine Degradation/Verdacht vor, aber die Anwendung läuft weiter?"}
F -->|Ja| G[WARN]
F -->|Nein| H[INFO]
3. DEBUG: Modus „Detektiv“
DEBUG ist der Level, auf den du die interne Küche legst: Parameter, Zwischenschritte, Vorbereitung von Anfragen, Entscheidungen „warum dieser Weg gewählt wurde“, Konfigurationswerte (falls sie sicher sind) sowie kurze Zusammenfassungen dessen, was bei internen Umwandlungen herausgekommen ist. Wichtig: DEBUG sollte fast nie die einzige Quelle der Bedeutung sein. Wenn ein Ereignis an sich wichtig ist, gehört es auf INFO oder höher.
Im ReadLater Starter ist es sehr naheliegend, DEBUG für die Client-Phase zu verwenden: Wir bauen URIs, setzen Timeouts, wählen den real/mock-Modus. All das ist nützlich zu sehen, nur wenn wir ein Problem untersuchen, nicht bei jedem Start.
Beispiel: Du baust eine URI für die Katalogsuche. Den Benutzer interessiert das gar nicht, aber für dich ist es beim Debuggen hilfreich.
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import java.net.URI;
public class CatalogUriTrace {
private static final Logger log = LoggerFactory.getLogger(CatalogUriTrace.class);
public void logSearchUri(URI uri) {
// Angenommen, die URI wurde bereits korrekt an anderer Stelle zusammengestellt.
log.debug("Prepared catalog search URI: {}", uri);
}
}
Beachte: Selbst wenn du dieses debug für immer im Code lässt, wird es bei root level = INFO einfach nicht in der Ausgabe erscheinen. Das heißt, du machst das Leben nicht zur Qual „entweder ohne Logs oder mit sehr vielen Logs“.
Ein weiteres typisches Detail für DEBUG ist die Wahl des Arbeitsmodus, weil das „interne Logik der Anwendung“ ist, aber dennoch wichtig für die Diagnose. Erinnere dich, wie traurig es ist, den Grund zu suchen „warum ich immer dasselbe JSON bekomme“, wenn die Anwendung stillschweigend auf mock umgeschaltet hat.
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class CatalogModeResolver {
private static final Logger log = LoggerFactory.getLogger(CatalogModeResolver.class);
public String resolve(String configuredMode) {
// Normalisiere die eingehende Konfiguration: dies ist interne Logik, daher DEBUG
String mode = (configuredMode == null || configuredMode.isBlank()) ? "real" : configuredMode;
// Wichtig zu sehen, welcher Modus tatsächlich gewählt wurde (besonders wenn plötzlich Mock aktiviert wurde)
log.debug("Catalog mode resolved: {}", mode);
return mode;
}
}
Und noch eine kleine, aber nützliche Nuance. Wenn du in DEBUG etwas „Teures“ schreiben willst (z.B. ein großes Objekt für eine hübsche Zeile serialisieren), solltest du das nicht immer tun. Prüfe zuerst, ob DEBUG aktiviert ist. In einem Übungsprojekt ist das selten, aber das Prinzip sollte man kennen.
// Wenn die Nachrichtenerstellung teuer ist – prüfen wir zuerst den Level
if (log.isDebugEnabled()) {
log.debug("Search query length={}", query.length());
}
4. INFO: Schlüsselereignisse
INFO ist dein „Tagebuch des Anwendungslebens“. Nicht „jeder Atemzug und jedes Ausatmen“, sondern Schlüsselereignisse, die helfen zu verstehen: Die Anwendung wurde gestartet, der Modus wurde gewählt, die Operation hat begonnen, die Operation wurde abgeschlossen, das Ergebnis wurde erhalten. Stell dir vor, du öffnest diese Logs in einer Woche und versuchst dich zu erinnern, was überhaupt passiert ist. Wenn es anhand von INFO unmöglich ist, die Geschichte in groben Zügen nachzuvollziehen – dann hast du INFO entweder zu sparsam oder zu chaotisch eingesetzt.
Für den ReadLater Starter drängen sich typische INFO-Ereignisse geradezu auf: Start der Anwendung, gewählter Befehl, Start der Operation catalog search/catalog details, Ergebnis der Operation (wie viele gefunden, erfolgreich), und in Zukunft – Start des Server-Modus und Port. Keine Mikromechanik – nur das „Skelett“ des Verhaltens.
Beispiel: Wir loggen den Start der Anwendung und den Startbefehl. Das ist klassisches INFO.
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class ReadLaterApplication {
private static final Logger log = LoggerFactory.getLogger(ReadLaterApplication.class);
public void run(String mode) {
// Schlüsselereignis des Anwendungslebenszyklus – INFO
log.info("Application started in mode {}", mode);
// weiter geht's mit der Verteilung nach Modi
}
}
Beispiel: INFO im Katalogservice. Wir wollen sehen, dass die Suche gestartet wurde und wie sie endete.
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import java.util.List;
public class CatalogService {
private static final Logger log = LoggerFactory.getLogger(CatalogService.class);
public List<String> searchTitles(String query) {
// Start der Operation – ein wichtiges Ereignis, daher INFO
log.info("Catalog search started, query={}", query);
// Hier würde im echten Code der Client-Aufruf stehen
List<String> titles = List.of();
// Abschluss der Operation und kurze Zusammenfassung – ebenfalls INFO
log.info("Catalog search completed, found={}", titles.size());
return titles;
}
}
Hier ein wichtiger Gedanke: INFO muss nicht „fröhlich“ sein. Es beschreibt eine Tatsache. Ein leeres Suchergebnis ist keine Katastrophe, sondern eine normale Geschäftssituation. Daher kann eine Nachricht wie „No books found“ durchaus auf INFO leben, besonders wenn sie zum Verständnis des Verhaltens nützlich ist.
Um die Idee „Level = Filter“ zu festigen, kann man sich vorstellen, wie die Ausgabe aussieht, wenn root = INFO und das catalog-Package manchmal auf DEBUG gesetzt wird. Zum Beispiel:
12:10:03 INFO ReadLaterApplication - Application started in mode catalog search
12:10:03 INFO CatalogService - Catalog search started, query=clean code
12:10:03 INFO CatalogService - Catalog search completed, found=5
Wenn später DEBUG nur für com.example.readlater.catalog aktiviert wird, erscheinen zwischen den INFO-Zeilen Details, aber das Grundgerüst bleibt dennoch auf INFO.
5. WARN: Es riecht nach Rauch
WARN ist der „schmalste“ Level aus diesen vieren, denn hier ist es leicht, in Extreme zu verfallen. Wenn du für jede Kleinigkeit ein warn schreibst – hast du einen ewigen „gelben Alarm“, und dein Gehirn hört auf zu reagieren. Wenn du überhaupt kein warn schreibst – verpasst du frühe Degradationssignale, die oft nützlicher sind als der finale error.
Eine gute praktische Formulierung: WARN ist, wenn die Anwendung weiterarbeitet, aber etwas schlechter, seltsamer oder potenziell gefährlicher geworden ist. In der Client-Phase des ReadLater Starter könnte das eine zu lange Antwortzeit, ein verdächtiger Status, ein seltsamer Konfigurationswert oder das Umschalten in den Fallback-Modus sein. Wichtig: warn sollte nicht zu einer „emotionalen Bewertung des Code-Autors“ werden. Es sollte ein Signal festhalten, das tatsächlich nützlich ist.
Beispiel: Wir haben die Dauer einer Anfrage gemessen und wenn sie über der Schwelle liegt, schreiben wir ein WARN. Die Operation könnte trotzdem erfolgreich abgeschlossen worden sein – daher ist error hier unnötig.
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class DurationWarnings {
private static final Logger log = LoggerFactory.getLogger(DurationWarnings.class);
public void warnIfSlow(long durationMs, long slowThresholdMs) {
// WARN – wenn noch alles läuft, aber eine Degradation vorliegt
if (durationMs > slowThresholdMs) {
log.warn("Catalog response is slow: durationMs={}", durationMs);
}
}
}
Ein weiteres Beispiel für WARN, das gut in unser Projekt passt: Die Konfiguration enthält eine Merkwürdigkeit, aber wir haben einen sicheren Default eingesetzt. Das ist kein Absturz, aber es ist ein wichtiges Signal: „Die Einstellungen sind nicht so, wie wir erwartet haben“.
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class ServerPortParser {
private static final Logger log = LoggerFactory.getLogger(ServerPortParser.class);
public int parseOrDefault(String rawPort) {
try {
// Versuche, die Konfiguration als Zahl zu parsen
return Integer.parseInt(rawPort);
} catch (Exception e) {
// Wir stürzen nicht ab, erfassen aber das Konfigurationsproblem und den gewählten Standardwert
log.warn("Invalid server.port={}, using default 8080", rawPort);
return 8080;
}
}
}
Beachte die Bedeutung: Wir schreiben keinen Stack Trace (das wäre eher error und gehört zur nächsten Vorlesung über Exceptions), aber wir teilen klar mit, dass die Eingabe seltsam war und welche Entscheidung getroffen wurde.
6. ERROR: Versprechen nicht erfüllt
ERROR ist nicht „irgendwas hat mir nicht gefallen“ oder „es lief nicht perfekt“. ERROR ist, wenn die Anwendung versprochen hat, eine Aktion auszuführen (z.B. „eine Suche im Katalog durchführen“) und es nicht geschafft hat, weil eine Exception aufgetreten ist, ein kritischer Fehler, die Unmöglichkeit, Daten zu erhalten, oder eine Verletzung einer grundlegenden Voraussetzung vorliegt. Wenn du anhand von ERROR nicht zumindest den groben Kontext des Problems verstehen kannst – dann ist das Log schlecht geschrieben.
Im ReadLater Starter ist ERROR angebracht, wenn ein externer Aufruf fehlschlägt (Timeout, Nichtverfügbarkeit), wenn JSON nicht geparst werden konnte (Vertrag gebrochen oder wir haben einen Fehler gemacht), oder wenn die Anwendung aufgrund einer kritischen Konfiguration nicht starten kann. Dabei ist wichtig zu bedenken: ERROR ist eine diagnostische Nachricht, kein Text für den Benutzer. Der Benutzer wird „Katalog nicht verfügbar“ sehen, während ERROR den technischen Grund und den Kontext speichert.
Das minimalste und ehrlichste Beispiel für ERROR ist das Loggen einer Exception mit Kontext. Tiefgründig werden wir das in der nächsten Vorlesung besprechen, hier erfassen wir nur die Bedeutung des Levels.
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class CatalogFacade {
private static final Logger log = LoggerFactory.getLogger(CatalogFacade.class);
public void search(String query) {
try {
// Hier würde der echte HTTP-Aufruf stehen
} catch (Exception e) {
// ERROR = Operation fehlgeschlagen: speichere Kontext + Ausnahme
log.error("Catalog search failed, query={}", query, e);
throw e;
}
}
}
Warum ist das ein error? Weil die Operation „Suche“ nicht ausgeführt wurde. Sie ist nicht „langsam“, nicht „fragwürdig“, nicht „leer“ – sie ist kaputtgegangen.
7. Weißes Rauschen und ein wenig Disziplin
Das traurigste Schicksal von Logs ist es, zu „Wetterrauschen“ zu werden: Es ist da, es schreibt etwas, aber man kann nichts daraus erkennen. Das passiert, wenn wir jeden Ausführungsschritt loggen, dasselbe auf verschiedenen Levels duplizieren, Nachrichten ohne Kontext schreiben oder umgekehrt versuchen, in ein einziges Log die halbe Welt unterzubringen. Die Levels helfen genau dabei, Disziplin zu wahren, aber sie allein retten nichts, wenn die Nachrichten sinnlos sind.
Eine nützliche Regel, die Anfänger oft rettet: Ein Fakt – ein Logging-Ort – ein Level. Wenn du bereits auf INFO geschrieben hast, dass „die Suche abgeschlossen ist“, schreib nicht gleich noch zehn INFO-Zeilen „Schritt 1 … Schritt 2 … Schritt 3 …“. Diese Schritte sind Kandidaten für DEBUG. Und wenn die Operation fehlgeschlagen ist und du an einer Stelle ERROR mit Kontext und Exception schreibst – kopiere diesen ERROR nicht noch in drei weiteren Schichten „nur für den Fall“.
Schlechtes Beispiel (rauscht auf INFO, obwohl es Interna sind):
// Interne Schritte auf INFO machen Logs zu weißem Rauschen
log.info("Step 1 started");
log.info("Step 2 started");
log.info("Step 3 started");
Etwas besser, wenn Interna nach DEBUG wandern und INFO für Schlüsselereignisse bleibt:
// INFO – Rahmen der Operation: Start und Ergebnis
log.info("Catalog search started, query={}", query);
// DEBUG – interne Details, die nur bei der Untersuchung benötigt werden
log.debug("Preparing HTTP request");
log.debug("Sending request");
log.info("Catalog search completed, found={}", foundCount);
Und noch eine Hygiene, die direkt mit den Levels zusammenhängt: Mach WARN und ERROR nicht „wegen der Stimmung“. Wenn alles normal ist, dir aber angst ist – das ist kein Grund für warn. Wenn alles nicht ideal, aber erwartbar ist – das ist auch kein Grund für error. In Logs schreiben wir keine Emotionen, sondern diagnostische Tatsachen.
8. Spickzettel der Levels für den ReadLater Starter
Wenn ein Projekt wächst, bekommt es schnell sein eigenes „Ereignis-Vokabular“. Damit du nicht jedes Mal neu entscheiden musst „was wohin gehört“, ist es nützlich, eine kleine Orientierung speziell für unsere Domäne und unsere Startmodi zu fixieren. Wichtig: Das ist nicht die „einzig wahre Lösung“, sondern eine Startdisziplin, damit Logs wie eine Sprache aussehen und nicht wie fünf Dialekte aus fünf Klassen.
Unten steht eine kompakte Tabelle, die für die aktuelle Phase des ReadLater Starter gut geeignet ist (Client-Phase sowie Vorbereitung auf den Server-Modus). Sie greift zukünftigen Vorlesungen über die Anfrageverarbeitung nicht vor, gibt aber bereits einen Stil vor.
| Ereignis im Projekt | Empfohlener Level | Beispielnachricht |
|---|---|---|
| Start der Anwendung und ausgewählter Modus | INFO | |
| Interne Entscheidung/Details (URI, gewählte Timeouts, real/mock-Modus) | DEBUG | |
| Start der Operation (search/details) | INFO | |
| Erfolgreicher Abschluss der Operation | INFO | |
| Leeres Suchergebnis (das ist kein Systemfehler) | INFO | |
| Langsame Antwort / verdächtige Degradation | WARN | |
| Ungültige Konfiguration, aber Standardwert vorhanden | WARN | |
| Operation fehlgeschlagen (Ausnahme, Unmöglichkeit, Aktion auszuführen) | ERROR | |
Wenn du schnell prüfen willst, „ob ich übertrieben habe“, verwende eine ganz einfache Selbstkontrolle. Stell dir vor, root=INFO ist aktiviert. Anhand der Logs sollte klar sein, dass die Anwendung gestartet ist, welchen Befehl sie ausgeführt hat und wie das endete. Und wenn du DEBUG für catalog aktiviert hast – solltest du Details sehen, aber das INFO-Skelett bleibt lesbar.
9. Typische Fehler bei der Level-Auswahl
Fehler Nr. 1: Alles auf info schreiben, weil „dann sehen wir es sicher“.
Ja, du siehst es – aber zusammen damit ertrinkst du in einem Strom von Nachrichten. Wenn jeder Schritt als info markiert ist, hört der Level auf, ein Filter zu sein, und wird zu Rauschen. Am Ende gehen wichtige Ereignisse zwischen technischen Details unter. info ist für Schlüsselereignisse, alles andere sollte in debug landen.
Fehler Nr. 2: Geschäftsergebnis mit Systemfehler verwechseln.
„Nichts gefunden“ ist ein normales Ergebnis, kein error. Wenn du solche Fälle auf Fehler-Level anhebst, erzeugst du das falsche Gefühl, dass das System ständig kaputt ist. Ein Fehler liegt vor, wenn das System seine Arbeit nicht verrichten konnte, nicht, wenn das Ergebnis leer ist.
Fehler Nr. 3: warn zur universellen Kategorie „für alle Fälle“ machen.
Wenn alles Seltsame und „Nichtideale“ in warn landet, verliert dieser Level schnell an Wert. Ein gutes warn ist ein Signal für mögliche Degradation oder verdächtiges Verhalten, das Aufmerksamkeit erfordert. Wenn warn ständig auftritt, wird es falsch verwendet.
Fehler Nr. 4: error ohne Kontext loggen.
Eine Nachricht wie error: failed hat keinen diagnostischen Wert. Es ist wichtig zu verstehen: Was genau ist passiert, bei welcher Operation, mit welchen Eingabedaten. Die Mindestanforderung ist der Operationsname, die wichtigsten Parameter (query, id, url) und die Exception selbst. Ohne das wird error zum Rätsel.
Fehler Nr. 5: Dasselbe Ereignis auf verschiedenen Levels duplizieren.
Wenn derselbe Fakt als warn, dann als error und dann noch einmal irgendwo darüber geloggt wird – verstärkst du das Signal nicht, sondern verwässerst es. Die Logs werden länger, aber nicht verständlicher. Wähle lieber eine Stelle mit maximalem Kontext und logge das Ereignis dort einmal, aber richtig.
GO TO FULL VERSION